﻿id	summary	reporter	owner	description	type	status	component	version	resolution	keywords	cc	guest	host
11318	Kernel module vboxdrv : Inconsistent lock state	mako		"Hi all,

the Linux kernel module vboxdrv of Virtualbox 4.2.6 (and also 4.2.4 and 4.2.2) uses an inconsistent lock state.
According to the hint of Thomas Gleixner I enabled the kernel debugging feature ""CONFIG_PROVE_LOCKING"" in a vanilla kernel 3.2.34.
(Please find my kernel config attached).

When loading vboxdrv.ko dmesg shows the following output:

----------- BEGIN dmesg ------------
vboxdrv: Found 4 processor cores.
vboxdrv: fAsync=0 offMin=0x514 offMax=0x57f5

=================================
[ INFO: inconsistent lock state ]
3.2.34-2 #2
---------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
swapper/1/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
 (&(&pThis->Spinlock)->rlock){?.+...}, at: [<f883d7a9>] VBoxHost_RTSpinlockAcquire+0x15/0x24 [vboxdrv]
{HARDIRQ-ON-W} state was registered at:
  [<c104b99a>] __lock_acquire+0x509/0x1337
  [<c104cb3a>] lock_acquire+0x42/0x59
  [<c13204d5>] _raw_spin_lock+0x25/0x34
  [<f883d7b3>] VBoxHost_RTSpinlockAcquire+0x1f/0x24 [vboxdrv]
  [<f883a86f>] VBoxHost_RTMpNotificationRegister+0x36/0x11a [vboxdrv]
  [<f88334f8>] supdrvInitDevExt+0x4f4/0x65c [vboxdrv]
  [<f8869053>] VBoxDrvLinuxInit+0x53/0xcd [vboxdrv]
  [<c100106b>] do_one_initcall+0x6b/0x10c
  [<c1054299>] sys_init_module+0x122f/0x13fa
  [<c1321990>] sysenter_do_call+0x12/0x36
irq event stamp: 146398
hardirqs last  enabled at (146395): [<c1007c3a>] mwait_idle+0x57/0x7c
hardirqs last disabled at (146396): [<c1320f34>] call_function_interrupt+0x28/0x34
softirqs last  enabled at (146398): [<c102e3db>] _local_bh_enable+0xd/0xf
softirqs last disabled at (146397): [<c102e7a8>] irq_enter+0x29/0x4e

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(&(&pThis->Spinlock)->rlock);
  <Interrupt>
    lock(&(&pThis->Spinlock)->rlock);

 *** DEADLOCK ***

no locks held by swapper/1/0.

stack backtrace:
Pid: 0, comm: swapper/1 Tainted: G           O 3.2.34-2 #2
Call Trace:
 [<c131c0bb>] print_usage_bug.part.27+0x1f0/0x1fa
 [<c104b313>] mark_lock+0x334/0x4b2
 [<c104a95b>] ? check_usage_backwards+0xce/0xce
 [<c104b92d>] __lock_acquire+0x49c/0x1337
 [<c104cb3a>] lock_acquire+0x42/0x59
 [<f883d7a9>] ? VBoxHost_RTSpinlockAcquire+0x15/0x24 [vboxdrv]
 [<c1320583>] _raw_spin_lock_irqsave+0x2e/0x3e
 [<f883d7a9>] ? VBoxHost_RTSpinlockAcquire+0x15/0x24 [vboxdrv]
 [<f883d7a9>] VBoxHost_RTSpinlockAcquire+0x15/0x24 [vboxdrv]
 [<f8832d69>] ? supdrvGipMpEventOnline+0x14d/0x14d [vboxdrv]
 [<f8832c77>] supdrvGipMpEventOnline+0x5b/0x14d [vboxdrv]
 [<f8832d69>] ? supdrvGipMpEventOnline+0x14d/0x14d [vboxdrv]
 [<f8832d77>] supdrvGipInitOnCpu+0xe/0x10 [vboxdrv]
 [<f883c688>] rtmpLinuxWrapper+0x22/0x2d [vboxdrv]
 [<f883c666>] ? VBoxHost_RTMpCpuId+0xa/0xa [vboxdrv]
 [<c1051253>] generic_smp_call_function_interrupt+0x6b/0x112
 [<c1014595>] smp_call_function_interrupt+0x20/0x2e
 [<c1320f3b>] call_function_interrupt+0x2f/0x34
 [<c104007b>] ? __run_hrtimer.isra.28+0x33/0x9e
 [<c1007c42>] ? mwait_idle+0x5f/0x7c
 [<c10014c2>] cpu_idle+0x4d/0x76
 [<c14ff2e8>] start_secondary+0x1ab/0x1b2
vboxdrv: TSC mode is 'synchronous', kernel timer mode is 'normal'.
vboxdrv: Successfully loaded version 4.2.6 (interface 0x001a0004).
----------- END dmesg ------------

This behaviour leads likely to the freeze on a RT_PREEMPT system as described in ticket #11286.
[https://www.virtualbox.org/ticket/11286]


"	defect	closed	other	VirtualBox 4.2.6	obsolete			other	Linux
