Rsync send very very slow

Ask Fedora
1

The iperf3 test shows speeds of 2.3 gbps or higher on all machines.

  • Server info
$ cat /etc/fedora-release
Fedora release 40 (Forty)

$ uname -a
Linux bypass 6.10.6-200.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Aug 19 14:09:30 UTC 2024 x86_64 GNU/Linux

$ rsync --version
rsync  version 3.3.0  protocol version 31
  • Shell script: send 1MB file
#!/bin/bash

start_time=$(date +"%Y-%m-%d %H:%M:%S")
start_timestamp=$(date +%s)

echo "Script started at: $start_time"

# rsync send 1MB file
rsync -vvvavhP testfile  back2:/dst/temp/2024

end_time=$(date +"%Y-%m-%d %H:%M:%S")
end_timestamp=$(date +%s)

execution_time=$(($end_timestamp - $start_timestamp))

echo "Script ended at: $end_time"
echo "Total execution time: ${execution_time} seconds"
  • result: Fedora-server → backupserver
$ ./rsync.sh
Script started at: 2024-08-29 04:59:52
cmd=<NULL> machine=back2 user=<NULL> path=/dst/temp/2024
cmd[0]=ssh cmd[1]=back2 cmd[2]=rsync cmd[3]=--server cmd[4]=-vvvvlogDtpre.iLsfxCIvu cmd[5]=--partial cmd[6]=. cmd[7]=/dst/temp/2024
opening connection using: ssh back2 rsync --server -vvvvlogDtpre.iLsfxCIvu --partial . /dst/temp/2024  (8 args)
msg checking charset: UTF-8
(Server) Protocol versions: remote=31, negotiated=31
(Client) Protocol versions: remote=31, negotiated=31
sending incremental file list
[sender] make_file(testfile,*,0)
[sender] flist start=1, used=1, low=0, high=0
[sender] i=1 <NULL> testfile mode=0100644 len=1,000,000 uid=0 gid=0 flags=1005
send_file_list done
[sender] flist_eof=1
file list sent
send_files starting
server_recv(2) starting pid=6797
uid 0(root) maps to 0
process has 2 gids:  100 101
gid 0(root) maps to 0
recv_file_name(testfile)
received 1 names
[Receiver] flist start=1, used=1, low=0, high=0
[Receiver] i=1 1 testfile mode=0100644 len=1,000,000 gid=(0) flags=1400
recv_file_list done
[Receiver] flist_eof=1
get_local_name count=1 /dst/temp/2024
generator starting pid=6797
delta-transmission enabled
recv_generator(testfile,1)
send_files(1, testfile)
count=0 n=0 rem=0
send_files mapped testfile of size 1000000
calling match_sums testfile
testfile
         32.77K   3%    0.00kB/s    0:00:00
