Bug 198102 - inconsistent lock state, while testing IPv6
Summary: inconsistent lock state, while testing IPv6
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 6
Hardware: i386
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Brian Brock
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2006-07-09 17:47 UTC by Dave Habben
Modified: 2007-11-30 22:11 UTC (History)
1 user (show)

Fixed In Version: kernel-2.6.17-1.2505.fc6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2006-08-02 14:12:22 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Dave Habben 2006-07-09 17:47:10 UTC
Description of problem:
Kernel reported the following while testing some IPv6 commands:
=================================
[ INFO: inconsistent lock state ]
---------------------------------
inconsistent {softirq-on-W} -> {in-softirq-R} usage.
ping6/864 [HC0[0]:SC1[2]:HE1:SE0] takes:
 (&sk->sk_dst_lock){---?}, at: [<c05b0392>] sk_dst_check+0x1b/0xff
{softirq-on-W} state was registered at:
  [<c043c546>] lock_acquire+0x4b/0x6d
  [<c060e2f0>] _write_lock+0x19/0x28
  [<c05e9b64>] ip4_datagram_connect+0x288/0x2e0
  [<c05f1041>] inet_dgram_connect+0x4b/0x55
  [<c05ad846>] sys_connect+0x67/0x84
  [<c05adeb8>] sys_socketcall+0x8c/0x186
  [<c0403f2f>] syscall_call+0x7/0xb
irq event stamp: 1534
hardirqs last  enabled at (1534): [<c042961d>] local_bh_enable_ip+0xc6/0xcf
hardirqs last disabled at (1533): [<c04295b0>] local_bh_enable_ip+0x59/0xcf
softirqs last  enabled at (1526): [<c05b7b2d>] dev_queue_xmit+0x217/0x222
softirqs last disabled at (1527): [<c04065ab>] do_softirq+0x5a/0xbe

other info that might help us debug this:
2 locks held by ping6/864:
 #0:  (sk_lock-AF_INET6){--..}, at: [<e09fbfb0>] rawv6_sendmsg+0x6df/0x9be [ipv6]
 #1:  (slock-AF_INET6){-+..}, at: [<e09fd28e>] icmpv6_rcv+0x309/0x5fb [ipv6]

stack backtrace:
 [<c0405167>] show_trace_log_lvl+0x54/0xfd
 [<c040571e>] show_trace+0xd/0x10
 [<c040583d>] dump_stack+0x19/0x1b
 [<c043a982>] print_usage_bug+0x1ca/0x1d7
 [<c043add1>] mark_lock+0x19f/0x36a
 [<c043ba22>] __lock_acquire+0x3da/0x98d
 [<c043c546>] lock_acquire+0x4b/0x6d
 [<c060e3d2>] _read_lock+0x19/0x28
 [<c05b0392>] sk_dst_check+0x1b/0xff
 [<e09ea349>] ip6_dst_lookup+0x31/0x180 [ipv6]
 [<e09fd2bb>] icmpv6_rcv+0x336/0x5fb [ipv6]
 [<e09eba07>] ip6_input+0x1c7/0x29a [ipv6]
 [<e09ebf6c>] ipv6_rcv+0x1c3/0x213 [ipv6]
 [<c05b5bb0>] netif_receive_skb+0x1fe/0x26b
 [<c05b7854>] process_backlog+0x99/0x15b
 [<c05b7682>] net_rx_action+0xa6/0x1df
 [<c0429809>] __do_softirq+0x78/0xf2
 [<c04065ab>] do_softirq+0x5a/0xbe
 [<c0429533>] local_bh_enable+0xe2/0x106
 [<c05b7b2d>] dev_queue_xmit+0x217/0x222
 [<c05bc3c7>] neigh_resolve_output+0x1d1/0x1fd
 [<e09e9b13>] ip6_output2+0x1ed/0x21b [ipv6]
 [<e09ea2ee>] ip6_output+0x6d0/0x6fa [ipv6]
 [<e09ea755>] ip6_push_pending_frames+0x2bd/0x379 [ipv6]
 [<e09fc1d1>] rawv6_sendmsg+0x900/0x9be [ipv6]
 [<c05f110d>] inet_sendmsg+0x3b/0x48
 [<c05ac5df>] sock_sendmsg+0xe8/0x103
 [<c05ad7a7>] sys_sendto+0xbe/0xdc
 [<c05adf27>] sys_socketcall+0xfb/0x186
 [<c0403f2f>] syscall_call+0x7/0xb


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

How reproducible:
 Have not tried yet

