I did not meet error message like timeout or connection broken when scping or rsyncing. Just the transfer speed slow down to zero. At least the connection between our scp/rsync server and client is ok. Your problem maybe the server side (scp/rsync server process) or the client side，otherwise the network between them. Did you see your dmesg or journal during your copy ? There maybe some surprise. — Best Regards Li, Ning > On Dec 6, 2018, at 17:05, Marc Roos <M.Roos@xxxxxxxxxxxxxxxxx> wrote: > > > > > I am not sure if this rsync error message is entirely correct, the > networking people cannot see what is causing this. I have this only with > one server that has 'big' files on it. Typical solutions like ssh > sessions that could time out, I already checked. I just wondered what > error do you get from rsync in your specific case. > > > > -----Original Message----- > From: Li,Ning [mailto:lining916740672@xxxxxxxxxx] > Sent: 05 December 2018 11:41 > To: Marc Roos > Subject: Re: 【cephfs】cephfs hung when scp/rsync large > files > > Hi Roos, > > Thanks for replying. > > Our problem’s behavior is different. We have no this error messages. > The connection is not broken, the copy process is normal. There are just > other writing cephfs process hung. > > > Best Regards > Li, Ning > > > > > On Dec 5, 2018, at 16:30, Marc Roos <M.Roos@xxxxxxxxxxxxxxxxx> > wrote: > > > Do you then get these types of error messages? > > packet_write_wait: Connection to 192.168.10.43 port 22: Broken pipe > rsync: connection unexpectedly closed (2345281724 bytes received so > far) > [receiver] > rsync error: error in rsync protocol data stream (code 12) at > io.c(226) > [receiver=3.1.2] > rsync: connection unexpectedly closed (1078793 bytes received so > far) > [generator] > rsync error: unexplained error (code 255) at io.c(226) > [generator=3.1.2] > > And > > rsync: [generator] write error: Broken pipe (32)rsync: connection > unexpectedly closed (3214826211 bytes received so far) [receiver] > > rsync error: unexplained error (code 255) at io.c(820) > [generator=3.1.2] > rsync error: error in rsync protocol data stream (code 12) at > io.c(226) > [receiver=3.1.2] > > > -----Original Message----- > From: NingLi [mailto:lining916740672@xxxxxxxxxx] > Sent: 05 December 2018 07:33 > To: ceph-users@xxxxxxxxxxxxxx > Cc: Yilong Ren > Subject: 【cephfs】cephfs hung when scp/rsync large > files > > Hi all, > > We found that some process writing cephfs will hang for a long > time (> > 120s) when uploading(scp/rsync) large files（totally 50G ~ > 300G）to the > app node's cephfs mountpoint. > > This problem is not always reproduciable. But when this problem > occurs, > the web(nginx) or some other services can’t be access, it’s > embarrassing. > > > Please give some tips. > > > We are using ceph version 13.2.1 and 3.10.0-693.el7.x86_64 > kernel. > > > When this problem occurs, the memory pressure is a bit high. > # free -h > total used free shared > buff/cache > available > Mem: 30G 11G 230M 3.3M 18G > > 18G > Swap: 0B 0B 0B > > # mpstat -P ALL > Average: CPU %usr %nice %sys %iowait %irq %soft > %steal > %guest %gnice %idle > Average: all 3.80 0.04 1.46 55.12 0.00 > 0.08 > 0.00 0.00 0.00 39.49 > Average: 0 1.52 0.00 0.51 97.98 0.00 > 0.00 > 0.00 0.00 0.00 0.00 > Average: 1 13.07 0.00 1.51 0.00 0.00 > 0.00 > 0.00 0.00 0.00 85.43 > Average: 2 3.00 0.00 3.00 0.50 0.00 > > 0.00 0.00 0.00 0.00 93.50 > Average: 3 2.50 0.00 2.00 0.00 0.00 > > 0.00 0.00 0.00 0.00 95.50 > Average: 4 1.50 0.50 1.50 96.00 0.00 > 0.50 > 0.00 0.00 0.00 0.00 > Average: 5 0.50 0.00 1.01 32.16 0.00 > 0.00 > 0.00 0.00 0.00 66.33 > Average: 6 2.49 0.00 2.49 0.00 0.00 > 0.50 > 0.00 0.00 0.00 94.53 > Average: 7 1.52 0.00 0.51 97.98 0.00 > 0.00 > 0.00 0.00 0.00 0.00 > Average: 8 1.50 0.00 1.50 97.00 0.00 > 0.00 > 0.00 0.00 0.00 0.00 > Average: 9 14.07 0.00 2.01 46.23 0.00 > 0.00 > 0.00 0.00 0.00 37.69 > Average: 10 2.00 0.00 0.50 97.50 0.00 > 0.00 > 0.00 0.00 0.00 0.00 > Average: 11 2.01 0.00 1.01 96.98 0.00 > 0.00 > 0.00 0.00 0.00 0.00 > > We can see some process in state ‘D’ for a long time. here are 2 > > fragments in dmesg. > > [Fri Nov 30 15:10:43 2018] INFO: task java:11662 blocked for more > than > 120 seconds. > [Fri Nov 30 15:10:43 2018] "echo 0 > > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [Fri Nov 30 15:10:43 2018] java D ffffffff816a4180 0 > > 11662 10409 0x00000180 > [Fri Nov 30 15:10:43 2018] ffff8805f4febbd0 0000000000000082 > ffff8807e2edcf10 ffff8805f4febfd8 [Fri Nov 30 15:10:43 2018] > ffff8805f4febfd8 ffff8805f4febfd8 ffff8807e2edcf10 ffff88086df56cc0 > [Fri > Nov 30 15:10:43 2018] 0000000000000000 7fffffffffffffff > ffff88087ffc3be8 ffffffff816a4180 [Fri Nov 30 15:10:43 2018] Call > Trace: > [Fri Nov 30 15:10:43 2018] [<ffffffff816a4180>] ? > bit_wait+0x50/0x50 > [Fri Nov 30 15:10:43 2018] [<ffffffff816a6059>] schedule+0x29/0x70 > [Fri > Nov 30 15:10:43 2018] [<ffffffff816a3b69>] > schedule_timeout+0x239/0x2c0 > [Fri Nov 30 15:10:43 2018] [<ffffffff81190541>] ? > pagevec_lookup_tag+0x21/0x30 [Fri Nov 30 15:10:43 2018] > [<ffffffffc082b598>] ? ceph_writepages_start+0x1298/0x1520 [ceph] > [Fri > Nov 30 15:10:43 2018] [<ffffffff810e939c>] ? > ktime_get_ts64+0x4c/0xf0 > [Fri Nov 30 15:10:43 2018] [<ffffffff816a4180>] ? > bit_wait+0x50/0x50 > [Fri Nov 30 15:10:43 2018] [<ffffffff816a56dd>] > io_schedule_timeout+0xad/0x130 [Fri Nov 30 15:10:43 2018] > [<ffffffff816a5778>] io_schedule+0x18/0x20 [Fri Nov 30 15:10:43 > 2018] > [<ffffffff816a4191>] bit_wait_io+0x11/0x50 [Fri Nov 30 15:10:43 > 2018] > [<ffffffff816a3cb5>] __wait_on_bit+0x65/0x90 [Fri Nov 30 15:10:43 > 2018] > [<ffffffff81181cb1>] wait_on_page_bit+0x81/0xa0 [Fri Nov 30 > 15:10:43 > 2018] [<ffffffff810b19d0>] ? wake_bit_function+0x40/0x40 [Fri Nov > 30 > 15:10:43 2018] [<ffffffff81181de1>] > __filemap_fdatawait_range+0x111/0x190 > [Fri Nov 30 15:10:43 2018] [<ffffffff811b0d79>] ? > do_numa_page+0x159/0x1e0 [Fri Nov 30 15:10:43 2018] > [<ffffffff8118f42e>] ? do_writepages+0x1e/0x40 [Fri Nov 30 15:10:43 > > 2018] [<ffffffff81181e74>] filemap_fdatawait_range+0x14/0x30 [Fri > Nov > 30 15:10:43 2018] [<ffffffff81183db6>] > filemap_write_and_wait_range+0x56/0x90 > [Fri Nov 30 15:10:43 2018] [<ffffffffc083326c>] > ceph_fsync+0x6c/0x510 > [ceph] [Fri Nov 30 15:10:43 2018] [<ffffffff81137273>] ? > __secure_computing+0x73/0x240 [Fri Nov 30 15:10:43 2018] > [<ffffffff8111f5c6>] ? __audit_syscall_exit+0x1e6/0x280 [Fri Nov 30 > > 15:10:43 2018] [<ffffffff81231d85>] do_fsync+0x65/0xa0 [Fri Nov 30 > > 15:10:43 2018] [<ffffffff81232083>] SyS_fdatasync+0x13/0x20 [Fri > Nov 30 > 15:10:43 2018] [<ffffffff816b1d4e>] tracesys+0xd9/0xde > > > [Fri Nov 30 15:12:43 2018] INFO: task prometheus:9919 blocked for > more > than 120 seconds. > [Fri Nov 30 15:12:43 2018] "echo 0 > > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [Fri Nov 30 15:12:43 2018] prometheus D ffff8807e87dbad8 0 > > 9919 9879 0x00000080 > [Fri Nov 30 15:12:43 2018] ffff8807e87db970 0000000000000082 > ffff8803e273cf10 ffff8807e87dbfd8 [Fri Nov 30 15:12:43 2018] > ffff8807e87dbfd8 ffff8807e87dbfd8 ffff8803e273cf10 ffff88046e716cc0 > [Fri > Nov 30 15:12:43 2018] 0000000000000000 7fffffffffffffff > ffffffff816a4180 ffff8807e87dbad8 [Fri Nov 30 15:12:43 2018] Call > Trace: > [Fri Nov 30 15:12:43 2018] [<ffffffff816a4180>] ? > bit_wait+0x50/0x50 > [Fri Nov 30 15:12:43 2018] [<ffffffff816a6059>] schedule+0x29/0x70 > [Fri > Nov 30 15:12:43 2018] [<ffffffff816a3b69>] > schedule_timeout+0x239/0x2c0 > [Fri Nov 30 15:12:43 2018] [<ffffffff81090007>] ? > local_bh_enable+0x17/0x20 [Fri Nov 30 15:12:43 2018] > [<ffffffff816a4180>] ? bit_wait+0x50/0x50 [Fri Nov 30 15:12:43 > 2018] > [<ffffffff816a56dd>] io_schedule_timeout+0xad/0x130 [Fri Nov 30 > 15:12:43 > 2018] [<ffffffff816a5778>] io_schedule+0x18/0x20 [Fri Nov 30 > 15:12:43 > 2018] [<ffffffff816a4191>] bit_wait_io+0x11/0x50 [Fri Nov 30 > 15:12:43 > 2018] [<ffffffff816a3eaf>] __wait_on_bit_lock+0x5f/0xc0 [Fri Nov > 30 > 15:12:43 2018] [<ffffffff81182094>] __lock_page+0x74/0x90 [Fri Nov > 30 > 15:12:43 2018] [<ffffffff810b19d0>] ? wake_bit_function+0x40/0x40 > [Fri > Nov 30 15:12:43 2018] [<ffffffff81182a34>] > __find_lock_page+0x54/0x70 > [Fri Nov 30 15:12:43 2018] [<ffffffff811836e2>] > grab_cache_page_write_begin+0x62/0xd0 > [Fri Nov 30 15:12:43 2018] [<ffffffffc082a203>] > ceph_write_begin+0x43/0xe0 [ceph] [Fri Nov 30 15:12:43 2018] > [<ffffffff811824ce>] generic_file_buffered_write+0x11e/0x2a0 > [Fri Nov 30 15:12:43 2018] [<ffffffffc08259c4>] > ceph_aio_write+0xac4/0xc60 [ceph] [Fri Nov 30 15:12:43 2018] > [<ffffffff8160417a>] ? inet_recvmsg+0x7a/0xa0 [Fri Nov 30 15:12:43 > 2018] > [<ffffffff811feb3d>] do_sync_write+0x8d/0xd0 [Fri Nov 30 15:12:43 > 2018] > [<ffffffff811ff5fd>] vfs_write+0xbd/0x1e0 [Fri Nov 30 15:12:43 > 2018] > [<ffffffff8120040f>] SyS_write+0x7f/0xe0 [Fri Nov 30 15:12:43 2018] > > [<ffffffff816b1b49>] system_call_fastpath+0x16/0x1b > > > But the cephfs status shows healthy. > # ceph -s > cluster: > id: b27bc9a3-2e32-4782-b60f-b7901b0b26e5 > health: HEALTH_OK > > services: > mon: 2 daemons, quorum skyaxe-storage-0,skyaxe-storage-1 > mgr: skyaxe-storage-0(active), standbys: skyaxe-storage-1 > mds: cephfs-1/1/1 up {0=skyaxe-storage-1=up:active}, 1 > up:standby > osd: 8 osds: 8 up, 8 in > > data: > pools: 2 pools, 512 pgs > objects: 599.7 k objects, 876 GiB > usage: 2.6 TiB used, 13 TiB / 15 TiB avail > pgs: 512 active+clean > > io: > client: 3.7 KiB/s wr, 0 op/s rd, 1 op/s wr > > > We can see some unfinished requests in osdc. > > # cat /sys/kernel/debug/ceph/xxx/osdc > REQUESTS 98 homeless 0 > 8529 osd1 1.1bfdee5 [1,7]/1 [1,7]/1 > 100000011be.00000000 > 0x400024 1 0'0 write > 8532 osd1 1.2d81c338 [1,6]/1 [1,6]/1 > 100000011c0.00000000 > 0x400024 1 0'0 write > 8536 osd1 1.49324f26 [1,4]/1 [1,4]/1 > 100000011c4.00000000 > 0x400024 1 0'0 write > 8542 osd1 1.1403106f [1,7]/1 [1,7]/1 > 100000011c8.00000000 > 0x400024 1 0'0 write > 8549 osd1 1.ea273113 [1,4]/1 [1,4]/1 > 100000011ce.00000000 > 0x400024 1 0'0 write > 8562 osd1 1.f2d68e9a [1,5]/1 [1,5]/1 > 100000011d8.00000000 > 0x400024 1 0'0 write > 8566 osd1 1.1f212283 [1,4]/1 [1,4]/1 > 100000011db.00000000 > 0x400024 1 0'0 write > 8568 osd1 1.2e1984e7 [1,5]/1 [1,5]/1 > 100000011de.00000000 > 0x400024 1 0'0 write > 8576 osd1 1.da7e63d0 [1,5]/1 [1,5]/1 > 100000011e1.00000000 > 0x400024 1 0'0 write > 8581 osd1 1.3b0d280 [1,4]/1 [1,4]/1 > 100000011e8.00000000 > 0x400024 1 0'0 write > 8582 osd1 1.80227f0b [1,5]/1 [1,5]/1 > 100000011ea.00000000 > 0x400024 1 0'0 write > 8593 osd1 1.1efd9391 [1,6]/1 [1,6]/1 > 100000011ef.00000000 > 0x400024 1 0'0 write > 8594 osd1 1.3db6e880 [1,4]/1 [1,4]/1 > 100000011f0.00000000 > 0x400024 1 0'0 write > 8611 osd1 1.6d20c41d [1,4]/1 [1,4]/1 > 1000000028c.00000000 > 0x400024 1 0'0 write > 8612 osd1 1.6d20c41d [1,4]/1 [1,4]/1 > 1000000028c.00000000 > 0x400024 1 0'0 write > 8616 osd1 1.f4d90a4d [1,7]/1 [1,7]/1 > 10000001206.00000000 > 0x400024 1 0'0 write > 8619 osd1 1.740514fe [1,5]/1 [1,5]/1 > 10000001208.00000000 > 0x400024 1 0'0 write > 8630 osd1 1.d5fbabe0 [1,6]/1 [1,6]/1 > 10000001216.00000000 > 0x400024 1 0'0 write > 8631 osd1 1.daf28f83 [1,4]/1 [1,4]/1 > 10000001217.00000000 > 0x400024 1 0'0 write > 8635 osd1 1.d29e01a6 [1,5]/1 [1,5]/1 > 1000000121a.00000000 > 0x400024 1 0'0 write > 8640 osd1 1.2de0ff63 [1,7]/1 [1,7]/1 > 10000001220.00000000 > 0x400024 1 0'0 write > 8658 osd1 1.2f91206f [1,7]/1 [1,7]/1 > 1000000122c.00000000 > 0x400064 1 0'0 write,startsync > ... > > > Here is our ceph config： > > # cat /etc/ceph/ceph.conf > [global] > fsid = b27bc9a3-2e32-4782-b60f-b7901b0b26e5 > mon_initial_members = skyaxe-storage-0, skyaxe-storage-1 > mon_host = 10.0.30.111,10.0.30.112 > auth_cluster_required = cephx > auth_service_required = cephx > auth_client_required = cephx > > osd_pool_default_size = 2 > public_network = 10.0.30.0/24 > cluster_network = 10.0.40.0/24 > osd_pool_default_min_size = 1 > > max_open_files = 131072 > > [osd] > osd_journal_size = 56320 > > journal_max_write_bytes = 1073741824 > journal_max_write_entries = 10000 > journal_queue_max_ops = 50000 > journal_queue_max_bytes = 10737418240 > > osd_mkfs_type = xfs > osd_mkfs_options_xfs = -f > osd_mount_options_xfs = > "rw,noexec,nodev,noatime,nodiratime,nobarrier" > > osd_max_write_size = 512 > osd_client_message_size_cap = 2147483648 > osd_deep_scrub_stride = 131072 > osd_op_threads = 8 > osd_disk_threads = 4 > osd_map_cache_size = 1024 > osd_map_cache_bl_size = 128 > osd_recovery_op_priority = 4 > osd_recovery_max_active = 10 > osd_max_backfills = 4 > > > Best Regards > Li, Ning > > > > > > > > > _______________________________________________ ceph-users mailing list ceph-users@xxxxxxxxxxxxxx http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
 |