Bug 201560

Summary: INFO: inconsistent lock state - during boot .2528
Product: [Fedora] Fedora Reporter: Tom London <selinux>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED RAWHIDE QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: rawhideCC: wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2006-08-17 13:53:15 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 208089    

Description Tom London 2006-08-07 13:46:23 UTC
Description of problem:
Get this on boot of new kernel:

Aug  7 06:47:44 localhost kernel: [ INFO: inconsistent lock state ]
Aug  7 06:47:44 localhost pcscd: winscard.c:219:SCardConnect() Reader E-Gate 0 0
Not Found
Aug  7 06:47:44 localhost kernel: ---------------------------------
Aug  7 06:47:44 localhost kernel: inconsistent {in-softirq-W} -> {softirq-on-W}
usage.
Aug  7 06:47:44 localhost kernel: ip/2617 [HC0[0]:SC0[0]:HE1:SE1] takes:
Aug  7 06:47:44 localhost kernel:  (&ifa->lock){-+..}, at: [<f90a3836>]
inet6_addr_add+0xf8/0x13e [ipv6]
Aug  7 06:47:44 localhost kernel: {in-softirq-W} state was registered at:
Aug  7 06:47:44 localhost kernel:   [<c043bfb9>] lock_acquire+0x4b/0x6a
Aug  7 06:47:44 localhost kernel:   [<c060f428>] _spin_lock_bh+0x1e/0x2d
Aug  7 06:47:44 localhost kernel:   [<f90a4757>] addrconf_dad_timer+0x3a/0xe2 [ipv6]
Aug  7 06:47:44 localhost pcscd: winscard.c:219:SCardConnect() Reader E-Gate 0 0
Not Found
Aug  7 06:47:44 localhost kernel:   [<c042dbc0>] run_timer_softirq+0x108/0x167
Aug  7 06:47:44 localhost kernel:   [<c04293ab>] __do_softirq+0x78/0xf2
Aug  7 06:47:44 localhost kernel:   [<c0406673>] do_softirq+0x5a/0xbe
Aug  7 06:47:44 localhost kernel: irq event stamp: 3551
Aug  7 06:47:44 localhost kernel: hardirqs last  enabled at (3551): [<c04291bf>]
local_bh_enable_ip+0xc6/0xcf
Aug  7 06:47:45 localhost kernel: hardirqs last disabled at (3549): [<c0429152>]
local_bh_enable_ip+0x59/0xcf
Aug  7 06:47:45 localhost kernel: softirqs last  enabled at (3550): [<f90a09ce>]
ipv6_add_addr+0x210/0x254 [ipv6]
Aug  7 06:47:45 localhost kernel: softirqs last disabled at (3538): [<c060f4f7>]
_read_lock_bh+0xb/0x2d
Aug  7 06:47:45 localhost kernel:
Aug  7 06:47:45 localhost kernel: other info that might help us debug this:
Aug  7 06:47:45 localhost kernel: 1 lock held by ip/2617:
Aug  7 06:47:45 localhost kernel:  #0:  (rtnl_mutex){--..}, at: [<c060e378>]
mutex_lock+0x21/0x24
Aug  7 06:47:45 localhost kernel:
Aug  7 06:47:45 localhost kernel: stack backtrace:
Aug  7 06:47:45 localhost kernel:  [<c04051ee>] show_trace_log_lvl+0x58/0x159
Aug  7 06:47:45 localhost kernel:  [<c04057ea>] show_trace+0xd/0x10
Aug  7 06:47:45 localhost kernel:  [<c0405903>] dump_stack+0x19/0x1b
Aug  7 06:47:45 localhost kernel:  [<c043a402>] print_usage_bug+0x1ca/0x1d7
Aug  7 06:47:45 localhost kernel:  [<c043a8eb>] mark_lock+0x239/0x353
Aug  7 06:47:45 localhost kernel:  [<c043b50a>] __lock_acquire+0x459/0x997
Aug  7 06:47:45 localhost kernel:  [<c043bfb9>] lock_acquire+0x4b/0x6a
Aug  7 06:47:45 localhost kernel:  [<c060f3fb>] _spin_lock+0x19/0x28
Aug  7 06:47:45 localhost kernel:  [<f90a3836>] inet6_addr_add+0xf8/0x13e [ipv6]
Aug  7 06:47:45 localhost kernel:  [<f90a3a39>] inet6_rtm_newaddr+0x1bd/0x1d2 [ipv6]
Aug  7 06:47:45 localhost kernel:  [<c05bf5f3>] rtnetlink_rcv_msg+0x1b3/0x1d6
Aug  7 06:47:45 localhost kernel:  [<c05cae7b>] netlink_run_queue+0x69/0xfe
Aug  7 06:47:45 localhost kernel:  [<c05bf3f6>] rtnetlink_rcv+0x29/0x42
Aug  7 06:47:45 localhost kernel:  [<c05cb308>] netlink_data_ready+0x12/0x50
Aug  7 06:47:45 localhost kernel:  [<c05ca370>] netlink_sendskb+0x1f/0x37
Aug  7 06:47:45 localhost kernel:  [<c05cac49>] netlink_unicast+0x1a1/0x1bb
Aug  7 06:47:45 localhost kernel:  [<c05cb2e9>] netlink_sendmsg+0x275/0x282
Aug  7 06:47:45 localhost kernel:  [<c05ae91a>] sock_sendmsg+0xe8/0x103
Aug  7 06:47:45 localhost kernel:  [<c05af129>] sys_sendmsg+0x14d/0x1a8
Aug  7 06:47:45 localhost kernel:  [<c05b02fb>] sys_socketcall+0x16b/0x186
Aug  7 06:47:45 localhost kernel:  [<c0403faf>] syscall_call+0x7/0xb
Aug  7 06:47:45 localhost kernel: DWARF2 unwinder stuck at syscall_call+0x7/0xb
Aug  7 06:47:45 localhost kernel: Leftover inexact backtrace:
Aug  7 06:47:45 localhost avahi-daemon[2392]: New relevant interface eth0.IPv6
for mDNS.
Aug  7 06:47:45 localhost kernel:  [<c04057ea>] show_trace+0xd/0x10
Aug  7 06:47:45 localhost avahi-daemon[2392]: Joining mDNS multicast group on
interface eth0.IPv6 with address fe80::20a:e4ff:fe3f:8bc4.
Aug  7 06:47:45 localhost kernel:  [<c0405903>] dump_stack+0x19/0x1b
Aug  7 06:47:45 localhost avahi-daemon[2392]: Registering new address record for
fe80::20a:e4ff:fe3f:8bc4 on eth0.
Aug  7 06:47:45 localhost kernel:  [<c043a402>] print_usage_bug+0x1ca/0x1d7
Aug  7 06:47:45 localhost kernel:  [<c043a8eb>] mark_lock+0x239/0x353
Aug  7 06:47:45 localhost kernel:  [<c043b50a>] __lock_acquire+0x459/0x997
Aug  7 06:47:45 localhost kernel:  [<c043bfb9>] lock_acquire+0x4b/0x6a
Aug  7 06:47:45 localhost kernel:  [<c060f3fb>] _spin_lock+0x19/0x28
Aug  7 06:47:45 localhost kernel:  [<f90a3836>] inet6_addr_add+0xf8/0x13e [ipv6]
Aug  7 06:47:45 localhost kernel:  [<f90a3a39>] inet6_rtm_newaddr+0x1bd/0x1d2 [ipv6]
Aug  7 06:47:45 localhost kernel:  [<c05bf5f3>] rtnetlink_rcv_msg+0x1b3/0x1d6
Aug  7 06:47:45 localhost kernel:  [<c05cae7b>] netlink_run_queue+0x69/0xfe
Aug  7 06:47:45 localhost kernel:  [<c05bf3f6>] rtnetlink_rcv+0x29/0x42
Aug  7 06:47:45 localhost kernel:  [<c05cb308>] netlink_data_ready+0x12/0x50
Aug  7 06:47:45 localhost kernel:  [<c05ca370>] netlink_sendskb+0x1f/0x37
Aug  7 06:47:45 localhost kernel:  [<c05cac49>] netlink_unicast+0x1a1/0x1bb
Aug  7 06:47:45 localhost kernel:  [<c05cb2e9>] netlink_sendmsg+0x275/0x282
Aug  7 06:47:45 localhost kernel:  [<c05ae91a>] sock_sendmsg+0xe8/0x103
Aug  7 06:47:45 localhost kernel:  [<c05af129>] sys_sendmsg+0x14d/0x1a8
Aug  7 06:47:45 localhost kernel:  [<c05b02fb>] sys_socketcall+0x16b/0x186
Aug  7 06:47:45 localhost kernel:  [<c0403faf>] syscall_call+0x7/0xb
Aug  7 06:47:47 localhost kernel: [drm] Initialized drm 1.0.1 20051102
Aug  7 06:47:47 localhost kernel: ACPI: PCI Interrupt 0000:00:02.0[A] -> GSI 16
(level, low) -> IRQ 177
Aug  7 06:47:47 localhost kernel: [drm] Initialized i915 1.5.0 20060119 on minor 0
Aug  7 06:48:08 localhost audispd: s == 0


