linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [BUG] INFO: inconsistent lock state
@ 2009-01-06  2:34 Li Zefan
  2009-01-06 10:18 ` Zdenek Kabelac
  2009-01-07 12:13 ` Herbert Xu
  0 siblings, 2 replies; 12+ messages in thread
From: Li Zefan @ 2009-01-06  2:34 UTC (permalink / raw)
  To: David Miller; +Cc: LKML, netdev

I am using Linus' tree, and the top commit is:

commit fe0bdec68b77020281dc814805edfe594ae89e0f
Merge: 099e657... 5af75d8...
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date:   Sun Jan 4 16:32:11 2009 -0800

    Merge branch 'audit.b61' of git://git.kernel.org/pub/scm/linux/kernel/git/viro/audit-current

don't know how I triggered this, and not sure whom to CC, network related?

=================================
[ INFO: inconsistent lock state ]
2.6.28 #483
---------------------------------
inconsistent {softirq-on-W} -> {in-softirq-W} usage.
swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
 (&fbc->lock){-+..}, at: [<c05127a6>] __percpu_counter_add+0x52/0x7a
{softirq-on-W} state was registered at:
  [<c044bcd2>] __lock_acquire+0x539/0x700
  [<c044bef6>] lock_acquire+0x5d/0x7a
  [<c061ca68>] _spin_lock+0x20/0x2f
  [<c05127a6>] __percpu_counter_add+0x52/0x7a
  [<c049d615>] get_empty_filp+0x97/0x135
  [<c04a59c2>] path_lookup_open+0x23/0x7a
  [<c04a5ac0>] do_filp_open+0xa7/0x659
  [<c049af1d>] do_sys_open+0x49/0xbe
  [<c049afde>] sys_open+0x23/0x2b
  [<c040332a>] syscall_call+0x7/0xb
  [<ffffffff>] 0xffffffff
irq event stamp: 3606392
hardirqs last  enabled at (3606392): [<c061ce03>] _spin_unlock_irqrestore+0x3b/0x41
hardirqs last disabled at (3606391): [<c061cd31>] _spin_lock_irqsave+0x14/0x39
softirqs last  enabled at (3606338): [<c0430aef>] __do_softirq+0x135/0x13d
softirqs last disabled at (3606369): [<c0404ab6>] do_softirq+0x6a/0xc0

other info that might help us debug this:
4 locks held by swapper/0:
 #0:  (rcu_read_lock){..--}, at: [<c05c3226>] net_rx_action+0x57/0x194
 #1:  (rcu_read_lock){..--}, at: [<c05c0a7b>] netif_receive_skb+0x123/0x2c3
 #2:  (rcu_read_lock){..--}, at: [<c05da9dc>] ip_local_deliver+0x4b/0x119
 #3:  (slock-AF_INET/1){-+..}, at: [<c05f1eec>] tcp_v4_rcv+0x237/0x50f