sending file_sum
false_alarms=0 hash_hits=0 matches=0
          1.00M 100%  307.47MB/s    0:00:00 (xfr#1, to-chk=0/1)
sender finished testfile
generate_files phase=1
recv_files(1) starting
recv_files(testfile)
data recv 32768 at 0
data recv 32768 at 32768
data recv 32768 at 65536
data recv 32768 at 98304
data recv 32768 at 131072
data recv 32768 at 163840
data recv 32768 at 196608
data recv 32768 at 229376
data recv 32768 at 262144
data recv 32768 at 294912
data recv 32768 at 327680
data recv 32768 at 360448
data recv 32768 at 393216
data recv 32768 at 425984
data recv 32768 at 458752
data recv 32768 at 491520
data recv 32768 at 524288
data recv 32768 at 557056
data recv 32768 at 589824
data recv 32768 at 622592
data recv 32768 at 655360
data recv 32768 at 688128
data recv 32768 at 720896
data recv 32768 at 753664
data recv 32768 at 786432
data recv 32768 at 819200
data recv 32768 at 851968
data recv 32768 at 884736
data recv 32768 at 917504
data recv 32768 at 950272
data recv 16960 at 983040
got file_sum
set modtime of .testfile.JhPsBl to (1724874533) Thu Aug 29 04:48:53 2024
renaming .testfile.JhPsBl to testfile
send_files phase=1
recv_files phase=1
generate_files phase=2
send_files phase=2
send files finished
total: matches=0  hash_hits=0  false_alarms=0 data=1000000
recv_files phase=2
recv_files finished
generate_files phase=3
generate_files finished
client_run waiting on 928415

sent 1.00M bytes  received 1.74K bytes  18.73K bytes/sec
total size is 1.00M  speedup is 1.00
[sender] _exit_cleanup(code=0, file=main.c, line=1338): entered
[sender] _exit_cleanup(code=0, file=main.c, line=1338): about to call exit(0)
Script ended at: 2024-08-29 05:00:45
Total execution time: 53 seconds

It took 53 seconds to send a single file of 1 MB in size.

However, on other machines, the file transfer completes instantly (0 seconds).

othermachine → backupserver

Script started at: 2024-08-29 05:00:59
cmd=<NULL> machine=back2 user=<NULL> path=/dst/temp/2024
cmd[0]=ssh cmd[1]=back2 cmd[2]=rsync cmd[3]=--server cmd[4]=-vvvvlogDtpre.iLsfxCIvu cmd[5]=--partial cmd[6]=. cmd[7]=/dst/temp/2024
opening connection using: ssh back2 rsync --server -vvvvlogDtpre.iLsfxCIvu --partial . /dst/temp/2024  (8 args)
msg checking charset: UTF-8
(Client) Protocol versions: remote=31, negotiated=31
(Server) Protocol versions: remote=31, negotiated=31
sending incremental file list
[sender] make_file(temp-file,*,0)
[sender] flist start=1, used=1, low=0, high=0
[sender] i=1 <NULL> temp-file mode=0100644 len=1,000,000 uid=197108 gid=197121 flags=1005
send_file_list done
[sender] flist_eof=1
file list sent
send_files starting
server_recv(2) starting pid=7078
uid 197108(Administrator) maps to 197108
process has 2 gids:  100 101
gid 197121() maps to 197121
recv_file_name(temp-file)
received 1 names
[Receiver] flist start=1, used=1, low=0, high=0
[Receiver] i=1 1 temp-file mode=0100644 len=1,000,000 gid=(197121) flags=1400
recv_file_list done
[Receiver] flist_eof=1
get_local_name count=1 /dst/temp/2024
generator starting pid=7078
delta-transmission enabled
recv_generator(temp-file,1)
send_files(1, temp-file)
count=0 n=0 rem=0
send_files mapped temp-file of size 1000000
calling match_sums temp-file
temp-file
         32.77K   3%    0.00kB/s    0:00:00
sending file_sum
false_alarms=0 hash_hits=0 matches=0
          1.00M 100%  307.47MB/s    0:00:00 (xfr#1, to-chk=0/1)
sender finished temp-file
generate_files phase=1
recv_files(1) starting
recv_files(temp-file)
data recv 32768 at 0
data recv 32768 at 32768
data recv 32768 at 65536
data recv 32768 at 98304
data recv 32768 at 131072
data recv 32768 at 163840
data recv 32768 at 196608
data recv 32768 at 229376
data recv 32768 at 262144
data recv 32768 at 294912
data recv 32768 at 327680
data recv 32768 at 360448
data recv 32768 at 393216
data recv 32768 at 425984
data recv 32768 at 458752
data recv 32768 at 491520
data recv 32768 at 524288
data recv 32768 at 557056
data recv 32768 at 589824
data recv 32768 at 622592
data recv 32768 at 655360
data recv 32768 at 688128
data recv 32768 at 720896
data recv 32768 at 753664
data recv 32768 at 786432
data recv 32768 at 819200
data recv 32768 at 851968
data recv 32768 at 884736
data recv 32768 at 917504
data recv 32768 at 950272
data recv 16960 at 983040
got file_sum
set modtime of .temp-file.2nyVRB to (1724874747) Thu Aug 29 04:52:27 2024
renaming .temp-file.2nyVRB to temp-file
send_files phase=1
recv_files phase=1
generate_files phase=2
send_files phase=2
send files finished
total: matches=0  hash_hits=0  false_alarms=0 data=1000000
recv_files phase=2
recv_files finished
generate_files phase=3
generate_files finished
client_run waiting on 2016

sent 1.00M bytes  received 1.77K bytes  2.00M bytes/sec
total size is 1.00M  speedup is 1.00
[sender] _exit_cleanup(code=0, file=main.c, line=1338): entered
[sender] _exit_cleanup(code=0, file=main.c, line=1338): about to call exit(0)
Script ended at: 2024-08-29 05:00:59
Total execution time: 0 seconds
2

Information very little.

3

Sorry. I accidentally clicked the button while writing the post.

1 Like
4

Check your network. Are there errors happening between the two machines?
You could try using ping and see if packets arebeing dropped.

5 
PING 192.168.1.132 (192.168.1.132) 56(84) bytes of data.
64 bytes from 192.168.1.132: icmp_seq=1 ttl=64 time=0.725 ms
64 bytes from 192.168.1.132: icmp_seq=2 ttl=64 time=0.702 ms
64 bytes from 192.168.1.132: icmp_seq=3 ttl=64 time=0.634 ms
64 bytes from 192.168.1.132: icmp_seq=4 ttl=64 time=0.846 ms
64 bytes from 192.168.1.132: icmp_seq=5 ttl=64 time=0.750 ms
64 bytes from 192.168.1.132: icmp_seq=6 ttl=64 time=0.653 ms
64 bytes from 192.168.1.132: icmp_seq=7 ttl=64 time=0.765 ms
64 bytes from 192.168.1.132: icmp_seq=8 ttl=64 time=0.724 ms
64 bytes from 192.168.1.132: icmp_seq=9 ttl=64 time=0.525 ms
64 bytes from 192.168.1.132: icmp_seq=10 ttl=64 time=0.772 ms
64 bytes from 192.168.1.132: icmp_seq=11 ttl=64 time=0.804 ms
64 bytes from 192.168.1.132: icmp_seq=12 ttl=64 time=0.691 ms
64 bytes from 192.168.1.132: icmp_seq=13 ttl=64 time=0.590 ms
64 bytes from 192.168.1.132: icmp_seq=14 ttl=64 time=0.498 ms
64 bytes from 192.168.1.132: icmp_seq=15 ttl=64 time=0.822 ms
64 bytes from 192.168.1.132: icmp_seq=16 ttl=64 time=0.705 ms
64 bytes from 192.168.1.132: icmp_seq=17 ttl=64 time=0.800 ms
64 bytes from 192.168.1.132: icmp_seq=18 ttl=64 time=0.624 ms
64 bytes from 192.168.1.132: icmp_seq=19 ttl=64 time=0.584 ms
64 bytes from 192.168.1.132: icmp_seq=20 ttl=64 time=0.724 ms
64 bytes from 192.168.1.132: icmp_seq=21 ttl=64 time=0.653 ms
64 bytes from 192.168.1.132: icmp_seq=22 ttl=64 time=0.784 ms
64 bytes from 192.168.1.132: icmp_seq=23 ttl=64 time=0.766 ms

$ traceroute 192.168.1.132
traceroute to 192.168.1.132 (192.168.1.132), 30 hops max, 60 byte packets
 1  _gateway (192.168.1.1)  0.445 ms  0.397 ms  0.360 ms
 2  192.168.1.132 (192.168.1.132)  6.406 ms  6.394 ms  6.379 ms

Network should be fine, I think.

6

If you just do a regular rsync copy without using the script, do you get consistently low throughput numbers?

$ dd if=/dev/urandom of=128MB.test bs=64M count=2 iflag=fullblock
$ rsync -v 128MB.test back2:/dst/temp/2024
7

Ping doesn’t tell you anything, it just tells you that the remote system is reachable.
You did not share how your systems are connected, ethernet / Wi-Fi?
Slow egress speeds with ethernet are usually caused by failed auto neg settings, e.g NIC set to half-duplex while switch port configured to full-duplex etc.
A damaged patch cable could also be the root cause.

8

iperf3 test

[ ID] Interval           Transfer     Bitrate         Retr  Cwnd
[  5]   0.00-1.00   sec   283 MBytes  2.38 Gbits/sec    0    650 KBytes
[  5]   1.00-2.00   sec   281 MBytes  2.36 Gbits/sec    0    684 KBytes
[  5]   2.00-3.00   sec   280 MBytes  2.35 Gbits/sec    0    684 KBytes
[  5]   3.00-4.00   sec   281 MBytes  2.36 Gbits/sec    0    684 KBytes
[  5]   4.00-5.00   sec   280 MBytes  2.35 Gbits/sec    0    684 KBytes
[  5]   5.00-6.00   sec   280 MBytes  2.35 Gbits/sec    0    684 KBytes
[  5]   6.00-7.00   sec   281 MBytes  2.36 Gbits/sec    0    684 KBytes
[  5]   7.00-8.00   sec   280 MBytes  2.35 Gbits/sec    0    684 KBytes
[  5]   8.00-9.00   sec   281 MBytes  2.36 Gbits/sec    0    684 KBytes
[  5]   9.00-10.00  sec   280 MBytes  2.35 Gbits/sec    0    717 KBytes
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate         Retr
[  5]   0.00-10.00  sec  2.74 GBytes  2.36 Gbits/sec    0             sender
[  5]   0.00-10.00  sec  2.74 GBytes  2.35 Gbits/sec                  receiver

iperf Done.
9 
$ rsync -vvv 128MB.test back2:/dst/temp/2024
opening connection using: ssh back2 rsync --server -vvve.LsfxCIvu . /dst/temp/2024  (7 args)
[sender] make_file(128MB.test,*,0)
send_file_list done
send_files starting
server_recv(2) starting pid=1444
recv_file_name(128MB.test)
received 1 names
recv_file_list done
get_local_name count=1 /dst/temp/2024
generator starting pid=1444
delta-transmission enabled
recv_generator(128MB.test,0)
got ACL-based default perms 700 for directory .
send_files(0, 128MB.test)
send_files mapped 128MB.test of size 134217728
calling match_sums 128MB.test
128MB.test
sending file_sum
false_alarms=0 hash_hits=0 matches=0
sender finished 128MB.test
generate_files phase=1
send_files phase=1
recv_files(1) starting
recv_files(128MB.test)
got ACL-based default perms 700 for directory .
got file_sum
renaming .128MB.test.U0BHze to 128MB.test
recv_files phase=1
generate_files phase=2
send_files phase=2
send files finished
total: matches=0  hash_hits=0  false_alarms=0 data=134217728
recv_files phase=2
recv_files finished
generate_files phase=3
generate_files finished

sent 134,250,577 bytes  received 582 bytes  2,509,367.46 bytes/sec
total size is 134,217,728  speedup is 1.00
[sender] _exit_cleanup(code=0, file=main.c, line=1338): about to call exit(0)
10

It’s not particularly fast, but at 2.5MB/s it should still have done your 1MB file in less than a second

11

Do you get same results with iperf3 -c back2 -R?

some more point you may want to check:

  • ethtool <nic devicename>
  • netstat -s
  • how long does it take to login with ssh back2
  • test with sftp to upload/download files to/from back2.
  • is ssh compression enabled? Should be disabled.
12

If you see packet lose during the ping test that tells you you have issues.
But its not putting load on the network that may trigger the issue.

13

it’s a basic test and has very limited value when trying to find reasons for bad network performance esp. in a local LAN.