Hi,
This program
http://www.daimi.au.dk/~sandmann/lockup.c
locks up hard for me on a Pentium 4 in 32 bit mode, with the hrtimer
patches applied (-tip for example).
What the program does is spawn a thread that just spins, and then 400
threads that each create a performance counter of type
PERF_COUNT_SW_CPU_CLOCK and a sample period of 1000000 and a
sample_type of
PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_CALLCHAIN
These threads then map the event buffer and read it continuously.
It does not apparently lock up if SAMPLE_CALLCHAIN is removed; also I
cannot get it to lock up on Core 2 Duo in either 32 or 64 bit mode.
Soren
On Thu, Oct 29, 2009 at 08:15:03PM +0100, Soeren Sandmann wrote:
> Hi,
>
> This program
>
> http://www.daimi.au.dk/~sandmann/lockup.c
>
> locks up hard for me on a Pentium 4 in 32 bit mode, with the hrtimer
> patches applied (-tip for example).
>
> What the program does is spawn a thread that just spins, and then 400
> threads that each create a performance counter of type
> PERF_COUNT_SW_CPU_CLOCK and a sample period of 1000000 and a
> sample_type of
>
> PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_CALLCHAIN
>
> These threads then map the event buffer and read it continuously.
>
> It does not apparently lock up if SAMPLE_CALLCHAIN is removed; also I
> cannot get it to lock up on Core 2 Duo in either 32 or 64 bit mode.
>
>
> Soren
It locks up hard for me too, no more blinking cursor, nothing.
I've attached my config, it's against tip:master from yesterday.
Indeed it happens only with callchains enabled.
The nmi watchdog doesn't report anything. I will retry with
early_printk=vga (I don't have any serial line in my laptop).
On Wed, 2009-11-11 at 05:50 +0100, Frederic Weisbecker wrote:
> On Thu, Oct 29, 2009 at 08:15:03PM +0100, Soeren Sandmann wrote:
> > Hi,
> >
> > This program
> >
> > http://www.daimi.au.dk/~sandmann/lockup.c
> >
> > locks up hard for me on a Pentium 4 in 32 bit mode, with the hrtimer
> > patches applied (-tip for example).
> >
> > What the program does is spawn a thread that just spins, and then 400
> > threads that each create a performance counter of type
> > PERF_COUNT_SW_CPU_CLOCK and a sample period of 1000000 and a
> > sample_type of
> >
> > PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_CALLCHAIN
> >
> > These threads then map the event buffer and read it continuously.
> >
> > It does not apparently lock up if SAMPLE_CALLCHAIN is removed; also I
> > cannot get it to lock up on Core 2 Duo in either 32 or 64 bit mode.
> >
> >
> > Soren
>
>
>
> It locks up hard for me too, no more blinking cursor, nothing.
> I've attached my config, it's against tip:master from yesterday.
What kind of cpu does your laptop have? The .config seems to suggest a
Core2. Which would make Soeren's report of not being able to trash a
64bit core2 'interesting' ;-)
On Thu, 2009-10-29 at 20:15 +0100, Soeren Sandmann wrote:
> Hi,
>
> This program
>
> http://www.daimi.au.dk/~sandmann/lockup.c
>
> locks up hard for me on a Pentium 4 in 32 bit mode, with the hrtimer
> patches applied (-tip for example).
>
> What the program does is spawn a thread that just spins, and then 400
> threads that each create a performance counter of type
> PERF_COUNT_SW_CPU_CLOCK and a sample period of 1000000 and a
> sample_type of
>
> PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_CALLCHAIN
>
> These threads then map the event buffer and read it continuously.
>
> It does not apparently lock up if SAMPLE_CALLCHAIN is removed; also I
> cannot get it to lock up on Core 2 Duo in either 32 or 64 bit mode.
My dual-core opteron running a 64bit kernel is decidedly unhappy about
it too... no console, no ping, but a constant stream of softlockup msgs
might give a clue, will poke at it.
[ 327.635584] hrtimer: interrupt too slow, forcing clock min delta to 51117 ns
[ 391.916984] BUG: soft lockup - CPU#1 stuck for 61s! [lockup:2313]
[ 391.916984] Modules linked in: nfsd exportfs autofs4 nfs lockd nfs_acl auth_rpcgss sunrpc cpufreq_ondemand kvm_amd kvm uinput sr_mod floppy cdrom pcspkr sg serio_raw button shpchp [last unloaded: scsi_wait_scan]
[ 391.916984] irq event stamp: 211957
[ 391.916984] hardirqs last enabled at (211956): [<ffffffff813660c0>] restore_args+0x0/0x30
[ 391.916984] hardirqs last disabled at (211957): [<ffffffff81002bd7>] save_args+0x67/0x70
[ 391.916984] softirqs last enabled at (1222): [<ffffffff8104b8fc>] __do_softirq+0x21e/0x22e
[ 391.916984] softirqs last disabled at (1303): [<ffffffff81003d7c>] call_softirq+0x1c/0x3e
[ 391.916984] CPU 1
[ 391.916984] Modules linked in: nfsd exportfs autofs4 nfs lockd nfs_acl auth_rpcgss sunrpc cpufreq_ondemand kvm_amd kvm uinput sr_mod floppy cdrom pcspkr sg serio_raw button shpchp [last unloaded: scsi_wait_scan]
[ 391.916984] Pid: 2313, comm: lockup Not tainted 2.6.32-rc6-tip+ #6 To Be Filled By O.E.M.
[ 391.916984] RIP: 0010:[<ffffffff810751f4>] [<ffffffff810751f4>] lock_release+0x1ac/0x1b9
[ 391.916984] RSP: 0000:ffff880005e03850 EFLAGS: 00000246
[ 391.916984] RAX: ffff88007ce966c0 RBX: ffff880005e03880 RCX: 0000000000000001
[ 391.916984] RDX: 0000004c527a1a29 RSI: ffffffff810654a1 RDI: 0000000000000001
[ 391.916984] RBP: ffffffff81003753 R08: ffff88007ebb36c0 R09: 03c01e08c8078259
[ 391.916984] R10: 0000000000000000 R11: ffff88007efe58a0 R12: ffff880005e037d0
[ 391.916984] R13: ffffffff815774d0 R14: ffff88007ce966c0 R15: ffffffff8136b547
[ 391.916984] FS: 00007f9da116d710(0000) GS:ffff880005e00000(0000) knlGS:00000000f75b26c0
[ 391.916984] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 391.916984] CR2: 00007f9db408b000 CR3: 000000007ce46000 CR4: 00000000000006e0
[ 391.916984] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 391.916984] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 391.916984] Process lockup (pid: 2313, threadinfo ffff88007eeac000, task ffff88007ce966c0)
[ 391.916984] Stack:
[ 391.916984] ffff88007ebb36c0 ffff88007efe5800 ffff88007f996980 0000000000000000
[ 391.916984] <0> ffff88007ebb36c0 ffff88007efe5880 ffff880005e038d0 ffffffff812fb3e6
[ 391.916984] <0> ffffffff812fb16e ffff88007f9ee000 ffff88007efe58a0 ffff88007fa88740
[ 391.916984] Call Trace:
[ 391.916984] <IRQ>
[ 391.916984] [<ffffffff812fb3e6>] ? dev_queue_xmit+0x401/0x43a
[ 391.916984] [<ffffffff812fb16e>] ? dev_queue_xmit+0x189/0x43a
[ 391.916984] [<ffffffff8131af48>] ? ip_finish_output+0x26e/0x2b7
[ 391.916984] [<ffffffff81008eaf>] ? native_sched_clock+0x37/0x71
[ 391.916984] [<ffffffff8131b025>] ? ip_output+0x94/0x9d
[ 391.916984] [<ffffffff8131867e>] ? ip_local_out+0x65/0x67
[ 391.916984] [<ffffffff8131a891>] ? ip_queue_xmit+0x2f5/0x36e
[ 391.916984] [<ffffffff810718c2>] ? mark_held_locks+0x4d/0x6b
[ 391.916984] [<ffffffff810f0f37>] ? __kmalloc+0xc6/0x152
[ 391.916984] [<ffffffff8132bf14>] ? tcp_transmit_skb+0x63a/0x679
[ 391.916984] [<ffffffff8132c139>] ? tcp_send_ack+0x116/0x11a
[ 391.916984] [<ffffffff81329421>] ? __tcp_ack_snd_check+0x6a/0x82
[ 391.916984] [<ffffffff8132a0fd>] ? tcp_rcv_established+0x7f5/0x940
[ 391.916984] [<ffffffff81330b6e>] ? tcp_v4_do_rcv+0x36/0x1dc
[ 391.916984] [<ffffffff81365640>] ? _spin_lock_nested+0x70/0x78
[ 391.916984] [<ffffffff81331147>] ? tcp_v4_rcv+0x433/0x63e
[ 391.916984] [<ffffffff8131633b>] ? ip_local_deliver+0x6c/0x1b5
[ 391.916984] [<ffffffff813163bd>] ? ip_local_deliver+0xee/0x1b5
[ 391.916984] [<ffffffff8131633b>] ? ip_local_deliver+0x6c/0x1b5
[ 391.916984] [<ffffffff81316296>] ? ip_rcv+0x5a2/0x5db
[ 391.916984] [<ffffffff812f9b8c>] ? netif_receive_skb+0x311/0x36f
[ 391.916984] [<ffffffff812f9a0c>] ? netif_receive_skb+0x191/0x36f
[ 391.916984] [<ffffffff81279488>] ? e1000_clean_rx_irq+0x372/0x438
[ 391.916984] [<ffffffff8127bfdc>] ? e1000_clean+0x317/0x49f
[ 391.916984] [<ffffffff810bf640>] ? perf_output_end+0x65/0x7e
[ 391.916984] [<ffffffff812fa425>] ? net_rx_action+0xdc/0x283
[ 391.916984] [<ffffffff812fa57f>] ? net_rx_action+0x236/0x283
[ 391.916984] [<ffffffff810654a1>] ? cpu_clock+0x2d/0x3f
[ 391.916984] [<ffffffff8104b81d>] ? __do_softirq+0x13f/0x22e
[ 391.916984] [<ffffffff81070059>] ? lock_release_holdtime+0x102/0x107
[ 391.916984] [<ffffffff81003d7c>] ? call_softirq+0x1c/0x3e
[ 391.916984] [<ffffffff81005391>] ? do_softirq+0x3d/0x88
[ 391.916984] [<ffffffff8104b2fe>] ? irq_exit+0x4a/0x92
[ 391.916984] [<ffffffff8136b4aa>] ? do_IRQ+0xb2/0xc9
[ 391.916984] [<ffffffff81366013>] ? ret_from_intr+0x0/0xf
[ 391.916984] <EOI>
[ 391.916984] Code: e8 89 ad ff ff eb 0e 4c 89 ea 4c 89 e6 48 89 df e8 e5 fb ff ff 65 48 8b 04 25 00 b5 00 00 c7 80 84 07 00 00 00 00 00 00 41 57 9d <41> 58 5b 41 5c 41 5d 41 5e 41 5f c9 c3 55 65 48 8b 04 25 00 b5
[ 391.916984] Call Trace:
[ 391.916984] <IRQ> [<ffffffff812fb3e6>] ? dev_queue_xmit+0x401/0x43a
[ 391.916984] [<ffffffff812fb16e>] ? dev_queue_xmit+0x189/0x43a
[ 391.916984] [<ffffffff8131af48>] ? ip_finish_output+0x26e/0x2b7
[ 391.916984] [<ffffffff81008eaf>] ? native_sched_clock+0x37/0x71
[ 391.916984] [<ffffffff8131b025>] ? ip_output+0x94/0x9d
[ 391.916984] [<ffffffff8131867e>] ? ip_local_out+0x65/0x67
[ 391.916984] [<ffffffff8131a891>] ? ip_queue_xmit+0x2f5/0x36e
[ 391.916984] [<ffffffff810718c2>] ? mark_held_locks+0x4d/0x6b
[ 391.916984] [<ffffffff810f0f37>] ? __kmalloc+0xc6/0x152
[ 391.916984] [<ffffffff8132bf14>] ? tcp_transmit_skb+0x63a/0x679
[ 391.916984] [<ffffffff8132c139>] ? tcp_send_ack+0x116/0x11a
[ 391.916984] [<ffffffff81329421>] ? __tcp_ack_snd_check+0x6a/0x82
[ 391.916984] [<ffffffff8132a0fd>] ? tcp_rcv_established+0x7f5/0x940
[ 391.916984] [<ffffffff81330b6e>] ? tcp_v4_do_rcv+0x36/0x1dc
[ 391.916984] [<ffffffff81365640>] ? _spin_lock_nested+0x70/0x78
[ 391.916984] [<ffffffff81331147>] ? tcp_v4_rcv+0x433/0x63e
[ 391.916984] [<ffffffff8131633b>] ? ip_local_deliver+0x6c/0x1b5
[ 391.916984] [<ffffffff813163bd>] ? ip_local_deliver+0xee/0x1b5
[ 391.916984] [<ffffffff8131633b>] ? ip_local_deliver+0x6c/0x1b5
[ 391.916984] [<ffffffff81316296>] ? ip_rcv+0x5a2/0x5db
[ 391.916984] [<ffffffff812f9b8c>] ? netif_receive_skb+0x311/0x36f
[ 391.916984] [<ffffffff812f9a0c>] ? netif_receive_skb+0x191/0x36f
[ 391.916984] [<ffffffff81279488>] ? e1000_clean_rx_irq+0x372/0x438
[ 391.916984] [<ffffffff8127bfdc>] ? e1000_clean+0x317/0x49f
[ 391.916984] [<ffffffff810bf640>] ? perf_output_end+0x65/0x7e
[ 391.916984] [<ffffffff812fa425>] ? net_rx_action+0xdc/0x283
[ 391.916984] [<ffffffff812fa57f>] ? net_rx_action+0x236/0x283
[ 391.916984] [<ffffffff810654a1>] ? cpu_clock+0x2d/0x3f
[ 391.916984] [<ffffffff8104b81d>] ? __do_softirq+0x13f/0x22e
[ 391.916984] [<ffffffff81070059>] ? lock_release_holdtime+0x102/0x107
[ 391.916984] [<ffffffff81003d7c>] ? call_softirq+0x1c/0x3e
[ 391.916984] [<ffffffff81005391>] ? do_softirq+0x3d/0x88
[ 391.916984] [<ffffffff8104b2fe>] ? irq_exit+0x4a/0x92
[ 391.916984] [<ffffffff8136b4aa>] ? do_IRQ+0xb2/0xc9
[ 391.916984] [<ffffffff81366013>] ? ret_from_intr+0x0/0xf
[ 391.916984] <EOI>
[ 392.990186] BUG: soft lockup - CPU#0 stuck for 61s! [distccd:1734]
[ 392.990186] Modules linked in: nfsd exportfs autofs4 nfs lockd nfs_acl auth_rpcgss sunrpc cpufreq_ondemand kvm_amd kvm uinput sr_mod floppy cdrom pcspkr sg serio_raw button shpchp [last unloaded: scsi_wait_scan]
[ 392.990186] irq event stamp: 970145
[ 392.990186] hardirqs last enabled at (970144): [<ffffffff813660c0>] restore_args+0x0/0x30
[ 392.990186] hardirqs last disabled at (970145): [<ffffffff81002bd7>] save_args+0x67/0x70
[ 392.990186] softirqs last enabled at (105208): [<ffffffff8104b8fc>] __do_softirq+0x21e/0x22e
[ 392.990186] softirqs last disabled at (105334): [<ffffffff813656d5>] _spin_lock_bh+0x18/0x7b
[ 392.990186] CPU 0
[ 392.990186] Modules linked in: nfsd exportfs autofs4 nfs lockd nfs_acl auth_rpcgss sunrpc cpufreq_ondemand kvm_amd kvm uinput sr_mod floppy cdrom pcspkr sg serio_raw button shpchp [last unloaded: scsi_wait_scan]
[ 392.990186] Pid: 1734, comm: distccd Not tainted 2.6.32-rc6-tip+ #6 To Be Filled By O.E.M.
[ 392.990186] RIP: 0010:[<ffffffff811c54af>] [<ffffffff811c54af>] delay_tsc+0x2e/0xcf
[ 392.990186] RSP: 0018:ffff88007e18dd38 EFLAGS: 00000202
[ 392.990186] RAX: 0000000000000000 RBX: ffff88007e18dd68 RCX: ffffffff81330fc9
[ 392.990186] RDX: ffffffff811c54c5 RSI: 0000000000000001 RDI: 0000000000000001
[ 392.990186] RBP: ffffffff8100374e R08: ffff88007e18a780 R09: 000000000000020f
[ 392.990186] R10: ffffffff815b8010 R11: 0000000000000202 R12: 000000000000027d
[ 392.990186] R13: 00000000001d2ec0 R14: ffff88007e18c000 R15: ffff88007e18dfd8
[ 392.990186] FS: 00007f9db3992710(0000) GS:ffff880005c00000(0063) knlGS:00000000f75b26c0
[ 392.990186] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[ 392.990186] CR2: 00007f9db4126000 CR3: 000000007e072000 CR4: 00000000000006f0
[ 392.990186] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 392.990186] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 392.990186] Process distccd (pid: 1734, threadinfo ffff88007e18c000, task ffff88007e18a780)
[ 392.990186] Stack:
[ 392.990186] 0000000000000001 000000000ba09c7e ffff88007efb5500 0000000000000001
[ 392.990186] <0> ffff88007e18a780 ffff88007e18ac50 ffff88007e18dd78 ffffffff811c53af
[ 392.990186] <0> ffff88007e18ddb8 ffffffff811c96c5 000000008eaa23f8 ffff88007efb5518
[ 392.990186] Call Trace:
[ 392.990186] [<ffffffff811c53af>] ? __delay+0xf/0x11
[ 392.990186] [<ffffffff811c96c5>] ? _raw_spin_lock+0xde/0x147
[ 392.990186] [<ffffffff81365723>] ? _spin_lock_bh+0x66/0x7b
[ 392.990186] [<ffffffff812eda05>] ? lock_sock_nested+0x28/0xf0
[ 392.990186] [<ffffffff812eda05>] ? lock_sock_nested+0x28/0xf0
[ 392.990186] [<ffffffff81320f8d>] ? do_tcp_setsockopt+0x9e/0x361
[ 392.990186] [<ffffffff810f6fc5>] ? fget+0x0/0x131
[ 392.990186] [<ffffffff8132126f>] ? compat_tcp_setsockopt+0x1f/0x21
[ 392.990186] [<ffffffff812ecd48>] ? compat_sock_common_setsockopt+0x1d/0x25
[ 392.990186] [<ffffffff8130a551>] ? compat_sys_setsockopt+0x1d0/0x204
[ 392.990186] [<ffffffff8102b3e8>] ? sysretl_from_sys_call+0x2b/0x34
[ 392.990186] [<ffffffff8130a6bf>] ? compat_sys_socketcall+0x13a/0x190
[ 392.990186] [<ffffffff8102b398>] ? cstar_dispatch+0x7/0x2c
[ 392.990186] Code: e5 41 57 41 56 41 55 41 54 53 48 83 ec 08 0f 1f 44 00 00 49 89 fc bf 01 00 00 00 e8 e7 38 1a 00 e8 83 4e 00 00 41 89 c6 0f ae f0 <66> 66 90 0f 31 89 c3 65 4c 8b 3c 25 08 b5 00 00 0f ae f0 66 66
[ 392.990186] Call Trace:
[ 392.990186] [<ffffffff811c54a9>] ? delay_tsc+0x28/0xcf
[ 392.990186] [<ffffffff811c53af>] ? __delay+0xf/0x11
[ 392.990186] [<ffffffff811c96c5>] ? _raw_spin_lock+0xde/0x147
[ 392.990186] [<ffffffff81365723>] ? _spin_lock_bh+0x66/0x7b
[ 392.990186] [<ffffffff812eda05>] ? lock_sock_nested+0x28/0xf0
[ 392.990186] [<ffffffff812eda05>] ? lock_sock_nested+0x28/0xf0
[ 392.990186] [<ffffffff81320f8d>] ? do_tcp_setsockopt+0x9e/0x361
[ 392.990186] [<ffffffff810f6fc5>] ? fget+0x0/0x131
[ 392.990186] [<ffffffff8132126f>] ? compat_tcp_setsockopt+0x1f/0x21
[ 392.990186] [<ffffffff812ecd48>] ? compat_sock_common_setsockopt+0x1d/0x25
[ 392.990186] [<ffffffff8130a551>] ? compat_sys_setsockopt+0x1d0/0x204
[ 392.990186] [<ffffffff8102b3e8>] ? sysretl_from_sys_call+0x2b/0x34
[ 392.990186] [<ffffffff8130a6bf>] ? compat_sys_socketcall+0x13a/0x190
[ 392.990186] [<ffffffff8102b398>] ? cstar_dispatch+0x7/0x2c
On Wed, Nov 11, 2009 at 02:23:01PM +0100, Peter Zijlstra wrote:
> On Wed, 2009-11-11 at 05:50 +0100, Frederic Weisbecker wrote:
> > On Thu, Oct 29, 2009 at 08:15:03PM +0100, Soeren Sandmann wrote:
> > > Hi,
> > >
> > > This program
> > >
> > > http://www.daimi.au.dk/~sandmann/lockup.c
> > >
> > > locks up hard for me on a Pentium 4 in 32 bit mode, with the hrtimer
> > > patches applied (-tip for example).
> > >
> > > What the program does is spawn a thread that just spins, and then 400
> > > threads that each create a performance counter of type
> > > PERF_COUNT_SW_CPU_CLOCK and a sample period of 1000000 and a
> > > sample_type of
> > >
> > > PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_CALLCHAIN
> > >
> > > These threads then map the event buffer and read it continuously.
> > >
> > > It does not apparently lock up if SAMPLE_CALLCHAIN is removed; also I
> > > cannot get it to lock up on Core 2 Duo in either 32 or 64 bit mode.
> > >
> > >
> > > Soren
> >
> >
> >
> > It locks up hard for me too, no more blinking cursor, nothing.
> > I've attached my config, it's against tip:master from yesterday.
>
> What kind of cpu does your laptop have? The .config seems to suggest a
> Core2. Which would make Soeren's report of not being able to trash a
> 64bit core2 'interesting' ;-)
Nop it's a Pentium Dual Core :)
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Pentium(R) Dual CPU T2310 @ 1.46GHz
stepping : 13
cpu MHz : 800.000
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr
sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good aperfmperf pni dtes64 monitor ds_cpl
est tm2 ssse3 cx16 xtpr pdcm lahf_lm
bogomips : 2925.95
clflush size : 64
cache_alignment : 64
address sizes : 36 bits physical, 48 bits virtual
power management: