xfslogd-spinlock bug?
Hello, list,
I am the "big red button men" with the one big 14TB xfs, if somebody can remember me. :-)
Now i found something in the 2.6.16.18, and try the 2.6.18.4, and the 2.6.19, but the bug still exists:
Dec 11 22:47:21 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 11 22:47:21 dy-base general protection fault: 0000 [1] Dec 11 22:47:21 dy-base SMP Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base CPU 3 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Modules linked in: Dec 11 22:47:21 dy-base nbd Dec 11 22:47:21 dy-base rd Dec 11 22:47:21 dy-base netconsole Dec 11 22:47:21 dy-base e1000 Dec 11 22:47:21 dy-base video Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 11 22:47:21 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 11 22:47:21 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:21 dy-base RSP: 0018:ffff81011fb89bc0 EFLAGS: 00010002 Dec 11 22:47:21 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000 Dec 11 22:47:21 dy-base RDX: ffffffff808137a0 RSI: 0000000000000082 RDI: 0000000100000000 Dec 11 22:47:21 dy-base RBP: ffff81011fb89be0 R08: 0000000000026a70 R09: 000000006b6b6b6b Dec 11 22:47:21 dy-base R10: 0000000000000082 R11: ffff81000584d380 R12: ffff8100db92ad80 Dec 11 22:47:21 dy-base R13: ffffffff80642dc6 R14: 0000000000000000 R15: 0000000000000003 Dec 11 22:47:21 dy-base FS: 0000000000000000(0000) GS:ffff81011fc76b90(0000) knlGS:0000000000000000 Dec 11 22:47:21 dy-base CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b Dec 11 22:47:21 dy-base CR2: 00002ba007700000 CR3: 0000000108c05000 CR4: 00000000000006e0 Dec 11 22:47:21 dy-base Process xfslogd/3 (pid: 317, threadinfo ffff81011fb88000, task ffff81011fa7f830) Dec 11 22:47:21 dy-base Stack: Dec 11 22:47:21 dy-base ffff81011fb89be0 Dec 11 22:47:21 dy-base ffff8100db92ad80 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base ffff81011fb89c10 Dec 11 22:47:21 dy-base ffffffff803f3bdc Dec 11 22:47:21 dy-base 0000000000000282 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base ffff81011fb89c30 Dec 11 22:47:21 dy-base ffffffff805e7f2b Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Call Trace: Dec 11 22:47:21 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 11 22:47:21 dy-base [<ffffffff805e7f2b>] _spin_lock_irqsave+0x11/0x18 Dec 11 22:47:21 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 Dec 11 22:47:21 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23 Dec 11 22:47:21 dy-base [<ffffffff803970a4>] xfs_buf_item_unpin+0x2e/0xa6 Dec 11 22:47:21 dy-base [<ffffffff803bc460>] xfs_trans_chunk_committed+0xc3/0xf7 Dec 11 22:47:21 dy-base [<ffffffff803bc4dd>] xfs_trans_committed+0x49/0xde Dec 11 22:47:21 dy-base [<ffffffff803b1bde>] xlog_state_do_callback+0x185/0x33f Dec 11 22:47:21 dy-base [<ffffffff803b1e9c>] xlog_iodone+0x104/0x131 Dec 11 22:47:22 dy-base [<ffffffff803c9dae>] xfs_buf_iodone_work+0x1a/0x3e Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023937e>] run_workqueue+0xa8/0xf8 Dec 11 22:47:22 dy-base [<ffffffff803c9d94>] xfs_buf_iodone_work+0x0/0x3e Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff80239ad3>] worker_thread+0xfb/0x134 Dec 11 22:47:22 dy-base [<ffffffff80223f6c>] default_wake_function+0x0/0xf Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023c6e5>] kthread+0xd8/0x10b Dec 11 22:47:22 dy-base [<ffffffff802256ac>] schedule_tail+0x45/0xa6 Dec 11 22:47:22 dy-base [<ffffffff8020a6a8>] child_rip+0xa/0x12 Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023c60d>] kthread+0x0/0x10b Dec 11 22:47:22 dy-base [<ffffffff8020a69e>] child_rip+0x0/0x12 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Code: Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 83 Dec 11 22:47:22 dy-base 0c Dec 11 22:47:22 dy-base 01 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 48 Dec 11 22:47:22 dy-base 8d Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 98 Dec 11 22:47:22 dy-base 02 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 54 Dec 11 22:47:22 dy-base 24 Dec 11 22:47:22 dy-base 04 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 89 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base RIP Dec 11 22:47:22 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:22 dy-base RSP <ffff81011fb89bc0> Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Kernel panic - not syncing: Fatal exception Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Rebooting in 5 seconds..
After this, sometimes the server reboots normally, but sometimes hangs, no console, no sysreq, no nothing.
This is a "simple" crash, no "too much" data lost, or else.
Can somebody help me to tracking down the problem?
Thanks,
Janos Haar
I'm not sure what is causing this problem but I was curious is this on a 32bit or 64bit platform?
Justin.
Quoted 129 lines · Haar János
Hello, list,
I am the "big red button men" with the one big 14TB xfs, if somebody can remember me. :-)
Now i found something in the 2.6.16.18, and try the 2.6.18.4, and the 2.6.19, but the bug still exists:
Dec 11 22:47:21 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 11 22:47:21 dy-base general protection fault: 0000 [1] Dec 11 22:47:21 dy-base SMP Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base CPU 3 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Modules linked in: Dec 11 22:47:21 dy-base nbd Dec 11 22:47:21 dy-base rd Dec 11 22:47:21 dy-base netconsole Dec 11 22:47:21 dy-base e1000 Dec 11 22:47:21 dy-base video Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 11 22:47:21 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 11 22:47:21 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:21 dy-base RSP: 0018:ffff81011fb89bc0 EFLAGS: 00010002 Dec 11 22:47:21 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000 Dec 11 22:47:21 dy-base RDX: ffffffff808137a0 RSI: 0000000000000082 RDI: 0000000100000000 Dec 11 22:47:21 dy-base RBP: ffff81011fb89be0 R08: 0000000000026a70 R09: 000000006b6b6b6b Dec 11 22:47:21 dy-base R10: 0000000000000082 R11: ffff81000584d380 R12: ffff8100db92ad80 Dec 11 22:47:21 dy-base R13: ffffffff80642dc6 R14: 0000000000000000 R15: 0000000000000003 Dec 11 22:47:21 dy-base FS: 0000000000000000(0000) GS:ffff81011fc76b90(0000) knlGS:0000000000000000 Dec 11 22:47:21 dy-base CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b Dec 11 22:47:21 dy-base CR2: 00002ba007700000 CR3: 0000000108c05000 CR4: 00000000000006e0 Dec 11 22:47:21 dy-base Process xfslogd/3 (pid: 317, threadinfo ffff81011fb88000, task ffff81011fa7f830) Dec 11 22:47:21 dy-base Stack: Dec 11 22:47:21 dy-base ffff81011fb89be0 Dec 11 22:47:21 dy-base ffff8100db92ad80 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base ffff81011fb89c10 Dec 11 22:47:21 dy-base ffffffff803f3bdc Dec 11 22:47:21 dy-base 0000000000000282 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base ffff81011fb89c30 Dec 11 22:47:21 dy-base ffffffff805e7f2b Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Call Trace: Dec 11 22:47:21 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 11 22:47:21 dy-base [<ffffffff805e7f2b>] _spin_lock_irqsave+0x11/0x18 Dec 11 22:47:21 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 Dec 11 22:47:21 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23 Dec 11 22:47:21 dy-base [<ffffffff803970a4>] xfs_buf_item_unpin+0x2e/0xa6 Dec 11 22:47:21 dy-base [<ffffffff803bc460>] xfs_trans_chunk_committed+0xc3/0xf7 Dec 11 22:47:21 dy-base [<ffffffff803bc4dd>] xfs_trans_committed+0x49/0xde Dec 11 22:47:21 dy-base [<ffffffff803b1bde>] xlog_state_do_callback+0x185/0x33f Dec 11 22:47:21 dy-base [<ffffffff803b1e9c>] xlog_iodone+0x104/0x131 Dec 11 22:47:22 dy-base [<ffffffff803c9dae>] xfs_buf_iodone_work+0x1a/0x3e Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023937e>] run_workqueue+0xa8/0xf8 Dec 11 22:47:22 dy-base [<ffffffff803c9d94>] xfs_buf_iodone_work+0x0/0x3e Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff80239ad3>] worker_thread+0xfb/0x134 Dec 11 22:47:22 dy-base [<ffffffff80223f6c>] default_wake_function+0x0/0xf Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023c6e5>] kthread+0xd8/0x10b Dec 11 22:47:22 dy-base [<ffffffff802256ac>] schedule_tail+0x45/0xa6 Dec 11 22:47:22 dy-base [<ffffffff8020a6a8>] child_rip+0xa/0x12 Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 11 22:47:22 dy-base [<ffffffff8023c60d>] kthread+0x0/0x10b Dec 11 22:47:22 dy-base [<ffffffff8020a69e>] child_rip+0x0/0x12 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Code: Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 83 Dec 11 22:47:22 dy-base 0c Dec 11 22:47:22 dy-base 01 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 48 Dec 11 22:47:22 dy-base 8d Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 98 Dec 11 22:47:22 dy-base 02 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 54 Dec 11 22:47:22 dy-base 24 Dec 11 22:47:22 dy-base 04 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 89 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base RIP Dec 11 22:47:22 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:22 dy-base RSP <ffff81011fb89bc0> Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Kernel panic - not syncing: Fatal exception Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Rebooting in 5 seconds..After this, sometimes the server reboots normally, but sometimes hangs, no console, no sysreq, no nothing.
This is a "simple" crash, no "too much" data lost, or else.
Can somebody help me to tracking down the problem?
Thanks,
Janos Haar
Hello, Justin,
This is a 64bit system.
But i cannot understand, what is the curious? :-)
I am not a kernel developer, and not a C programmer, but the long pointers shows me, the 64 bit.
Or am i on the wrong clue? :-)
Anyway, this issue happens for me about daily, or max 2-3 day often. But i have no idea what cause this exactly.
The 2.6.16.18 was stable for me a long time, and one day starts to tricking me, and happens more and more often.
Thats why i thinking some bad part of the (14TB) FS on the disks.
(this fs have a lot of errors, what the xfs_repair cannot be corrected, but anyway this is a productive system, and works well, except this issue. Some months before i have replaced the parity disk in one of the RAID4 array, and the next day, during the resync process, another one disk died. I almost lost everything, but thanks to the raid4, and mdadm, i have successfully recovered a lot of data with the 1 day older parity-only drive. This was really bad, and leave some scars on the fs. )
This issue looks like for me a race condition between the cpus. (2x Xeon HT)
Am i right? :-)
Thanks,
Janos
----- Original Message -----
From: "Justin Piszcz" <[email protected]>
To: "Haar János" <[email protected]>
Cc: <[email protected]>; <[email protected]>
Sent: Tuesday, December 12, 2006 3:32 PM
Subject: Re: xfslogd-spinlock bug?
I'm not sure what is causing this problem but I was curious is this on a 32bit or 64bit platform?
Justin.
Quoted 59 lines · Haar János
Hello, list,
I am the "big red button men" with the one big 14TB xfs, if somebody can remember me. :-)
Now i found something in the 2.6.16.18, and try the 2.6.18.4, and the 2.6.19, but the bug still exists:
Dec 11 22:47:21 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 11 22:47:21 dy-base general protection fault: 0000 [1] Dec 11 22:47:21 dy-base SMP Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base CPU 3 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Modules linked in: Dec 11 22:47:21 dy-base nbd Dec 11 22:47:21 dy-base rd Dec 11 22:47:21 dy-base netconsole Dec 11 22:47:21 dy-base e1000 Dec 11 22:47:21 dy-base video Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 11 22:47:21 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 11 22:47:21 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:21 dy-base RSP: 0018:ffff81011fb89bc0 EFLAGS: 00010002 Dec 11 22:47:21 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000 Dec 11 22:47:21 dy-base RDX: ffffffff808137a0 RSI: 0000000000000082 RDI: 0000000100000000 Dec 11 22:47:21 dy-base RBP: ffff81011fb89be0 R08: 0000000000026a70 R09: 000000006b6b6b6b Dec 11 22:47:21 dy-base R10: 0000000000000082 R11: ffff81000584d380 R12: ffff8100db92ad80 Dec 11 22:47:21 dy-base R13: ffffffff80642dc6 R14: 0000000000000000 R15: 0000000000000003 Dec 11 22:47:21 dy-base FS: 0000000000000000(0000) GS:ffff81011fc76b90(0000) knlGS:0000000000000000 Dec 11 22:47:21 dy-base CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b Dec 11 22:47:21 dy-base CR2: 00002ba007700000 CR3: 0000000108c05000 CR4: 00000000000006e0 Dec 11 22:47:21 dy-base Process xfslogd/3 (pid: 317, threadinfo ffff81011fb88000, task ffff81011fa7f830) Dec 11 22:47:21 dy-base Stack: Dec 11 22:47:21 dy-base ffff81011fb89be0 Dec 11 22:47:21 dy-base ffff8100db92ad80 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base ffff81011fb89c10 Dec 11 22:47:21 dy-base ffffffff803f3bdc Dec 11 22:47:21 dy-base 0000000000000282 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base ffff81011fb89c30 Dec 11 22:47:21 dy-base ffffffff805e7f2b Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Call Trace:
Quoted 8 lines
Dec 11 22:47:21 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 11 22:47:21 dy-base [<ffffffff805e7f2b>] _spin_lock_irqsave+0x11/0x18 Dec 11 22:47:21 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 Dec 11 22:47:21 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23 Dec 11 22:47:21 dy-base [<ffffffff803970a4>] xfs_buf_item_unpin+0x2e/0xa6 Dec 11 22:47:21 dy-base [<ffffffff803bc460>] xfs_trans_chunk_committed+0xc3/0xf7 Dec 11 22:47:21 dy-base [<ffffffff803bc4dd>]
xfs_trans_committed+0x49/0xde
Quoted 4 lines
Dec 11 22:47:21 dy-base [<ffffffff803b1bde>] xlog_state_do_callback+0x185/0x33f Dec 11 22:47:21 dy-base [<ffffffff803b1e9c>] xlog_iodone+0x104/0x131 Dec 11 22:47:22 dy-base [<ffffffff803c9dae>]
xfs_buf_iodone_work+0x1a/0x3e > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023937e>] run_workqueue+0xa8/0xf8 > Dec 11 22:47:22 dy-base [<ffffffff803c9d94>] xfs_buf_iodone_work+0x0/0x3e > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff80239ad3>] worker_thread+0xfb/0x134
Quoted 1 line
Dec 11 22:47:22 dy-base [<ffffffff80223f6c>]
default_wake_function+0x0/0xf > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023c6e5>] kthread+0xd8/0x10b > Dec 11 22:47:22 dy-base [<ffffffff802256ac>] schedule_tail+0x45/0xa6 > Dec 11 22:47:22 dy-base [<ffffffff8020a6a8>] child_rip+0xa/0x12 > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023c60d>] kthread+0x0/0x10b > Dec 11 22:47:22 dy-base [<ffffffff8020a69e>] child_rip+0x0/0x12
Quoted 45 lines
Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Code: Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 83 Dec 11 22:47:22 dy-base 0c Dec 11 22:47:22 dy-base 01 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 48 Dec 11 22:47:22 dy-base 8d Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 98 Dec 11 22:47:22 dy-base 02 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 54 Dec 11 22:47:22 dy-base 24 Dec 11 22:47:22 dy-base 04 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 89 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base RIP Dec 11 22:47:22 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:22 dy-base RSP <ffff81011fb89bc0> Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Kernel panic - not syncing: Fatal exception Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Rebooting in 5 seconds..After this, sometimes the server reboots normally, but sometimes hangs, no console, no sysreq, no nothing.
This is a "simple" crash, no "too much" data lost, or else.
Can somebody help me to tracking down the problem?
Thanks,
Janos Haar
Hi
I have some news.
I dont know there is a context between 2 messages, but i can see, the spinlock bug comes always on cpu #3.
Somebody have any idea?
Thanks
Janos
Dec 16 11:42:48 dy-base BUG: warning at mm/truncate.c:398/invalidate_inode_pages2_range() Dec 16 11:42:49 dy-base Dec 16 11:42:49 dy-base Call Trace: Dec 16 11:42:49 dy-base [<ffffffff8025b8a2>] invalidate_inode_pages2_range+0x285/0x2b8 Dec 16 11:42:49 dy-base [<ffffffff805e7ddd>] _spin_unlock+0x9/0xb Dec 16 11:42:49 dy-base [<ffffffff8031b98d>] nfs_sync_inode_wait+0x1ab/0x1bd Dec 16 11:42:49 dy-base [<ffffffff8025b8e4>] invalidate_inode_pages2+0xf/0x11 Dec 16 11:42:49 dy-base [<ffffffff80314859>] nfs_revalidate_mapping+0xa0/0x152 Dec 16 11:42:49 dy-base [<ffffffff80312a07>] nfs_file_read+0x6e/0xbe Dec 16 11:42:49 dy-base [<ffffffff80273f99>] do_sync_read+0xe2/0x126 Dec 16 11:42:49 dy-base [<ffffffff805e7ffc>] unlock_kernel+0x35/0x37 Dec 16 11:42:49 dy-base [<ffffffff8023c804>] autoremove_wake_function+0x0/0x38 Dec 16 11:42:49 dy-base [<ffffffff802729e7>] nameidata_to_filp+0x2d/0x3e Dec 16 11:42:49 dy-base [<ffffffff8026fd15>] poison_obj+0x27/0x32 Dec 16 11:42:49 dy-base [<ffffffff8026fee6>] cache_free_debugcheck+0x1c6/0x1d6 Dec 16 11:42:49 dy-base [<ffffffff8027cb26>] putname+0x37/0x39 Dec 16 11:42:49 dy-base [<ffffffff80274849>] vfs_read+0xcc/0x172 Dec 16 11:42:49 dy-base [<ffffffff80274d3e>] sys_pread64+0x55/0x76 Dec 16 11:42:49 dy-base [<ffffffff802098ee>] system_call+0x7e/0x83 Dec 16 11:42:49 dy-base
....
Dec 16 12:08:36 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 16 12:08:36 dy-base general protection fault: 0000 [1] Dec 16 12:08:36 dy-base SMP Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base CPU 3 Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Modules linked in: Dec 16 12:08:36 dy-base nbd Dec 16 12:08:36 dy-base rd Dec 16 12:08:36 dy-base netconsole Dec 16 12:08:36 dy-base e1000 Dec 16 12:08:36 dy-base video Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 16 12:08:36 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 16 12:08:36 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000 Dec 16 12:08:36 dy-base RDX: ffffffff807f3be2 RSI: 0000000000000082 RDI: 0000000100000000 Dec 16 12:08:36 dy-base RBP: ffff81011fdedbe0 R08: 0000000000006eb2 R09: 000000006b6b6b6b Dec 16 12:08:36 dy-base R10: 0000000000000082 R11: ffff81000584d280 R12: ffff810081476098 Dec 16 12:08:36 dy-base R13: ffffffff80642dc6 R14: 0000000000000000 R15: 0000000000000003 Dec 16 12:08:36 dy-base FS: 0000000000000000(0000) GS:ffff81011fc76b90(0000) knlGS:0000000000000000 Dec 16 12:08:36 dy-base CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b Dec 16 12:08:36 dy-base CR2: 00002afc7d3ea000 CR3: 0000000117afc000 CR4: 00000000000006e0 Dec 16 12:08:36 dy-base Process xfslogd/3 (pid: 317, threadinfo ffff81011fdec000, task ffff81011fafc140) Dec 16 12:08:36 dy-base Stack: Dec 16 12:08:36 dy-base ffff81011fdedbe0 Dec 16 12:08:36 dy-base ffff810081476098 Dec 16 12:08:36 dy-base 0000000000000000 Dec 16 12:08:36 dy-base 0000000000000000 Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base ffff81011fdedc10 Dec 16 12:08:36 dy-base ffffffff803f3bdc Dec 16 12:08:36 dy-base 0000000000000282 Dec 16 12:08:36 dy-base 0000000000000000 Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base 0000000000000000 Dec 16 12:08:36 dy-base 0000000000000000 Dec 16 12:08:36 dy-base ffff81011fdedc30 Dec 16 12:08:36 dy-base ffffffff805e7f2b Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Call Trace: Dec 16 12:08:36 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 16 12:08:36 dy-base [<ffffffff805e7f2b>] _spin_lock_irqsave+0x11/0x18 Dec 16 12:08:36 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 Dec 16 12:08:36 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23 Dec 16 12:08:36 dy-base [<ffffffff803970a4>] xfs_buf_item_unpin+0x2e/0xa6 Dec 16 12:08:36 dy-base [<ffffffff803bc460>] xfs_trans_chunk_committed+0xc3/0xf7 Dec 16 12:08:37 dy-base [<ffffffff803bc4dd>] xfs_trans_committed+0x49/0xde Dec 16 12:08:37 dy-base [<ffffffff803b1bde>] xlog_state_do_callback+0x185/0x33f Dec 16 12:08:37 dy-base [<ffffffff803b1e9c>] xlog_iodone+0x104/0x131 Dec 16 12:08:37 dy-base [<ffffffff803c9dae>] xfs_buf_iodone_work+0x1a/0x3e Dec 16 12:08:37 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 16 12:08:37 dy-base [<ffffffff8023937e>] run_workqueue+0xa8/0xf8 Dec 16 12:08:37 dy-base [<ffffffff803c9d94>] xfs_buf_iodone_work+0x0/0x3e Dec 16 12:08:37 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 16 12:08:37 dy-base [<ffffffff80239ad3>] worker_thread+0xfb/0x134 Dec 16 12:08:37 dy-base [<ffffffff80223f6c>] default_wake_function+0x0/0xf Dec 16 12:08:37 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 16 12:08:37 dy-base [<ffffffff8023c6e5>] kthread+0xd8/0x10b Dec 16 12:08:37 dy-base [<ffffffff802256ac>] schedule_tail+0x45/0xa6 Dec 16 12:08:37 dy-base [<ffffffff8020a6a8>] child_rip+0xa/0x12 Dec 16 12:08:37 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 Dec 16 12:08:37 dy-base [<ffffffff8023c60d>] kthread+0x0/0x10b Dec 16 12:08:38 dy-base [<ffffffff8020a69e>] child_rip+0x0/0x12 Dec 16 12:08:38 dy-base Dec 16 12:08:38 dy-base Dec 16 12:08:38 dy-base Code: Dec 16 12:08:38 dy-base 8b Dec 16 12:08:38 dy-base 83 Dec 16 12:08:38 dy-base 0c Dec 16 12:08:38 dy-base 01 Dec 16 12:08:38 dy-base 00 Dec 16 12:08:38 dy-base 00 Dec 16 12:08:38 dy-base 48 Dec 16 12:08:38 dy-base 8d Dec 16 12:08:38 dy-base 8b Dec 16 12:08:38 dy-base 98 Dec 16 12:08:38 dy-base 02 Dec 16 12:08:38 dy-base 00 Dec 16 12:08:38 dy-base 00 Dec 16 12:08:38 dy-base 41 Dec 16 12:08:38 dy-base 8b Dec 16 12:08:38 dy-base 54 Dec 16 12:08:38 dy-base 24 Dec 16 12:08:38 dy-base 04 Dec 16 12:08:38 dy-base 41 Dec 16 12:08:38 dy-base 89 Dec 16 12:08:38 dy-base Dec 16 12:08:38 dy-base RIP Dec 16 12:08:38 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 16 12:08:38 dy-base RSP <ffff81011fdedbc0> Dec 16 12:08:38 dy-base Dec 16 12:08:38 dy-base Kernel panic - not syncing: Fatal exception Dec 16 12:08:38 dy-base Dec 16 12:08:38 dy-base Rebooting in 5 seconds..
----- Original Message -----
From: "Haar János" <[email protected]>
To: "Justin Piszcz" <[email protected]>
Cc: <[email protected]>; <[email protected]>
Sent: Wednesday, December 13, 2006 2:11 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 6 lines
Hello, Justin,
This is a 64bit system.
But i cannot understand, what is the curious? :-)
Quoted 7 lines
I am not a kernel developer, and not a C programmer, but the long pointers shows me, the 64 bit.
Or am i on the wrong clue? :-)Anyway, this issue happens for me about daily, or max 2-3 day often. But i have no idea what cause this exactly.
The 2.6.16.18 was stable for me a long time, and one day starts to
tricking
Quoted 4 lines
me, and happens more and more often.
Thats why i thinking some bad part of the (14TB) FS on the disks.(this fs have a lot of errors, what the
xfs_repaircannot be corrected,
but
Quoted 5 lines
anyway this is a productive system, and works well, except this issue. Some months before i have replaced the parity disk in one of the RAID4 array, and the next day, during the resync process, another one disk died. I almost lost everything, but thanks to the raid4, and mdadm, i have successfully recovered a lot of data with the 1 day older parity-only
drive.
Quoted 3 lines
This was really bad, and leave some scars on the fs. )
This issue looks like for me a race condition between the cpus. (2x Xeon
HT)
Quoted 18 lines
Am i right? :-)
Thanks,
Janos
----- Original Message -----
From: "Justin Piszcz" <[email protected]>
To: "Haar János" <[email protected]>
Cc: <[email protected]>; <[email protected]>
Sent: Tuesday, December 12, 2006 3:32 PM
Subject: Re: xfslogd-spinlock bug?
Quoted 45 lines
I'm not sure what is causing this problem but I was curious is this on a 32bit or 64bit platform?
Justin.
Quoted 38 lines · Haar János
Hello, list,
I am the "big red button men" with the one big 14TB xfs, if somebody can remember me. :-)
Now i found something in the 2.6.16.18, and try the 2.6.18.4, and the 2.6.19, but the bug still exists:
Dec 11 22:47:21 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 11 22:47:21 dy-base general protection fault: 0000 [1] Dec 11 22:47:21 dy-base SMP Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base CPU 3 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Modules linked in: Dec 11 22:47:21 dy-base nbd Dec 11 22:47:21 dy-base rd Dec 11 22:47:21 dy-base netconsole Dec 11 22:47:21 dy-base e1000 Dec 11 22:47:21 dy-base video Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 11 22:47:21 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 11 22:47:21 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:21 dy-base RSP: 0018:ffff81011fb89bc0 EFLAGS: 00010002 Dec 11 22:47:21 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000 Dec 11 22:47:21 dy-base RDX: ffffffff808137a0 RSI: 0000000000000082 RDI: 0000000100000000 Dec 11 22:47:21 dy-base RBP: ffff81011fb89be0 R08: 0000000000026a70 R09: 000000006b6b6b6b Dec 11 22:47:21 dy-base R10: 0000000000000082 R11: ffff81000584d380 R12: ffff8100db92ad80 Dec 11 22:47:21 dy-base R13: ffffffff80642dc6 R14: 0000000000000000 R15: 0000000000000003 Dec 11 22:47:21 dy-base FS: 0000000000000000(0000) GS:ffff81011fc76b90(0000) knlGS:0000000000000000 Dec 11 22:47:21 dy-base CS: 0010 DS: 0018 ES: 0018 CR0:
000000008005003b
Quoted 15 lines
Quoted 15 lines
Dec 11 22:47:21 dy-base CR2: 00002ba007700000 CR3: 0000000108c05000 CR4: 00000000000006e0 Dec 11 22:47:21 dy-base Process xfslogd/3 (pid: 317, threadinfo ffff81011fb88000, task ffff81011fa7f830) Dec 11 22:47:21 dy-base Stack: Dec 11 22:47:21 dy-base ffff81011fb89be0 Dec 11 22:47:21 dy-base ffff8100db92ad80 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base ffff81011fb89c10 Dec 11 22:47:21 dy-base ffffffff803f3bdc Dec 11 22:47:21 dy-base 0000000000000282 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base
Quoted 8 lines
Quoted 8 lines
Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base 0000000000000000 Dec 11 22:47:21 dy-base ffff81011fb89c30 Dec 11 22:47:21 dy-base ffffffff805e7f2b Dec 11 22:47:21 dy-base Dec 11 22:47:21 dy-base Call Trace: Dec 11 22:47:21 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 11 22:47:21 dy-base [<ffffffff805e7f2b>]
_spin_lock_irqsave+0x11/0x18 > > Dec 11 22:47:21 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 > > Dec 11 22:47:21 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23
Quoted 1 line
Quoted 1 line
Dec 11 22:47:21 dy-base [<ffffffff803970a4>]
xfs_buf_item_unpin+0x2e/0xa6
Quoted 12 lines
Quoted 3 lines
Dec 11 22:47:21 dy-base [<ffffffff803bc460>] xfs_trans_chunk_committed+0xc3/0xf7 Dec 11 22:47:21 dy-base [<ffffffff803bc4dd>]
xfs_trans_committed+0x49/0xdeQuoted 4 lines
Dec 11 22:47:21 dy-base [<ffffffff803b1bde>] xlog_state_do_callback+0x185/0x33f Dec 11 22:47:21 dy-base [<ffffffff803b1e9c>] xlog_iodone+0x104/0x131 Dec 11 22:47:22 dy-base [<ffffffff803c9dae>]xfs_buf_iodone_work+0x1a/0x3e > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023937e>] run_workqueue+0xa8/0xf8Quoted 1 line
Dec 11 22:47:22 dy-base [<ffffffff803c9d94>]
xfs_buf_iodone_work+0x0/0x3e > > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > > Dec 11 22:47:22 dy-base [<ffffffff80239ad3>] worker_thread+0xfb/0x134
Quoted 42 lines
Quoted 1 line
Dec 11 22:47:22 dy-base [<ffffffff80223f6c>]default_wake_function+0x0/0xf > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023c6e5>] kthread+0xd8/0x10b > Dec 11 22:47:22 dy-base [<ffffffff802256ac>] schedule_tail+0x45/0xa6 > Dec 11 22:47:22 dy-base [<ffffffff8020a6a8>] child_rip+0xa/0x12 > Dec 11 22:47:22 dy-base [<ffffffff802399d8>] worker_thread+0x0/0x134 > Dec 11 22:47:22 dy-base [<ffffffff8023c60d>] kthread+0x0/0x10b > Dec 11 22:47:22 dy-base [<ffffffff8020a69e>] child_rip+0x0/0x12Quoted 33 lines
Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Code: Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 83 Dec 11 22:47:22 dy-base 0c Dec 11 22:47:22 dy-base 01 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 48 Dec 11 22:47:22 dy-base 8d Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 98 Dec 11 22:47:22 dy-base 02 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 00 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 8b Dec 11 22:47:22 dy-base 54 Dec 11 22:47:22 dy-base 24 Dec 11 22:47:22 dy-base 04 Dec 11 22:47:22 dy-base 41 Dec 11 22:47:22 dy-base 89 Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base RIP Dec 11 22:47:22 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 11 22:47:22 dy-base RSP <ffff81011fb89bc0> Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Kernel panic - not syncing: Fatal exception Dec 11 22:47:22 dy-base Dec 11 22:47:22 dy-base Rebooting in 5 seconds..After this, sometimes the server reboots normally, but sometimes hangs,
no
Quoted 19 lines
Quoted 12 lines
console, no sysreq, no nothing.
This is a "simple" crash, no "too much" data lost, or else.
Can somebody help me to tracking down the problem?
Thanks,
Janos Haar-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" inthe body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Quoted 8 lines · Haar János
Hi
I have some news.
I dont know there is a context between 2 messages, but i can see, the spinlock bug comes always on cpu #3.
Somebody have any idea?
Your disk interrupts are directed to CPU 3, and so log I/O completion occurs on that CPU.
Quoted 8 lines
Dec 16 12:08:36 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 16 12:08:36 dy-base general protection fault: 0000 [1] Dec 16 12:08:36 dy-base SMP Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base CPU 3 Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Modules linked in: Dec 16 12:08:36 dy-base nbd
Are you using XFS on a NBD?
Quoted 10 lines
Dec 16 12:08:36 dy-base rd Dec 16 12:08:36 dy-base netconsole Dec 16 12:08:36 dy-base e1000 Dec 16 12:08:36 dy-base video Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 16 12:08:36 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 16 12:08:36 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX:
^^^^^^^^^^^^^^^^
Anyone recognise that pattern?
Quoted 6 lines
Dec 16 12:08:36 dy-base Call Trace: Dec 16 12:08:36 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 16 12:08:36 dy-base [<ffffffff805e7f2b>] _spin_lock_irqsave+0x11/0x18 Dec 16 12:08:36 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 Dec 16 12:08:36 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23 Dec 16 12:08:36 dy-base [<ffffffff803970a4>] xfs_buf_item_unpin+0x2e/0xa6
This implies a spinlock inside a wait_queue_head_t is corrupt.
What are you type of system do you have, and what sort of workload are you running?
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "Haar János" <[email protected]>
Cc: <[email protected]>; <[email protected]>
Sent: Sunday, December 17, 2006 11:44 PM
Subject: Re: xfslogd-spinlock bug?
Quoted 5 lines · Haar János
Quoted 4 lines
Hi
I have some news.
Quoted 7 lines
Quoted 4 lines
I dont know there is a context between 2 messages, but i can see, the spinlock bug comes always on cpu #3.
Somebody have any idea?
Your disk interrupts are directed to CPU 3, and so log I/O completion occurs on that CPU.
CPU0 CPU1 CPU2 CPU3
0: 100 0 0 4583704 IO-APIC-edge timer 1: 0 0 0 2 IO-APIC-edge i8042 4: 0 0 0 3878668 IO-APIC-edge serial 8: 0 0 0 0 IO-APIC-edge rtc 9: 0 0 0 0 IO-APIC-fasteoi acpi 12: 0 0 0 3 IO-APIC-edge i8042 14: 3072118 0 0 181 IO-APIC-edge ide0 16: 0 0 0 0 IO-APIC-fasteoi
uhci_hcd:usb2
18: 0 0 0 0 IO-APIC-fasteoi
uhci_hcd:usb4
19: 0 0 0 0 IO-APIC-fasteoi
uhci_hcd:usb3
23: 0 0 0 0 IO-APIC-fasteoi
ehci_hcd:usb1
52: 0 0 0 213052723 IO-APIC-fasteoi eth1 53: 0 0 0 91913759 IO-APIC-fasteoi eth2 100: 0 0 0 16776910 IO-APIC-fasteoi eth0 NMI: 42271 43187 42234 43168 LOC: 4584247 4584219 4584215 4584198 ERR: 0
Maybe....
I have 3 XFS on this system, with 3 source.
1. 200G one ide hdd.
2. 2x200G mirror on 1 ide + 1 sata hdd.
3. 4x3.3TB strip on NBD.
The NBD serves through eth1, and it is on the CPU3, but the ide0 is on the CPU0.
Quoted 11 lines
Quoted 9 lines
Dec 16 12:08:36 dy-base BUG: spinlock bad magic on CPU#3, xfslogd/3/317 Dec 16 12:08:36 dy-base general protection fault: 0000 [1] Dec 16 12:08:36 dy-base SMP Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base CPU 3 Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Modules linked in: Dec 16 12:08:36 dy-base nbdAre you using XFS on a NBD?
Yes, on the 3. source.
I used it about 1.5 years.
(The nbd deadlock is fixed on my system, thanks to Herbert Xu on 2.6.14.)
Quoted 11 lines
Quoted 11 lines
Dec 16 12:08:36 dy-base rd Dec 16 12:08:36 dy-base netconsole Dec 16 12:08:36 dy-base e1000 Dec 16 12:08:36 dy-base video Dec 16 12:08:36 dy-base Dec 16 12:08:36 dy-base Pid: 317, comm: xfslogd/3 Not tainted 2.6.19 #1 Dec 16 12:08:36 dy-base RIP: 0010:[<ffffffff803f3aba>] Dec 16 12:08:36 dy-base [<ffffffff803f3aba>] spin_bug+0x69/0xdf Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX:
Quoted 2 lines
^^^^^^^^^^^^^^^^Anyone recognise that pattern?
I think i have one idea.
This issue can stops sometimes the 5sec automatic restart on crash, and this shows possible memory corruption, and if the bug occurs in the IRQ handling.... :-)
I have a lot of logs about this issue, and the RAX, RBX always the same.
Quoted 4 lines
Quoted 4 lines
Dec 16 12:08:36 dy-base Call Trace: Dec 16 12:08:36 dy-base [<ffffffff803f3bdc>] _raw_spin_lock+0x23/0xf1 Dec 16 12:08:36 dy-base [<ffffffff805e7f2b>]
_spin_lock_irqsave+0x11/0x18 > > Dec 16 12:08:36 dy-base [<ffffffff80222aab>] __wake_up+0x22/0x50 > > Dec 16 12:08:36 dy-base [<ffffffff803c97f9>] xfs_buf_unpin+0x21/0x23
Quoted 1 line
Quoted 1 line
Dec 16 12:08:36 dy-base [<ffffffff803970a4>]
xfs_buf_item_unpin+0x2e/0xa6
Quoted 5 lines
This implies a spinlock inside a
wait_queue_head_tis corrupt.What are you type of system do you have, and what sort of workload are you running?
OS: Fedora 5, 64bit.
HW: dual xeon, with HT, ram 4GB.
(the min_free_kbytes limit is set to 128000, because sometimes the e1000 driver run out the reserved memory during irq handling.)
Workload:
I use this system for free web storage.
(2x apache 2.0.xx, 12x pure-ftpd, 2x mysql but sql only use the source #2
fs.)
The normal system load is ~20-40, but currently i have a little problem with apache, because it sometimes starts to read a lot from the big XFS device, and eats all memory, the load is rising to 700-800.
At this point i use httpd restart, and everithing go back to normal, but if i offline.....
Thanks a lot!
Janos
Quoted 8 lines
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
Quoted 13 lines · Haar János
Quoted 8 lines · Haar János
Quoted 4 lines
I dont know there is a context between 2 messages, but i can see, the spinlock bug comes always on cpu #3.
Somebody have any idea?
Your disk interrupts are directed to CPU 3, and so log I/O completion occurs on that CPU.
CPU0 CPU1 CPU2 CPU3
0: 100 0 0 4583704 IO-APIC-edge timer 1: 0 0 0 2 IO-APIC-edge i8042 4: 0 0 0 3878668 IO-APIC-edge serial
.....
Quoted 1 line
14: 3072118 0 0 181 IO-APIC-edge ide0
.....
Quoted 3 lines
52: 0 0 0 213052723 IO-APIC-fasteoi eth1 53: 0 0 0 91913759 IO-APIC-fasteoi eth2 100: 0 0 0 16776910 IO-APIC-fasteoi eth0
....
Quoted 10 lines
Maybe....
I have 3 XFS on this system, with 3 source.1. 200G one ide hdd.
2. 2x200G mirror on 1 ide + 1 sata hdd.
3. 4x3.3TB strip on NBD.The NBD serves through eth1, and it is on the CPU3, but the ide0 is on the CPU0.
I'd say your NBD based XFS filesystem is having trouble.
Quoted 3 lines
Quoted 1 line
Are you using XFS on a NBD?
Yes, on the 3. source.
Ok, I've never heard of a problem like this before and you are doing something that very few ppl are doing (i.e. XFS on NBD). I'd start Hence I'd start by suspecting a bug in the NBD driver.
Quoted 10 lines
Quoted 4 lines
Quoted 2 lines
Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b RCX:^^^^^^^^^^^^^^^^Anyone recognise that pattern?
I think i have one idea.
This issue can stops sometimes the 5sec automatic restart on crash, and this shows possible memory corruption, and if the bug occurs in the IRQ handling.... :-)
I have a lot of logs about this issue, and the RAX, RBX always the same.
And is this the only place where you see the problem? Or are there other stack traces that you see this in as well?
Quoted 9 lines
Quoted 4 lines
This implies a spinlock inside a
wait_queue_head_tis corrupt.What are you type of system do you have, and what sort of workload are you running?
OS: Fedora 5, 64bit.
HW: dual xeon, with HT, ram 4GB.
(themin_free_kbyteslimit is set to 128000, because sometimes the e1000 driver run out the reserved memory during irq handling.)
That does not sound good. What happens when it does run out of memory? Is that when you start to see the above corruptions?
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "Haar János" <[email protected]>
Cc: "David Chinner" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Monday, December 18, 2006 7:24 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 3 lines · Haar János
Quoted 2 lines
Quoted 2 lines · Haar János
Quoted 1 line
I dont know there is a context between 2 messages, but i can see,
the
Quoted 9 lines
Quoted 9 lines
Quoted 6 lines
Quoted 3 lines
spinlock bug comes always on cpu #3.
Somebody have any idea?
Your disk interrupts are directed to CPU 3, and so log I/O completion occurs on that CPU.
CPU0 CPU1 CPU2 CPU3
0: 100 0 0 4583704 IO-APIC-edge
timer
Quoted 1 line
Quoted 1 line
1: 0 0 0 2 IO-APIC-edge
i8042
Quoted 1 line
Quoted 1 line
4: 0 0 0 3878668 IO-APIC-edge
serial
Quoted 2 lines
.....
Quoted 1 line
14: 3072118 0 0 181 IO-APIC-edge
ide0
Quoted 2 lines
.....
Quoted 1 line
52: 0 0 0 213052723 IO-APIC-fasteoi
eth1
Quoted 1 line
Quoted 1 line
53: 0 0 0 91913759 IO-APIC-fasteoi
eth2
Quoted 1 line
Quoted 1 line
100: 0 0 0 16776910 IO-APIC-fasteoi
eth0
Quoted 10 lines
....
Quoted 9 lines
Maybe....
I have 3 XFS on this system, with 3 source.1. 200G one ide hdd.
2. 2x200G mirror on 1 ide + 1 sata hdd.
3. 4x3.3TB strip on NBD.The NBD serves through eth1, and it is on the CPU3, but the ide0 is on
the
Quoted 11 lines
Quoted 1 line
CPU0.
I'd say your NBD based XFS filesystem is having trouble.
Quoted 3 lines
Quoted 1 line
Are you using XFS on a NBD?
Yes, on the 3. source.
Ok, I've never heard of a problem like this before and you are doing something that very few ppl are doing (i.e. XFS on NBD). I'd start Hence I'd start by suspecting a bug in the NBD driver.
Ok, if you have right, this also can be in context with the following issue:
http://download.netcenter.hu/bughunt/20061217/messages.txt (10KB)
Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6b
RCX:
Quoted 5 lines
Quoted 5 lines
Quoted 2 lines
^^^^^^^^^^^^^^^^Anyone recognise that pattern?
I think i have one idea.
This issue can stops sometimes the 5sec automatic restart on crash, and
this
Quoted 6 lines
Quoted 3 lines
shows possible memory corruption, and if the bug occurs in the IRQ handling.... :-)
I have a lot of logs about this issue, and the RAX, RBX always the same.And is this the only place where you see the problem? Or are there other stack traces that you see this in as well?
I have used the 2.6.16.18 for a long time, and it was stable, except this issue. (~20 dump with xfslogd)
And i try the new releases, and now i have more. :-)
What do you think exactly?
I can see in the logs, but search for what?
The RAX, RBX thing, or the xfslogd-spinlock problem or the old nbd-deadlock
+ mem corruption?
[root@NetCenter netlog]# grep "0000000000000033" messages* messages.1:Dec 11 22:47:21 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.1:Dec 12 18:16:35 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.1:Dec 13 11:40:05 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.1:Dec 14 22:25:32 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.1:Dec 15 06:24:44 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.1:Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.11:Oct 3 19:49:44 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.11:Oct 7 01:11:17 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.13:Sep 21 15:35:31 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.15:Sep 3 16:13:35 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.15:Sep 5 21:00:38 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.2:Dec 9 00:10:47 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.2:Dec 9 14:07:01 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.2:Dec 10 04:44:48 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.3:Nov 30 10:59:21 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.3:Dec 2 00:54:23 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.5:Nov 13 10:44:49 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.5:Nov 14 03:14:14 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.5:Nov 14 03:37:07 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.5:Nov 15 01:39:54 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 6 14:48:54 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 7 04:36:13 dy-base RAX: 0000000000000033 RBX:ffff8100057d2080 RCX: ffff810050d638f8 messages.6:Nov 7 04:36:13 dy-base RDX: 0000000000000008 RSI:0000000000012cff RDI: 0000000000000033 messages.6:Nov 7 11:12:06 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 8 03:20:38 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 8 15:02:16 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 8 15:27:12 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 10 15:29:43 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.6:Nov 11 20:44:14 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.9:Oct 18 15:31:02 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000 messages.9:Oct 19 13:53:24 dy-base RAX: 0000000000000033 RBX:6b6b6b6b6b6b6b6b RCX: 0000000000000000
Quoted 6 lines
Quoted 6 lines
Quoted 5 lines
This implies a spinlock inside a
wait_queue_head_tis corrupt.What are you type of system do you have, and what sort of workload are you running?
Quoted 6 lines
Quoted 4 lines
OS: Fedora 5, 64bit.
HW: dual xeon, with HT, ram 4GB.
(themin_free_kbyteslimit is set to 128000, because sometimes the e1000 driver run out the reserved memory during irq handling.)That does not sound good. What happens when it does run out of memory?
This is an old problem, on 2.6.16.18 .
The default min_free_kbytes is 38xx , and the GIGE controller easily can be overflow this little place.
If this happens, the system freez, and i can only use the serial console + sysreq to dump stack:
download.netcenter.hu/bughunt/20060530/261618-good.txt download.netcenter.hu/bughunt/20060530/dmesg.txt download.netcenter.hu/bughunt/20060530/dump.txt
This problem is already fixed with set the min_free_kbytes to 128M.
Quoted 1 line
Is that when you start to see the above corruptions?
I think no, but i am not 100% sure.
Cheers,
Janos
Quoted 8 lines
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
Quoted 11 lines · Haar János
From: "David Chinner" <[email protected]>
Quoted 1 line
Quoted 1 line
The NBD serves through eth1, and it is on the CPU3, but the ide0 is on
the
Quoted 8 lines
Quoted 1 line
CPU0.
I'd say your NBD based XFS filesystem is having trouble.
Quoted 3 lines
Quoted 1 line
Are you using XFS on a NBD?
Yes, on the 3. source.
Quoted 7 lines
Quoted 3 lines
Ok, I've never heard of a problem like this before and you are doing something that very few ppl are doing (i.e. XFS on NBD). I'd start Hence I'd start by suspecting a bug in the NBD driver.
Ok, if you have right, this also can be in context with the following issue:
http://download.netcenter.hu/bughunt/20061217/messages.txt (10KB)
Which appears to be a crash in wake_up_process() when doing memory reclaim (waking the xfsbufd).
Quoted 5 lines
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS: 00010002 Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX: 6b6b6b6b6b6b6b6bRCX:
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
^^^^^^^^^^^^^^^^Anyone recognise that pattern?
Ok, I've found this pattern:
#define POISON_FREE 0x6b
Can you confirm that you are running with CONFIG_DEBUG_SLAB=y?
If so, we have a use after free occurring here and it would also explain why no-one has reported it before.
FWIW, can you turn on CONFIG_XFS_DEBUG=y and see if that triggers a different bug check prior to the above dump?
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "Haar János" <[email protected]>
Cc: "David Chinner" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Monday, December 18, 2006 11:36 PM
Subject: Re: xfslogd-spinlock bug?
Quoted 3 lines · Haar János
Quoted 2 lines
From: "David Chinner" <[email protected]>
Quoted 1 line
Quoted 1 line
The NBD serves through eth1, and it is on the CPU3, but the ide0 is
on
Quoted 7 lines
Quoted 7 lines
the
Quoted 6 lines
Quoted 1 line
CPU0.
I'd say your NBD based XFS filesystem is having trouble.
Quoted 2 lines
Quoted 1 line
Are you using XFS on a NBD?
Quoted 7 lines
Quoted 7 lines
Quoted 5 lines
Quoted 1 line
Yes, on the 3. source.
Ok, I've never heard of a problem like this before and you are doing something that very few ppl are doing (i.e. XFS on NBD). I'd start Hence I'd start by suspecting a bug in the NBD driver.
Ok, if you have right, this also can be in context with the following
issue:
Quoted 5 lines
Quoted 2 lines
http://download.netcenter.hu/bughunt/20061217/messages.txt (10KB)
Which appears to be a crash in
wake_up_process()when doing memory reclaim (waking the xfsbufd).
Sorry, can you translate it to "poor mans language"? :-) This is a different bug?
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Quoted 2 lines
Dec 16 12:08:36 dy-base RSP: 0018:ffff81011fdedbc0 EFLAGS:
00010002
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Dec 16 12:08:36 dy-base RAX: 0000000000000033 RBX:
6b6b6b6b6b6b6b6b
Quoted 2 lines
Quoted 2 lines
RCX:
Quoted 1 line
Quoted 1 line
Quoted 1 line
^^^^^^^^^^^^^^^^
Quoted 7 lines
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Anyone recognise that pattern?
Ok, I've found this pattern:
#define
POISON_FREE0x6bCan you confirm that you are running with
CONFIG_DEBUG_SLAB=y?
Yes, i build with this option enabled.
Is this wrong?
Quoted 6 lines
If so, we have a use after free occurring here and it would also explain why no-one has reported it before.
FWIW, can you turn on
CONFIG_XFS_DEBUG=yand see if that triggers a different bug check prior to the above dump?
[root@X64 linux-2.6.19]# make bzImage scripts/kconfig/conf -s arch/x86_64/Kconfig .config:7:warning: trying to assign nonexistent symbol XFS_DEBUG
I have missed something?
Thanks,
Janos
Quoted 8 lines
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
Quoted 10 lines · Haar János
From: "David Chinner" <[email protected]>
Quoted 7 lines · Haar János
Quoted 6 lines
From: "David Chinner" <[email protected]>
Quoted 3 lines
Ok, I've never heard of a problem like this before and you are doing something that very few ppl are doing (i.e. XFS on NBD). I'd start Hence I'd start by suspecting a bug in the NBD driver.
Ok, if you have right, this also can be in context with the following
issue:
Quoted 1 line
Quoted 1 line
Quoted 7 lines
Quoted 4 lines
Quoted 1 line
http://download.netcenter.hu/bughunt/20061217/messages.txt (10KB)
Which appears to be a crash in
wake_up_process()when doing memory reclaim (waking the xfsbufd).Sorry, can you translate it to "poor mans language"? :-) This is a different bug?
Don't know - it's a different crash, but once again one that I've never heard of occurring before.
Quoted 8 lines
Quoted 5 lines
Ok, I've found this pattern:
#define
POISON_FREE0x6bCan you confirm that you are running with
CONFIG_DEBUG_SLAB=y?Yes, i build with this option enabled.
Is this wrong?
No, but it does slow your machine down.
Quoted 11 lines
Quoted 5 lines
If so, we have a use after free occurring here and it would also explain why no-one has reported it before.
FWIW, can you turn on
CONFIG_XFS_DEBUG=yand see if that triggers a different bug check prior to the above dump?[root@X64 linux-2.6.19]# make bzImage
scripts/kconfig/conf-sarch/x86_64/Kconfig.config:7:warning: trying to assign nonexistent symbolXFS_DEBUGI have missed something?
No - I forgot that config option doesn't exist in mainline XFS - it's only in the dev tree.
FWIW, I've run XFSQA twice now on a scsi disk with slab debuggin turned on and I haven't seen this problem. I'm not sure how to track down the source of the problem without a test case, but as a quick test, can you try the following patch?
Cheers,
Dave.
Signature · 36 lines
Dave Chinner
Principal Engineer
SGI Australian Software Group
---
fs/xfs/linux-2.6/xfs_buf.c | 4 ++++
1 file changed, 4 insertions(+)
Index: 2.6.x-xfs-new/fs/xfs/linux-2.6/xfs_buf.c
===================================================================
--- 2.6.x-xfs-new.orig/fs/xfs/linux-2.6/xfs_buf.c 2006-12-19 12:22:54.000000000 +1100
+++ 2.6.x-xfs-new/fs/xfs/linux-2.6/xfs_buf.c 2006-12-19 13:48:36.937118569 +1100
@@ -942,11 +942,14 @@ xfs_buf_unlock(
/*
* Pinning Buffer Storage in Memory
* Ensure that no attempt to force a buffer to disk will succeed.
+ * Hold the buffer so we don't attempt to free it while it
+ * is pinned.
*/
void
xfs_buf_pin(
xfs_buf_t *bp)
{
+ xfs_buf_hold(bp);
atomic_inc(&bp->b_pin_count);
XB_TRACE(bp, "pin", (long)bp->b_pin_count.counter);
}
@@ -958,6 +961,7 @@ xfs_buf_unpin(
if (atomic_dec_and_test(&bp->b_pin_count))
wake_up_all(&bp->b_waiters);
XB_TRACE(bp, "unpin", (long)bp->b_pin_count.counter);
+ xfs_buf_rele(bp);
}
intQuoted 7 lines · David Chinner
Quoted 6 lines · Haar János
From: "David Chinner" <[email protected]>
Quoted 3 lines
#define
POISON_FREE0x6bCan you confirm that you are running with
CONFIG_DEBUG_SLAB=y?Yes, i build with this option enabled.
......
Quoted 4 lines
FWIW, I've run XFSQA twice now on a scsi disk with slab debuggin turned on and I haven't seen this problem. I'm not sure how to track down the source of the problem without a test case, but as a quick test, can you try the following patch?
Third try an I got a crash on a poisoned object:
[1]kdb> md8c40 e00000300d7d51000xe00000300d7d5100 000000005a2cf071 0000000000000000 q.,Z............0xe00000300d7d5110 000000005a2cf071 6b6b6b6b6b6b6b6b q.,Z....kkkkkkkk0xe00000300d7d5120 e0000039eb7b6320 6b6b6b6b6b6b6b6b c{.9...kkkkkkkk
0xe00000300d7d5130 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5140 6b6b6b6f6b6b6b6b 6b6b6b6b6b6b6b6b kkkkokkkkkkkkkkk 0xe00000300d7d5150 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5160 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5170 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5180 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5190 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51a0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51b0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51c0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51d0 6b6b6b6b6b6b6b6b a56b6b6b6b6b6b6b kkkkkkkkkkkkkkk. 0xe00000300d7d51e0 000000005a2cf071 a000000100468c30 q.,Z....0.F.....
[1]kdb> mds 0xe00000300d7d51e00xe00000300d7d51e0 5a2cf071 q.,Z....0xe00000300d7d51e8 a000000100468c30 xfs_inode_item_destroy+0x30
So the use-after-free here is on an inode item. You're tripping over a buffer item.
Unfortunately, it is not the same problem - the problem I've just hit is to do with a QA test that does a forced shutdown on an active filesystem, and:
[1]kdb> xmount 0xe00000304393e238
.....
flags 0x440010 <FSSHUTDOWN IDELETE COMPAT_IOSIZE >
The filesystem was being shutdown so xfs_inode_item_destroy() just frees the inode log item without removing it from the AIL. I'll fix that, and see if i have any luck....
So I'd still try that patch i sent in the previous email...
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
Hello,
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "David Chinner" <[email protected]>
Cc: "Haar János" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Tuesday, December 19, 2006 5:47 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 49 lines · David Chinner
Quoted 7 lines · Haar János
Quoted 6 lines
From: "David Chinner" <[email protected]>
Quoted 3 lines
#define
POISON_FREE0x6bCan you confirm that you are running with
CONFIG_DEBUG_SLAB=y?Yes, i build with this option enabled.
......
Quoted 4 lines
FWIW, I've run XFSQA twice now on a scsi disk with slab debuggin turned on and I haven't seen this problem. I'm not sure how to track down the source of the problem without a test case, but as a quick test, can you try the following patch?
Third try an I got a crash on a poisoned object:
[1]kdb> md8c40
e00000300d7d51000xe00000300d7d5100000000005a2cf0710000000000000000 q.,Z............0xe00000300d7d5110000000005a2cf0716b6b6b6b6b6b6b6bq.,Z....kkkkkkkk0xe00000300d7d5120e0000039eb7b63206b6b6b6b6b6b6b6bc{.9...kkkkkkkk0xe00000300d7d5130 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5140 6b6b6b6f6b6b6b6b 6b6b6b6b6b6b6b6b kkkkokkkkkkkkkkk 0xe00000300d7d5150 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5160 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5170 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5180 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d5190 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51a0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51b0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51c0 6b6b6b6b6b6b6b6b 6b6b6b6b6b6b6b6b kkkkkkkkkkkkkkkk 0xe00000300d7d51d0 6b6b6b6b6b6b6b6b a56b6b6b6b6b6b6b kkkkkkkkkkkkkkk. 0xe00000300d7d51e0 000000005a2cf071 a000000100468c30 q.,Z....0.F.....[1]kdb> mds
0xe00000300d7d51e00xe00000300d7d51e05a2cf071q.,Z....0xe00000300d7d51e8a000000100468c30xfs_inode_item_destroy+0x30So the use-after-free here is on an inode item. You're tripping over a buffer item.
Unfortunately, it is not the same problem - the problem I've just hit is to do with a QA test that does a forced shutdown on an active filesystem, and:
[1]kdb> xmount
0xe00000304393e238
.....
flags0x440010<FSSHUTDOWN IDELETECOMPAT_IOSIZE>
Quoted 5 lines
The filesystem was being shutdown so
xfs_inode_item_destroy()just frees the inode log item without removing it from the AIL. I'll fix that, and see if i have any luck....So I'd still try that patch i sent in the previous email...
I still using the patch, but didnt shows any messages at this point.
I'v got 3 crash/reboot, but 2 causes nbd disconneted, and this one:
Dec 27 13:41:29 dy-base BUG: warning at kernel/mutex.c:220/__mutex_unlock_common_slowpath() Dec 27 13:41:29 dy-base Unable to handle kernel paging request at 0000000066604480 RIP: Dec 27 13:41:29 dy-base [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base PGD 115246067 PUD 0 Dec 27 13:41:29 dy-base Oops: 0000 [1] SMP Dec 27 13:41:29 dy-base CPU 1 Dec 27 13:41:29 dy-base Modules linked in: nbd rd netconsole e1000 video Dec 27 13:41:29 dy-base Pid: 4069, comm: httpd Not tainted 2.6.19 #3 Dec 27 13:41:29 dy-base RIP: 0010:[<ffffffff80222c64>] [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base RSP: 0018:ffff810105c01b78 EFLAGS: 00010083 Dec 27 13:41:29 dy-base RAX: ffffffff807d5800 RBX: 00001749fd97c214 RCX: ffff81001cbd0000 Dec 27 13:41:29 dy-base RDX: 000000001cbd0048 RSI: ffff810005834068 RDI: ffff8101047bf040 Dec 27 13:41:29 dy-base RBP: ffff810105c01b78 R08: 0000000000000001 R09: 0000000000000000 Dec 27 13:41:29 dy-base R10: 0000000000000057 R11: ffff81000583cd80 R12: ffff810116693140 Dec 27 13:41:29 dy-base R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000000 Dec 27 13:41:29 dy-base FS: 00002ba3c1ad07d0(0000) GS:ffff81011fc769c8(0000) knlGS:0000000000000000 Dec 27 13:41:29 dy-base CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Dec 27 13:41:29 dy-base CR2: 0000000066604480 CR3: 0000000118196000 CR4: 00000000000006e0 Dec 27 13:41:29 dy-base Process httpd (pid: 4069, threadinfo ffff810105c00000, task ffff8101166e1040) Dec 27 13:41:29 dy-base Stack: ffff810105c01bf8 ffffffff80223f37 ffff810002996a00 0000000002cba600 Dec 27 13:41:29 dy-base 000000000000000f 0000000000000001 ffff810005833700 0000000100000000 Dec 27 13:41:29 dy-base 0000000000000005 0000000000000296 ffff810105c01bd8 ffff810117fef690 Dec 27 13:41:29 dy-base Call Trace: Dec 27 13:41:29 dy-base [<ffffffff80223f37>] try_to_wake_up+0x3a7/0x3dc Dec 27 13:41:29 dy-base [<ffffffff80223f98>] wake_up_process+0x10/0x12 Dec 27 13:41:29 dy-base [<ffffffff803c9186>] xfsbufd_wakeup+0x34/0x61 Dec 27 13:41:29 dy-base [<ffffffff8025cdf9>] shrink_slab+0x64/0x163 Dec 27 13:41:29 dy-base [<ffffffff8025d913>] try_to_free_pages+0x19c/0x289 Dec 27 13:41:29 dy-base [<ffffffff80258b62>] __alloc_pages+0x1b8/0x2c0 Dec 27 13:41:29 dy-base [<ffffffff80267f94>] anon_vma_prepare+0x29/0xf1 Dec 27 13:41:29 dy-base [<ffffffff80260d52>] __handle_mm_fault+0x496/0x9e3 Dec 27 13:41:29 dy-base [<ffffffff805e7dfd>] _spin_unlock+0x9/0xb Dec 27 13:41:29 dy-base [<ffffffff8021a1b6>] do_page_fault+0x418/0x7b6 Dec 27 13:41:29 dy-base [<ffffffff802082ed>] __switch_to+0x280/0x28f Dec 27 13:41:29 dy-base [<ffffffff805e7efb>] _spin_unlock_irq+0x9/0xc Dec 27 13:41:29 dy-base [<ffffffff805e5ca8>] thread_return+0x5e/0xf7 Dec 27 13:41:29 dy-base [<ffffffff805e809d>] error_exit+0x0/0x84 Dec 27 13:41:29 dy-base Dec 27 13:41:29 dy-base Dec 27 13:41:29 dy-base Code: 48 8b 14 d5 40 42 78 80 48 03 42 08 8b 00 85 c0 7e 0a 0f 0b Dec 27 13:41:29 dy-base RIP [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base RSP <ffff810105c01b78> Dec 27 13:41:29 dy-base CR2: 0000000066604480 Dec 27 13:41:29 dy-base <0>Kernel panic - not syncing: Fatal exception Dec 27 13:41:29 dy-base Dec 27 13:41:29 dy-base Rebooting in 5 seconds..
I found one bug on my apache config, and i think, the test case is changed. :-(
Before the config is fixed, some users can stress the xfs source device readahead, and can periodically overload the system, with this action. I think, the original bug only comes on the highly overloaded system, and about readahead+buffering/caching.
Thanks,
Janos
Quoted 8 lines
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
Quoted 23 lines · Haar János
Hello,
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "David Chinner" <[email protected]>
Cc: "Haar János" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Tuesday, December 19, 2006 5:47 AM
Subject: Re: xfslogd-spinlock bug?Quoted 7 lines · David Chinner
The filesystem was being shutdown so
xfs_inode_item_destroy()just frees the inode log item without removing it from the AIL. I'll fix that, and see if i have any luck....So I'd still try that patch i sent in the previous email...
I still using the patch, but didnt shows any messages at this point.
I'v got 3 crash/reboot, but 2 causes nbd disconneted, and this one:
Quoted 14 lines
Dec 27 13:41:29 dy-base BUG: warning at kernel/mutex.c:220/__mutex_unlock_common_slowpath() Dec 27 13:41:29 dy-base Unable to handle kernel paging request at 0000000066604480 RIP: Dec 27 13:41:29 dy-base [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base PGD 115246067 PUD 0 Dec 27 13:41:29 dy-base Oops: 0000 [1] SMP Dec 27 13:41:29 dy-base CPU 1 Dec 27 13:41:29 dy-base Modules linked in: nbd rd netconsole e1000 video Dec 27 13:41:29 dy-base Pid: 4069, comm: httpd Not tainted 2.6.19 #3 Dec 27 13:41:29 dy-base RIP: 0010:[<ffffffff80222c64>] [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base RSP: 0018:ffff810105c01b78 EFLAGS: 00010083 Dec 27 13:41:29 dy-base RAX: ffffffff807d5800 RBX: 00001749fd97c214 RCX:
Different corruption in RBX here. Looks like semi-random garbage there. I wonder - what's the mac and ip address(es) of your machine and nbd servers?
(i.e. I suspect this is a nbd problem, not an XFS problem)
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "Haar János" <[email protected]>
Cc: "David Chinner" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Monday, January 08, 2007 12:14 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 12 lines · Haar János
Quoted 11 lines
Hello,
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "David Chinner" <[email protected]>
Cc: "Haar János" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Tuesday, December 19, 2006 5:47 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 4 lines
Quoted 4 lines
Quoted 4 lines · David Chinner
The filesystem was being shutdown so
xfs_inode_item_destroy()just frees the inode log item without removing it from the AIL. I'll fix
that,
Quoted 8 lines
Quoted 8 lines
Quoted 3 lines
and see if i have any luck....
So I'd still try that patch i sent in the previous email...
I still using the patch, but didnt shows any messages at this point.
I'v got 3 crash/reboot, but 2 causes nbd disconneted, and this one:
Quoted 11 lines
Quoted 11 lines
Dec 27 13:41:29 dy-base BUG: warning at kernel/mutex.c:220/__mutex_unlock_common_slowpath() Dec 27 13:41:29 dy-base Unable to handle kernel paging request at 0000000066604480 RIP: Dec 27 13:41:29 dy-base [<ffffffff80222c64>] resched_task+0x12/0x64 Dec 27 13:41:29 dy-base PGD 115246067 PUD 0 Dec 27 13:41:29 dy-base Oops: 0000 [1] SMP Dec 27 13:41:29 dy-base CPU 1 Dec 27 13:41:29 dy-base Modules linked in: nbd rd netconsole e1000 video Dec 27 13:41:29 dy-base Pid: 4069, comm: httpd Not tainted 2.6.19 #3 Dec 27 13:41:29 dy-base RIP: 0010:[<ffffffff80222c64>]
[<ffffffff80222c64>]
Quoted 7 lines
Quoted 3 lines
resched_task+0x12/0x64 Dec 27 13:41:29 dy-base RSP: 0018:ffff810105c01b78 EFLAGS: 00010083 Dec 27 13:41:29 dy-base RAX: ffffffff807d5800 RBX: 00001749fd97c214 RCX:Different corruption in RBX here. Looks like semi-random garbage there. I wonder - what's the mac and ip address(es) of your machine and nbd servers?
dy-base:
eth0 Link encap:Ethernet HWaddr 00:90:27:A2:7B:8B eth0:1 Link encap:Ethernet HWaddr 00:90:27:A2:7B:8B eth0:2 Link encap:Ethernet HWaddr 00:90:27:A2:7B:8B eth1 Link encap:Ethernet HWaddr 00:07:E9:32:E6:D8 eth1:1 Link encap:Ethernet HWaddr 00:07:E9:32:E6:D8 eth1:2 Link encap:Ethernet HWaddr 00:07:E9:32:E6:D8 eth2 Link encap:Ethernet HWaddr 00:07:E9:32:E6:D9
node1-4:
00:0E:0C:A0:E5:7E
00:0E:0C:A0:EF:5E
00:0E:0C:A0:E9:58
00:0E:0C:A0:EF:A3
Some new stuff:
Jan 8 18:11:16 dy-base BUG: warning at kernel/mutex.c:220/__mutex_unlock_common_slowpath() Jan 8 18:11:16 dy-base Unable to handle kernel NULL pointer dereference at 0000000000000008 RIP: Jan 8 18:11:16 dy-base [<ffffffff80222c74>] resched_task+0x1a/0x64 Jan 8 18:11:16 dy-base PGD 9859d067 PUD 4e347067 PMD 0 Jan 8 18:11:16 dy-base Oops: 0000 [1] SMP Jan 8 18:11:16 dy-base CPU 3 Jan 8 18:11:16 dy-base Modules linked in: nbd rd netconsole e1000 Jan 8 18:11:16 dy-base Pid: 3471, comm: ls Not tainted 2.6.19 #4 Jan 8 18:11:16 dy-base RIP: 0010:[<ffffffff80222c74>] [<ffffffff80222c74>] resched_task+0x1a/0x64 Jan 8 18:11:16 dy-base RSP: 0000:ffff81011fd1fb10 EFLAGS: 00010097 Jan 8 18:11:16 dy-base RAX: ffffffff80810800 RBX: 000004f0e2850659 RCX: ffff81010c0a2000 Jan 8 18:11:16 dy-base RDX: 0000000000000000 RSI: ffff81000583c368 RDI: ffff81002b809830 Jan 8 18:11:16 dy-base RBP: ffff81011fd1fb10 R08: 0000000000000000 R09: 0000000000000080 Jan 8 18:11:16 dy-base R10: 0000000000000080 R11: ffff81000584d280 R12: ffff8100d852a7b0 Jan 8 18:11:16 dy-base R13: 0000000000000003 R14: 0000000000000001 R15: 0000000000000001 Jan 8 18:11:16 dy-base FS: 00002b69786c8a90(0000) GS:ffff81011fcb98c0(0000) knlGS:0000000000000000 Jan 8 18:11:16 dy-base CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b Jan 8 18:11:16 dy-base CR2: 0000000000000008 CR3: 0000000056ec5000 CR4: 00000000000006e0 Jan 8 18:11:16 dy-base Process ls (pid: 3471, threadinfo ffff810080d80000, task ffff8100dcdea770) Jan 8 18:11:16 dy-base Stack: ffff81011fd1fb90 ffffffff80223f3f ffff81011fd1fb50 0000000000000282 Jan 8 18:11:16 dy-base 0000000000000001 0000000000000001 ffff81000583ba00 00000003032ca4b8 Jan 8 18:11:16 dy-base 000000000000000a 0000000000000082 ffff810103539d00 ffff810013867bf8 Jan 8 18:11:16 dy-base Call Trace: Jan 8 18:11:16 dy-base <IRQ> [<ffffffff80223f3f>] try_to_wake_up+0x3a7/0x3dc Jan 8 18:11:16 dy-base [<ffffffff80223f81>] default_wake_function+0xd/0xf Jan 8 18:11:16 dy-base [<ffffffff8023c81d>] autoremove_wake_function+0x11/0x38 Jan 8 18:11:16 dy-base [<ffffffff802225b1>] __wake_up_common+0x3e/0x68 Jan 8 18:11:16 dy-base [<ffffffff80222ac9>] __wake_up+0x38/0x50 Jan 8 18:11:16 dy-base [<ffffffff80569d1c>] sk_stream_write_space+0x5d/0x83 Jan 8 18:11:16 dy-base [<ffffffff80591afd>] tcp_check_space+0x8f/0xcd Jan 8 18:11:16 dy-base [<ffffffff80596de0>] tcp_rcv_established+0x116/0x76e Jan 8 18:11:16 dy-base [<ffffffff8059ce41>] tcp_v4_do_rcv+0x2d/0x322 Jan 8 18:11:16 dy-base [<ffffffff8059f59e>] tcp_v4_rcv+0x8bb/0x925 Jan 8 18:11:16 dy-base [<ffffffff80583b24>] ip_local_deliver_finish+0x0/0x1ce Jan 8 18:11:16 dy-base [<ffffffff805843e6>] ip_local_deliver+0x172/0x238 Jan 8 18:11:16 dy-base [<ffffffff8058422c>] ip_rcv+0x44f/0x497 Jan 8 18:11:16 dy-base [<ffffffff88004bbc>] :e1000:e1000_alloc_rx_buffers+0x1e7/0x2cb Jan 8 18:11:16 dy-base [<ffffffff8056c0a6>] netif_receive_skb+0x1ee/0x255 Jan 8 18:11:16 dy-base [<ffffffff8056de0c>] process_backlog+0x8a/0x10f Jan 8 18:11:16 dy-base [<ffffffff8056e060>] net_rx_action+0xa9/0x16e Jan 8 18:11:16 dy-base [<ffffffff8022edf9>] __do_softirq+0x57/0xc7 Jan 8 18:11:16 dy-base [<ffffffff8020aa1c>] call_softirq+0x1c/0x28 Jan 8 18:11:16 dy-base [<ffffffff8020c68a>] do_softirq+0x34/0x87 Jan 8 18:11:16 dy-base [<ffffffff8022ed0f>] irq_exit+0x3f/0x41 Jan 8 18:11:16 dy-base [<ffffffff8020c786>] do_IRQ+0xa9/0xc7 Jan 8 18:11:16 dy-base [<ffffffff80209e11>] ret_from_intr+0x0/0xa Jan 8 18:11:16 dy-base <EOI> Jan 8 18:11:16 dy-base Jan 8 18:11:16 dy-base Code: 48 03 42 08 8b 00 85 c0 7e 0a 0f 0b 68 ed 80 64 80 c2 f0 03 Jan 8 18:11:16 dy-base RIP [<ffffffff80222c74>] resched_task+0x1a/0x64 Jan 8 18:11:16 dy-base RSP <ffff81011fd1fb10> Jan 8 18:11:16 dy-base CR2: 0000000000000008 Jan 8 18:11:16 dy-base <0>Kernel panic - not syncing: Fatal exception Jan 8 18:11:16 dy-base Jan 8 18:11:16 dy-base Rebooting in 5 seconds..
(i have disabled the slab debuggint, because i need more perf.)
Thanks,
Janos
Quoted 15 lines
(i.e. I suspect this is a nbd problem, not an XFS problem)
Cheers,
Dave.
Signature · 8 lines
Dave Chinner Principal Engineer SGI Australian Software Group - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Quoted 6 lines · Janos Haar
From: "David Chinner" <[email protected]>
Quoted 3 lines
Different corruption in RBX here. Looks like semi-random garbage there. I wonder - what's the mac and ip address(es) of your machine and nbd servers?
dy-base:
no matches. Oh well, it was a long shot.
Quoted 2 lines
Some new stuff:
Jan 8 18:11:16 dy-base RAX: ffffffff80810800 RBX: 000004f0e2850659 RCX:
RBX trashed again with more random garbage.
Quoted 27 lines
Jan 8 18:11:16 dy-base [<ffffffff80223f81>] default_wake_function+0xd/0xf Jan 8 18:11:16 dy-base [<ffffffff8023c81d>] autoremove_wake_function+0x11/0x38 Jan 8 18:11:16 dy-base [<ffffffff802225b1>] __wake_up_common+0x3e/0x68 Jan 8 18:11:16 dy-base [<ffffffff80222ac9>] __wake_up+0x38/0x50 Jan 8 18:11:16 dy-base [<ffffffff80569d1c>] sk_stream_write_space+0x5d/0x83 Jan 8 18:11:16 dy-base [<ffffffff80591afd>] tcp_check_space+0x8f/0xcd Jan 8 18:11:16 dy-base [<ffffffff80596de0>] tcp_rcv_established+0x116/0x76e Jan 8 18:11:16 dy-base [<ffffffff8059ce41>] tcp_v4_do_rcv+0x2d/0x322 Jan 8 18:11:16 dy-base [<ffffffff8059f59e>] tcp_v4_rcv+0x8bb/0x925 Jan 8 18:11:16 dy-base [<ffffffff80583b24>] ip_local_deliver_finish+0x0/0x1ce Jan 8 18:11:16 dy-base [<ffffffff805843e6>] ip_local_deliver+0x172/0x238 Jan 8 18:11:16 dy-base [<ffffffff8058422c>] ip_rcv+0x44f/0x497 Jan 8 18:11:16 dy-base [<ffffffff88004bbc>] :e1000:e1000_alloc_rx_buffers+0x1e7/0x2cb Jan 8 18:11:16 dy-base [<ffffffff8056c0a6>] netif_receive_skb+0x1ee/0x255 Jan 8 18:11:16 dy-base [<ffffffff8056de0c>] process_backlog+0x8a/0x10f Jan 8 18:11:16 dy-base [<ffffffff8056e060>] net_rx_action+0xa9/0x16e Jan 8 18:11:16 dy-base [<ffffffff8022edf9>] __do_softirq+0x57/0xc7 Jan 8 18:11:16 dy-base [<ffffffff8020aa1c>] call_softirq+0x1c/0x28 Jan 8 18:11:16 dy-base [<ffffffff8020c68a>] do_softirq+0x34/0x87 Jan 8 18:11:16 dy-base [<ffffffff8022ed0f>] irq_exit+0x3f/0x41 Jan 8 18:11:16 dy-base [<ffffffff8020c786>] do_IRQ+0xa9/0xc7 Jan 8 18:11:16 dy-base [<ffffffff80209e11>] ret_from_intr+0x0/0xa
......
Quoted 1 line
Quoted 1 line
(i.e. I suspect this is a nbd problem, not an XFS problem)
There's something seriously wrong in your kernel that has, AFAICT, nothing to do with XFS. I suggest talking to the NBD folk as that is the only unusualy thing that I can see that you are using....
Cheers,
Dave.
Signature · 3 lines
Dave Chinner Principal Engineer SGI Australian Software Group
----- Original Message -----
From: "David Chinner" <[email protected]>
To: "Janos Haar" <[email protected]>
Cc: "David Chinner" <[email protected]>; <[email protected]>; <[email protected]>
Sent: Thursday, January 11, 2007 4:34 AM
Subject: Re: xfslogd-spinlock bug?
Quoted 3 lines · Janos Haar
Quoted 2 lines
From: "David Chinner" <[email protected]>
Quoted 1 line
Different corruption in RBX here. Looks like semi-random garbage
there.
Quoted 13 lines
Quoted 4 lines
Quoted 2 lines
I wonder - what's the mac and ip address(es) of your machine and nbd servers?
dy-base:
no matches. Oh well, it was a long shot.
Quoted 2 lines
Some new stuff:
Jan 8 18:11:16 dy-base RAX: ffffffff80810800 RBX: 000004f0e2850659 RCX:RBX trashed again with more random garbage.
Quoted 1 line
Jan 8 18:11:16 dy-base [<ffffffff80223f81>]
default_wake_function+0xd/0xf
Quoted 6 lines
Quoted 6 lines
Jan 8 18:11:16 dy-base [<ffffffff8023c81d>] autoremove_wake_function+0x11/0x38 Jan 8 18:11:16 dy-base [<ffffffff802225b1>] __wake_up_common+0x3e/0x68 Jan 8 18:11:16 dy-base [<ffffffff80222ac9>] __wake_up+0x38/0x50 Jan 8 18:11:16 dy-base [<ffffffff80569d1c>]
sk_stream_write_space+0x5d/0x83
Quoted 8 lines
Quoted 8 lines
Jan 8 18:11:16 dy-base [<ffffffff80591afd>] tcp_check_space+0x8f/0xcd Jan 8 18:11:16 dy-base [<ffffffff80596de0>] tcp_rcv_established+0x116/0x76e Jan 8 18:11:16 dy-base [<ffffffff8059ce41>] tcp_v4_do_rcv+0x2d/0x322 Jan 8 18:11:16 dy-base [<ffffffff8059f59e>] tcp_v4_rcv+0x8bb/0x925 Jan 8 18:11:16 dy-base [<ffffffff80583b24>] ip_local_deliver_finish+0x0/0x1ce Jan 8 18:11:16 dy-base [<ffffffff805843e6>]
ip_local_deliver+0x172/0x238 > > Jan 8 18:11:16 dy-base [<ffffffff8058422c>] ip_rcv+0x44f/0x497
Quoted 3 lines
Quoted 3 lines
Jan 8 18:11:16 dy-base [<ffffffff88004bbc>] :e1000:e1000_alloc_rx_buffers+0x1e7/0x2cb Jan 8 18:11:16 dy-base [<ffffffff8056c0a6>]
netif_receive_skb+0x1ee/0x255 > > Jan 8 18:11:16 dy-base [<ffffffff8056de0c>] process_backlog+0x8a/0x10f > > Jan 8 18:11:16 dy-base [<ffffffff8056e060>] net_rx_action+0xa9/0x16e > > Jan 8 18:11:16 dy-base [<ffffffff8022edf9>] __do_softirq+0x57/0xc7 > > Jan 8 18:11:16 dy-base [<ffffffff8020aa1c>] call_softirq+0x1c/0x28 > > Jan 8 18:11:16 dy-base [<ffffffff8020c68a>] do_softirq+0x34/0x87 > > Jan 8 18:11:16 dy-base [<ffffffff8022ed0f>] irq_exit+0x3f/0x41 > > Jan 8 18:11:16 dy-base [<ffffffff8020c786>] do_IRQ+0xa9/0xc7 > > Jan 8 18:11:16 dy-base [<ffffffff80209e11>] ret_from_intr+0x0/0xa
Quoted 8 lines
......
Quoted 1 line
Quoted 1 line
(i.e. I suspect this is a nbd problem, not an XFS problem)
There's something seriously wrong in your kernel that has, AFAICT, nothing to do with XFS. I suggest talking to the NBD folk as that is the only unusualy thing that I can see that you are using....
Cheers,
OK, i will try....
Thanks a lot,
Janos
Quoted 11 lines
Dave.
Signature · 8 lines
Dave Chinner Principal Engineer SGI Australian Software Group - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/