* libaio ioengine cause initiator crash
@ 2010-02-08 21:57 charles zhuang
2010-02-08 22:10 ` Jens Axboe
0 siblings, 1 reply; 4+ messages in thread
From: charles zhuang @ 2010-02-08 21:57 UTC (permalink / raw)
To: fio
Hi,
I am using fio libaio ioengine to benchmark on stgt iser target stack (http://stgt.sourceforge.net/). I found out that using bs size at 2k and under (2k, 1k, 512) keeps causing the iser initiator crash at different places. The initiator kernel stack dump at various places, with some of them has aio_* call involved. Most of the oops message looks like:
Oops: 0000 [1] SMP
last sysfs file: /block/sdb/stat
...
The easiest way I can produce this problem is after the initiator log in to iser stack, run following command from initiator (where /dev/sdb is the exported disk from target):
> fio --rw=read --bs=2k --numjobs=32 --iodepth=64 --sync=0 --direct=1 --randrepeat=0 --group_reporting --ioengine=libaio --filename=/dev/sdb --name=test --loops=100 --size=524288000 --runtime=30 --softrandommap=1
If I change "--bw=2k" to "--bs=4k" and over, it runs fine.
Initially I am only looking at the iser target (stgt) side. But now I suspect it's something to do with the initiator page coherency size, which I believe is 4k.
Jens and other, can you provide some insights for this? Thanks for any help.
Thanks,
Charles
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: libaio ioengine cause initiator crash
2010-02-08 21:57 libaio ioengine cause initiator crash charles zhuang
@ 2010-02-08 22:10 ` Jens Axboe
2010-02-08 22:47 ` charles zhuang
2010-02-08 23:27 ` charles zhuang
0 siblings, 2 replies; 4+ messages in thread
From: Jens Axboe @ 2010-02-08 22:10 UTC (permalink / raw)
To: charles zhuang; +Cc: fio
On Mon, Feb 08 2010, charles zhuang wrote:
> Hi,
> I am using fio libaio ioengine to benchmark on stgt iser target stack (http://stgt.sourceforge.net/). I found out that using bs size at 2k and under (2k, 1k, 512) keeps causing the iser initiator crash at different places. The initiator kernel stack dump at various places, with some of them has aio_* call involved. Most of the oops message looks like:
> Oops: 0000 [1] SMP
> last sysfs file: /block/sdb/stat
> ...
>
> The easiest way I can produce this problem is after the initiator log in to iser stack, run following command from initiator (where /dev/sdb is the exported disk from target):
> > fio --rw=read --bs=2k --numjobs=32 --iodepth=64 --sync=0 --direct=1 --randrepeat=0 --group_reporting --ioengine=libaio --filename=/dev/sdb --name=test --loops=100 --size=524288000 --runtime=30 --softrandommap=1
>
> If I change "--bw=2k" to "--bs=4k" and over, it runs fine.
>
> Initially I am only looking at the iser target (stgt) side. But now I suspect it's something to do with the initiator page coherency size, which I believe is 4k.
>
> Jens and other, can you provide some insights for this? Thanks for any help.
It's crashing in the kernel, so it should be reported as a kernel issue.
If you include the full oops in a reply, I can take a look.
If stgt is restricted to page size transfers, then it should set the
hardware block size to that (which would then cause fio with 2k bs and
O_DIRECT to error out, instead of crash).
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: libaio ioengine cause initiator crash
2010-02-08 22:10 ` Jens Axboe
@ 2010-02-08 22:47 ` charles zhuang
2010-02-08 23:27 ` charles zhuang
1 sibling, 0 replies; 4+ messages in thread
From: charles zhuang @ 2010-02-08 22:47 UTC (permalink / raw)
To: Jens Axboe; +Cc: fio
>> It's crashing in the kernel, so it should be reported as a kernel issue.
>> If you include the full oops in a reply, I can take a look.
Hi Jens,
Thanks for the quick response. I have included a few crash (separate by ===== ), let me know if you can tell anything from it, or, need me to reproduce again.
crash> log
....
sd 2:0:0:1: Attached scsi generic sg2 type 0
Unable to handle kernel paging request at ffffa3fb09d94000 RIP:
[<ffffffff8000873a>] __handle_mm_fault+0xcf/0xe5c
PGD 0
Oops: 0000 [1] SMP
last sysfs file: /block/sdb/stat
CPU 0
Modules linked in: ib_iser(U) iscsi_tcp(U) libiscsi(U) scsi_transport_iscsi(U) autofs4 hidp rfcomm l2cap bluetooth lockd(U) sunrpc(U) rdma_ucm(U) qlgc_vnic(U) ib_sdp(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ipoib_helper(U) ib_cm(U) ib_sa(U) ipv6 xfrm_nalgo crypto_api ib_uverbs(U) ib_umad(U) iw_nes(U) iw_cxgb3(U) cxgb3(U) ib_ipath(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) dm_multipath scsi_dh video hwmon backlight sbs i2c_ec i2c_core button battery asus_acpi acpi_memhotplug ac parport_pc lp parport sg tg3 libphy mlx4_core(U) shpchp pcspkr serio_raw dm_raid45 dm_message dm_region_hash dm_mem_cache dm_snapshot dm_zero dm_mirror dm_log dm_mod ata_piix libata sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 8637, comm: fio Tainted: G 2.6.18-128.el5 #1
RIP: 0010:[<ffffffff8000873a>] [<ffffffff8000873a>] __handle_mm_fault+0xcf/0xe5c
RSP: 0018:ffff810067ebbc18 EFLAGS: 00010286
RAX: 0000000000000000 RBX: ffffa3fb09d94000 RCX: 0000000000000001
RDX: ffffa3fb09d94000 RSI: ffff810067b011e8 RDI: ffff81007df2e100
RBP: ffff810000000000 R08: 0000000000000000 R09: 0000000000000247
R10: ffff81007b103bc0 R11: 000000004b703a70 R12: 00003ffffffff000
R13: ffff810067ebbda8 R14: ffff810067b011e8 R15: ffff810066dbe040
FS: 00002b33483fd0f0(0000) GS:ffffffff803ac000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: ffffa3fb09d94000 CR3: 00000000672e6000 CR4: 00000000000006e0
Process fio (pid: 8637, threadinfo ffff810067eba000, task ffff810066dbe040)
Stack: ffff810067bbd0a8 0000000100000004 0000000018ef0600 ffff81007df2e100
0000000000000400 00000000000085d4 0000000000800010 ffffffff8001bd3d
ffff810066dbe230 0000000480034508 ffff810067eb8ce8 0000000000000007
Call Trace:
[<ffffffff8001bd3d>] generic_make_request+0x1d2/0x1e9
[<ffffffff80066b9a>] do_page_fault+0x4cb/0x830
[<ffffffff800dd928>] bio_set_pages_dirty+0x23/0x38
[<ffffffff8005be48>] blk_backing_dev_unplug+0x54/0x58
[<ffffffff80089c4a>] dequeue_task+0x18/0x37
[<ffffffff8005dde9>] error_exit+0x0/0x84
[<ffffffff80061e03>] copy_user_generic+0x8f/0x16c
[<ffffffff800ea594>] sys_io_getevents+0x32b/0x3b0
[<ffffffff800e9a3b>] timeout_func+0x0/0x10
[<ffffffff8008a461>] default_wake_function+0x0/0xe
[<ffffffff8005d28d>] tracesys+0xd5/0xe0
Code: 48 83 3b 00 75 1a 48 8b 54 24 10 48 8b 7c 24 18 48 89 de e8
RIP [<ffffffff8000873a>] __handle_mm_fault+0xcf/0xe5c
RSP <ffff810067ebbc18>
crash> bt
PID: 8637 TASK: ffff810066dbe040 CPU: 0 COMMAND: "fio"
#0 [ffff810067ebb970] crash_kexec at ffffffff800aaa0c
#1 [ffff810067ebba30] __die at ffffffff8006520f
#2 [ffff810067ebba70] do_page_fault at ffffffff80066e1c
#3 [ffff810067ebbb60] error_exit at ffffffff8005dde9
[exception RIP: __handle_mm_fault+207]
RIP: ffffffff8000873a RSP: ffff810067ebbc18 RFLAGS: 00010286
RAX: 0000000000000000 RBX: ffffa3fb09d94000 RCX: 0000000000000001
RDX: ffffa3fb09d94000 RSI: ffff810067b011e8 RDI: ffff81007df2e100
RBP: ffff810000000000 R8: 0000000000000000 R9: 0000000000000247
R10: ffff81007b103bc0 R11: 000000004b703a70 R12: 00003ffffffff000
R13: ffff810067ebbda8 R14: ffff810067b011e8 R15: ffff810066dbe040
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#4 [ffff810067ebbc50] generic_make_request at ffffffff8001bd3d
#5 [ffff810067ebbcf0] bio_set_pages_dirty at ffffffff800dd928
#6 [ffff810067ebbd10] blk_backing_dev_unplug at ffffffff8005be48
#7 [ffff810067ebbda0] error_exit at ffffffff8005dde9
[exception RIP: copy_user_generic+143]
RIP: ffffffff80061e03 RSP: ffff810067ebbe58 RFLAGS: 00010202
RAX: 0000000000000000 RBX: 0000000000000008 RCX: 0000000000000004
RDX: 0000000000000020 RSI: ffff810067ebbf18 RDI: 0000000018ef0600
RBP: 0000000000000001 R8: 0000000000000000 R9: 0000000000000247
R10: ffff81007b103bc0 R11: 000000004b703a70 R12: ffff810068253340
R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#8 [ffff810067ebbe60] sys_io_getevents at ffffffff800ea594
#9 [ffff810067ebbf80] tracesys at ffffffff8005d28d (via system_call)
RIP: 00002b33481fb5b4 RSP: 00007fff628b9c10 RFLAGS: 00000246
RAX: ffffffffffffffda RBX: ffffffff8005d28d RCX: ffffffffffffffff
RDX: 0000000000000001 RSI: 0000000000000001 RDI: 00002b334c8df000
RBP: 0000000000000001 R8: 0000000000000000 R9: 0000000000000000
R10: 0000000018ef0600 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000001 R15: 00007fff628b9c50
ORIG_RAX: 00000000000000d0 CS: 0033 SS: 002b
==================================================================
crash> log
sd 2:0:0:1: Attached scsi disk sdb
sd 2:0:0:1: Attached scsi generic sg2 type 0
list_del corruption. prev->next should be ffff810061d24548, but was 29b63c9ee4946311
----------- [cut here ] --------- [please bite here ] ---------
Kernel BUG at lib/list_debug.c:65
invalid opcode: 0000 [1] SMP
last sysfs file: /block/sdb/stat
CPU 0
Modules linked in: ib_iser(U) iscsi_tcp(U) libiscsi(U) scsi_transport_iscsi(U) autofs4 hidp rfcomm l2cap bluetooth lockd(U) sunrpc(U) rdma_ucm(U) qlgc_vnic(U) ib_sdp(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ipoib_helper(U) ib_cm(U) ib_sa(U) ipv6 xfrm_nalgo crypto_api ib_uverbs(U) ib_umad(U) iw_nes(U) iw_cxgb3(U) cxgb3(U) ib_ipath(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) dm_multipath scsi_dh video hwmon backlight sbs i2c_ec i2c_core button battery asus_acpi acpi_memhotplug ac parport_pc lp parport sg pcspkr tg3 serio_raw mlx4_core(U) libphy shpchp dm_raid45 dm_message dm_region_hash dm_mem_cache dm_snapshot dm_zero dm_mirror dm_log dm_mod ata_piix libata sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 0, comm: swapper Tainted: G 2.6.18-128.el5 #1
RIP: 0010:[<ffffffff8014c5a3>] [<ffffffff8014c5a3>] list_del+0x21/0x71
RSP: 0018:ffffffff80425d30 EFLAGS: 00010082
RAX: 0000000000000058 RBX: ffff810061d24548 RCX: ffffffff802f7aa8
RDX: ffffffff802f7aa8 RSI: 0000000000000000 RDI: ffffffff802f7aa0
RBP: ffff8100606cf200 R08: ffffffff802f7aa8 R09: 0000000000000046
R10: 0000000000000001 R11: ffffffff80161742 R12: ffff810061d24548
R13: 0000000000000800 R14: 0000000000000000 R15: 0000000000000213
FS: 0000000000000000(0000) GS:ffffffff803ac000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00002afdc88d3000 CR3: 000000006230e000 CR4: 00000000000006e0
Process swapper (pid: 0, threadinfo ffffffff803dc000, task ffffffff802eeae0)
Stack: ffff810061d24480 ffffffff800e993e ffff810061d24480 ffff8100606cf200
ffff8100606cf268 ffffffff800e9e24 0000000000000282 0000000000000000
ffff8100624f0400 ffff8100624f071c 0000000000000246 0000000000000800
Call Trace:
<IRQ> [<ffffffff800e993e>] __aio_put_req+0x4a/0x117
[<ffffffff800e9e24>] aio_complete+0x18c/0x1c8
[<ffffffff800ee095>] dio_bio_end_aio+0x9f/0xbf
[<ffffffff8002ca64>] __end_that_request_first+0x265/0x5df
[<ffffffff88079fb4>] :scsi_mod:scsi_end_request+0x27/0xcd
[<ffffffff8807a1a8>] :scsi_mod:scsi_io_completion+0x14e/0x324
[<ffffffff880a67cd>] :sd_mod:sd_rw_intr+0x21d/0x257
[<ffffffff8807a43d>] :scsi_mod:scsi_device_unbusy+0x67/0x81
[<ffffffff800376ff>] blk_done_softirq+0x5f/0x6d
[<ffffffff80011fbc>] __do_softirq+0x89/0x133
[<ffffffff8005e2fc>] call_softirq+0x1c/0x28
[<ffffffff8006cada>] do_softirq+0x2c/0x85
[<ffffffff8006c962>] do_IRQ+0xec/0xf5
[<ffffffff80056be3>] mwait_idle+0x0/0x4a
[<ffffffff8005d615>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff80056c19>] mwait_idle+0x36/0x4a
[<ffffffff80048d19>] cpu_idle+0x95/0xb8
[<ffffffff803e7801>] start_kernel+0x220/0x225
[<ffffffff803e722f>] _sinittext+0x22f/0x236
Code: 0f 0b 68 3e 62 2a 80 c2 41 00 48 8b 03 48 8b 50 08 48 39 da
RIP [<ffffffff8014c5a3>] list_del+0x21/0x71
RSP <ffffffff80425d30>
crash> bt
PID: 0 TASK: ffffffff802eeae0 CPU: 0 COMMAND: "swapper"
#0 [ffffffff80425a90] crash_kexec at ffffffff800aaa0c
#1 [ffffffff80425b50] __die at ffffffff8006520f
#2 [ffffffff80425b90] die at ffffffff8006bc17
#3 [ffffffff80425bc0] do_invalid_op at ffffffff8006c1d7
#4 [ffffffff80425c80] error_exit at ffffffff8005dde9
[exception RIP: list_del+33]
RIP: ffffffff8014c5a3 RSP: ffffffff80425d30 RFLAGS: 00010082
RAX: 0000000000000058 RBX: ffff810061d24548 RCX: ffffffff802f7aa8
RDX: ffffffff802f7aa8 RSI: 0000000000000000 RDI: ffffffff802f7aa0
RBP: ffff8100606cf200 R8: ffffffff802f7aa8 R9: 0000000000000046
R10: 0000000000000001 R11: ffffffff80161742 R12: ffff810061d24548
R13: 0000000000000800 R14: 0000000000000000 R15: 0000000000000213
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#5 [ffffffff80425d38] __aio_put_req at ffffffff800e993e
#6 [ffffffff80425d58] aio_complete at ffffffff800e9e24
#7 [ffffffff80425d98] dio_bio_end_aio at ffffffff800ee095
#8 [ffffffff80425dc8] __end_that_request_first at ffffffff8002ca64
#9 [ffffffff80425e58] scsi_io_completion at ffffffff8807a1a8
#10 [ffffffff80425eb8] sd_rw_intr at ffffffff880a67cd
#11 [ffffffff80425f18] blk_done_softirq at ffffffff800376ff
#12 [ffffffff80425f38] __do_softirq at ffffffff80011fbc
#13 [ffffffff80425f68] call_softirq at ffffffff8005e2fc
#14 [ffffffff80425f80] do_softirq at ffffffff8006cada
#15 [ffffffff80425f90] do_IRQ at ffffffff8006c962
--- <IRQ stack> ---
#16 [ffffffff803ddee8] ret_from_intr at ffffffff8005d615
[exception RIP: mwait_idle+54]
RIP: ffffffff80056c19 RSP: ffffffff803ddf90 RFLAGS: 00000246
RAX: 0000000000000000 RBX: 0000000000090000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff802f0658
RBP: ffffffff802eecd0 R8: ffffffff803dc000 R9: 000000000000003f
R10: ffff81005e5ed0c0 R11: 0000000000000050 R12: 00000000005f44fb
R13: 0000008ef40d85b4 R14: ffff810037fd9080 R15: ffffffff802eeae0
ORIG_RAX: ffffffffffffffbd CS: 0010 SS: 0018
#17 [ffffffff803ddf90] cpu_idle at ffffffff80048d19
=====================================================
crash> log
sd 2:0:0:1: Attached scsi generic sg2 type 0
stack segment: 0000 [1] SMP
last sysfs file: /block/sdb/stat
CPU 0
Modules linked in: ib_iser(U) iscsi_tcp(U) libiscsi(U) scsi_transport_iscsi(U) autofs4 hidp rfcomm l2cap bluetooth lockd(U) sunrpc(U) rdma_ucm(U) qlgc_vnic(U) ib_sdp(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ipoib_helper(U) ib_cm(U) ib_sa(U) ipv6 xfrm_nalgo crypto_api ib_uverbs(U) ib_umad(U) iw_nes(U) iw_cxgb3(U) cxgb3(U) ib_ipath(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) dm_multipath scsi_dh video hwmon backlight sbs i2c_ec i2c_core button battery asus_acpi acpi_memhotplug ac parport_pc lp parport sg mlx4_core(U) serio_raw pcspkr tg3 shpchp libphy dm_raid45 dm_message dm_region_hash dm_mem_cache dm_snapshot dm_zero dm_mirror dm_log dm_mod ata_piix libata sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 0, comm: swapper Tainted: G 2.6.18-128.el5 #1
RIP: 0010:[<ffffffff886940fe>] [<ffffffff886940fe>] :ib_iser:iser_snd_completion+0x1d/0xf7
RSP: 0018:ffffffff80425e90 EFLAGS: 00010297
RAX: 0000000000000000 RBX: ffff810068092440 RCX: 0000000000000000
RDX: 00000000a03c0000 RSI: 0000000000000286 RDI: ffff810068092340
RBP: 60c6a2c052d4011f R08: ffffffff803dc000 R09: 0000000000000000
R10: 0000000000000042 R11: 0000000000000000 R12: ffff810068092340
R13: 000000000000000a R14: 0000000000000000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffffffff803ac000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00002ada14c6e000 CR3: 0000000068ae5000 CR4: 00000000000006e0
Process swapper (pid: 0, threadinfo ffffffff803dc000, task ffffffff802eeae0)
Stack: ffff81006b97f860 ffff810068092340 ffff81006e9a0800 000000000000000a
0000000000000000 ffffffff886934f2 ffff810068092340 0000008000000000
0000004c7c078780 ffff81006b850600 0000000000000000 0002000000000000
Call Trace:
<IRQ> [<ffffffff886934f2>] :ib_iser:iser_cq_tasklet_fn+0x4e/0x14f
[<ffffffff800923c3>] tasklet_action+0x89/0xfd
[<ffffffff80011fbc>] __do_softirq+0x89/0x133
[<ffffffff8005e2fc>] call_softirq+0x1c/0x28
[<ffffffff8006cada>] do_softirq+0x2c/0x85
[<ffffffff8006c962>] do_IRQ+0xec/0xf5
[<ffffffff80056be3>] mwait_idle+0x0/0x4a
[<ffffffff8005d615>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff80056c19>] mwait_idle+0x36/0x4a
[<ffffffff80048d19>] cpu_idle+0x95/0xb8
[<ffffffff803e7801>] start_kernel+0x220/0x225
[<ffffffff803e722f>] _sinittext+0x22f/0x236
Code: 4c 8b 75 00 4d 8b 2e 7e 18 48 89 da 48 c7 c6 a0 63 69 88 48
RIP [<ffffffff886940fe>] :ib_iser:iser_snd_completion+0x1d/0xf7
RSP <ffffffff80425e90>
crash> bt
PID: 0 TASK: ffffffff802eeae0 CPU: 0 COMMAND: "swapper"
#0 [ffffffff80426de0] crash_kexec at ffffffff800aaa0c
#1 [ffffffff80426ea0] __die at ffffffff8006520f
#2 [ffffffff80426ee0] die at ffffffff8006bc17
#3 [ffffffff80426f10] do_stack_segment at ffffffff8006c564
#4 [ffffffff80426f50] stack_segment at ffffffff8005e221
[exception RIP: iser_snd_completion+29]
RIP: ffffffff886940fe RSP: ffffffff80425e90 RFLAGS: 00010297
RAX: 0000000000000000 RBX: ffff810068092440 RCX: 0000000000000000
RDX: 00000000a03c0000 RSI: 0000000000000286 RDI: ffff810068092340
RBP: 60c6a2c052d4011f R8: ffffffff803dc000 R9: 0000000000000000
R10: 0000000000000042 R11: 0000000000000000 R12: ffff810068092340
R13: 000000000000000a R14: 0000000000000000 R15: 0000000000000000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
--- <exception stack> ---
#5 [ffffffff80425e90] iser_snd_completion at ffffffff886940fe
#6 [ffffffff80425eb8] iser_cq_tasklet_fn at ffffffff886934f2
#7 [ffffffff80425f18] tasklet_action at ffffffff800923c3
#8 [ffffffff80425f38] __do_softirq at ffffffff80011fbc
#9 [ffffffff80425f68] call_softirq at ffffffff8005e2fc
#10 [ffffffff80425f80] do_softirq at ffffffff8006cada
#11 [ffffffff80425f90] do_IRQ at ffffffff8006c962
--- <IRQ stack> ---
#12 [ffffffff803ddee8] ret_from_intr at ffffffff8005d615
[exception RIP: mwait_idle+54]
RIP: ffffffff80056c19 RSP: ffffffff803ddf90 RFLAGS: 00000246
RAX: 0000000000000000 RBX: 0000000000090000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff802f0658
RBP: ffffffff802eecd0 R8: ffffffff803dc000 R9: 000000000000003f
R10: ffff81006a3ef1c0 R11: ffff810068b03ee8 R12: 00000000000384db
R13: 00000102e7100b0e R14: ffff810037fd9080 R15: ffffffff802eeae0
ORIG_RAX: ffffffffffffffbd CS: 0010 SS: 0018
#13 [ffffffff803ddf90] cpu_idle at ffffffff80048d19
===========================================================
crash> log
sd 4:0:0:1: Attached scsi disk sdb
sd 4:0:0:1: Attached scsi generic sg3 type 0
NMI Watchdog detected LOCKUP on CPU 2
CPU 2
Modules linked in: ib_iser(U) iscsi_tcp(U) libiscsi(U) scsi_transport_iscsi(U) autofs4 hidp rfcomm l2cap bluetooth lockd(U) sunrpc(U) cpufreq_ondemand acpi_cpufreq freq_table rdma_ucm(U) qlgc_vnic(U) ib_sdp(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ipoib_helper(U) ib_cm(U) ib_sa(U) ipv6 xfrm_nalgo crypto_api ib_uverbs(U) ib_umad(U) iw_nes(U) iw_cxgb3(U) cxgb3(U) ib_ipath(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) dm_multipath scsi_dh video hwmon backlight sbs i2c_ec button battery asus_acpi acpi_memhotplug ac parport_pc lp parport snd_hda_intel snd_seq_dummy snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device sr_mod snd_pcm_oss cdrom snd_mixer_oss fio_driver(PU) shpchp snd_pcm i2c_i801 pcspkr sg snd_timer snd_page_alloc snd_hwdep snd serio_raw i2c_core e1000e soundcore fio_port(PU) mlx4_core(U) dm_raid45 dm_message dm_region_hash dm_mem_cache dm_snapshot dm_zero dm_mirror dm_log dm_mod ata_piix libata sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd
ehci_hcd
Pid: 0, comm: swapper Tainted: P 2.6.18-128.el5 #1
RIP: 0010:[<ffffffff80064cc0>] [<ffffffff80064cc0>] .text.lock.spinlock+0xe/0x30
RSP: 0018:ffff810104787d98 EFLAGS: 00000086
RAX: 0000000000000246 RBX: 0000000000000000 RCX: ffff8101093c3340
RDX: 0000000000000063 RSI: ffff8101093c3340 RDI: ffff81010915b71c
RBP: ffff81010915b400 R08: 0000000000000286 R09: ffff81010a577800
R10: ffff810110523800 R11: ffffffff800449ab R12: ffff81010915b71c
R13: ffff810108283708 R14: 0000000000000800 R15: 0000000000001800
FS: 0000000000000000(0000) GS:ffff81010475fe40(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 000000000040e000 CR3: 00000001079d0000 CR4: 00000000000006e0
Process swapper (pid: 0, threadinfo ffff810104780000, task ffff810104760080)
Stack: ffffffff800ee02d ffff8101080e235c 0000000000000000 ffff8101093c3340
ffff8101388ff340 ffff810108283708 ffffffff8002ca64 ffff8101388ff340
0000000000000001 0000000000000000 0000000000000286 0000000000000001
Call Trace:
<IRQ> [<ffffffff800ee02d>] dio_bio_end_aio+0x37/0xbf
[<ffffffff8002ca64>] __end_that_request_first+0x265/0x5df
[<ffffffff88079fb4>] :scsi_mod:scsi_end_request+0x27/0xcd
[<ffffffff8807a1a8>] :scsi_mod:scsi_io_completion+0x14e/0x324
[<ffffffff880a67cd>] :sd_mod:sd_rw_intr+0x21d/0x257
[<ffffffff8807a43d>] :scsi_mod:scsi_device_unbusy+0x67/0x81
[<ffffffff800376ff>] blk_done_softirq+0x5f/0x6d
[<ffffffff80011fbc>] __do_softirq+0x89/0x133
[<ffffffff8005e2fc>] call_softirq+0x1c/0x28
[<ffffffff8006cada>] do_softirq+0x2c/0x85
[<ffffffff8006c962>] do_IRQ+0xec/0xf5
[<ffffffff8005d615>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff8018d192>] acpi_processor_idle+0x275/0x43a
[<ffffffff8018d188>] acpi_processor_idle+0x26b/0x43a
[<ffffffff8018cf1d>] acpi_processor_idle+0x0/0x43a
[<ffffffff8018cf1d>] acpi_processor_idle+0x0/0x43a
[<ffffffff80048d19>] cpu_idle+0x95/0xb8
[<ffffffff80076be6>] start_secondary+0x45a/0x469
Code: 83 3f 00 7e f9 e9 f9 fe ff ff f3 90 83 3f 00 7e f9 e9 f8 fe
BUG: warning at arch/x86_64/kernel/crash.c:148/nmi_shootdown_cpus() (Tainted: P )
Call Trace:
<NMI> [<ffffffff80079d56>] machine_crash_shutdown+0xaa/0xf3
[<ffffffff800aaa00>] crash_kexec+0xcc/0xe8
[<ffffffff800449ab>] mempool_free_slab+0x0/0xe
[<ffffffff80064cc0>] .text.lock.spinlock+0xe/0x30
[<ffffffff8006535d>] die_nmi+0x46/0xa3
[<ffffffff80065ac3>] nmi_watchdog_tick+0x157/0x1d3
[<ffffffff800656e1>] default_do_nmi+0x81/0x225
[<ffffffff8006594e>] do_nmi+0x43/0x61
[<ffffffff80064fa7>] nmi+0x7f/0x88
[<ffffffff800449ab>] mempool_free_slab+0x0/0xe
[<ffffffff80064cc0>] .text.lock.spinlock+0xe/0x30
<<EOE>> <IRQ> [<ffffffff800ee02d>] dio_bio_end_aio+0x37/0xbf
[<ffffffff8002ca64>] __end_that_request_first+0x265/0x5df
[<ffffffff88079fb4>] :scsi_mod:scsi_end_request+0x27/0xcd
[<ffffffff8807a1a8>] :scsi_mod:scsi_io_completion+0x14e/0x324
[<ffffffff880a67cd>] :sd_mod:sd_rw_intr+0x21d/0x257
[<ffffffff8807a43d>] :scsi_mod:scsi_device_unbusy+0x67/0x81
[<ffffffff800376ff>] blk_done_softirq+0x5f/0x6d
[<ffffffff80011fbc>] __do_softirq+0x89/0x133
[<ffffffff8005e2fc>] call_softirq+0x1c/0x28
[<ffffffff8006cada>] do_softirq+0x2c/0x85
[<ffffffff8006c962>] do_IRQ+0xec/0xf5
[<ffffffff8005d615>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff8018d192>] acpi_processor_idle+0x275/0x43a
[<ffffffff8018d188>] acpi_processor_idle+0x26b/0x43a
[<ffffffff8018cf1d>] acpi_processor_idle+0x0/0x43a
[<ffffffff8018cf1d>] acpi_processor_idle+0x0/0x43a
[<ffffffff80048d19>] cpu_idle+0x95/0xb8
[<ffffffff80076be6>] start_secondary+0x45a/0x469
crash> bt
PID: 0 TASK: ffff810104760080 CPU: 2 COMMAND: "swapper"
#0 [ffff810104788dc0] crash_kexec at ffffffff800aaa0c
#1 [ffff810104788e80] die_nmi at ffffffff8006535d
#2 [ffff810104788ea0] nmi_watchdog_tick at ffffffff80065ac3
#3 [ffff810104788ef0] default_do_nmi at ffffffff800656e1
#4 [ffff810104788f40] do_nmi at ffffffff8006594e
#5 [ffff810104788f50] nmi at ffffffff80064fa7
[exception RIP: .text.lock.spinlock+14]
RIP: ffffffff80064cc0 RSP: ffff810104787d98 RFLAGS: 00000086
RAX: 0000000000000246 RBX: 0000000000000000 RCX: ffff8101093c3340
RDX: 0000000000000063 RSI: ffff8101093c3340 RDI: ffff81010915b71c
RBP: ffff81010915b400 R8: 0000000000000286 R9: ffff81010a577800
R10: ffff810110523800 R11: ffffffff800449ab R12: ffff81010915b71c
R13: ffff810108283708 R14: 0000000000000800 R15: 0000000000001800
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
--- <exception stack> ---
#6 [ffff810104787d98] .text.lock.spinlock at ffffffff80064cc0 (via _spin_lock_irqsave)
#7 [ffff810104787d98] dio_bio_end_aio at ffffffff800ee02d
#8 [ffff810104787dc8] __end_that_request_first at ffffffff8002ca64
#9 [ffff810104787e58] scsi_io_completion at ffffffff8807a1a8
#10 [ffff810104787eb8] sd_rw_intr at ffffffff880a67cd
#11 [ffff810104787f18] blk_done_softirq at ffffffff800376ff
#12 [ffff810104787f38] __do_softirq at ffffffff80011fbc
#13 [ffff810104787f68] call_softirq at ffffffff8005e2fc
#14 [ffff810104787f80] do_softirq at ffffffff8006cada
#15 [ffff810104787f90] do_IRQ at ffffffff8006c962
--- <IRQ stack> ---
#16 [ffff810104781df8] ret_from_intr at ffffffff8005d615
[exception RIP: acpi_processor_idle+629]
RIP: ffffffff8018d192 RSP: ffff810104781ea8 RFLAGS: 00000282
RAX: ffff810104781fd8 RBX: ffff81013baf5960 RCX: 0000000000000003
RDX: ffff81013baf5800 RSI: 0000000000000082 RDI: ffffffff8049fd6c
RBP: ffff810104781ee8 R8: ffff810104780000 R9: ffff810104781ecc
R10: 0000000000000046 R11: ffff810104781ee8 R12: ffff810107cb9880
R13: 0000000010008040 R14: ffff810107cb9880 R15: ffff810107cb9880
ORIG_RAX: ffffffffffffff85 CS: 0010 SS: 0018
#17 [ffff810104781ea0] acpi_processor_idle at ffffffff8018d188
#18 [ffff810104781ef0] cpu_idle at ffffffff80048d19
=============================================================
crash> log
sd 4:0:0:1: Attached scsi disk sdb
sd 4:0:0:1: Attached scsi generic sg3 type 0
__end_that: dev sdb: flags = REQ_SORTED REQ_CMD REQ_STARTED REQ_DONTPREP REQ_ELVPRIV
sector 756, nr/cnr 4/4
bio ffff8101095435c0, biotail ffff8101095435c0, buffer 0000000000000000, data 0000000000000000, len 0
__end_that_request_first: bio idx 57565 >= vcnt 3573
general protection fault: 0000 [1] SMP
last sysfs file: /block/sdb/stat
CPU 2
Modules linked in: ib_iser(U) iscsi_tcp(U) libiscsi(U) scsi_transport_iscsi(U) autofs4 hidp rfcomm l2cap bluetooth lockd(U) sunrpc(U) cpufreq_ondemand acpi_cpufreq freq_table rdma_ucm(U) qlgc_vnic(U) ib_sdp(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ipoib_helper(U) ib_cm(U) ib_sa(U) ipv6 xfrm_nalgo crypto_api ib_uverbs(U) ib_umad(U) iw_nes(U) iw_cxgb3(U) cxgb3(U) ib_ipath(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) dm_multipath scsi_dh video hwmon backlight sbs i2c_ec button battery asus_acpi acpi_memhotplug ac parport_pc lp parport snd_hda_intel snd_seq_dummy snd_seq_oss fio_driver(PU) snd_seq_midi_event snd_seq fio_port(PU) snd_seq_device sr_mod snd_pcm_oss i2c_i801 e1000e cdrom snd_mixer_oss i2c_core shpchp snd_pcm serio_raw pcspkr snd_timer snd_page_alloc snd_hwdep snd soundcore mlx4_core(U) sg dm_raid45 dm_message dm_region_hash dm_mem_cache dm_snapshot dm_zero dm_mirror dm_log dm_mod ata_piix libata sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd
ehci_hcd
Pid: 3695, comm: fio Tainted: P 2.6.18-128.el5 #1
RIP: 0010:[<ffffffff8002cc0e>] [<ffffffff8002cc0e>] __end_that_request_first+0x40f/0x5df
RSP: 0018:ffff810104787dd0 EFLAGS: 00010202
RAX: 00000000000e0dd0 RBX: 0000000000000000 RCX: a0a6be50cb5fe143
RDX: ffff8101095435c0 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffff8101095435c0 R08: ffffffff802f7aa8 R09: 0000000000000046
R10: ffff810104787a70 R11: 0000000000000080 R12: ffff81010892d968
R13: ffff810107c87e78 R14: 0000000000000000 R15: 0000000000000800
FS: 00002b7ea90760f0(0000) GS:ffff81010475fe40(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000000040e000 CR3: 0000000106eff000 CR4: 00000000000006e0
Process fio (pid: 3695, threadinfo ffff810106c98000, task ffff8101381ac7a0)
Stack: ffff81010892d968 0000000000000001 0000000000000000 ffffffff8005bd48
0000000000000001 ffff810107c87e78 ffff81011e9663c0 ffff81010892d968
0000000000000001 0000000000000001 0000000000000000 ffffffff88079fb4
Call Trace:
<IRQ> [<ffffffff8005bd48>] blk_run_queue+0x41/0x72
[<ffffffff88079fb4>] :scsi_mod:scsi_end_request+0x27/0xcd
[<ffffffff8807a1a8>] :scsi_mod:scsi_io_completion+0x14e/0x324
[<ffffffff880a67cd>] :sd_mod:sd_rw_intr+0x21d/0x257
[<ffffffff8807a43d>] :scsi_mod:scsi_device_unbusy+0x67/0x81
[<ffffffff800376ff>] blk_done_softirq+0x5f/0x6d
[<ffffffff80011fbc>] __do_softirq+0x89/0x133
[<ffffffff8005e2fc>] call_softirq+0x1c/0x28
[<ffffffff8006cada>] do_softirq+0x2c/0x85
[<ffffffff8006c962>] do_IRQ+0xec/0xf5
[<ffffffff8005d615>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff800e95a7>] aio_pread+0x0/0x9b
[<ffffffff800e9ef3>] aio_run_iocb+0x93/0x18a
[<ffffffff80126d43>] selinux_file_permission+0x9f/0xb6
[<ffffffff800eaa84>] io_submit_one+0x29d/0x2ea
[<ffffffff800eafc3>] sys_io_submit+0x9b/0x108
[<ffffffff8005d28d>] tracesys+0xd5/0xe0
Code: 8b 44 08 08 c1 e8 09 41 89 45 50 41 89 45 38 0f b7 72 2a 48
RIP [<ffffffff8002cc0e>] __end_that_request_first+0x40f/0x5df
RSP <ffff810104787dd0>
crash> bt
PID: 3695 TASK: ffff8101381ac7a0 CPU: 2 COMMAND: "fio"
#0 [ffff810104787bb0] crash_kexec at ffffffff800aaa0c
#1 [ffff810104787c70] __die at ffffffff8006520f
#2 [ffff810104787cb0] die at ffffffff8006bc17
#3 [ffff810104787ce0] do_general_protection at ffffffff80065657
#4 [ffff810104787d20] error_exit at ffffffff8005dde9
[exception RIP: __end_that_request_first+1039]
RIP: ffffffff8002cc0e RSP: ffff810104787dd0 RFLAGS: 00010202
RAX: 00000000000e0dd0 RBX: 0000000000000000 RCX: a0a6be50cb5fe143
RDX: ffff8101095435c0 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffff8101095435c0 R8: ffffffff802f7aa8 R9: 0000000000000046
R10: ffff810104787a70 R11: 0000000000000080 R12: ffff81010892d968
R13: ffff810107c87e78 R14: 0000000000000000 R15: 0000000000000800
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#5 [ffff810104787de8] blk_run_queue at ffffffff8005bd48
#6 [ffff810104787e28] scsi_end_request at ffffffff88079fb4
#7 [ffff810104787e58] scsi_io_completion at ffffffff8807a1a8
#8 [ffff810104787eb8] sd_rw_intr at ffffffff880a67cd
#9 [ffff810104787f18] blk_done_softirq at ffffffff800376ff
#10 [ffff810104787f38] __do_softirq at ffffffff80011fbc
#11 [ffff810104787f68] call_softirq at ffffffff8005e2fc
#12 [ffff810104787f80] do_softirq at ffffffff8006cada
#13 [ffff810104787f90] do_IRQ at ffffffff8006c962
--- <IRQ stack> ---
#14 [ffff810106c99df8] ret_from_intr at ffffffff8005d615
[exception RIP: aio_run_iocb+147]
RIP: ffffffff800e9ef3 RSP: ffff810106c99ea8 RFLAGS: 00000282
RAX: 0000000000000000 RBX: ffff810107c45bf8 RCX: ffffffff800e95a7
RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff8101095bcbc0
RBP: 0000000000000001 R8: ffff810106c99d28 R9: 0000000000000000
R10: 0000000000000000 R11: 0000000000000048 R12: ffff81010b602118
R13: ffff8101381ac7a0 R14: ffffffff80124525 R15: ffff810106510ec0
ORIG_RAX: ffffffffffffff85 CS: 0010 SS: 0018
#15 [ffff810106c99ea0] selinux_file_permission at ffffffff80126d43
#16 [ffff810106c99ec0] io_submit_one at ffffffff800eaa84
#17 [ffff810106c99ef0] sys_io_submit at ffffffff800eafc3
#18 [ffff810106c99f80] tracesys at ffffffff8005d28d (via system_call)
RIP: 00002b7ea8e74607 RSP: 00007fff01c473d8 RFLAGS: 00000202
RAX: ffffffffffffffda RBX: ffffffff8005d28d RCX: ffffffffffffffff
RDX: 0000000015bb0e10 RSI: 0000000000000001 RDI: 00002b7ead554000
RBP: 0000000015bab980 R8: 0000000012c75a91 R9: 00000000001a81fc
R10: 000000004b704f43 R11: 0000000000000202 R12: 0000000015bb1020
R13: 0000000000000000 R14: 00002b7ead1ddb00 R15: 00007fff01c47430
ORIG_RAX: 00000000000000d1 CS: 0033 SS: 002b
==================================================================
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: libaio ioengine cause initiator crash
2010-02-08 22:10 ` Jens Axboe
2010-02-08 22:47 ` charles zhuang
@ 2010-02-08 23:27 ` charles zhuang
1 sibling, 0 replies; 4+ messages in thread
From: charles zhuang @ 2010-02-08 23:27 UTC (permalink / raw)
To: Jens Axboe; +Cc: fio
>> If stgt is restricted to page size transfers, then it should set the
hardware block size to that (which would then cause fio with 2k bs and
O_DIRECT to error out, instead of crash).
Hi Jens,
Block size is not an issue. I can use other ioengine (like sync) to run thru the test with bs=2k & under, only libaio ioengine has this problem.
Besides, when I run fio with "--ioengine=sync" and "--iodepth=64", the initiator immediately crash. I know iodepth is only matter to aio type, but it shouldn't crash the kernel.
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2010-02-08 23:27 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2010-02-08 21:57 libaio ioengine cause initiator crash charles zhuang
2010-02-08 22:10 ` Jens Axboe
2010-02-08 22:47 ` charles zhuang
2010-02-08 23:27 ` charles zhuang
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.