From mboxrd@z Thu Jan 1 00:00:00 1970 From: kai@gnukai.com (Kai Meyer) Date: Thu, 08 Dec 2011 11:20:03 -0700 Subject: What does inconsistent lock state mean? In-Reply-To: References: <4EDFF49F.3060204@gnukai.com> Message-ID: <4EE0FFD3.3090808@gnukai.com> To: kernelnewbies@lists.kernelnewbies.org List-Id: kernelnewbies.lists.kernelnewbies.org On 12/08/2011 07:47 AM, Srivatsa Bhat wrote: > 2 things: > 1. Documentation/lockdep-design.txt explains the "cryptic lock state > symbols". > 2. Please post the lockdep splat _exactly_ as it appears, and _in full_ > (and without line-wrapping, if possible). Usually lockdep is > intelligent > enough to tell you the possible scenario that would lock up your > system. > That gives a very good clue, in case you find it difficult to make > out what > is wrong from the cryptic symbols. > > Regards, > Srivatsa S. Bhat > > > > > _______________________________________________ > Kernelnewbies mailing list > Kernelnewbies at kernelnewbies.org > http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies Oh, sorry. I suppose I only included things that made any sense to me. If I were to hazard a guess after reading through the design doc, it sounds like there's a problem with the context in which locks are being acquired? That seems odd to me, since I don't get the inconsistent lock state until I'm trying to spin_unlock &sblsnap_snapshot_table[i].sblsnap_lock (which is why I assume it's listed as one that's currently held. Dec 7 15:52:20 dev2 kernel: ================================= Dec 7 15:52:20 dev2 kernel: [ INFO: inconsistent lock state ] Dec 7 15:52:20 dev2 kernel: 2.6.32-220.el6.x86_64.debug #1 Dec 7 15:52:20 dev2 kernel: --------------------------------- Dec 7 15:52:20 dev2 kernel: inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. Dec 7 15:52:20 dev2 kernel: tee/1966 [HC0[0]:SC0[0]:HE1:SE1] takes: Dec 7 15:52:20 dev2 kernel: (&vblk->lock){?.-...}, at: [] sblsnap_snap_now+0x25a/0x2a0 [sblsnap] Dec 7 15:52:20 dev2 kernel: {IN-HARDIRQ-W} state was registered at: Dec 7 15:52:20 dev2 kernel: [] __lock_acquire+0x77a/0x1570 Dec 7 15:52:20 dev2 kernel: [] lock_acquire+0xa4/0x120 Dec 7 15:52:20 dev2 kernel: [] _spin_lock_irqsave+0x55/0xa0 Dec 7 15:52:20 dev2 kernel: [] blk_done+0x2b/0x110 [virtio_blk] Dec 7 15:52:20 dev2 kernel: [] vring_interrupt+0x3c/0xd0 [virtio_ring] Dec 7 15:52:20 dev2 kernel: [] handle_IRQ_event+0x50/0x160 Dec 7 15:52:20 dev2 kernel: [] handle_edge_irq+0xe0/0x170 Dec 7 15:52:20 dev2 kernel: [] handle_irq+0x49/0xa0 Dec 7 15:52:20 dev2 kernel: [] do_IRQ+0x6c/0xf0 Dec 7 15:52:20 dev2 kernel: [] ret_from_intr+0x0/0x16 Dec 7 15:52:20 dev2 kernel: [] default_idle+0x52/0xc0 Dec 7 15:52:20 dev2 kernel: [] cpu_idle+0xbb/0x110 Dec 7 15:52:20 dev2 kernel: [] start_secondary+0x211/0x254 Dec 7 15:52:20 dev2 kernel: irq event stamp: 4699 Dec 7 15:52:20 dev2 kernel: hardirqs last enabled at (4699): [] __kmalloc+0x241/0x330 Dec 7 15:52:20 dev2 kernel: hardirqs last disabled at (4698): [] __kmalloc+0x120/0x330 Dec 7 15:52:20 dev2 kernel: softirqs last enabled at (4696): [] __do_softirq+0x14a/0x200 Dec 7 15:52:20 dev2 kernel: softirqs last disabled at (4681): [] call_softirq+0x1c/0x30 Dec 7 15:52:20 dev2 kernel: Dec 7 15:52:20 dev2 kernel: other info that might help us debug this: Dec 7 15:52:20 dev2 kernel: 1 lock held by tee/1966: Dec 7 15:52:20 dev2 kernel: #0: (&sblsnap_snapshot_table[i].sblsnap_lock){+.+.+.}, at: [] sblsnap_snap_now+0xac/0x2a0 [sblsnap] Dec 7 15:52:20 dev2 kernel: Dec 7 15:52:20 dev2 kernel: stack backtrace: Dec 7 15:52:20 dev2 kernel: Pid: 1966, comm: tee Not tainted 2.6.32-220.el6.x86_64.debug #1 Dec 7 15:52:20 dev2 kernel: Call Trace: Dec 7 15:52:20 dev2 kernel: [] ? print_usage_bug+0x177/0x180 Dec 7 15:52:20 dev2 kernel: [] ? mark_lock+0x35d/0x430 Dec 7 15:52:20 dev2 kernel: [] ? __lock_acquire+0x609/0x1570 Dec 7 15:52:20 dev2 kernel: [] ? trace_hardirqs_off+0xd/0x10 Dec 7 15:52:20 dev2 kernel: [] ? _spin_unlock_irqrestore+0x67/0x80 Dec 7 15:52:20 dev2 kernel: [] ? release_console_sem+0x203/0x250 Dec 7 15:52:20 dev2 kernel: [] ? lock_acquire+0xa4/0x120 Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_snap_now+0x25a/0x2a0 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? _spin_lock+0x36/0x70 Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_snap_now+0x25a/0x2a0 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_snap_now+0x25a/0x2a0 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_patch_blkdev+0x74/0x120 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_get_snapshot+0x1f/0x60 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_create_snapshot+0x69/0x120 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? sblsnap_config_write+0x26b/0x2c0 [sblsnap] Dec 7 15:52:20 dev2 kernel: [] ? proc_file_write+0x73/0xb0 Dec 7 15:52:20 dev2 kernel: [] ? proc_file_write+0x0/0xb0 Dec 7 15:52:20 dev2 kernel: [] ? proc_reg_write+0x85/0xc0 Dec 7 15:52:20 dev2 kernel: [] ? vfs_write+0xb8/0x1a0 Dec 7 15:52:20 dev2 kernel: [] ? audit_syscall_entry+0x272/0x2a0 Dec 7 15:52:20 dev2 kernel: [] ? sys_write+0x51/0x90 Dec 7 15:52:20 dev2 kernel: [] ? system_call_fastpath+0x16/0x1b -------------- next part -------------- An HTML attachment was scrubbed... URL: http://lists.kernelnewbies.org/pipermail/kernelnewbies/attachments/20111208/b711349a/attachment.html