stack backtrace:
Pid: 0, comm: swapper Not tainted 2.6.28-mc #483
Call Trace:
 [<c0449246>] print_usage_bug+0x155/0x161
 [<c0449e2e>] mark_lock+0x34b/0x905
 [<c044bc5a>] __lock_acquire+0x4c1/0x700
 [<c044bef6>] lock_acquire+0x5d/0x7a
 [<c05127a6>] ? __percpu_counter_add+0x52/0x7a
 [<c061ca68>] _spin_lock+0x20/0x2f
 [<c05127a6>] ? __percpu_counter_add+0x52/0x7a
 [<c05127a6>] __percpu_counter_add+0x52/0x7a
 [<c05f1403>] tcp_v4_destroy_sock+0x15d/0x165
 [<c05e184b>] inet_csk_destroy_sock+0x8c/0xbd
 [<c05e2a5d>] tcp_done+0x5e/0x61
 [<c05eba12>] tcp_rcv_state_process+0x7b9/0x8ad
 [<c05f1eec>] ? tcp_v4_rcv+0x237/0x50f
 [<c05f0901>] tcp_v4_do_rcv+0x138/0x17d
 [<c05f217d>] tcp_v4_rcv+0x4c8/0x50f
 [<c05daa2d>] ip_local_deliver+0x9c/0x119
 [<c05daeb5>] ip_rcv+0x40b/0x452
 [<c05c0bd5>] netif_receive_skb+0x27d/0x2c3
 [<f83f06f0>] rtl8169_rx_interrupt+0x2de/0x39a [r8169]
 [<f83f1963>] rtl8169_poll+0x34/0x155 [r8169]
 [<c05c3291>] net_rx_action+0xc2/0x194
 [<c0430a44>] __do_softirq+0x8a/0x13d
 [<c04309ba>] ? __do_softirq+0x0/0x13d
 <IRQ>  [<c046891f>] ? handle_fasteoi_irq+0x0/0xb5
 [<c043098c>] ? irq_exit+0x49/0x77
 [<c0404bbf>] ? do_IRQ+0xb3/0xcc
 [<c04038ac>] ? common_interrupt+0x2c/0x34
 [<c044007b>] ? hrtimer_get_next_event+0x55/0xc0
 [<c0408541>] ? mwait_idle+0x41/0x4c
 [<c0401dd0>] ? cpu_idle+0x78/0x91
 [<c0617ad4>] ? start_secondary+0x193/0x198

