1045481 – inconsistent lock state

Bug 1045481 - inconsistent lock state

Summary: inconsistent lock state

Keywords:
Status:	CLOSED DUPLICATE of bug 1044765
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	kernel
Sub Component:
Version:	rawhide
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	---
Assignee:	Kernel Maintainer List
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2013-12-20 14:44 UTC by Harald Reindl
Modified:	2013-12-20 14:56 UTC (History)
CC List:	5 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2013-12-20 14:56:18 UTC
Type:	Bug
Dependent Products:

Attachments	(Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Description Harald Reindl 2013-12-20 14:44:37 UTC

that looks not good and happens right after first time using yum on a fresh rebooted VMware guest

[  100.806397] =================================
[  100.806424] [ INFO: inconsistent lock state ]
[  100.806452] 3.13.0-0.rc4.git1.1.fc21.x86_64 #1 Tainted: G        W   
[  100.806487] ---------------------------------
[  100.806513] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[  100.806572] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
[  100.806612]  (&(&sk->sk_dst_lock)->rlock){+.?...}, at: [<ffffffff81698873>] __udp4_lib_rcv+0xb73/0xbc0
[  100.806836] {SOFTIRQ-ON-W} state was registered at:
[  100.806865]   [<ffffffff810cf36c>] __lock_acquire+0x5dc/0x1c10
[  100.806916]   [<ffffffff810d1192>] lock_acquire+0xa2/0x1d0
[  100.806962]   [<ffffffff8175e18e>] _raw_spin_lock+0x3e/0x80
[  100.807009]   [<ffffffff81606f58>] sock_setsockopt+0x1f8/0xaf0
[  100.807058]   [<ffffffff816003c6>] SyS_setsockopt+0xb6/0xd0
[  100.807104]   [<ffffffff81768429>] system_call_fastpath+0x16/0x1b
[  100.807154] irq event stamp: 582276
[  100.807177] hardirqs last  enabled at (582276): [<ffffffff8107b201>] local_bh_enable+0x71/0xd0
[  100.807238] hardirqs last disabled at (582275): [<ffffffff8107b1c5>] local_bh_enable+0x35/0xd0
[  100.807329] softirqs last  enabled at (582254): [<ffffffff81079b12>] _local_bh_enable+0x22/0x50
[  100.807484] softirqs last disabled at (582255): [<ffffffff8107b47d>] irq_exit+0xcd/0xe0
[  100.807744] 
other info that might help us debug this:
[  100.807865]  Possible unsafe locking scenario:

[  100.807956]        CPU0
[  100.808004]        ----
[  100.808052]   lock(&(&sk->sk_dst_lock)->rlock);
[  100.808143]   <Interrupt>
[  100.808194]     lock(&(&sk->sk_dst_lock)->rlock);
[  100.808280] 
 *** DEADLOCK ***

[  100.808394] 2 locks held by swapper/0/0:
[  100.808449]  #0:  (rcu_read_lock){.+.+..}, at: [<ffffffff8161bbdb>] __netif_receive_skb_core+0x13b/0xdb0
[  100.808794]  #1:  (rcu_read_lock){.+.+..}, at: [<ffffffff8165fdb3>] ip_local_deliver_finish+0x43/0x460
[  100.808976] 
stack backtrace:
[  100.809060] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    3.13.0-0.rc4.git1.1.fc21.x86_64 #1
[  100.809170] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/31/2013
[  100.809289]  ffffffff825baea0 ffff88002fc039f0 ffffffff8175578d ffffffff81c134c0
[  100.809415]  ffff88002fc03a40 ffffffff817514a6 0000000000000001 ffffffff00000001
[  100.809539]  ffff880000000000 0000000000000006 ffffffff81c134c0 ffffffff810cdc80
[  100.809833] Call Trace:
[  100.809883]  <IRQ>  [<ffffffff8175578d>] dump_stack+0x4d/0x66
[  100.809978]  [<ffffffff817514a6>] print_usage_bug+0x1f4/0x205
[  100.810043]  [<ffffffff810cdc80>] ? check_usage_backwards+0x140/0x140
[  100.810117]  [<ffffffff810ce683>] mark_lock+0x223/0x2b0
[  100.810195]  [<ffffffff810cf319>] __lock_acquire+0x589/0x1c10
[  100.810260]  [<ffffffff8107b201>] ? local_bh_enable+0x71/0xd0
[  100.810328]  [<ffffffff816c6ee7>] ? ipt_do_table+0x317/0x6b0
[  100.810393]  [<ffffffff810b6435>] ? sched_clock_cpu+0xb5/0x100
[  100.810459]  [<ffffffff810219e3>] ? native_sched_clock+0x13/0x80
[  100.810525]  [<ffffffff81021a59>] ? sched_clock+0x9/0x10
[  100.810735]  [<ffffffff810b6435>] ? sched_clock_cpu+0xb5/0x100
[  100.810818]  [<ffffffff810d1192>] lock_acquire+0xa2/0x1d0
[  100.810881]  [<ffffffff81698873>] ? __udp4_lib_rcv+0xb73/0xbc0
[  100.810947]  [<ffffffff8175e18e>] _raw_spin_lock+0x3e/0x80
[  100.811011]  [<ffffffff81698873>] ? __udp4_lib_rcv+0xb73/0xbc0
[  100.811076]  [<ffffffff81698873>] __udp4_lib_rcv+0xb73/0xbc0
[  100.811141]  [<ffffffff8169902a>] udp_rcv+0x1a/0x20
[  100.811202]  [<ffffffff8165feaf>] ip_local_deliver_finish+0x13f/0x460
[  100.811269]  [<ffffffff8165fdb3>] ? ip_local_deliver_finish+0x43/0x460
[  100.811338]  [<ffffffff81660bc8>] ip_local_deliver+0x48/0x80
[  100.811402]  [<ffffffff81660330>] ip_rcv_finish+0x160/0x760
[  100.811467]  [<ffffffff81660e94>] ip_rcv+0x294/0x3d0
[  100.811529]  [<ffffffff8161c492>] __netif_receive_skb_core+0x9f2/0xdb0
[  100.811764]  [<ffffffff8161bbdb>] ? __netif_receive_skb_core+0x13b/0xdb0
[  100.811834]  [<ffffffff8161c868>] __netif_receive_skb+0x18/0x60
[  100.811900]  [<ffffffff8161c8e3>] netif_receive_skb+0x33/0x200
[  100.811965]  [<ffffffff8161de00>] napi_gro_receive+0x80/0xb0
[  100.812031]  [<ffffffffa000f922>] vmxnet3_rq_rx_complete+0x682/0x970 [vmxnet3]
[  100.812103]  [<ffffffffa00101aa>] vmxnet3_poll_rx_only+0x3a/0xb0 [vmxnet3]
[  100.812190]  [<ffffffff810ce902>] ? trace_hardirqs_on_caller+0xb2/0x1d0
[  100.812259]  [<ffffffff8161cf82>] net_rx_action+0x162/0x370
[  100.812323]  [<ffffffff8107ad64>] __do_softirq+0x104/0x430
[  100.812387]  [<ffffffff8107b47d>] irq_exit+0xcd/0xe0
[  100.812450]  [<ffffffff8176a696>] do_IRQ+0x56/0xc0
[  100.812511]  [<ffffffff8175f1b2>] common_interrupt+0x72/0x72
[  100.812575]  <EOI>  [<ffffffff810578d6>] ? native_safe_halt+0x6/0x10
[  100.812848]  [<ffffffff810cea2d>] ? trace_hardirqs_on+0xd/0x10
[  100.812914]  [<ffffffff81022934>] default_idle+0x24/0x250
[  100.812977]  [<ffffffff8102342e>] arch_cpu_idle+0x2e/0x40
[  100.813041]  [<ffffffff810e2d65>] cpu_startup_entry+0xc5/0x420
[  100.813109]  [<ffffffff81749f0d>] rest_init+0x13d/0x150
[  100.813171]  [<ffffffff81749dd5>] ? rest_init+0x5/0x150
[  100.813236]  [<ffffffff81f60f8c>] start_kernel+0x469/0x474
[  100.813300]  [<ffffffff81f6092c>] ? repair_env_string+0x5c/0x5c
[  100.813366]  [<ffffffff81f60120>] ? early_idt_handlers+0x120/0x120
[  100.813435]  [<ffffffff81f605de>] x86_64_start_reservations+0x2a/0x2c
[  100.813505]  [<ffffffff81f6071e>] x86_64_start_kernel+0x13e/0x14d
[root@rawhide ~]# cat messages 
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel: =================================
Dec 20 15:41:11 rawhide kernel: [ INFO: inconsistent lock state ]
Dec 20 15:41:11 rawhide kernel: 3.13.0-0.rc4.git1.1.fc21.x86_64 #1 Tainted: G        W   
Dec 20 15:41:11 rawhide kernel: ---------------------------------
Dec 20 15:41:11 rawhide kernel: inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
Dec 20 15:41:11 rawhide kernel: swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
Dec 20 15:41:11 rawhide kernel: (&(&sk->sk_dst_lock)->rlock){+.?...}, at: [<ffffffff81698873>] __udp4_lib_rcv+0xb73/0xbc0
Dec 20 15:41:11 rawhide kernel: {SOFTIRQ-ON-W} state was registered at:
Dec 20 15:41:11 rawhide kernel:  [<ffffffff810cf36c>] __lock_acquire+0x5dc/0x1c10
Dec 20 15:41:11 rawhide kernel:  [<ffffffff810d1192>] lock_acquire+0xa2/0x1d0
Dec 20 15:41:11 rawhide kernel:  [<ffffffff8175e18e>] _raw_spin_lock+0x3e/0x80
Dec 20 15:41:11 rawhide kernel:  [<ffffffff81606f58>] sock_setsockopt+0x1f8/0xaf0
Dec 20 15:41:11 rawhide kernel:  [<ffffffff816003c6>] SyS_setsockopt+0xb6/0xd0
Dec 20 15:41:11 rawhide kernel:  [<ffffffff81768429>] system_call_fastpath+0x16/0x1b
Dec 20 15:41:11 rawhide kernel: irq event stamp: 582276
Dec 20 15:41:11 rawhide kernel: hardirqs last  enabled at (582276): [<ffffffff8107b201>] local_bh_enable+0x71/0xd0
Dec 20 15:41:11 rawhide kernel: hardirqs last disabled at (582275): [<ffffffff8107b1c5>] local_bh_enable+0x35/0xd0
Dec 20 15:41:11 rawhide kernel: softirqs last  enabled at (582254): [<ffffffff81079b12>] _local_bh_enable+0x22/0x50
Dec 20 15:41:11 rawhide kernel: softirqs last disabled at (582255): [<ffffffff8107b47d>] irq_exit+0xcd/0xe0
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel: other info that might help us debug this:
Dec 20 15:41:11 rawhide kernel: Possible unsafe locking scenario:
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel:       CPU0
Dec 20 15:41:11 rawhide kernel:       ----
Dec 20 15:41:11 rawhide kernel:  lock(&(&sk->sk_dst_lock)->rlock);
Dec 20 15:41:11 rawhide kernel:  <Interrupt>
Dec 20 15:41:11 rawhide kernel:    lock(&(&sk->sk_dst_lock)->rlock);
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel: *** DEADLOCK ***
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel: 2 locks held by swapper/0/0:
Dec 20 15:41:11 rawhide kernel: #0:  (rcu_read_lock){.+.+..}, at: [<ffffffff8161bbdb>] __netif_receive_skb_core+0x13b/0xdb0
Dec 20 15:41:11 rawhide kernel: #1:  (rcu_read_lock){.+.+..}, at: [<ffffffff8165fdb3>] ip_local_deliver_finish+0x43/0x460
Dec 20 15:41:11 rawhide kernel: 
Dec 20 15:41:11 rawhide kernel: stack backtrace:
Dec 20 15:41:11 rawhide kernel: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    3.13.0-0.rc4.git1.1.fc21.x86_64 #1
Dec 20 15:41:11 rawhide kernel: Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/31/2013
Dec 20 15:41:11 rawhide kernel: ffffffff825baea0 ffff88002fc039f0 ffffffff8175578d ffffffff81c134c0
Dec 20 15:41:11 rawhide kernel: ffff88002fc03a40 ffffffff817514a6 0000000000000001 ffffffff00000001
Dec 20 15:41:11 rawhide kernel: ffff880000000000 0000000000000006 ffffffff81c134c0 ffffffff810cdc80
Dec 20 15:41:11 rawhide kernel: Call Trace:
Dec 20 15:41:11 rawhide kernel: <IRQ>  [<ffffffff8175578d>] dump_stack+0x4d/0x66
Dec 20 15:41:11 rawhide kernel: [<ffffffff817514a6>] print_usage_bug+0x1f4/0x205
Dec 20 15:41:11 rawhide kernel: [<ffffffff810cdc80>] ? check_usage_backwards+0x140/0x140
Dec 20 15:41:11 rawhide kernel: [<ffffffff810ce683>] mark_lock+0x223/0x2b0
Dec 20 15:41:11 rawhide kernel: [<ffffffff810cf319>] __lock_acquire+0x589/0x1c10
Dec 20 15:41:11 rawhide kernel: [<ffffffff8107b201>] ? local_bh_enable+0x71/0xd0
Dec 20 15:41:11 rawhide kernel: [<ffffffff816c6ee7>] ? ipt_do_table+0x317/0x6b0
Dec 20 15:41:11 rawhide kernel: [<ffffffff810b6435>] ? sched_clock_cpu+0xb5/0x100
Dec 20 15:41:11 rawhide kernel: [<ffffffff810219e3>] ? native_sched_clock+0x13/0x80
Dec 20 15:41:11 rawhide kernel: [<ffffffff81021a59>] ? sched_clock+0x9/0x10
Dec 20 15:41:11 rawhide kernel: [<ffffffff810b6435>] ? sched_clock_cpu+0xb5/0x100
Dec 20 15:41:11 rawhide kernel: [<ffffffff810d1192>] lock_acquire+0xa2/0x1d0
Dec 20 15:41:11 rawhide kernel: [<ffffffff81698873>] ? __udp4_lib_rcv+0xb73/0xbc0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8175e18e>] _raw_spin_lock+0x3e/0x80
Dec 20 15:41:11 rawhide kernel: [<ffffffff81698873>] ? __udp4_lib_rcv+0xb73/0xbc0
Dec 20 15:41:11 rawhide kernel: [<ffffffff81698873>] __udp4_lib_rcv+0xb73/0xbc0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8169902a>] udp_rcv+0x1a/0x20
Dec 20 15:41:11 rawhide kernel: [<ffffffff8165feaf>] ip_local_deliver_finish+0x13f/0x460
Dec 20 15:41:11 rawhide kernel: [<ffffffff8165fdb3>] ? ip_local_deliver_finish+0x43/0x460
Dec 20 15:41:11 rawhide kernel: [<ffffffff81660bc8>] ip_local_deliver+0x48/0x80
Dec 20 15:41:11 rawhide kernel: [<ffffffff81660330>] ip_rcv_finish+0x160/0x760
Dec 20 15:41:11 rawhide kernel: [<ffffffff81660e94>] ip_rcv+0x294/0x3d0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161c492>] __netif_receive_skb_core+0x9f2/0xdb0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161bbdb>] ? __netif_receive_skb_core+0x13b/0xdb0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161c868>] __netif_receive_skb+0x18/0x60
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161c8e3>] netif_receive_skb+0x33/0x200
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161de00>] napi_gro_receive+0x80/0xb0
Dec 20 15:41:11 rawhide kernel: [<ffffffffa000f922>] vmxnet3_rq_rx_complete+0x682/0x970 [vmxnet3]
Dec 20 15:41:11 rawhide kernel: [<ffffffffa00101aa>] vmxnet3_poll_rx_only+0x3a/0xb0 [vmxnet3]
Dec 20 15:41:11 rawhide kernel: [<ffffffff810ce902>] ? trace_hardirqs_on_caller+0xb2/0x1d0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8161cf82>] net_rx_action+0x162/0x370
Dec 20 15:41:11 rawhide kernel: [<ffffffff8107ad64>] __do_softirq+0x104/0x430
Dec 20 15:41:11 rawhide kernel: [<ffffffff8107b47d>] irq_exit+0xcd/0xe0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8176a696>] do_IRQ+0x56/0xc0
Dec 20 15:41:11 rawhide kernel: [<ffffffff8175f1b2>] common_interrupt+0x72/0x72
Dec 20 15:41:11 rawhide kernel: <EOI>  [<ffffffff810578d6>] ? native_safe_halt+0x6/0x10
Dec 20 15:41:11 rawhide kernel: [<ffffffff810cea2d>] ? trace_hardirqs_on+0xd/0x10
Dec 20 15:41:11 rawhide kernel: [<ffffffff81022934>] default_idle+0x24/0x250
Dec 20 15:41:11 rawhide kernel: [<ffffffff8102342e>] arch_cpu_idle+0x2e/0x40
Dec 20 15:41:11 rawhide kernel: [<ffffffff810e2d65>] cpu_startup_entry+0xc5/0x420
Dec 20 15:41:11 rawhide kernel: [<ffffffff81749f0d>] rest_init+0x13d/0x150
Dec 20 15:41:11 rawhide kernel: [<ffffffff81749dd5>] ? rest_init+0x5/0x150
Dec 20 15:41:11 rawhide kernel: [<ffffffff81f60f8c>] start_kernel+0x469/0x474
Dec 20 15:41:11 rawhide kernel: [<ffffffff81f6092c>] ? repair_env_string+0x5c/0x5c
Dec 20 15:41:11 rawhide kernel: [<ffffffff81f60120>] ? early_idt_handlers+0x120/0x120
Dec 20 15:41:11 rawhide kernel: [<ffffffff81f605de>] x86_64_start_reservations+0x2a/0x2c
Dec 20 15:41:11 rawhide kernel: [<ffffffff81f6071e>] x86_64_start_kernel+0x13e/0x14d
Dec 20 15:41:21 rawhide yum[553]: Updated: net-tools-2.0-0.19.20131119git.fc21.x86_64

Comment 1 Josh Boyer 2013-12-20 14:56:18 UTC


*** This bug has been marked as a duplicate of bug 1044765 ***

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