Version-Release number of selected component (if applicable):
kernel-2.6.17-1.2528.fc6

How reproducible:


Steps to Reproduce:
1. boot
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Tom London 2006-08-08 14:31:19 UTC
Got this again with 2.6.17-1.2530.fc6 during boot. Believe this is a similar
traceback:

Aug  8 07:00:46 localhost kernel:
Aug  8 07:00:46 localhost kernel: =================================
Aug  8 07:00:46 localhost kernel: [ INFO: inconsistent lock state ]
Aug  8 07:00:46 localhost kernel: ---------------------------------
Aug  8 07:00:46 localhost kernel: inconsistent {in-softirq-W} -> {softirq-on-W}
usage.
Aug  8 07:00:46 localhost kernel: ip/2663 [HC0[0]:SC0[0]:HE1:SE1] takes:
Aug  8 07:00:46 localhost kernel:  (&ifa->lock){-+..}, at: [<f90a2836>]
inet6_addr_add+0xf8/0x13e [ipv6]
Aug  8 07:00:46 localhost kernel: {in-softirq-W} state was registered at:
Aug  8 07:00:46 localhost kernel:   [<c043bfc5>] lock_acquire+0x4b/0x6a
Aug  8 07:00:46 localhost kernel:   [<c060f460>] _spin_lock_bh+0x1e/0x2d
Aug  8 07:00:46 localhost kernel:   [<f90a3757>] addrconf_dad_timer+0x3a/0xe2 [ipv6]
Aug  8 07:00:46 localhost kernel:   [<c042dbcc>] run_timer_softirq+0x108/0x167
Aug  8 07:00:46 localhost kernel:   [<c04293ab>] __do_softirq+0x78/0xf2
Aug  8 07:00:46 localhost kernel:   [<c0406673>] do_softirq+0x5a/0xbe
Aug  8 07:00:47 localhost kernel: irq event stamp: 3647
Aug  8 07:00:47 localhost kernel: hardirqs last  enabled at (3647): [<c04291bf>]
local_bh_enable_ip+0xc6/0xcf
Aug  8 07:00:47 localhost kernel: hardirqs last disabled at (3645): [<c0429152>]
local_bh_enable_ip+0x59/0xcf
Aug  8 07:00:48 localhost kernel: softirqs last  enabled at (3646): [<f909f9ce>]
ipv6_add_addr+0x210/0x254 [ipv6]
Aug  8 07:00:48 localhost kernel: softirqs last disabled at (3634): [<c060f52f>]
_read_lock_bh+0xb/0x2d
Aug  8 07:00:48 localhost kernel:
Aug  8 07:00:49 localhost kernel: other info that might help us debug this:
Aug  8 07:00:49 localhost kernel: 1 lock held by ip/2663:
Aug  8 07:00:50 localhost kernel:  #0:  (rtnl_mutex){--..}, at: [<c060e3b0>]
mutex_lock+0x21/0x24
Aug  8 07:00:50 localhost kernel:
Aug  8 07:00:50 localhost kernel: stack backtrace:
Aug  8 07:00:51 localhost kernel:  [<c04051ee>] show_trace_log_lvl+0x58/0x159
Aug  8 07:00:51 localhost kernel:  [<c04057ea>] show_trace+0xd/0x10
Aug  8 07:00:52 localhost kernel:  [<c0405903>] dump_stack+0x19/0x1b
Aug  8 07:00:52 localhost kernel:  [<c043a40e>] print_usage_bug+0x1ca/0x1d7
Aug  8 07:00:52 localhost kernel:  [<c043a8f7>] mark_lock+0x239/0x353
Aug  8 07:00:53 localhost kernel:  [<c043b516>] __lock_acquire+0x459/0x997
Aug  8 07:00:53 localhost kernel:  [<c043bfc5>] lock_acquire+0x4b/0x6a
Aug  8 07:00:53 localhost kernel:  [<c060f433>] _spin_lock+0x19/0x28
Aug  8 07:00:54 localhost audispd: s == 0
Aug  8 07:00:54 localhost kernel:  [<f90a2836>] inet6_addr_add+0xf8/0x13e [ipv6]
Aug  8 07:00:54 localhost audispd: s == 0
Aug  8 07:00:55 localhost kernel:  [<f90a2a39>] inet6_rtm_newaddr+0x1bd/0x1d2 [ipv6]
Aug  8 07:00:55 localhost audispd: s == 0
Aug  8 07:00:56 localhost kernel:  [<c05bf613>] rtnetlink_rcv_msg+0x1b3/0x1d6
Aug  8 07:00:57 localhost audispd: s == 0
Aug  8 07:00:57 localhost kernel:  [<c05cae9b>] netlink_run_queue+0x69/0xfe
Aug  8 07:00:58 localhost audispd: s == 0
Aug  8 07:00:58 localhost kernel:  [<c05bf416>] rtnetlink_rcv+0x29/0x42
Aug  8 07:00:59 localhost audispd: s == 0
Aug  8 07:00:59 localhost kernel:  [<c05cb328>] netlink_data_ready+0x12/0x50
Aug  8 07:00:59 localhost gconfd (tbl-2724): starting (version 2.14.0), pid 2724
user 'tbl'
Aug  8 07:01:00 localhost kernel:  [<c05ca390>] netlink_sendskb+0x1f/0x37
Aug  8 07:01:00 localhost gconfd (tbl-2724): Resolved address
"xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration
source at position 0
Aug  8 07:01:01 localhost kernel:  [<c05cac69>] netlink_unicast+0x1a1/0x1bb
Aug  8 07:01:01 localhost audispd: s == 0
Aug  8 07:01:01 localhost gconfd (tbl-2724): Resolved address
"xml:readwrite:/home/tbl/.gconf" to a writable configuration source at position 1
Aug  8 07:01:02 localhost kernel:  [<c05cb309>] netlink_sendmsg+0x275/0x282
Aug  8 07:01:02 localhost audispd: s == 0
Aug  8 07:01:02 localhost gconfd (tbl-2724): Resolved address
"xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source
at position 2
Aug  8 07:01:02 localhost kernel:  [<c05ae93a>] sock_sendmsg+0xe8/0x103
Aug  8 07:01:02 localhost audispd: s == 0
Aug  8 07:01:02 localhost kernel:  [<c05af149>] sys_sendmsg+0x14d/0x1a8
Aug  8 07:01:02 localhost audispd: s == 0
Aug  8 07:01:02 localhost kernel:  [<c05b031b>] sys_socketcall+0x16b/0x186
Aug  8 07:01:02 localhost audispd: s == 0
Aug  8 07:01:02 localhost kernel:  [<c0403faf>] syscall_call+0x7/0xb
Aug  8 07:01:02 localhost audispd: s == 0
Aug  8 07:01:02 localhost kernel: DWARF2 unwinder stuck at syscall_call+0x7/0xb
Aug  8 07:01:02 localhost kernel: Leftover inexact backtrace:
Aug  8 07:01:02 localhost kernel:  [<c04057ea>] show_trace+0xd/0x10
Aug  8 07:01:02 localhost kernel:  [<c0405903>] dump_stack+0x19/0x1b
Aug  8 07:01:03 localhost kernel:  [<c043a40e>] print_usage_bug+0x1ca/0x1d7
Aug  8 07:01:03 localhost kernel:  [<c043a8f7>] mark_lock+0x239/0x353
Aug  8 07:01:03 localhost kernel:  [<c043b516>] __lock_acquire+0x459/0x997
Aug  8 07:01:03 localhost kernel:  [<c043bfc5>] lock_acquire+0x4b/0x6a
Aug  8 07:01:04 localhost kernel:  [<c060f433>] _spin_lock+0x19/0x28
Aug  8 07:01:04 localhost kernel:  [<f90a2836>] inet6_addr_add+0xf8/0x13e [ipv6]
Aug  8 07:01:04 localhost kernel:  [<f90a2a39>] inet6_rtm_newaddr+0x1bd/0x1d2 [ipv6]
Aug  8 07:01:04 localhost kernel:  [<c05bf613>] rtnetlink_rcv_msg+0x1b3/0x1d6
Aug  8 07:01:04 localhost kernel:  [<c05cae9b>] netlink_run_queue+0x69/0xfe
Aug  8 07:01:04 localhost kernel:  [<c05bf416>] rtnetlink_rcv+0x29/0x42
Aug  8 07:01:04 localhost kernel:  [<c05cb328>] netlink_data_ready+0x12/0x50
Aug  8 07:01:04 localhost kernel:  [<c05ca390>] netlink_sendskb+0x1f/0x37
Aug  8 07:01:04 localhost kernel:  [<c05cac69>] netlink_unicast+0x1a1/0x1bb
Aug  8 07:01:04 localhost kernel:  [<c05cb309>] netlink_sendmsg+0x275/0x282
Aug  8 07:01:04 localhost kernel:  [<c05ae93a>] sock_sendmsg+0xe8/0x103
Aug  8 07:01:04 localhost kernel:  [<c05af149>] sys_sendmsg+0x14d/0x1a8
Aug  8 07:01:04 localhost kernel:  [<c05b031b>] sys_socketcall+0x16b/0x186
Aug  8 07:01:04 localhost kernel:  [<c0403faf>] syscall_call+0x7/0xb
Aug  8 07:01:13 localhost gconfd (tbl-2724): Resolved address
"xml:readwrite:/home/tbl/.gconf" to a writable configuration source at position 0
Aug  8 07:01:15 localhost NetworkManager: <information> Updating allowed
wireless network lists.
Aug  8 07:01:57 localhost audispd: s == 0
Aug  8 07:01:58 localhost last message repeated 3 times


Comment 2 Tom London 2006-08-11 13:26:47 UTC
Haven't seen this since 2.6.17-1.2532.fc6