From: Simon Kirby <sim@hostway.ca>
To: Thomas Gleixner <tglx@linutronix.de>, David Miller <davem@davemloft.net>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>,
Linus Torvalds <torvalds@linux-foundation.org>,
Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
Dave Jones <davej@redhat.com>,
Martin Schwidefsky <schwidefsky@de.ibm.com>,
Ingo Molnar <mingo@elte.hu>,
Network Development <netdev@vger.kernel.org>
Subject: Re: Linux 3.1-rc9
Date: Tue, 25 Oct 2011 13:20:49 -0700 [thread overview]
Message-ID: <20111025202049.GB25043@hostway.ca> (raw)
In-Reply-To: <20111024190203.GA24410@hostway.ca>
On Mon, Oct 24, 2011 at 12:02:03PM -0700, Simon Kirby wrote:
> Ok, hit the hang about 4 more times, but only this morning on a box with
> a serial cable attached. Yay!
Here's lockdep output from another box. This one looks a bit different.
Simon-
[583223.799383] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[583223.805083] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[583223.805093]
[583223.805094] =================================
[583223.805096] [ INFO: inconsistent lock state ]
[583223.805098] 3.1.0-rc10-hw-lockdep+ #51
[583223.805100] ---------------------------------
[583223.805102] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
[583223.805105] swapper/0 [HC0[0]:SC0[0]:HE1:SE1] takes:
[583223.805107] (slock-AF_INET){+.?.-.}, at: [<ffffffff81604540>] sk_clone+0x120/0x420
[583223.805116] {IN-SOFTIRQ-W} state was registered at:
[583223.805117] [<ffffffff81098c7c>] __lock_acquire+0xcbc/0x2180
[583223.805123] [<ffffffff8109a7b9>] lock_acquire+0x109/0x140
[583223.805126] [<ffffffff816f55fc>] _raw_spin_lock+0x3c/0x50
[583223.805131] [<ffffffff8166bd3d>] udp_queue_rcv_skb+0x26d/0x4b0
[583223.805135] [<ffffffff8166c6a3>] __udp4_lib_rcv+0x2f3/0x910
[583223.805139] [<ffffffff8166ccd5>] udp_rcv+0x15/0x20
[583223.805142] [<ffffffff81641960>] ip_local_deliver_finish+0x100/0x2f0
[583223.805146] [<ffffffff81641bdd>] ip_local_deliver+0x8d/0xa0
[583223.805149] [<ffffffff81641203>] ip_rcv_finish+0x1a3/0x510
[583223.805152] [<ffffffff816417e2>] ip_rcv+0x272/0x2f0
[583223.805154] [<ffffffff81610d67>] __netif_receive_skb+0x4d7/0x560
[583223.805158] [<ffffffff81610ec0>] process_backlog+0xd0/0x1e0
[583223.805161] [<ffffffff81613880>] net_rx_action+0x140/0x2c0
[583223.805164] [<ffffffff810640b8>] __do_softirq+0x138/0x250
[583223.805168] [<ffffffff817002bc>] call_softirq+0x1c/0x30
[583223.805172] [<ffffffff810153c5>] do_softirq+0x95/0xd0
[583223.805176] [<ffffffff81063ecd>] local_bh_enable+0xed/0x110
[583223.805179] [<ffffffff81614c48>] dev_queue_xmit+0x1a8/0x8a0
[583223.805181] [<ffffffff8161f1aa>] neigh_resolve_output+0x17a/0x220
[583223.805185] [<ffffffff81647d4c>] ip_finish_output+0x2ec/0x590
[583223.805188] [<ffffffff81648078>] ip_output+0x88/0xe0
[583223.805191] [<ffffffff81646cd8>] ip_local_out+0x28/0x80
[583223.805194] [<ffffffff81646d39>] ip_send_skb+0x9/0x40
[583223.805197] [<ffffffff8166aeb2>] udp_send_skb+0x122/0x390
[583223.805200] [<ffffffff8166db0c>] udp_sendmsg+0x7dc/0x920
[583223.805203] [<ffffffff81675e1f>] inet_sendmsg+0xbf/0x120
[583223.805207] [<ffffffff815ff333>] sock_sendmsg+0xe3/0x110
[583223.805209] [<ffffffff815ffc55>] sys_sendto+0x105/0x140
[583223.805212] [<ffffffff816fe052>] system_call_fastpath+0x16/0x1b
[583223.805217] irq event stamp: 4284605374
[583223.805219] hardirqs last enabled at (4284605372): [<ffffffff816101ad>] net_rps_action_and_irq_enable+0x8d/0xa0
[583223.805222] hardirqs last disabled at (4284605373): [<ffffffff8106412d>] __do_softirq+0x1ad/0x250
[583223.805226] softirqs last enabled at (4284605374): [<ffffffff81064176>] __do_softirq+0x1f6/0x250
[583223.805230] softirqs last disabled at (4284605313): [<ffffffff817002bc>] call_softirq+0x1c/0x30
[583223.805233]
[583223.805233] other info that might help us debug this:
[583223.805235] Possible unsafe locking scenario:
[583223.805236]
[583223.805237] CPU0
[583223.805238] ----
[583223.805239] lock(slock-AF_INET);
[583223.805241] <Interrupt>
[583223.805242] lock(slock-AF_INET);
[583223.805244]
[583223.805245] *** DEADLOCK ***
[583223.805246]
[583223.805248] 1 lock held by swapper/0:
[583223.805249] #0: (slock-AF_INET){+.?.-.}, at: [<ffffffff81604540>] sk_clone+0x120/0x420
[583223.805254]
[583223.805254] stack backtrace:
[583223.805257] Pid: 0, comm: swapper Not tainted 3.1.0-rc10-hw-lockdep+ #51
[583223.805259] Call Trace:
[583223.805264] [<ffffffff81096033>] print_usage_bug+0x243/0x310
[583223.805267] [<ffffffff810965b4>] mark_lock+0x4b4/0x6c0
[583223.805271] [<ffffffff81097400>] ? check_usage_forwards+0x110/0x110
[583223.805275] [<ffffffff81096862>] mark_held_locks+0xa2/0x130
[583223.805278] [<ffffffff816f6334>] ? retint_restore_args+0x13/0x13
[583223.805281] [<ffffffff81096c0d>] trace_hardirqs_on_caller+0x13d/0x1c0
[583223.805286] [<ffffffff813a60ae>] trace_hardirqs_on_thunk+0x3a/0x3f
[583223.805290] [<ffffffff81092b8e>] ? tick_nohz_stop_sched_tick+0x2fe/0x430
[583223.805293] [<ffffffff816f6334>] ? retint_restore_args+0x13/0x13
[583223.805297] [<ffffffff8101b80e>] ? mwait_idle+0x14e/0x170
[583223.805301] [<ffffffff8101b805>] ? mwait_idle+0x145/0x170
[583223.805304] [<ffffffff81013156>] cpu_idle+0x96/0xf0
[583223.805307] [<ffffffff816ca491>] rest_init+0xd1/0xe0
[583223.805310] [<ffffffff816ca3c0>] ? csum_partial_copy_generic+0x170/0x170
[583223.805315] [<ffffffff81adcc55>] start_kernel+0x360/0x3ac
[583223.805318] [<ffffffff81adc2a2>] x86_64_start_reservations+0x82/0x89
[583223.805321] [<ffffffff81adc3b8>] x86_64_start_kernel+0x10f/0x12a
[583223.805325] [<ffffffff81adc140>] ? early_idt_handlers+0x140/0x140
[583226.813848] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[583232.802948] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[583244.833571] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[583253.849631] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[583268.837126] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[587843.931805] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[587846.165584] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[587850.602316] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[587859.482841] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[587873.940136] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000102, exited with 00000103?
[587877.240624] huh, entered softirq 3 NET_RX ffffffff81613740 preempt_count 00000101, exited with 00000102?
[590476.272022] BUG: soft lockup - CPU#0 stuck for 22s! [swapper:0]
[590476.276002] Modules linked in: ipmi_devintf ipmi_si ipmi_msghandler xt_recent nf_conntrack_ftp xt_state xt_owner nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 bnx2
[590476.276002] irq event stamp: 4284605374
[590476.276002] hardirqs last enabled at (4284605372): [<ffffffff816101ad>] net_rps_action_and_irq_enable+0x8d/0xa0
[590476.276002] hardirqs last disabled at (4284605373): [<ffffffff8106412d>] __do_softirq+0x1ad/0x250
[590476.276002] softirqs last enabled at (4284605374): [<ffffffff81064176>] __do_softirq+0x1f6/0x250
[590476.276002] softirqs last disabled at (4284605313): [<ffffffff817002bc>] call_softirq+0x1c/0x30
[590476.276002] CPU 0
[590476.276002] Modules linked in: ipmi_devintf ipmi_si ipmi_msghandler xt_recent nf_conntrack_ftp xt_state xt_owner nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 bnx2
[590476.276002]
[590476.276002] Pid: 0, comm: swapper Not tainted 3.1.0-rc10-hw-lockdep+ #51 Dell Inc. PowerEdge 1950/0UR033
[590476.276002] RIP: 0010:[<ffffffff813a4ee3>] [<ffffffff813a4ee3>] delay_tsc+0x73/0xd0
[590476.276002] RSP: 0018:ffff88022fc03cf0 EFLAGS: 00000206
[590476.276002] RAX: 00042f884dcdaa24 RBX: ffff88022fc0d3c0 RCX: 000000004dcdaa24
[590476.380029] BUG: soft lockup - CPU#1 stuck for 22s! [php:10828]
[590476.380033] Modules linked in: ipmi_devintf ipmi_si ipmi_msghandler xt_recent nf_conntrack_ftp xt_state xt_owner nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 bnx2
[590476.380044] irq event stamp: 0
[590476.380045] hardirqs last enabled at (0): [< (null)>] (null)
[590476.380048] hardirqs last disabled at (0): [<ffffffff8105aa8b>] copy_process+0x65b/0x1450
[590476.380056] softirqs last enabled at (0): [<ffffffff8105aa8b>] copy_process+0x65b/0x1450
[590476.380060] softirqs last disabled at (0): [< (null)>] (null)
[590476.380063] CPU 1
[590476.380064] Modules linked in: ipmi_devintf ipmi_si ipmi_msghandler xt_recent nf_conntrack_ftp xt_state xt_owner nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 bnx2
[590476.380072]
[590476.380075] Pid: 10828, comm: php Not tainted 3.1.0-rc10-hw-lockdep+ #51 Dell Inc. PowerEdge 1950/0UR033
[590476.380079] RIP: 0010:[<ffffffff8101afa6>] [<ffffffff8101afa6>] native_read_tsc+0x6/0x20
[590476.380086] RSP: 0000:ffff88022fc43ce0 EFLAGS: 00000206
[590476.380088] RAX: 000000005aa56d04 RBX: ffffffff816f6334 RCX: 000000005aa56c92
[590476.380091] RDX: 0000000000042f88 RSI: ffffffff818f9896 RDI: 0000000000000001
[590476.380093] RBP: ffff88022fc43ce0 R08: 000000005aa56c92 R09: 0000000000000000
[590476.380096] R10: ffff88014b9a9f20 R11: 0000000000000000 R12: ffff88022fc43c58
[590476.380098] R13: ffffffff816feb33 R14: ffff88022fc43ce0 R15: 000000000e27878c
[590476.380101] FS: 00007fb61c8fa720(0000) GS:ffff88022fc40000(0000) knlGS:0000000000000000
[590476.380103] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[590476.380106] CR2: 00000000027914a0 CR3: 000000013a070000 CR4: 00000000000006e0
[590476.380108] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[590476.380110] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[590476.380113] Process php (pid: 10828, threadinfo ffff88014a1f2000, task ffff88014b9a9f20)
[590476.380115] Stack:
[590476.380117] ffff88022fc43d30 ffffffff813a4eaf ffff88014a1f2000 000000005aa56c38
[590476.380121] 00000001818f9896 ffff88001db58048 000000000e27878c 0000000076e96800
[590476.380125] 0000000000000001 ffff88014b9a9f20 ffff88022fc43d40 ffffffff813a4f6a
[590476.380129] Call Trace:
[590476.380132] <IRQ>
[590476.380137] [<ffffffff813a4eaf>] delay_tsc+0x3f/0xd0
[590476.380141] [<ffffffff813a4f6a>] __delay+0xa/0x10
[590476.380145] [<ffffffff813ac2ab>] do_raw_spin_lock+0x13b/0x180
[590476.380151] [<ffffffff816f5604>] _raw_spin_lock+0x44/0x50
[590476.380157] [<ffffffff81661823>] ? tcp_keepalive_timer+0x23/0x270
[590476.380161] [<ffffffff81661823>] tcp_keepalive_timer+0x23/0x270
[590476.380166] [<ffffffff8106cd5d>] run_timer_softirq+0x26d/0x410
[590476.380169] [<ffffffff8106cc88>] ? run_timer_softirq+0x198/0x410
[590476.380174] [<ffffffff81661800>] ? tcp_init_xmit_timers+0x20/0x20
[590476.380179] [<ffffffff810640b8>] __do_softirq+0x138/0x250
[590476.380184] [<ffffffff817002bc>] call_softirq+0x1c/0x30
[590476.380188] [<ffffffff810153c5>] do_softirq+0x95/0xd0
[590476.380191] [<ffffffff81063c8d>] irq_exit+0xdd/0x110
[590476.380196] [<ffffffff810310c9>] smp_apic_timer_interrupt+0x69/0xa0
[590476.380200] [<ffffffff816feb33>] apic_timer_interrupt+0x73/0x80
[590476.380203] <EOI>
[590476.380206] [<ffffffff816f6319>] ? retint_swapgs+0x13/0x1b
[590476.380208] Code: 08 ff 15 46 5c a1 00 48 c7 43 08 00 00 00 00 48 89 03 48 83 c4 08 5b c9 c3 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 0f 31
[590476.380227] c1 48 89 d0 48 c1 e0 20 89 ca 48 09 d0 c9 c3 66 2e 0f 1f 84
[590476.380236] Call Trace:
[590476.380237] <IRQ> [<ffffffff813a4eaf>] delay_tsc+0x3f/0xd0
[590476.380242] [<ffffffff813a4f6a>] __delay+0xa/0x10
[590476.380246] [<ffffffff813ac2ab>] do_raw_spin_lock+0x13b/0x180
[590476.380249] [<ffffffff816f5604>] _raw_spin_lock+0x44/0x50
[590476.380252] [<ffffffff81661823>] ? tcp_keepalive_timer+0x23/0x270
[590476.380256] [<ffffffff81661823>] tcp_keepalive_timer+0x23/0x270
[590476.380259] [<ffffffff8106cd5d>] run_timer_softirq+0x26d/0x410
[590476.380262] [<ffffffff8106cc88>] ? run_timer_softirq+0x198/0x410
[590476.380265] [<ffffffff81661800>] ? tcp_init_xmit_timers+0x20/0x20
[590476.380268] [<ffffffff810640b8>] __do_softirq+0x138/0x250
[590476.380271] [<ffffffff817002bc>] call_softirq+0x1c/0x30
[590476.380274] [<ffffffff810153c5>] do_softirq+0x95/0xd0
[590476.380277] [<ffffffff81063c8d>] irq_exit+0xdd/0x110
[590476.380280] [<ffffffff810310c9>] smp_apic_timer_interrupt+0x69/0xa0
[590476.380283] [<ffffffff816feb33>] apic_timer_interrupt+0x73/0x80
[590476.380285] <EOI> [<ffffffff816f6319>] ? retint_swapgs+0x13/0x1b
[590476.484032] BUG: soft lockup - CPU#2 stuck for 23s! [suexec:10831]
...
next prev parent reply other threads:[~2011-10-25 20:20 UTC|newest]
Thread overview: 31+ messages / expand[flat|nested] mbox.gz Atom feed top
[not found] <1318847658.6594.40.camel@twins>
[not found] ` <CA+55aFxaGKEyhXdHXNxvPrPQ-SGSpbXdfoeXrxfjPx3VXsgvtg@mail.gmail.com>
[not found] ` <1318874090.4172.84.camel@twins>
[not found] ` <CA+55aFwCBy=4YK6amE=H-BYu9-boj4Po2Zkgf4V261mCx0DC4A@mail.gmail.com>
[not found] ` <1318879396.4172.92.camel@twins>
[not found] ` <alpine.LFD.2.02.1110172237030.3240@ionos>
[not found] ` <alpine.LFD.2.02.1110181037120.3240@ionos>
[not found] ` <1318928713.21167.4.camel@twins>
[not found] ` <20111018182046.GF1309@hostway.ca>
[not found] ` <alpine.LFD.2.02.1110182146440.3240@ionos>
[not found] ` <20111024190203.GA24410@hostway.ca>
2011-10-25 7:13 ` Linux 3.1-rc9 Linus Torvalds
2011-10-25 9:01 ` David Miller
2011-10-25 12:30 ` Thomas Gleixner
2011-10-25 23:18 ` David Miller
2011-10-25 20:20 ` Simon Kirby [this message]
2011-10-31 17:32 ` Simon Kirby
2011-11-02 16:40 ` Thomas Gleixner
2011-11-02 17:27 ` Eric Dumazet
2011-11-02 17:46 ` Linus Torvalds
2011-11-02 17:53 ` Eric Dumazet
2011-11-02 18:00 ` Linus Torvalds
2011-11-02 18:05 ` Eric Dumazet
2011-11-02 18:10 ` Linus Torvalds
2011-11-02 17:49 ` Eric Dumazet
2011-11-02 17:58 ` Eric Dumazet
2011-11-02 19:16 ` Simon Kirby
2011-11-02 22:42 ` Eric Dumazet
2011-11-03 0:24 ` Thomas Gleixner
2011-11-03 0:52 ` Simon Kirby
2011-11-03 22:07 ` David Miller
2011-11-03 6:06 ` Jörg-Volker Peetz
2011-11-02 17:54 ` Thomas Gleixner
2011-11-02 18:04 ` Eric Dumazet
2011-11-02 18:28 ` Simon Kirby
2011-11-02 18:30 ` Thomas Gleixner
2011-11-02 22:10 ` Steven Rostedt
2011-11-02 23:00 ` Steven Rostedt
2011-11-03 0:09 ` Simon Kirby
2011-11-03 0:15 ` Steven Rostedt
2011-11-03 0:17 ` Simon Kirby
[not found] <CA+55aFxPNszU5UHFrDDYnshLEMupaviFwhgEsgmPkqpmuWNZ8A@mail.gmail.com>
[not found] ` <20111007070842.GA27555@hostway.ca>
[not found] ` <20111007174848.GA11011@hostway.ca>
[not found] ` <1318010515.398.8.camel@twins>
[not found] ` <20111008005035.GC22843@hostway.ca>
[not found] ` <1318060551.8395.0.camel@twins>
[not found] ` <20111012213555.GC24461@hostway.ca>
2011-10-18 5:40 ` Simon Kirby
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20111025202049.GB25043@hostway.ca \
--to=sim@hostway.ca \
--cc=a.p.zijlstra@chello.nl \
--cc=davej@redhat.com \
--cc=davem@davemloft.net \
--cc=linux-kernel@vger.kernel.org \
--cc=mingo@elte.hu \
--cc=netdev@vger.kernel.org \
--cc=schwidefsky@de.ibm.com \
--cc=tglx@linutronix.de \
--cc=torvalds@linux-foundation.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
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).