Steps to Reproduce:
 Here are the commands I ran:
  ping6 ::1
  ifconfig
  ping6 fe80::202:55ff:feb7:63a7
  ping6 -I eth0 fe80::202:55ff:feb7:63a7
  ip -6 addr show dev eth0 scope link

Comment 1 Dave Jones 2006-07-12 04:06:03 UTC
should be fixed in tomorrows rawhide push (kernel-2.6.17-1.2375.fc6 or higher).

Comment 2 Dave Habben 2006-07-15 21:00:45 UTC
Still occurring with: 
 kernel-2.6.17-1.2396.fc6

Steps to Reproduce:
 ping6 ::1

Here is the output from dmesg:
=================================
[ INFO: inconsistent lock state ]
---------------------------------
inconsistent {softirq-on-W} -> {in-softirq-R} usage.
ping6/1586 [HC0[0]:SC1[2]:HE1:SE0] takes:
 (&sk->sk_dst_lock){---?}, at: [<c05b1495>] sk_dst_check+0x1b/0xf8
{softirq-on-W} state was registered at:
  [<c043c469>] lock_acquire+0x4b/0x6a
  [<c060f720>] _write_lock+0x19/0x28
  [<c05eae24>] ip4_datagram_connect+0x288/0x2e0
  [<c05f22d7>] inet_dgram_connect+0x4b/0x55
  [<c05ae99a>] sys_connect+0x67/0x84
  [<c05af00c>] sys_socketcall+0x8c/0x186
  [<c0403f8b>] syscall_call+0x7/0xb
irq event stamp: 1594
hardirqs last  enabled at (1594): [<c042905d>] local_bh_enable_ip+0xc6/0xcf
hardirqs last disabled at (1593): [<c0428ff0>] local_bh_enable_ip+0x59/0xcf
softirqs last  enabled at (1586): [<c05b8d50>] dev_queue_xmit+0x22a/0x24e
softirqs last disabled at (1587): [<c0406607>] do_softirq+0x5a/0xbe

other info that might help us debug this:
2 locks held by ping6/1586:
 #0:  (sk_lock-AF_INET6){--..}, at: [<e0a00f3b>] rawv6_sendmsg+0x6f2/0x9b7 [ipv6]
 #1:  (&sk_lock_internal_key){-+..}, at: [<e0a02211>] icmpv6_rcv+0x303/0x5f6 [ipv6]

stack backtrace:
 [<c04051c1>] show_trace_log_lvl+0x54/0xfd
 [<c0405778>] show_trace+0xd/0x10
 [<c0405897>] dump_stack+0x19/0x1b
 [<c043a8b4>] print_usage_bug+0x1ca/0x1d7
 [<c043acfa>] mark_lock+0x196/0x353
 [<c043b938>] __lock_acquire+0x3d7/0x997
 [<c043c469>] lock_acquire+0x4b/0x6a
 [<c060f802>] _read_lock+0x19/0x28
 [<c05b1495>] sk_dst_check+0x1b/0xf8
 [<e09ef348>] ip6_dst_lookup+0x31/0x196 [ipv6]
 [<e0a0223e>] icmpv6_rcv+0x330/0x5f6 [ipv6]
 [<e09f0a33>] ip6_input+0x1c3/0x296 [ipv6]
 [<e09f0f94>] ipv6_rcv+0x1c3/0x213 [ipv6]
 [<c05b6db7>] netif_receive_skb+0x204/0x271
 [<c05b8a64>] process_backlog+0x99/0x15b
 [<c05b8894>] net_rx_action+0xa7/0x1de
 [<c0429249>] __do_softirq+0x78/0xf2
 [<c0406607>] do_softirq+0x5a/0xbe
 [<c0428f73>] local_bh_enable+0xe2/0x106
 [<c05b8d50>] dev_queue_xmit+0x22a/0x24e
 [<c05bd61d>] neigh_resolve_output+0x1cf/0x1fb
 [<e09eeb03>] ip6_output2+0x1ed/0x21b [ipv6]
 [<e09ef2dc>] ip6_output+0x6ce/0x709 [ipv6]
 [<e09ef782>] ip6_push_pending_frames+0x2d5/0x394 [ipv6]
 [<e0a01142>] rawv6_sendmsg+0x8f9/0x9b7 [ipv6]
 [<c05f23a3>] inet_sendmsg+0x3b/0x48
 [<c05ad70a>] sock_sendmsg+0xe8/0x103
 [<c05ae8fb>] sys_sendto+0xbe/0xdc
 [<c05af07b>] sys_socketcall+0xfb/0x186
 [<c0403f8b>] syscall_call+0x7/0xb

