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.r...@f1-outsourcing.eu> 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:lining916740...@icloud.com] 
> Sent: 05 December 2018 11:41
> To: Marc Roos
> Subject: Re: [ceph-users] 【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.r...@f1-outsourcing.eu> 
> 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:lining916740...@icloud.com] 
>       Sent: 05 December 2018 07:33
>       To: ceph-users@lists.ceph.com
>       Cc: Yilong Ren
>       Subject: [ceph-users] 【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@lists.ceph.com
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com

Reply via email to