^ permalink raw reply	[flat|nested] 12+ messages in thread
* [BUG] INFO: inconsistent lock state
@ 2011-09-20  9:16 Srivatsa S. Bhat
  2011-09-26  8:40 ` Paul Bolle
  0 siblings, 1 reply; 12+ messages in thread
From: Srivatsa S. Bhat @ 2011-09-20  9:16 UTC (permalink / raw)
  To: Linux PM mailing list; +Cc: linux-kernel, Rafael J. Wysocki

Hi,

While running kernel compilation along with suspend/resume
tests using the pm_test framework (at the processors level),
lockdep reports inconsistent lock state.
This is with Kernel 3.0.4.

Excerpt of the log:
kernel: [ 8221.176651] Freezing user space processes ... (elapsed 0.01 seconds) done.
kernel: [ 8221.247173] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
kernel: [ 8221.321962] PM: Preallocating image memory... 
kernel: [ 8221.768104] =================================
kernel: [ 8221.806233] [ INFO: inconsistent lock state ]
kernel: [ 8221.842744] 3.0.4 #1
kernel: [ 8221.861076] ---------------------------------
kernel: [ 8221.897583] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
kernel: [ 8221.952270] test_processors/5971 [HC0[0]:SC0[0]:HE1:SE1] takes:
kernel: [ 8222.001872]  (&sb->s_type->i_mutex_key#13){+.+.?.}, at: [<ffffffffa01262ee>] ext4_evict_inode+0x2e/0x3d0 [ext4]
kernel: [ 8222.086774] {RECLAIM_FS-ON-W} state was registered at:
kernel: [ 8222.129821]   [<ffffffff810a6033>] mark_held_locks+0x73/0xa0
kernel: [ 8222.177316]   [<ffffffff810a60ff>] lockdep_trace_alloc+0x9f/0xd0
kernel: [ 8222.227720]   [<ffffffff81164dd6>] kmem_cache_alloc+0x36/0x1f0
kernel: [ 8222.276675]   [<ffffffff81191927>] d_alloc+0x27/0x1d0
kernel: [ 8222.319078]   [<ffffffff811864dd>] d_alloc_and_lookup+0x2d/0x90
kernel: [ 8222.368755]   [<ffffffff81188473>] do_lookup+0x2b3/0x300
kernel: [ 8222.413340]   [<ffffffff8118983f>] link_path_walk+0x18f/0x930
kernel: [ 8222.461564]   [<ffffffff8118a665>] path_lookupat+0x55/0x690
kernel: [ 8222.508330]   [<ffffffff8118acd1>] do_path_lookup+0x31/0xc0
kernel: [ 8222.555098]   [<ffffffff8118b9c9>] user_path_at+0x59/0xa0
kernel: [ 8222.600413]   [<ffffffff8118018c>] vfs_fstatat+0x4c/0x90
kernel: [ 8222.645001]   [<ffffffff811802fb>] vfs_stat+0x1b/0x20
kernel: [ 8222.687397]   [<ffffffff81180324>] sys_newstat+0x24/0x50
kernel: [ 8222.731986]   [<ffffffff8152fa82>] system_call_fastpath+0x16/0x1b
kernel: [ 8222.783119] irq event stamp: 2109279487
kernel: [ 8222.815258] hardirqs last  enabled at (2109279487): [<ffffffff81526fe0>] _raw_spin_unlock_irq+0x30/0x40
kernel: [ 8222.894087] hardirqs last disabled at (2109279486): [<ffffffff8152665f>] _raw_spin_lock_irq+0x1f/0x80
kernel: [ 8222.971464] softirqs last  enabled at (2109279484): [<ffffffff8106ea7c>] __do_softirq+0x14c/0x250
kernel: [ 8223.045929] softirqs last disabled at (2109279461): [<ffffffff81530d3c>] call_softirq+0x1c/0x30
kernel: [ 8223.118941] 
kernel: [ 8223.118942] other info that might help us debug this:
kernel: [ 8223.173776]  Possible unsafe locking scenario:
kernel: [ 8223.173777] 
kernel: [ 8223.223525]        CPU0
kernel: [ 8223.244031]        ----
kernel: [ 8223.264541]   lock(&sb->s_type->i_mutex_key);
kernel: [ 8223.301204]   <Interrupt>
kernel: [ 8223.323168]     lock(&sb->s_type->i_mutex_key);
kernel: [ 8223.361284] 
kernel: [ 8223.361285]  *** DEADLOCK ***
kernel: [ 8223.361285] 
kernel: [ 8223.411172] 5 locks held by test_processors/5971:
kernel: [ 8223.450586]  #0:  (&buffer->mutex){+.+.+.}, at: [<ffffffff811ee0a4>] sysfs_write_file+0x44/0x170
kernel: [ 8223.524561]  #1:  (s_active#79){.+.+.+}, at: [<ffffffff811ee12d>] sysfs_write_file+0xcd/0x170
kernel: [ 8223.596444]  #2:  (pm_mutex){+.+.+.}, at: [<ffffffff810b8a7c>] hibernate+0x1c/0x200
kernel: [ 8223.660968]  #3:  (shrinker_rwsem){++++..}, at: [<ffffffff8112b98d>] shrink_slab+0x3d/0x1b0
kernel: [ 8223.731320]  #4:  (iprune_sem){.+.+.-}, at: [<ffffffff81196cc1>] prune_icache+0x31/0x310
kernel: [ 8223.799493] 
kernel: [ 8223.799493] stack backtrace:
kernel: [ 8223.836149] Pid: 5971, comm: test_processors Not tainted 3.0.4 #1
kernel: [ 8223.887194] Call Trace:
kernel: [ 8223.907706]  [<ffffffff810a5439>] print_usage_bug+0x179/0x180
kernel: [ 8223.955846]  [<ffffffff810a5440>] ? print_usage_bug+0x180/0x180
kernel: [ 8224.005444]  [<ffffffff810a5aae>] mark_lock_irq+0xfe/0x290
kernel: [ 8224.051402]  [<ffffffff810a5d91>] mark_lock+0x151/0x1f0
kernel: [ 8224.095182]  [<ffffffff810a5ef6>] mark_irqflags+0xc6/0x190
kernel: [ 8224.141139]  [<ffffffff810a7624>] __lock_acquire+0x344/0x4f0
kernel: [ 8224.188555]  [<ffffffff810a7e84>] lock_acquire+0xa4/0x130
kernel: [ 8224.233792]  [<ffffffffa01262ee>] ? ext4_evict_inode+0x2e/0x3d0 [ext4]
kernel: [ 8224.288477]  [<ffffffff81524fed>] __mutex_lock_common+0x4d/0x3f0
kernel: [ 8224.338805]  [<ffffffffa01262ee>] ? ext4_evict_inode+0x2e/0x3d0 [ext4]
kernel: [ 8224.393486]  [<ffffffff810a190d>] ? trace_hardirqs_off+0xd/0x10
kernel: [ 8224.443082]  [<ffffffff8109439f>] ? local_clock+0x6f/0x80
kernel: [ 8224.488323]  [<ffffffffa01262ee>] ? ext4_evict_inode+0x2e/0x3d0 [ext4]
kernel: [ 8224.543012]  [<ffffffff810a5865>] ? lock_release_holdtime+0x35/0x180
kernel: [ 8224.596243]  [<ffffffff810a7c99>] ? __lock_release+0x129/0x190
kernel: [ 8224.645122]  [<ffffffff811966d5>] ? evict+0x75/0x180
kernel: [ 8224.686721]  [<ffffffff815254fa>] mutex_lock_nested+0x4a/0x60
kernel: [ 8224.734871]  [<ffffffffa01262ee>] ext4_evict_inode+0x2e/0x3d0 [ext4]
kernel: [ 8224.788104]  [<ffffffff811966e3>] evict+0x83/0x180
kernel: [ 8224.828248]  [<ffffffff81196827>] dispose_list+0x47/0x60
kernel: [ 8224.872752]  [<ffffffff81196de5>] prune_icache+0x155/0x310
kernel: [ 8224.918708]  [<ffffffff81196fe6>] shrink_icache_memory+0x46/0x50
kernel: [ 8224.969034]  [<ffffffff8112ba82>] shrink_slab+0x132/0x1b0
kernel: [ 8225.014268]  [<ffffffff8112db02>] do_try_to_free_pages+0x2d2/0x3c0
kernel: [ 8225.066044]  [<ffffffff8112dcad>] shrink_all_memory+0xbd/0xf0
kernel: [ 8225.114192]  [<ffffffff81136d76>] ? next_online_pgdat+0x26/0x50
kernel: [ 8225.163789]  [<ffffffff810ba6a5>] hibernate_preallocate_memory+0x1e5/0x2a0
kernel: [ 8225.221379]  [<ffffffff810b896d>] hibernation_snapshot+0x8d/0x180
kernel: [ 8225.272424]  [<ffffffff810b8b58>] hibernate+0xf8/0x200
kernel: [ 8225.315476]  [<ffffffff810b6ffc>] state_store+0xec/0x100
kernel: [ 8225.359984]  [<ffffffff8125f8b7>] kobj_attr_store+0x17/0x20
kernel: [ 8225.406670]  [<ffffffff811ee146>] sysfs_write_file+0xe6/0x170
kernel: [ 8225.454809]  [<ffffffff8117afd0>] vfs_write+0xd0/0x1a0
kernel: [ 8225.497856]  [<ffffffff8117b1a4>] sys_write+0x54/0xa0
kernel: [ 8225.540180]  [<ffffffff8152fa82>] system_call_fastpath+0x16/0x1b
kernel: [ 8226.890288] done (allocated 2511433 pages)
kernel: [ 8226.924630] PM: Allocated 10045732 kbytes in 5.54 seconds (1813.30 MB/s)

 
-- 
Regards,
Srivatsa S. Bhat  <srivatsa.bhat@linux.vnet.ibm.com>
Linux Technology Center,
IBM India Systems and Technology Lab

^ permalink raw reply	[flat|nested] 12+ messages in thread
end of thread, other threads:[~2011-09-26  9:51 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2009-01-06  2:34 [BUG] INFO: inconsistent lock state Li Zefan
2009-01-06 10:18 ` Zdenek Kabelac
2009-01-06 10:25   ` Li Zefan
2009-01-06 10:47     ` Zdenek Kabelac
2009-01-06 12:38     ` Zdenek Kabelac
2009-01-07 12:16       ` Herbert Xu
2009-01-06 13:53     ` Zdenek Kabelac
2009-01-07 12:13 ` Herbert Xu
  -- strict thread matches above, loose matches on Subject: below --
2011-09-20  9:16 Srivatsa S. Bhat
2011-09-26  8:40 ` Paul Bolle
2011-09-26  9:34   ` Paul Bolle
2011-09-26  9:51   ` Srivatsa S. Bhat

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).