Oleksandr Natalenko
2016-Jan-15 07:40 UTC
[Gluster-users] GlusterFS FUSE client hangs on rsyncing lots of file
While doing rsync over millions of files from ordinary partition to GlusterFS volume, just after approx. first 2 million rsync hang happens, and the following info appears in dmesg: ==[17075038.924481] INFO: task rsync:10310 blocked for more than 120 seconds. [17075038.931948] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17075038.940748] rsync D ffff88207fc13680 0 10310 10309 0x00000080 [17075038.940752] ffff8809c578be18 0000000000000086 ffff8809c578bfd8 0000000000013680 [17075038.940756] ffff8809c578bfd8 0000000000013680 ffff880310cbe660 ffff881159d16a30 [17075038.940759] ffff881e3aa25800 ffff8809c578be48 ffff881159d16b10 ffff88087d553980 [17075038.940762] Call Trace: [17075038.940770] [<ffffffff8160a1d9>] schedule+0x29/0x70 [17075038.940797] [<ffffffffa023a53d>] __fuse_request_send+0x13d/0x2c0 [fuse] [17075038.940801] [<ffffffffa023db30>] ? fuse_get_req_nofail_nopages+0xc0/0x1e0 [fuse] [17075038.940805] [<ffffffff81098350>] ? wake_up_bit+0x30/0x30 [17075038.940809] [<ffffffffa023a6d2>] fuse_request_send+0x12/0x20 [fuse] [17075038.940813] [<ffffffffa024382f>] fuse_flush+0xff/0x150 [fuse] [17075038.940817] [<ffffffff811c45c4>] filp_close+0x34/0x80 [17075038.940821] [<ffffffff811e4ed8>] __close_fd+0x78/0xa0 [17075038.940824] [<ffffffff811c6103>] SyS_close+0x23/0x50 [17075038.940828] [<ffffffff81614de9>] system_call_fastpath+0x16/0x1b == rsync blocks in D state, and to kill it, I have to do umount --lazy on GlusterFS mountpoint, and then kill corresponding client glusterfs process. Then rsync exits. Here is GlusterFS volume info: ==Volume Name: asterisk_records Type: Distributed-Replicate Volume ID: dc1fe561-fa3a-4f2e-8330-ec7e52c75ba4 Status: Started Number of Bricks: 3 x 2 = 6 Transport-type: tcp Bricks: Brick1: server1:/bricks/10_megaraid_0_3_9_x_0_4_3_hdd_r1_nolvm_hdd_storage_01/asterisk/records Brick2: server2:/bricks/10_megaraid_8_5_14_x_8_6_16_hdd_r1_nolvm_hdd_storage_01/asterisk/records Brick3: server1:/bricks/11_megaraid_0_5_4_x_0_6_5_hdd_r1_nolvm_hdd_storage_02/asterisk/records Brick4: server2:/bricks/11_megaraid_8_7_15_x_8_8_20_hdd_r1_nolvm_hdd_storage_02/asterisk/records Brick5: server1:/bricks/12_megaraid_0_7_6_x_0_13_14_hdd_r1_nolvm_hdd_storage_03/asterisk/records Brick6: server2:/bricks/12_megaraid_8_9_19_x_8_13_24_hdd_r1_nolvm_hdd_storage_03/asterisk/records Options Reconfigured: cluster.lookup-optimize: on cluster.readdir-optimize: on client.event-threads: 2 network.inode-lru-limit: 4096 server.event-threads: 4 performance.client-io-threads: on storage.linux-aio: on performance.write-behind-window-size: 4194304 performance.stat-prefetch: on performance.quick-read: on performance.read-ahead: on performance.flush-behind: on performance.write-behind: on performance.io-thread-count: 2 performance.cache-max-file-size: 1048576 performance.cache-size: 33554432 features.cache-invalidation: on performance.readdir-ahead: on == The issue reproduces each time I rsync such an amount of files. How could I debug this issue better?
Oleksandr Natalenko
2016-Jan-15 07:49 UTC
[Gluster-users] GlusterFS FUSE client hangs on rsyncing lots of file
Here is similar issue described on serverfault.com: https://serverfault.com/questions/716410/rsync-crashes-machine-while-performing-sync-on-glusterfs-mounted-share I've checked GlusterFS logs with no luck ? as if nothing happened. P.S. GlusterFS v3.7.6. 15.01.2016 09:40, Oleksandr Natalenko ???????:> While doing rsync over millions of files from ordinary partition to > GlusterFS volume, just after approx. first 2 million rsync hang > happens, and the following info appears in dmesg: > > ==> [17075038.924481] INFO: task rsync:10310 blocked for more than 120 > seconds. > [17075038.931948] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this message. > [17075038.940748] rsync D ffff88207fc13680 0 10310 > 10309 0x00000080 > [17075038.940752] ffff8809c578be18 0000000000000086 ffff8809c578bfd8 > 0000000000013680 > [17075038.940756] ffff8809c578bfd8 0000000000013680 ffff880310cbe660 > ffff881159d16a30 > [17075038.940759] ffff881e3aa25800 ffff8809c578be48 ffff881159d16b10 > ffff88087d553980 > [17075038.940762] Call Trace: > [17075038.940770] [<ffffffff8160a1d9>] schedule+0x29/0x70 > [17075038.940797] [<ffffffffa023a53d>] __fuse_request_send+0x13d/0x2c0 > [fuse] > [17075038.940801] [<ffffffffa023db30>] ? > fuse_get_req_nofail_nopages+0xc0/0x1e0 [fuse] > [17075038.940805] [<ffffffff81098350>] ? wake_up_bit+0x30/0x30 > [17075038.940809] [<ffffffffa023a6d2>] fuse_request_send+0x12/0x20 > [fuse] > [17075038.940813] [<ffffffffa024382f>] fuse_flush+0xff/0x150 [fuse] > [17075038.940817] [<ffffffff811c45c4>] filp_close+0x34/0x80 > [17075038.940821] [<ffffffff811e4ed8>] __close_fd+0x78/0xa0 > [17075038.940824] [<ffffffff811c6103>] SyS_close+0x23/0x50 > [17075038.940828] [<ffffffff81614de9>] system_call_fastpath+0x16/0x1b > ==> > rsync blocks in D state, and to kill it, I have to do umount --lazy on > GlusterFS mountpoint, and then kill corresponding client glusterfs > process. Then rsync exits. > > Here is GlusterFS volume info: > > ==> Volume Name: asterisk_records > Type: Distributed-Replicate > Volume ID: dc1fe561-fa3a-4f2e-8330-ec7e52c75ba4 > Status: Started > Number of Bricks: 3 x 2 = 6 > Transport-type: tcp > Bricks: > Brick1: > server1:/bricks/10_megaraid_0_3_9_x_0_4_3_hdd_r1_nolvm_hdd_storage_01/asterisk/records > Brick2: > server2:/bricks/10_megaraid_8_5_14_x_8_6_16_hdd_r1_nolvm_hdd_storage_01/asterisk/records > Brick3: > server1:/bricks/11_megaraid_0_5_4_x_0_6_5_hdd_r1_nolvm_hdd_storage_02/asterisk/records > Brick4: > server2:/bricks/11_megaraid_8_7_15_x_8_8_20_hdd_r1_nolvm_hdd_storage_02/asterisk/records > Brick5: > server1:/bricks/12_megaraid_0_7_6_x_0_13_14_hdd_r1_nolvm_hdd_storage_03/asterisk/records > Brick6: > server2:/bricks/12_megaraid_8_9_19_x_8_13_24_hdd_r1_nolvm_hdd_storage_03/asterisk/records > Options Reconfigured: > cluster.lookup-optimize: on > cluster.readdir-optimize: on > client.event-threads: 2 > network.inode-lru-limit: 4096 > server.event-threads: 4 > performance.client-io-threads: on > storage.linux-aio: on > performance.write-behind-window-size: 4194304 > performance.stat-prefetch: on > performance.quick-read: on > performance.read-ahead: on > performance.flush-behind: on > performance.write-behind: on > performance.io-thread-count: 2 > performance.cache-max-file-size: 1048576 > performance.cache-size: 33554432 > features.cache-invalidation: on > performance.readdir-ahead: on > ==> > The issue reproduces each time I rsync such an amount of files. > > How could I debug this issue better? > _______________________________________________ > Gluster-users mailing list > Gluster-users at gluster.org > http://www.gluster.org/mailman/listinfo/gluster-users
Oleksandr Natalenko
2016-Jan-15 14:09 UTC
[Gluster-users] GlusterFS FUSE client hangs on rsyncing lots of file
Another observation: if rsyncing is resumed after hang, rsync itself hangs a lot faster because it does stat of already copied files. So, the reason may be not writing itself, but massive stat on GlusterFS volume as well. 15.01.2016 09:40, Oleksandr Natalenko ???????:> While doing rsync over millions of files from ordinary partition to > GlusterFS volume, just after approx. first 2 million rsync hang > happens, and the following info appears in dmesg: > > ==> [17075038.924481] INFO: task rsync:10310 blocked for more than 120 > seconds. > [17075038.931948] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this message. > [17075038.940748] rsync D ffff88207fc13680 0 10310 > 10309 0x00000080 > [17075038.940752] ffff8809c578be18 0000000000000086 ffff8809c578bfd8 > 0000000000013680 > [17075038.940756] ffff8809c578bfd8 0000000000013680 ffff880310cbe660 > ffff881159d16a30 > [17075038.940759] ffff881e3aa25800 ffff8809c578be48 ffff881159d16b10 > ffff88087d553980 > [17075038.940762] Call Trace: > [17075038.940770] [<ffffffff8160a1d9>] schedule+0x29/0x70 > [17075038.940797] [<ffffffffa023a53d>] __fuse_request_send+0x13d/0x2c0 > [fuse] > [17075038.940801] [<ffffffffa023db30>] ? > fuse_get_req_nofail_nopages+0xc0/0x1e0 [fuse] > [17075038.940805] [<ffffffff81098350>] ? wake_up_bit+0x30/0x30 > [17075038.940809] [<ffffffffa023a6d2>] fuse_request_send+0x12/0x20 > [fuse] > [17075038.940813] [<ffffffffa024382f>] fuse_flush+0xff/0x150 [fuse] > [17075038.940817] [<ffffffff811c45c4>] filp_close+0x34/0x80 > [17075038.940821] [<ffffffff811e4ed8>] __close_fd+0x78/0xa0 > [17075038.940824] [<ffffffff811c6103>] SyS_close+0x23/0x50 > [17075038.940828] [<ffffffff81614de9>] system_call_fastpath+0x16/0x1b > ==> > rsync blocks in D state, and to kill it, I have to do umount --lazy on > GlusterFS mountpoint, and then kill corresponding client glusterfs > process. Then rsync exits. > > Here is GlusterFS volume info: > > ==> Volume Name: asterisk_records > Type: Distributed-Replicate > Volume ID: dc1fe561-fa3a-4f2e-8330-ec7e52c75ba4 > Status: Started > Number of Bricks: 3 x 2 = 6 > Transport-type: tcp > Bricks: > Brick1: > server1:/bricks/10_megaraid_0_3_9_x_0_4_3_hdd_r1_nolvm_hdd_storage_01/asterisk/records > Brick2: > server2:/bricks/10_megaraid_8_5_14_x_8_6_16_hdd_r1_nolvm_hdd_storage_01/asterisk/records > Brick3: > server1:/bricks/11_megaraid_0_5_4_x_0_6_5_hdd_r1_nolvm_hdd_storage_02/asterisk/records > Brick4: > server2:/bricks/11_megaraid_8_7_15_x_8_8_20_hdd_r1_nolvm_hdd_storage_02/asterisk/records > Brick5: > server1:/bricks/12_megaraid_0_7_6_x_0_13_14_hdd_r1_nolvm_hdd_storage_03/asterisk/records > Brick6: > server2:/bricks/12_megaraid_8_9_19_x_8_13_24_hdd_r1_nolvm_hdd_storage_03/asterisk/records > Options Reconfigured: > cluster.lookup-optimize: on > cluster.readdir-optimize: on > client.event-threads: 2 > network.inode-lru-limit: 4096 > server.event-threads: 4 > performance.client-io-threads: on > storage.linux-aio: on > performance.write-behind-window-size: 4194304 > performance.stat-prefetch: on > performance.quick-read: on > performance.read-ahead: on > performance.flush-behind: on > performance.write-behind: on > performance.io-thread-count: 2 > performance.cache-max-file-size: 1048576 > performance.cache-size: 33554432 > features.cache-invalidation: on > performance.readdir-ahead: on > ==> > The issue reproduces each time I rsync such an amount of files. > > How could I debug this issue better? > _______________________________________________ > Gluster-users mailing list > Gluster-users at gluster.org > http://www.gluster.org/mailman/listinfo/gluster-users