Comment 3 Dave Habben 2006-07-31 12:47:30 UTC
Here is the current output with:
 kernel-2.6.17-1.2462.fc6

Steps to Reproduce:
 ping6 ::1
 dmesg

If further backtraces are not useful just let me know.

=================================
[ INFO: inconsistent lock state ]
---------------------------------
inconsistent {softirq-on-W} -> {in-softirq-R} usage.
ping6/1628 [HC0[0]:SC1[2]:HE1:SE0] takes:
 (&sk->sk_dst_lock){---?}, at: [<c05ab98f>] sk_dst_check+0x1b/0xf8
{softirq-on-W} state was registered at:
  [<c043bfd7>] lock_acquire+0x4b/0x6c
  [<c06087e8>] _write_lock+0x19/0x28
  [<c05e4c10>] ip4_datagram_connect+0x284/0x2dc
  [<c05ec09f>] inet_dgram_connect+0x4b/0x55
  [<c05a8f4a>] sys_connect+0x67/0x84
  [<c05a95bc>] sys_socketcall+0x8c/0x186
  [<c0403faf>] syscall_call+0x7/0xb
irq event stamp: 1554
hardirqs last  enabled at (1554): [<c04291f5>] local_bh_enable_ip+0xc6/0xcf
hardirqs last disabled at (1553): [<c0429188>] local_bh_enable_ip+0x59/0xcf
softirqs last  enabled at (1546): [<c05b3169>] dev_queue_xmit+0x22a/0x251
softirqs last disabled at (1547): [<c040662f>] do_softirq+0x5a/0xbe

other info that might help us debug this:
2 locks held by ping6/1628:
 #0:  (sk_lock-AF_INET6){--..}, at: [<e0a0bef3>] rawv6_sendmsg+0x6ed/0x9b2 [ipv6]
 #1:  (&sk_lock_internal_key){-+..}, at: [<e0a0d1c6>] icmpv6_rcv+0x303/0x5f5 [ipv6]

stack backtrace:
 [<c04051ea>] show_trace_log_lvl+0x54/0xfd
 [<c04057a6>] show_trace+0xd/0x10
 [<c04058bf>] dump_stack+0x19/0x1b
 [<c043a422>] print_usage_bug+0x1ca/0x1d7
 [<c043a868>] mark_lock+0x196/0x353
 [<c043b4a6>] __lock_acquire+0x3d7/0x997
 [<c043bfd7>] lock_acquire+0x4b/0x6c
 [<c06088ca>] _read_lock+0x19/0x28
 [<c05ab98f>] sk_dst_check+0x1b/0xf8
 [<e09fa32f>] ip6_dst_lookup+0x31/0x194 [ipv6]
 [<e0a0d1f3>] icmpv6_rcv+0x330/0x5f5 [ipv6]
 [<e09fba1b>] ip6_input+0x1c3/0x296 [ipv6]
 [<e09fbf8b>] ipv6_rcv+0x1d2/0x21f [ipv6]
 [<c05b1300>] netif_receive_skb+0x204/0x271
 [<c05b2c63>] process_backlog+0x99/0xfa
 [<c05b2e46>] net_rx_action+0x9d/0x196
 [<c04293e1>] __do_softirq+0x78/0xf2
 [<c040662f>] do_softirq+0x5a/0xbe
 [<c042910b>] local_bh_enable+0xe2/0x106
 [<c05b3169>] dev_queue_xmit+0x22a/0x251
 [<c05b7a3a>] neigh_resolve_output+0x1cf/0x1fb
 [<e09f9aef>] ip6_output2+0x1ed/0x21b [ipv6]
 [<e09fa2c3>] ip6_output+0x6c9/0x704 [ipv6]
 [<e09fa767>] ip6_push_pending_frames+0x2d5/0x394 [ipv6]
 [<e0a0c0fa>] rawv6_sendmsg+0x8f4/0x9b2 [ipv6]
 [<c05ec16b>] inet_sendmsg+0x3b/0x48
 [<c05a7cba>] sock_sendmsg+0xe8/0x103
 [<c05a8eab>] sys_sendto+0xbe/0xdc
 [<c05a962b>] sys_socketcall+0xfb/0x186
 [<c0403faf>] syscall_call+0x7/0xb

Comment 4 Dave Habben 2006-08-02 14:12:22 UTC
This appears to be fixed and no longer reproducable as of: 
 kernel-2.6.17-1.2505.fc6


Note You need to log in before you can comment on or make changes to this bug.