extfs reliability
in [Kernel]
|
From: Vladislav Bolkhovitin on 29 Jul 2010 09:10 Christoph Hellwig, on 07/29/2010 12:31 PM wrote: > My reading of the ext3/jbd code we explicitly wait on I/O completion > of dependent writes, and only require those to actually be stable > by issueing a flush. If that wasn't the case the default ext3 > barriers off behaviour would not only be dangerous on devices with > volatile write caches, but also on devices that do not have them, > which in addition to the reading of the code is not what we've seen > in actual power fail testing, where ext3 does well as long as there > is no volatile write cache. Basically, it is so, but, unfortunately, not absolutely. I've just tried 2 tests on ext4 with iSCSI: # uname -a Linux ini 2.6.32-22-386 #36-Ubuntu SMP Fri Jun 4 00:27:09 UTC 2010 i686 GNU/Linux # e2fsck -f -y /dev/sdb e2fsck 1.41.11 (14-Mar-2010) Pass 1: Checking inodes, blocks, and sizes Pass 2: Checking directory structure Pass 3: Checking directory connectivity Pass 4: Checking reference counts Pass 5: Checking group summary information /dev/sdb: 49/640000 files (0.0% non-contiguous), 56496/1280000 blocks root(a)ini:~# mount -t ext4 -o barrier=1 /dev/sdb /mnt root(a)ini:~# cd /mnt/dbench-mod/ root(a)ini:/mnt/dbench-mod# ./dbench 50 50 clients started .... <-- Pull cable <-- After sometime a lot of warnings like: (22002) open CLIENTS/CLIENT44/~DMTMP/COREL/CDRBARS.CFG failed for handle 4235 (Read-only file system) (22004) open CLIENTS/CLIENT44/~DMTMP/COREL/ARTISTIC.ACL failed for handle 4236 (Read-only file system) (22010) open CLIENTS/CLIENT44/~DMTMP/COREL/@@@CDRW.TMP failed for handle 4237 (Read-only file system) (22011) nb_close: handle 4237 was not open (22014) unlink CLIENTS/CLIENT44/~DMTMP/COREL/@@@CDRW.TMP failed (Read-only file system) (22018) open CLIENTS/CLIENT44/~DMTMP/COREL/CORELDRW.CDT failed for handle 4238 (Read-only file system) (22021) nb_close: handle 4218 was not open (22032) open CLIENTS/CLIENT44/~DMTMP/COREL/GRAPHIC1.CDR failed for handle 4239 (Read-only file system) (22050) open CLIENTS/CLIENT44/~DMTMP/COREL/@@@CDRW.TMP failed for handle 4240 (Read-only file system) (22051) nb_close: handle 4240 was not open (22054) unlink CLIENTS/CLIENT44/~DMTMP/COREL/@@@CDRW.TMP failed (Read-only file system) (22057) nb_close: handle 4228 was not open (22061) nb_close: handle 4182 was not open (22065) nb_close: handle 4234 was not open (22078) open CLIENTS/CLIENT44/~DMTMP/COREL/GRAPH1.CDR failed for handle 4242 (Read-only file system)^C^C^C^C^C^C root(a)ini:/mnt/dbench-mod# ^C root(a)ini:/mnt/dbench-mod# ^C root(a)ini:~# umount /mnt Segmentation fault Kernel log: Jul 29 19:55:35 ini kernel: [ 3044.722313] c2c28e40: 00023740 00023741 00023742 00023743 @7..A7..B7..C7.. Jul 29 19:55:35 ini kernel: [ 3044.722320] c2c28e50: 00023744 00023745 00023746 00023747 D7..E7..F7..G7.. Jul 29 19:55:35 ini kernel: [ 3044.722327] c2c28e60: 00023748 00023749 0002374a 0002374b H7..I7..J7..K7.. Jul 29 19:55:35 ini kernel: [ 3044.722334] c2c28e70: 0002372c 00000000 00000000 00000000 ,7.............. Jul 29 19:55:35 ini kernel: [ 3044.722341] c2c28e80: 00000000 00000000 00000000 00000002 ................ Jul 29 19:55:35 ini kernel: [ 3044.722346] c2c28e90: 00000000 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722354] c2c28ea0: c2c28ea0 c2c28ea0 c307f138 c307f138 ........8...8... Jul 29 19:55:35 ini kernel: [ 3044.722360] c2c28eb0: 0003f800 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722366] c2c28ec0: c2c28ec0 c2c28ec0 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722373] c2c28ed0: 00100100 00200200 c2c28ed8 c2c28ed8 ...... ......... Jul 29 19:55:35 ini kernel: [ 3044.722379] c2c28ee0: c2c28ee0 c2c28ee0 0000800b 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722384] c2c28ef0: 00000001 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722391] c2c28f00: 00000001 00000000 0003f800 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722398] c2c28f10: 00000002 4c51a3cc 00000000 4c51a3cc ......QL......QL Jul 29 19:55:35 ini kernel: [ 3044.722404] c2c28f20: 00000000 4c51a3cc 00000000 00000208 ......QL........ Jul 29 19:55:35 ini kernel: [ 3044.722410] c2c28f30: 00000000 0000000c 81800000 00000101 ................ Jul 29 19:55:35 ini kernel: [ 3044.722416] c2c28f40: 00000001 00000000 c2c28f48 c2c28f48 ........H...H... Jul 29 19:55:35 ini kernel: [ 3044.722422] c2c28f50: 00000000 00000000 00000000 c2c28f5c ............\... Jul 29 19:55:35 ini kernel: [ 3044.722428] c2c28f60: c2c28f5c c0593440 c05933c0 ca228a00 \...@4Y..3Y...". Jul 29 19:55:35 ini kernel: [ 3044.722434] c2c28f70: 00000000 c2c28f78 c2c28ec8 00000000 ....x........... Jul 29 19:55:35 ini kernel: [ 3044.722440] c2c28f80: 00000020 00000000 00000505 00000000 ............... Jul 29 19:55:35 ini kernel: [ 3044.722446] c2c28f90: 00000000 00010001 c2c28f98 c2c28f98 ................ Jul 29 19:55:35 ini kernel: [ 3044.722451] c2c28fa0: 00000000 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722457] c2c28fb0: c0593680 000200da cdcc104c 00000202 .6Y.....L....... Jul 29 19:55:35 ini kernel: [ 3044.722463] c2c28fc0: c2c28fc0 c2c28fc0 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722469] c2c28fd0: 00000000 c2c28fd4 c2c28fd4 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722475] c2c28fe0: 0623225b 00000000 00000000 c2c28fec ["#............. Jul 29 19:55:35 ini kernel: [ 3044.722481] c2c28ff0: c2c28fec 00000001 00000000 c2c28ffc ................ Jul 29 19:55:35 ini kernel: [ 3044.722487] c2c29000: c2c28ffc 00000000 00000040 00000000 ........@....... Jul 29 19:55:35 ini kernel: [ 3044.722493] c2c29010: 00000000 00000000 00000000 ffffffff ................ Jul 29 19:55:35 ini kernel: [ 3044.722499] c2c29020: ffffffff 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722505] c2c29030: c2c29030 c2c29030 c2c28ec8 00000000 0...0........... Jul 29 19:55:35 ini kernel: [ 3044.722510] c2c29040: 00000000 00000000 00000000 00000000 ................ Jul 29 19:55:35 ini kernel: [ 3044.722516] c2c29050: 00000000 4c51a3d8 00000000 c2c2905c ......QL....\... Jul 29 19:55:35 ini kernel: [ 3044.722522] c2c29060: c2c2905c 00000101 ffffffff 00000000 \............... Jul 29 19:55:35 ini kernel: [ 3044.722528] c2c29070: 00000000 00000000 00000000 00000101 ................ Jul 29 19:55:35 ini kernel: [ 3044.722534] c2c29080: 00000000 00000000 c2c29088 c2c29088 ................ Jul 29 19:55:35 ini kernel: [ 3044.722540] c2c29090: 00000000 00005be2 00005be2 .....[...[.. Jul 29 19:55:35 ini kernel: [ 3044.722546] Pid: 1299, comm: umount Not tainted 2.6.32-22-386 #36-Ubuntu Jul 29 19:55:35 ini kernel: [ 3044.722550] Call Trace: Jul 29 19:55:35 ini kernel: [ 3044.722567] [<c0291731>] ext4_destroy_inode+0x91/0xa0 Jul 29 19:55:35 ini kernel: [ 3044.722577] [<c020ecb4>] destroy_inode+0x24/0x40 Jul 29 19:55:35 ini kernel: [ 3044.722583] [<c020f11e>] dispose_list+0x8e/0x100 Jul 29 19:55:35 ini kernel: [ 3044.722588] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 19:55:35 ini kernel: [ 3044.722598] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 19:55:35 ini kernel: [ 3044.722606] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 19:55:35 ini kernel: [ 3044.722612] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 19:55:35 ini kernel: [ 3044.722618] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 19:55:35 ini kernel: [ 3044.722625] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 19:55:35 ini kernel: [ 3044.722631] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 19:55:35 ini kernel: [ 3044.722636] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 19:55:35 ini kernel: [ 3044.722643] [<c01033ec>] syscall_call+0x7/0xb Jul 29 19:55:35 ini kernel: [ 3044.731043] sd 6:0:0:0: [sdb] Unhandled error code Jul 29 19:55:35 ini kernel: [ 3044.731049] sd 6:0:0:0: [sdb] Result: hostbyte=DID_TRANSPORT_FAILFAST driverbyte=DRIVER_OK Jul 29 19:55:35 ini kernel: [ 3044.731056] sd 6:0:0:0: [sdb] CDB: Write(10): 2a 00 00 00 00 00 00 00 01 00 Jul 29 19:55:35 ini kernel: [ 3044.743469] __ratelimit: 37 callbacks suppressed Jul 29 19:55:35 ini kernel: [ 3044.755695] lost page write due to I/O error on sdb Jul 29 19:55:36 ini kernel: [ 3044.823044] Modules linked in: crc32c ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi w83627hf hwmon_vid fbcon tileblit font bitblit softcursor ppdev adm1021 i2c_i801 vga16fb vgastate e7xxx_edac psmouse serio_raw parport_pc shpchp edac_core lp parport qla2xxx ohci1394 scsi_transport_fc r8169 sata_via ieee1394 mii scsi_tgt e1000 floppy Jul 29 19:55:36 ini kernel: [ 3044.823044] Jul 29 19:55:36 ini kernel: [ 3044.823044] Pid: 1299, comm: umount Not tainted (2.6.32-22-386 #36-Ubuntu) X5DPA Jul 29 19:55:36 ini kernel: [ 3044.823044] EIP: 0060:[<c0293c2a>] EFLAGS: 00010206 CPU: 0 Jul 29 19:55:36 ini kernel: [ 3044.823044] EIP is at ext4_put_super+0x2ea/0x350 Jul 29 19:55:36 ini kernel: [ 3044.823044] EAX: c2c28ea8 EBX: c307f000 ECX: ffffff52 EDX: c307f138 Jul 29 19:55:36 ini kernel: [ 3044.823044] ESI: ca228a00 EDI: c307f0fc EBP: cec6ff30 ESP: cec6fefc Jul 29 19:55:36 ini kernel: [ 3044.823044] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 Jul 29 19:55:36 ini kernel: [ 3044.823044] c06bb054 ca228b64 0000800b c2c28ec8 00008180 00000001 00000000 c307f138 Jul 29 19:55:36 ini kernel: [ 3044.823044] <0> c307f138 c307f138 ca228a00 c0593c80 c023b310 cec6ff48 c01fc60d ca228ac0 Jul 29 19:55:36 ini kernel: [ 3044.823044] <0> cec6ff44 cf328400 00000003 cec6ff58 c01fc6ca ca228a00 c0759d80 cec6ff6c Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fc60d>] ? generic_shutdown_super+0x4d/0xe0 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fc6ca>] ? kill_block_super+0x2a/0x50 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fd4e4>] ? deactivate_super+0x64/0x90 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c021282f>] ? mntput_no_expire+0x8f/0xe0 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c0212e47>] ? sys_umount+0x47/0xa0 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c0212ebe>] ? sys_oldumount+0x1e/0x20 Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01033ec>] ? syscall_call+0x7/0xb Jul 29 19:55:36 ini kernel: [ 3045.299442] ---[ end trace 426db011a0289db3 ]--- Jul 29 19:55:36 ini kernel: [ 3045.310429] ------------[ cut here ]------------ Jul 29 19:55:36 ini kernel: [ 3045.321086] WARNING: at /build/buildd/linux-2.6.32/kernel/exit.c:895 do_exit+0x2f9/0x300() Jul 29 19:55:36 ini kernel: [ 3045.342153] Hardware name: X5DPA Jul 29 19:55:36 ini kernel: [ 3045.352697] Modules linked in: crc32c ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi w83627hf hwmon_vid fbcon tileblit font bitblit softcursor ppdev adm1021 i2c_i801 vga16fb vgastate e7xxx_edac psmouse serio_raw parport_pc shpchp edac_core lp parport qla2xxx ohci1394 scsi_transport_fc r8169 sata_via ieee1394 mii scsi_tgt e1000 floppy Jul 29 19:55:36 ini kernel: [ 3045.422317] Pid: 1299, comm: umount Tainted: G D 2.6.32-22-386 #36-Ubuntu Jul 29 19:55:36 ini kernel: [ 3045.444158] Call Trace: Jul 29 19:55:36 ini kernel: [ 3045.454755] [<c01487a2>] warn_slowpath_common+0x72/0xa0 Jul 29 19:55:36 ini kernel: [ 3045.465152] [<c014ca49>] ? do_exit+0x2f9/0x300 Jul 29 19:55:36 ini kernel: [ 3045.475281] [<c014ca49>] ? do_exit+0x2f9/0x300 Jul 29 19:55:36 ini kernel: [ 3045.485296] [<c01487ea>] warn_slowpath_null+0x1a/0x20 Jul 29 19:55:36 ini kernel: [ 3045.495432] [<c014ca49>] do_exit+0x2f9/0x300 Jul 29 19:55:36 ini kernel: [ 3045.505640] [<c014856f>] ? print_oops_end_marker+0x2f/0x40 Jul 29 19:55:36 ini kernel: [ 3045.516012] [<c0579fc5>] oops_end+0x95/0xd0 Jul 29 19:55:36 ini kernel: [ 3045.526394] [<c01068a4>] die+0x54/0x80 Jul 29 19:55:36 ini kernel: [ 3045.536808] [<c0579716>] do_trap+0x96/0xc0 Jul 29 19:55:36 ini kernel: [ 3045.547268] [<c0104980>] ? do_invalid_op+0x0/0xa0 Jul 29 19:55:36 ini kernel: [ 3045.557756] [<c0104a0b>] do_invalid_op+0x8b/0xa0 Jul 29 19:55:36 ini kernel: [ 3045.568296] [<c0293c2a>] ? ext4_put_super+0x2ea/0x350 Jul 29 19:55:36 ini kernel: [ 3045.578561] [<c0149291>] ? vprintk+0x191/0x3f0 Jul 29 19:55:36 ini kernel: [ 3045.588708] [<c0579493>] error_code+0x73/0x80 Jul 29 19:55:36 ini kernel: [ 3045.598076] [<c0293c2a>] ? ext4_put_super+0x2ea/0x350 Jul 29 19:55:36 ini kernel: [ 3045.607381] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 19:55:36 ini kernel: [ 3045.616499] [<c01fc60d>] generic_shutdown_super+0x4d/0xe0 Jul 29 19:55:36 ini kernel: [ 3045.625688] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 19:55:36 ini kernel: [ 3045.634777] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 19:55:36 ini kernel: [ 3045.643744] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 19:55:36 ini kernel: [ 3045.652782] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 19:55:36 ini kernel: [ 3045.661514] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 19:55:36 ini kernel: [ 3045.670139] [<c01033ec>] syscall_call+0x7/0xb Jul 29 19:55:36 ini kernel: [ 3045.678566] ---[ end trace 426db011a0289db4 ]--- Another test. Everything is as before, only I did not pull the cable, but deleted the corresponding LUN on the target, so all the command starting from this moment failed. Then on umount system rebooted. Kernel log: Jul 29 20:20:42 ini kernel: [ 1320.251393] umount D 00478e55 0 1234 924 0x00000000 Jul 29 20:20:42 ini kernel: [ 1320.251403] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:20:42 ini kernel: [ 1320.251415] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:20:42 ini kernel: [ 1320.251425] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:20:42 ini kernel: [ 1320.251436] Call Trace: Jul 29 20:20:42 ini kernel: [ 1320.251452] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:20:42 ini kernel: [ 1320.251463] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:20:42 ini kernel: [ 1320.251470] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:20:42 ini kernel: [ 1320.251476] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:20:42 ini kernel: [ 1320.251483] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:20:42 ini kernel: [ 1320.251491] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:20:42 ini kernel: [ 1320.251499] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:20:42 ini kernel: [ 1320.251510] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:20:42 ini kernel: [ 1320.251517] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:20:42 ini kernel: [ 1320.251523] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:20:42 ini kernel: [ 1320.251529] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:20:42 ini kernel: [ 1320.251538] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:20:42 ini kernel: [ 1320.251546] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:20:42 ini kernel: [ 1320.251553] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:20:42 ini kernel: [ 1320.251559] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:20:42 ini kernel: [ 1320.251566] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:20:42 ini kernel: [ 1320.251573] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:20:42 ini kernel: [ 1320.251579] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:20:42 ini kernel: [ 1320.251586] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:22:42 ini kernel: [ 1440.285910] umount D 00478e55 0 1234 924 0x00000004 Jul 29 20:22:42 ini kernel: [ 1440.285919] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:22:42 ini kernel: [ 1440.285931] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:22:42 ini kernel: [ 1440.285942] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:22:42 ini kernel: [ 1440.285953] Call Trace: Jul 29 20:22:42 ini kernel: [ 1440.285969] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:22:42 ini kernel: [ 1440.285980] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:22:42 ini kernel: [ 1440.285987] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:22:42 ini kernel: [ 1440.285994] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:22:42 ini kernel: [ 1440.286001] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:22:42 ini kernel: [ 1440.286010] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:22:42 ini kernel: [ 1440.286018] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:22:42 ini kernel: [ 1440.286028] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:22:42 ini kernel: [ 1440.286035] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:22:42 ini kernel: [ 1440.286041] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:22:42 ini kernel: [ 1440.286047] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:22:42 ini kernel: [ 1440.286056] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:22:42 ini kernel: [ 1440.286064] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:22:42 ini kernel: [ 1440.286071] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:22:42 ini kernel: [ 1440.286077] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:22:42 ini kernel: [ 1440.286084] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:22:42 ini kernel: [ 1440.286091] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:22:42 ini kernel: [ 1440.286097] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:22:42 ini kernel: [ 1440.286104] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:24:42 ini kernel: [ 1560.321709] umount D 00478e55 0 1234 924 0x00000004 Jul 29 20:24:42 ini kernel: [ 1560.321718] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:24:42 ini kernel: [ 1560.321730] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:24:42 ini kernel: [ 1560.321741] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:24:42 ini kernel: [ 1560.321751] Call Trace: Jul 29 20:24:42 ini kernel: [ 1560.321767] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:24:42 ini kernel: [ 1560.321777] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:24:42 ini kernel: [ 1560.321784] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:24:42 ini kernel: [ 1560.321791] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:24:42 ini kernel: [ 1560.321797] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:24:42 ini kernel: [ 1560.321805] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:24:42 ini kernel: [ 1560.321814] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:24:42 ini kernel: [ 1560.321824] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:24:42 ini kernel: [ 1560.321831] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:24:42 ini kernel: [ 1560.321837] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:24:42 ini kernel: [ 1560.321845] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:24:42 ini kernel: [ 1560.321855] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:24:42 ini kernel: [ 1560.321864] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:24:42 ini kernel: [ 1560.321870] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:24:42 ini kernel: [ 1560.321877] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:24:42 ini kernel: [ 1560.321885] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:24:42 ini kernel: [ 1560.321892] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:24:42 ini kernel: [ 1560.321898] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:24:42 ini kernel: [ 1560.321905] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:24:42 ini kernel: [ 1560.358795] sync D 0004beb0 0 1265 1255 0x00000004 Jul 29 20:24:42 ini kernel: [ 1560.358803] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 Jul 29 20:24:42 ini kernel: [ 1560.358815] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 Jul 29 20:24:42 ini kernel: [ 1560.358826] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff Jul 29 20:24:42 ini kernel: [ 1560.358837] Call Trace: Jul 29 20:24:42 ini kernel: [ 1560.358845] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 Jul 29 20:24:42 ini kernel: [ 1560.358852] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 Jul 29 20:24:42 ini kernel: [ 1560.358858] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 Jul 29 20:24:42 ini kernel: [ 1560.358863] [<c057850c>] ? down_read+0x1c/0x20 Jul 29 20:24:42 ini kernel: [ 1560.358870] [<c021cb6d>] sync_filesystems+0xbd/0x110 Jul 29 20:24:42 ini kernel: [ 1560.358876] [<c021cc16>] sys_sync+0x16/0x40 Jul 29 20:24:42 ini kernel: [ 1560.358881] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:26:42 ini kernel: [ 1680.392190] umount D 00478e55 0 1234 924 0x00000004 Jul 29 20:26:42 ini kernel: [ 1680.392200] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:26:42 ini kernel: [ 1680.392212] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:26:42 ini kernel: [ 1680.392223] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:26:42 ini kernel: [ 1680.392233] Call Trace: Jul 29 20:26:42 ini kernel: [ 1680.392250] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:26:42 ini kernel: [ 1680.392260] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:26:42 ini kernel: [ 1680.392267] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:26:42 ini kernel: [ 1680.392274] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:26:42 ini kernel: [ 1680.392280] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:26:42 ini kernel: [ 1680.392289] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:26:42 ini kernel: [ 1680.392298] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:26:42 ini kernel: [ 1680.392308] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:26:42 ini kernel: [ 1680.392314] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:26:42 ini kernel: [ 1680.392321] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:26:42 ini kernel: [ 1680.392327] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:26:42 ini kernel: [ 1680.392336] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:26:42 ini kernel: [ 1680.392344] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:26:42 ini kernel: [ 1680.392351] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:26:42 ini kernel: [ 1680.392357] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:26:42 ini kernel: [ 1680.392364] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:26:42 ini kernel: [ 1680.392371] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:26:42 ini kernel: [ 1680.392378] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:26:42 ini kernel: [ 1680.392384] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:26:42 ini kernel: [ 1680.427874] sync D 0004beb0 0 1265 1255 0x00000004 Jul 29 20:26:42 ini kernel: [ 1680.427883] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 Jul 29 20:26:42 ini kernel: [ 1680.427894] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 Jul 29 20:26:42 ini kernel: [ 1680.427904] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff Jul 29 20:26:42 ini kernel: [ 1680.427915] Call Trace: Jul 29 20:26:42 ini kernel: [ 1680.427922] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 Jul 29 20:26:42 ini kernel: [ 1680.427929] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 Jul 29 20:26:42 ini kernel: [ 1680.427935] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 Jul 29 20:26:42 ini kernel: [ 1680.427940] [<c057850c>] ? down_read+0x1c/0x20 Jul 29 20:26:42 ini kernel: [ 1680.427947] [<c021cb6d>] sync_filesystems+0xbd/0x110 Jul 29 20:26:42 ini kernel: [ 1680.427953] [<c021cc16>] sys_sync+0x16/0x40 Jul 29 20:26:42 ini kernel: [ 1680.427958] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:28:42 ini kernel: [ 1800.458856] umount D 00478e55 0 1234 924 0x00000004 Jul 29 20:28:42 ini kernel: [ 1800.458866] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:28:42 ini kernel: [ 1800.458877] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:28:42 ini kernel: [ 1800.458888] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:28:42 ini kernel: [ 1800.458899] Call Trace: Jul 29 20:28:42 ini kernel: [ 1800.458915] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:28:42 ini kernel: [ 1800.458925] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:28:42 ini kernel: [ 1800.458932] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:28:42 ini kernel: [ 1800.458938] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:28:42 ini kernel: [ 1800.458945] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:28:42 ini kernel: [ 1800.458953] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:28:42 ini kernel: [ 1800.458961] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:28:42 ini kernel: [ 1800.458971] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:28:42 ini kernel: [ 1800.458978] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:28:42 ini kernel: [ 1800.458984] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:28:42 ini kernel: [ 1800.458991] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:28:42 ini kernel: [ 1800.458999] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:28:42 ini kernel: [ 1800.459007] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:28:42 ini kernel: [ 1800.459013] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:28:42 ini kernel: [ 1800.459020] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:28:42 ini kernel: [ 1800.459027] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:28:42 ini kernel: [ 1800.459033] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:28:42 ini kernel: [ 1800.459039] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:28:42 ini kernel: [ 1800.459046] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:28:42 ini kernel: [ 1800.493768] sync D 0004beb0 0 1265 1255 0x00000004 Jul 29 20:28:42 ini kernel: [ 1800.493777] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 Jul 29 20:28:42 ini kernel: [ 1800.493788] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 Jul 29 20:28:42 ini kernel: [ 1800.493798] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff Jul 29 20:28:42 ini kernel: [ 1800.493809] Call Trace: Jul 29 20:28:42 ini kernel: [ 1800.493816] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 Jul 29 20:28:42 ini kernel: [ 1800.493823] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 Jul 29 20:28:42 ini kernel: [ 1800.493828] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 Jul 29 20:28:42 ini kernel: [ 1800.493834] [<c057850c>] ? down_read+0x1c/0x20 Jul 29 20:28:42 ini kernel: [ 1800.493841] [<c021cb6d>] sync_filesystems+0xbd/0x110 Jul 29 20:28:42 ini kernel: [ 1800.493847] [<c021cc16>] sys_sync+0x16/0x40 Jul 29 20:28:42 ini kernel: [ 1800.493853] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:30:42 ini kernel: [ 1920.526729] umount D 00478e55 0 1234 924 0x00000004 Jul 29 20:30:42 ini kernel: [ 1920.526739] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 Jul 29 20:30:42 ini kernel: [ 1920.526750] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 Jul 29 20:30:42 ini kernel: [ 1920.526761] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 Jul 29 20:30:42 ini kernel: [ 1920.526772] Call Trace: Jul 29 20:30:42 ini kernel: [ 1920.526788] [<c057745a>] io_schedule+0x3a/0x60 Jul 29 20:30:42 ini kernel: [ 1920.526798] [<c01bd95d>] sync_page+0x3d/0x50 Jul 29 20:30:42 ini kernel: [ 1920.526805] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 Jul 29 20:30:42 ini kernel: [ 1920.526813] [<c01bd920>] ? sync_page+0x0/0x50 Jul 29 20:30:42 ini kernel: [ 1920.526819] [<c01bd8ee>] __lock_page+0x7e/0x90 Jul 29 20:30:42 ini kernel: [ 1920.526827] [<c01624d0>] ? wake_bit_function+0x0/0x50 Jul 29 20:30:42 ini kernel: [ 1920.526836] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 Jul 29 20:30:42 ini kernel: [ 1920.526845] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 Jul 29 20:30:42 ini kernel: [ 1920.526853] [<c01c724f>] truncate_inode_pages+0x1f/0x30 Jul 29 20:30:42 ini kernel: [ 1920.526859] [<c020f15c>] dispose_list+0xcc/0x100 Jul 29 20:30:42 ini kernel: [ 1920.526866] [<c020f534>] invalidate_inodes+0xf4/0x120 Jul 29 20:30:42 ini kernel: [ 1920.526874] [<c023b310>] ? vfs_quota_off+0x0/0x20 Jul 29 20:30:42 ini kernel: [ 1920.526882] [<c01fc602>] generic_shutdown_super+0x42/0xe0 Jul 29 20:30:42 ini kernel: [ 1920.526889] [<c01fc6ca>] kill_block_super+0x2a/0x50 Jul 29 20:30:42 ini kernel: [ 1920.526895] [<c01fd4e4>] deactivate_super+0x64/0x90 Jul 29 20:30:42 ini kernel: [ 1920.526902] [<c021282f>] mntput_no_expire+0x8f/0xe0 Jul 29 20:30:42 ini kernel: [ 1920.526908] [<c0212e47>] sys_umount+0x47/0xa0 Jul 29 20:30:42 ini kernel: [ 1920.526915] [<c0212ebe>] sys_oldumount+0x1e/0x20 Jul 29 20:30:42 ini kernel: [ 1920.526922] [<c01033ec>] syscall_call+0x7/0xb Jul 29 20:30:42 ini kernel: [ 1920.563739] sync D 0004beb0 0 1265 1255 0x00000004 Jul 29 20:30:42 ini kernel: [ 1920.563747] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 Jul 29 20:30:42 ini kernel: [ 1920.563758] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 Jul 29 20:30:42 ini kernel: [ 1920.563768] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff Jul 29 20:30:42 ini kernel: [ 1920.563779] Call Trace: Jul 29 20:30:42 ini kernel: [ 1920.563787] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 Jul 29 20:30:42 ini kernel: [ 1920.563793] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 Jul 29 20:30:42 ini kernel: [ 1920.563799] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 Jul 29 20:30:42 ini kernel: [ 1920.563804] [<c057850c>] ? down_read+0x1c/0x20 Jul 29 20:30:42 ini kernel: [ 1920.563812] [<c021cb6d>] sync_filesystems+0xbd/0x110 Jul 29 20:30:42 ini kernel: [ 1920.563817] [<c021cc16>] sys_sync+0x16/0x40 Jul 29 20:30:42 ini kernel: [ 1920.563823] [<c01033ec>] syscall_call+0x7/0xb Although in both cases the FS remained consistent: root(a)ini:~# mount -t ext4 /dev/sdb /mnt root(a)ini:~# umount /mnt root(a)ini:~# e2fsck -f -y /dev/sdb e2fsck 1.41.11 (14-Mar-2010) Pass 1: Checking inodes, blocks, and sizes Pass 2: Checking directory structure Pass 3: Checking directory connectivity Pass 4: Checking reference counts Pass 5: Checking group summary information /dev/sdb: ***** FILE SYSTEM WAS MODIFIED ***** /dev/sdb: 4194/640000 files (74.2% non-contiguous), 334774/1280000 blocks You can find full kernel logs starting from iSCSI load in the attachments. I already reported such issues some time ago, but my reports were not too much welcomed, so I gave up. Anyway, anybody can easily do my tests at any time. They don't need any special hardware, just 2 Linux boxes: one for iSCSI target and one for iSCSI initiator (the test box itself). But they are generic for other transports as well. You can see there's nothing iSCSI specific in the traces. Vlad
From: Vladislav Bolkhovitin on 29 Jul 2010 10:20 Christoph Hellwig, on 07/29/2010 05:08 PM wrote: > On Thu, Jul 29, 2010 at 05:00:10PM +0400, Vladislav Bolkhovitin wrote: >> You can find full kernel logs starting from iSCSI load in the attachments. >> >> I already reported such issues some time ago, but my reports were not too much welcomed, so I gave up. Anyway, anybody can easily do my tests at any time. They don't need any special hardware, just 2 Linux boxes: one for iSCSI target and one for iSCSI initiator (the test box itself). But they are generic for other transports as well. You can see there's nothing iSCSI specific in the traces. > > I was only talking about ext3. Yes, now ext3 is a lot more reliable. The only how I was able to confuse it was: .... (2197) nb_write: handle 4272 was not open size=65475 ofs=0 (2199) nb_write: handle 4272 was not open size=65475 ofs=65534 (2201) nb_write: handle 4272 was not open size=65475 ofs=131068 (2203) nb_write: handle 4272 was not open size=65475 ofs=196602 (2205) nb_write: handle 4272 was not open size=65475 ofs=262136^C ^C root(a)ini:/mnt/dbench-mod# ^C root(a)ini:/mnt/dbench-mod# ^C root(a)ini:/mnt/dbench-mod# cd root(a)ini:~# umount /mnt <- recover device root(a)ini:~# mount -t ext3 -o barrier=1 /dev/sdb /mnt mount: wrong fs type, bad option, bad superblock on /dev/sdb, missing codepage or helper program, or other error In some cases useful info is found in syslog - try dmesg | tail or so Kernel log: "Jul 29 22:05:32 ini kernel: [ 2905.423092] JBD: recovery failed" root(a)ini:~# mount -t ext3 -o barrier=1 /dev/sdb /mnt root(a)ini:~# Kernel log: Jul 29 22:05:54 ini kernel: [ 2927.832893] kjournald starting. Commit interval 5 seconds Jul 29 22:05:54 ini kernel: [ 2927.833430] EXT3 FS on sdb, internal journal Jul 29 22:05:54 ini kernel: [ 2927.833499] EXT3-fs: sdb: 1 orphan inode deleted Jul 29 22:05:54 ini kernel: [ 2927.833503] EXT3-fs: recovery complete. Jul 29 22:05:54 ini kernel: [ 2927.838122] EXT3-fs: mounted filesystem with ordered data mode. But it still remained consistent: root(a)ini:~# umount /mnt root(a)ini:~# e2fsck -f -y /dev/sdb e2fsck 1.41.11 (14-Mar-2010) Pass 1: Checking inodes, blocks, and sizes Pass 2: Checking directory structure Pass 3: Checking directory connectivity Pass 4: Checking reference counts Pass 5: Checking group summary information /dev/sdb: 3504/320000 files (21.1% non-contiguous), 307034/1280000 blocks Good progress since my original reports for kernels around 2.6.27! Vlad -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Jan Kara on 29 Jul 2010 10:30 On Thu 29-07-10 17:00:10, Vladislav Bolkhovitin wrote: > Christoph Hellwig, on 07/29/2010 12:31 PM wrote: > > My reading of the ext3/jbd code we explicitly wait on I/O completion > > of dependent writes, and only require those to actually be stable > > by issueing a flush. If that wasn't the case the default ext3 > > barriers off behaviour would not only be dangerous on devices with > > volatile write caches, but also on devices that do not have them, > > which in addition to the reading of the code is not what we've seen > > in actual power fail testing, where ext3 does well as long as there > > is no volatile write cache. > > Basically, it is so, but, unfortunately, not absolutely. I've just tried > 2 tests on ext4 with iSCSI: > > # uname -a > Linux ini 2.6.32-22-386 #36-Ubuntu SMP Fri Jun 4 00:27:09 UTC 2010 i686 GNU/Linux > > # e2fsck -f -y /dev/sdb > e2fsck 1.41.11 (14-Mar-2010) > Pass 1: Checking inodes, blocks, and sizes > Pass 2: Checking directory structure > Pass 3: Checking directory connectivity > Pass 4: Checking reference counts > Pass 5: Checking group summary information > /dev/sdb: 49/640000 files (0.0% non-contiguous), 56496/1280000 blocks > root(a)ini:~# mount -t ext4 -o barrier=1 /dev/sdb /mnt > root(a)ini:~# cd /mnt/dbench-mod/ > root(a)ini:/mnt/dbench-mod# ./dbench 50 > 50 clients started > ... > <-- Pull cable > <-- After sometime a lot of warnings like: > (22002) open CLIENTS/CLIENT44/~DMTMP/COREL/CDRBARS.CFG failed for handle 4235 (Read-only file system) > (22004) open CLIENTS/CLIENT44/~DMTMP/COREL/ARTISTIC.ACL failed for handle 4236 (Read-only file system) ... These are OK. You pulled a cable and now you start getting EIO from the kernel. > root(a)ini:/mnt/dbench-mod# ^C > root(a)ini:/mnt/dbench-mod# ^C > root(a)ini:~# umount /mnt > Segmentation fault This isn't OK of course ;) > Kernel log: > > Jul 29 19:55:35 ini kernel: [ 3044.722313] c2c28e40: 00023740 00023741 00023742 00023743 @7..A7..B7..C7.. > Jul 29 19:55:35 ini kernel: [ 3044.722320] c2c28e50: 00023744 00023745 00023746 00023747 D7..E7..F7..G7.. > Jul 29 19:55:35 ini kernel: [ 3044.722327] c2c28e60: 00023748 00023749 0002374a 0002374b H7..I7..J7..K7.. > Jul 29 19:55:35 ini kernel: [ 3044.722334] c2c28e70: 0002372c 00000000 00000000 00000000 ,7.............. > Jul 29 19:55:35 ini kernel: [ 3044.722341] c2c28e80: 00000000 00000000 00000000 00000002 ................ .... Sadly these messages above seem to have overwritten beginning of the message below. Hmm, but maybe it's just a warning message about inode still being on orphan list because the next oops still shows untainted kernel. > Jul 29 19:55:35 ini kernel: [ 3044.722546] Pid: 1299, comm: umount Not tainted 2.6.32-22-386 #36-Ubuntu > Jul 29 19:55:35 ini kernel: [ 3044.722550] Call Trace: > Jul 29 19:55:35 ini kernel: [ 3044.722567] [<c0291731>] ext4_destroy_inode+0x91/0xa0 > Jul 29 19:55:35 ini kernel: [ 3044.722577] [<c020ecb4>] destroy_inode+0x24/0x40 > Jul 29 19:55:35 ini kernel: [ 3044.722583] [<c020f11e>] dispose_list+0x8e/0x100 > Jul 29 19:55:35 ini kernel: [ 3044.722588] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 19:55:35 ini kernel: [ 3044.722598] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 19:55:35 ini kernel: [ 3044.722606] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 19:55:35 ini kernel: [ 3044.722612] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 19:55:35 ini kernel: [ 3044.722618] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 19:55:35 ini kernel: [ 3044.722625] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 19:55:35 ini kernel: [ 3044.722631] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 19:55:35 ini kernel: [ 3044.722636] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 19:55:35 ini kernel: [ 3044.722643] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 19:55:35 ini kernel: [ 3044.731043] sd 6:0:0:0: [sdb] Unhandled error code > Jul 29 19:55:35 ini kernel: [ 3044.731049] sd 6:0:0:0: [sdb] Result: hostbyte=DID_TRANSPORT_FAILFAST driverbyte=DRIVER_OK > Jul 29 19:55:35 ini kernel: [ 3044.731056] sd 6:0:0:0: [sdb] CDB: Write(10): 2a 00 00 00 00 00 00 00 01 00 > Jul 29 19:55:35 ini kernel: [ 3044.743469] __ratelimit: 37 callbacks suppressed > Jul 29 19:55:35 ini kernel: [ 3044.755695] lost page write due to I/O error on sdb > Jul 29 19:55:36 ini kernel: [ 3044.823044] Modules linked in: crc32c ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi w83627hf hwmon_vid fbcon tileblit font bitblit softcursor ppdev adm1021 i2c_i801 vga16fb vgastate e7xxx_edac psmouse serio_raw parport_pc shpchp edac_core lp parport qla2xxx ohci1394 scsi_transport_fc r8169 sata_via ieee1394 mii scsi_tgt e1000 floppy So here probably starts the real oops. But sadly we are missing the beginning as well. Can you send me disassembly of your ext4_put_super? > Jul 29 19:55:36 ini kernel: [ 3044.823044] > Jul 29 19:55:36 ini kernel: [ 3044.823044] Pid: 1299, comm: umount Not tainted (2.6.32-22-386 #36-Ubuntu) X5DPA > Jul 29 19:55:36 ini kernel: [ 3044.823044] EIP: 0060:[<c0293c2a>] EFLAGS: 00010206 CPU: 0 > Jul 29 19:55:36 ini kernel: [ 3044.823044] EIP is at ext4_put_super+0x2ea/0x350 > Jul 29 19:55:36 ini kernel: [ 3044.823044] EAX: c2c28ea8 EBX: c307f000 ECX: ffffff52 EDX: c307f138 > Jul 29 19:55:36 ini kernel: [ 3044.823044] ESI: ca228a00 EDI: c307f0fc EBP: cec6ff30 ESP: cec6fefc > Jul 29 19:55:36 ini kernel: [ 3044.823044] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 > Jul 29 19:55:36 ini kernel: [ 3044.823044] c06bb054 ca228b64 0000800b c2c28ec8 00008180 00000001 00000000 c307f138 > Jul 29 19:55:36 ini kernel: [ 3044.823044] <0> c307f138 c307f138 ca228a00 c0593c80 c023b310 cec6ff48 c01fc60d ca228ac0 > Jul 29 19:55:36 ini kernel: [ 3044.823044] <0> cec6ff44 cf328400 00000003 cec6ff58 c01fc6ca ca228a00 c0759d80 cec6ff6c > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fc60d>] ? generic_shutdown_super+0x4d/0xe0 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fc6ca>] ? kill_block_super+0x2a/0x50 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01fd4e4>] ? deactivate_super+0x64/0x90 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c021282f>] ? mntput_no_expire+0x8f/0xe0 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c0212e47>] ? sys_umount+0x47/0xa0 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c0212ebe>] ? sys_oldumount+0x1e/0x20 > Jul 29 19:55:36 ini kernel: [ 3044.823044] [<c01033ec>] ? syscall_call+0x7/0xb > Jul 29 19:55:36 ini kernel: [ 3045.299442] ---[ end trace 426db011a0289db3 ]--- .... > Another test. Everything is as before, only I did not pull the cable, but > deleted the corresponding LUN on the target, so all the command starting > from this moment failed. Then on umount system rebooted. Kernel log: Nasty. But the log actually contains only traces of processes in D state (generally waiting for a page to be unlocked). Do you have any sort of watchdog which might have rebooted the machine? > Jul 29 20:20:42 ini kernel: [ 1320.251393] umount D 00478e55 0 1234 924 0x00000000 > Jul 29 20:20:42 ini kernel: [ 1320.251403] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:20:42 ini kernel: [ 1320.251415] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:20:42 ini kernel: [ 1320.251425] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:20:42 ini kernel: [ 1320.251436] Call Trace: > Jul 29 20:20:42 ini kernel: [ 1320.251452] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:20:42 ini kernel: [ 1320.251463] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:20:42 ini kernel: [ 1320.251470] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:20:42 ini kernel: [ 1320.251476] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:20:42 ini kernel: [ 1320.251483] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:20:42 ini kernel: [ 1320.251491] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:20:42 ini kernel: [ 1320.251499] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:20:42 ini kernel: [ 1320.251510] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:20:42 ini kernel: [ 1320.251517] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:20:42 ini kernel: [ 1320.251523] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:20:42 ini kernel: [ 1320.251529] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:20:42 ini kernel: [ 1320.251538] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:20:42 ini kernel: [ 1320.251546] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:20:42 ini kernel: [ 1320.251553] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:20:42 ini kernel: [ 1320.251559] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:20:42 ini kernel: [ 1320.251566] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:20:42 ini kernel: [ 1320.251573] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:20:42 ini kernel: [ 1320.251579] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:20:42 ini kernel: [ 1320.251586] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:22:42 ini kernel: [ 1440.285910] umount D 00478e55 0 1234 924 0x00000004 > Jul 29 20:22:42 ini kernel: [ 1440.285919] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:22:42 ini kernel: [ 1440.285931] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:22:42 ini kernel: [ 1440.285942] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:22:42 ini kernel: [ 1440.285953] Call Trace: > Jul 29 20:22:42 ini kernel: [ 1440.285969] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:22:42 ini kernel: [ 1440.285980] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:22:42 ini kernel: [ 1440.285987] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:22:42 ini kernel: [ 1440.285994] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:22:42 ini kernel: [ 1440.286001] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:22:42 ini kernel: [ 1440.286010] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:22:42 ini kernel: [ 1440.286018] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:22:42 ini kernel: [ 1440.286028] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:22:42 ini kernel: [ 1440.286035] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:22:42 ini kernel: [ 1440.286041] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:22:42 ini kernel: [ 1440.286047] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:22:42 ini kernel: [ 1440.286056] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:22:42 ini kernel: [ 1440.286064] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:22:42 ini kernel: [ 1440.286071] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:22:42 ini kernel: [ 1440.286077] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:22:42 ini kernel: [ 1440.286084] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:22:42 ini kernel: [ 1440.286091] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:22:42 ini kernel: [ 1440.286097] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:22:42 ini kernel: [ 1440.286104] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:24:42 ini kernel: [ 1560.321709] umount D 00478e55 0 1234 924 0x00000004 > Jul 29 20:24:42 ini kernel: [ 1560.321718] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:24:42 ini kernel: [ 1560.321730] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:24:42 ini kernel: [ 1560.321741] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:24:42 ini kernel: [ 1560.321751] Call Trace: > Jul 29 20:24:42 ini kernel: [ 1560.321767] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:24:42 ini kernel: [ 1560.321777] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:24:42 ini kernel: [ 1560.321784] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:24:42 ini kernel: [ 1560.321791] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:24:42 ini kernel: [ 1560.321797] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:24:42 ini kernel: [ 1560.321805] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:24:42 ini kernel: [ 1560.321814] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:24:42 ini kernel: [ 1560.321824] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:24:42 ini kernel: [ 1560.321831] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:24:42 ini kernel: [ 1560.321837] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:24:42 ini kernel: [ 1560.321845] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:24:42 ini kernel: [ 1560.321855] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:24:42 ini kernel: [ 1560.321864] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:24:42 ini kernel: [ 1560.321870] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:24:42 ini kernel: [ 1560.321877] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:24:42 ini kernel: [ 1560.321885] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:24:42 ini kernel: [ 1560.321892] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:24:42 ini kernel: [ 1560.321898] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:24:42 ini kernel: [ 1560.321905] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:24:42 ini kernel: [ 1560.358795] sync D 0004beb0 0 1265 1255 0x00000004 > Jul 29 20:24:42 ini kernel: [ 1560.358803] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 > Jul 29 20:24:42 ini kernel: [ 1560.358815] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 > Jul 29 20:24:42 ini kernel: [ 1560.358826] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff > Jul 29 20:24:42 ini kernel: [ 1560.358837] Call Trace: > Jul 29 20:24:42 ini kernel: [ 1560.358845] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 > Jul 29 20:24:42 ini kernel: [ 1560.358852] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 > Jul 29 20:24:42 ini kernel: [ 1560.358858] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 > Jul 29 20:24:42 ini kernel: [ 1560.358863] [<c057850c>] ? down_read+0x1c/0x20 > Jul 29 20:24:42 ini kernel: [ 1560.358870] [<c021cb6d>] sync_filesystems+0xbd/0x110 > Jul 29 20:24:42 ini kernel: [ 1560.358876] [<c021cc16>] sys_sync+0x16/0x40 > Jul 29 20:24:42 ini kernel: [ 1560.358881] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:26:42 ini kernel: [ 1680.392190] umount D 00478e55 0 1234 924 0x00000004 > Jul 29 20:26:42 ini kernel: [ 1680.392200] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:26:42 ini kernel: [ 1680.392212] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:26:42 ini kernel: [ 1680.392223] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:26:42 ini kernel: [ 1680.392233] Call Trace: > Jul 29 20:26:42 ini kernel: [ 1680.392250] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:26:42 ini kernel: [ 1680.392260] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:26:42 ini kernel: [ 1680.392267] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:26:42 ini kernel: [ 1680.392274] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:26:42 ini kernel: [ 1680.392280] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:26:42 ini kernel: [ 1680.392289] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:26:42 ini kernel: [ 1680.392298] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:26:42 ini kernel: [ 1680.392308] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:26:42 ini kernel: [ 1680.392314] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:26:42 ini kernel: [ 1680.392321] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:26:42 ini kernel: [ 1680.392327] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:26:42 ini kernel: [ 1680.392336] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:26:42 ini kernel: [ 1680.392344] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:26:42 ini kernel: [ 1680.392351] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:26:42 ini kernel: [ 1680.392357] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:26:42 ini kernel: [ 1680.392364] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:26:42 ini kernel: [ 1680.392371] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:26:42 ini kernel: [ 1680.392378] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:26:42 ini kernel: [ 1680.392384] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:26:42 ini kernel: [ 1680.427874] sync D 0004beb0 0 1265 1255 0x00000004 > Jul 29 20:26:42 ini kernel: [ 1680.427883] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 > Jul 29 20:26:42 ini kernel: [ 1680.427894] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 > Jul 29 20:26:42 ini kernel: [ 1680.427904] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff > Jul 29 20:26:42 ini kernel: [ 1680.427915] Call Trace: > Jul 29 20:26:42 ini kernel: [ 1680.427922] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 > Jul 29 20:26:42 ini kernel: [ 1680.427929] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 > Jul 29 20:26:42 ini kernel: [ 1680.427935] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 > Jul 29 20:26:42 ini kernel: [ 1680.427940] [<c057850c>] ? down_read+0x1c/0x20 > Jul 29 20:26:42 ini kernel: [ 1680.427947] [<c021cb6d>] sync_filesystems+0xbd/0x110 > Jul 29 20:26:42 ini kernel: [ 1680.427953] [<c021cc16>] sys_sync+0x16/0x40 > Jul 29 20:26:42 ini kernel: [ 1680.427958] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:28:42 ini kernel: [ 1800.458856] umount D 00478e55 0 1234 924 0x00000004 > Jul 29 20:28:42 ini kernel: [ 1800.458866] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:28:42 ini kernel: [ 1800.458877] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:28:42 ini kernel: [ 1800.458888] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:28:42 ini kernel: [ 1800.458899] Call Trace: > Jul 29 20:28:42 ini kernel: [ 1800.458915] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:28:42 ini kernel: [ 1800.458925] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:28:42 ini kernel: [ 1800.458932] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:28:42 ini kernel: [ 1800.458938] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:28:42 ini kernel: [ 1800.458945] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:28:42 ini kernel: [ 1800.458953] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:28:42 ini kernel: [ 1800.458961] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:28:42 ini kernel: [ 1800.458971] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:28:42 ini kernel: [ 1800.458978] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:28:42 ini kernel: [ 1800.458984] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:28:42 ini kernel: [ 1800.458991] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:28:42 ini kernel: [ 1800.458999] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:28:42 ini kernel: [ 1800.459007] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:28:42 ini kernel: [ 1800.459013] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:28:42 ini kernel: [ 1800.459020] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:28:42 ini kernel: [ 1800.459027] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:28:42 ini kernel: [ 1800.459033] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:28:42 ini kernel: [ 1800.459039] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:28:42 ini kernel: [ 1800.459046] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:28:42 ini kernel: [ 1800.493768] sync D 0004beb0 0 1265 1255 0x00000004 > Jul 29 20:28:42 ini kernel: [ 1800.493777] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 > Jul 29 20:28:42 ini kernel: [ 1800.493788] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 > Jul 29 20:28:42 ini kernel: [ 1800.493798] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff > Jul 29 20:28:42 ini kernel: [ 1800.493809] Call Trace: > Jul 29 20:28:42 ini kernel: [ 1800.493816] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 > Jul 29 20:28:42 ini kernel: [ 1800.493823] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 > Jul 29 20:28:42 ini kernel: [ 1800.493828] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 > Jul 29 20:28:42 ini kernel: [ 1800.493834] [<c057850c>] ? down_read+0x1c/0x20 > Jul 29 20:28:42 ini kernel: [ 1800.493841] [<c021cb6d>] sync_filesystems+0xbd/0x110 > Jul 29 20:28:42 ini kernel: [ 1800.493847] [<c021cc16>] sys_sync+0x16/0x40 > Jul 29 20:28:42 ini kernel: [ 1800.493853] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:30:42 ini kernel: [ 1920.526729] umount D 00478e55 0 1234 924 0x00000004 > Jul 29 20:30:42 ini kernel: [ 1920.526739] ce579e10 00000086 00000082 00478e55 00000000 c082b330 cef574dc c082b330 > Jul 29 20:30:42 ini kernel: [ 1920.526750] c082b330 c082b330 cef574dc 0355459b 0000010d c082b330 c082b330 ce652000 > Jul 29 20:30:42 ini kernel: [ 1920.526761] 0000010d cef57230 c1407330 cef57230 ce579e5c ce579e20 c057745a ce579e54 > Jul 29 20:30:42 ini kernel: [ 1920.526772] Call Trace: > Jul 29 20:30:42 ini kernel: [ 1920.526788] [<c057745a>] io_schedule+0x3a/0x60 > Jul 29 20:30:42 ini kernel: [ 1920.526798] [<c01bd95d>] sync_page+0x3d/0x50 > Jul 29 20:30:42 ini kernel: [ 1920.526805] [<c0577aa7>] __wait_on_bit_lock+0x47/0x90 > Jul 29 20:30:42 ini kernel: [ 1920.526813] [<c01bd920>] ? sync_page+0x0/0x50 > Jul 29 20:30:42 ini kernel: [ 1920.526819] [<c01bd8ee>] __lock_page+0x7e/0x90 > Jul 29 20:30:42 ini kernel: [ 1920.526827] [<c01624d0>] ? wake_bit_function+0x0/0x50 > Jul 29 20:30:42 ini kernel: [ 1920.526836] [<c01c7219>] truncate_inode_pages_range+0x2a9/0x2c0 > Jul 29 20:30:42 ini kernel: [ 1920.526845] [<c02916c6>] ? ext4_destroy_inode+0x26/0xa0 > Jul 29 20:30:42 ini kernel: [ 1920.526853] [<c01c724f>] truncate_inode_pages+0x1f/0x30 > Jul 29 20:30:42 ini kernel: [ 1920.526859] [<c020f15c>] dispose_list+0xcc/0x100 > Jul 29 20:30:42 ini kernel: [ 1920.526866] [<c020f534>] invalidate_inodes+0xf4/0x120 > Jul 29 20:30:42 ini kernel: [ 1920.526874] [<c023b310>] ? vfs_quota_off+0x0/0x20 > Jul 29 20:30:42 ini kernel: [ 1920.526882] [<c01fc602>] generic_shutdown_super+0x42/0xe0 > Jul 29 20:30:42 ini kernel: [ 1920.526889] [<c01fc6ca>] kill_block_super+0x2a/0x50 > Jul 29 20:30:42 ini kernel: [ 1920.526895] [<c01fd4e4>] deactivate_super+0x64/0x90 > Jul 29 20:30:42 ini kernel: [ 1920.526902] [<c021282f>] mntput_no_expire+0x8f/0xe0 > Jul 29 20:30:42 ini kernel: [ 1920.526908] [<c0212e47>] sys_umount+0x47/0xa0 > Jul 29 20:30:42 ini kernel: [ 1920.526915] [<c0212ebe>] sys_oldumount+0x1e/0x20 > Jul 29 20:30:42 ini kernel: [ 1920.526922] [<c01033ec>] syscall_call+0x7/0xb > Jul 29 20:30:42 ini kernel: [ 1920.563739] sync D 0004beb0 0 1265 1255 0x00000004 > Jul 29 20:30:42 ini kernel: [ 1920.563747] cea6ff2c 00000086 00000001 0004beb0 00000000 c082b330 cde3db7c c082b330 > Jul 29 20:30:42 ini kernel: [ 1920.563758] c082b330 c082b330 cde3db7c 15c42f3f 00000140 c082b330 c082b330 ce653200 > Jul 29 20:30:42 ini kernel: [ 1920.563768] 00000140 cde3d8d0 cea6ff60 cde3d8d0 cefef23c cea6ff58 c0578de5 fffeffff > Jul 29 20:30:42 ini kernel: [ 1920.563779] Call Trace: > Jul 29 20:30:42 ini kernel: [ 1920.563787] [<c0578de5>] rwsem_down_failed_common+0x75/0x1a0 > Jul 29 20:30:42 ini kernel: [ 1920.563793] [<c0578f5d>] rwsem_down_read_failed+0x1d/0x30 > Jul 29 20:30:42 ini kernel: [ 1920.563799] [<c0578fb7>] call_rwsem_down_read_failed+0x7/0x10 > Jul 29 20:30:42 ini kernel: [ 1920.563804] [<c057850c>] ? down_read+0x1c/0x20 > Jul 29 20:30:42 ini kernel: [ 1920.563812] [<c021cb6d>] sync_filesystems+0xbd/0x110 > Jul 29 20:30:42 ini kernel: [ 1920.563817] [<c021cc16>] sys_sync+0x16/0x40 > Jul 29 20:30:42 ini kernel: [ 1920.563823] [<c01033ec>] syscall_call+0x7/0xb > > Although in both cases the FS remained consistent: Yes, at least something positive in the end ;). > root(a)ini:~# mount -t ext4 /dev/sdb /mnt > root(a)ini:~# umount /mnt > root(a)ini:~# e2fsck -f -y /dev/sdb > e2fsck 1.41.11 (14-Mar-2010) > Pass 1: Checking inodes, blocks, and sizes > Pass 2: Checking directory structure > Pass 3: Checking directory connectivity > Pass 4: Checking reference counts > Pass 5: Checking group summary information > > /dev/sdb: ***** FILE SYSTEM WAS MODIFIED ***** > /dev/sdb: 4194/640000 files (74.2% non-contiguous), 334774/1280000 blocks > > You can find full kernel logs starting from iSCSI load in the attachments. > > I already reported such issues some time ago, but my reports were not too much welcomed, so I gave up. Anyway, anybody can easily do my tests at any time. They don't need any special hardware, just 2 Linux boxes: one for iSCSI target and one for iSCSI initiator (the test box itself). But they are generic for other transports as well. You can see there's nothing iSCSI specific in the traces. Thanks for running the test. Honza -- Jan Kara <jack(a)suse.cz> SUSE Labs, CR -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Jan Kara on 29 Jul 2010 10:40 On Thu 29-07-10 18:12:29, Vladislav Bolkhovitin wrote: > > Christoph Hellwig, on 07/29/2010 05:08 PM wrote: > > On Thu, Jul 29, 2010 at 05:00:10PM +0400, Vladislav Bolkhovitin wrote: > >> You can find full kernel logs starting from iSCSI load in the attachments. > >> > >> I already reported such issues some time ago, but my reports were not too much welcomed, so I gave up. Anyway, anybody can easily do my tests at any time. They don't need any special hardware, just 2 Linux boxes: one for iSCSI target and one for iSCSI initiator (the test box itself). But they are generic for other transports as well. You can see there's nothing iSCSI specific in the traces. > > > > I was only talking about ext3. > > Yes, now ext3 is a lot more reliable. The only how I was able to confuse it was: > > ... > (2197) nb_write: handle 4272 was not open size=65475 ofs=0 > (2199) nb_write: handle 4272 was not open size=65475 ofs=65534 > (2201) nb_write: handle 4272 was not open size=65475 ofs=131068 > (2203) nb_write: handle 4272 was not open size=65475 ofs=196602 > (2205) nb_write: handle 4272 was not open size=65475 ofs=262136^C > ^C > root(a)ini:/mnt/dbench-mod# ^C > root(a)ini:/mnt/dbench-mod# ^C > root(a)ini:/mnt/dbench-mod# cd > root(a)ini:~# umount /mnt > > <- recover device > > root(a)ini:~# mount -t ext3 -o barrier=1 /dev/sdb /mnt > mount: wrong fs type, bad option, bad superblock on /dev/sdb, > missing codepage or helper program, or other error > In some cases useful info is found in syslog - try > dmesg | tail or so > > Kernel log: "Jul 29 22:05:32 ini kernel: [ 2905.423092] JBD: recovery failed" Hmm, this is strange. Are there more messages around this one? Honza -- Jan Kara <jack(a)suse.cz> SUSE Labs, CR -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Vladislav Bolkhovitin on 29 Jul 2010 14:30
Jan Kara, on 07/29/2010 06:34 PM wrote: > On Thu 29-07-10 18:12:29, Vladislav Bolkhovitin wrote: >> >> Christoph Hellwig, on 07/29/2010 05:08 PM wrote: >>> On Thu, Jul 29, 2010 at 05:00:10PM +0400, Vladislav Bolkhovitin wrote: >>>> You can find full kernel logs starting from iSCSI load in the attachments. >>>> >>>> I already reported such issues some time ago, but my reports were not too much welcomed, so I gave up. Anyway, anybody can easily do my tests at any time. They don't need any special hardware, just 2 Linux boxes: one for iSCSI target and one for iSCSI initiator (the test box itself). But they are generic for other transports as well. You can see there's nothing iSCSI specific in the traces. >>> >>> I was only talking about ext3. >> >> Yes, now ext3 is a lot more reliable. The only how I was able to confuse it was: >> >> ... >> (2197) nb_write: handle 4272 was not open size=65475 ofs=0 >> (2199) nb_write: handle 4272 was not open size=65475 ofs=65534 >> (2201) nb_write: handle 4272 was not open size=65475 ofs=131068 >> (2203) nb_write: handle 4272 was not open size=65475 ofs=196602 >> (2205) nb_write: handle 4272 was not open size=65475 ofs=262136^C >> ^C >> root(a)ini:/mnt/dbench-mod# ^C >> root(a)ini:/mnt/dbench-mod# ^C >> root(a)ini:/mnt/dbench-mod# cd >> root(a)ini:~# umount /mnt >> >> <- recover device >> >> root(a)ini:~# mount -t ext3 -o barrier=1 /dev/sdb /mnt >> mount: wrong fs type, bad option, bad superblock on /dev/sdb, >> missing codepage or helper program, or other error >> In some cases useful info is found in syslog - try >> dmesg | tail or so >> >> Kernel log: "Jul 29 22:05:32 ini kernel: [ 2905.423092] JBD: recovery failed" > Hmm, this is strange. Are there more messages around this one? Rather none: Jul 29 22:02:05 ini kernel: [ 2698.488446] sd 7:0:0:0: [sdb] CDB: Read(10): 28 00 00 07 88 69 00 00 01 00 Jul 29 22:02:05 ini kernel: [ 2698.505470] sd 7:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE Jul 29 22:02:05 ini kernel: [ 2698.505480] sd 7:0:0:0: [sdb] Sense Key : Illegal Request [current] Jul 29 22:02:05 ini kernel: [ 2698.505488] sd 7:0:0:0: [sdb] Add. Sense: Logical unit not supported Jul 29 22:02:05 ini kernel: [ 2698.505497] sd 7:0:0:0: [sdb] CDB: Read(10): 28 00 00 07 88 69 00 00 01 00 Jul 29 22:02:05 ini kernel: [ 2698.555147] sd 7:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE Jul 29 22:02:05 ini kernel: [ 2698.555157] sd 7:0:0:0: [sdb] Sense Key : Illegal Request [current] Jul 29 22:02:05 ini kernel: [ 2698.555165] sd 7:0:0:0: [sdb] Add. Sense: Logical unit not supported Jul 29 22:02:05 ini kernel: [ 2698.555175] sd 7:0:0:0: [sdb] CDB: Read(10): 28 00 00 07 88 69 00 00 01 00 Jul 29 22:02:05 ini kernel: [ 2698.582241] sd 7:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE Jul 29 22:02:05 ini kernel: [ 2698.582251] sd 7:0:0:0: [sdb] Sense Key : Illegal Request [current] Jul 29 22:02:05 ini kernel: [ 2698.582259] sd 7:0:0:0: [sdb] Add. Sense: Logical unit not supported Jul 29 22:02:05 ini kernel: [ 2698.582268] sd 7:0:0:0: [sdb] CDB: Read(10): 28 00 00 07 88 69 00 00 01 00 Jul 29 22:02:05 ini kernel: [ 2698.614789] sd 7:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE Jul 29 22:02:05 ini kernel: [ 2698.614799] sd 7:0:0:0: [sdb] Sense Key : Illegal Request [current] Jul 29 22:02:05 ini kernel: [ 2698.614807] sd 7:0:0:0: [sdb] Add. Sense: Logical unit not supported Jul 29 22:02:05 ini kernel: [ 2698.614817] sd 7:0:0:0: [sdb] CDB: Read(10): 28 00 00 07 88 69 00 00 01 00 Jul 29 22:02:45 ini kernel: [ 2738.474386] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474529] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474536] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474570] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474583] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474603] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474615] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474621] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474633] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:02:45 ini kernel: [ 2738.474659] __journal_remove_journal_head: freeing b_committed_data Jul 29 22:05:32 ini kernel: [ 2905.423092] JBD: recovery failed Jul 29 22:05:54 ini kernel: [ 2927.832893] kjournald starting. Commit interval 5 seconds Jul 29 22:05:54 ini kernel: [ 2927.833430] EXT3 FS on sdb, internal journal Jul 29 22:05:54 ini kernel: [ 2927.833499] EXT3-fs: sdb: 1 orphan inode deleted Jul 29 22:05:54 ini kernel: [ 2927.833503] EXT3-fs: recovery complete. Jul 29 22:05:54 ini kernel: [ 2927.838122] EXT3-fs: mounted filesystem with ordered data mode. -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/ |