rsync from F27 box causes higher (30x) cpu on F26 box?

[Kasper Pedersen]

I have been poking at this for some hours, and by now I could use
a second opinion. Or clue. Thirteen black candles?


Somehow, when I sit on a F27 machine and pull from a F26 machine using
rsync, something extremely inefficient happens in the F26 machine.

If I sit on a F26 machine and pull from the F26 machine, it is fast.


The good state:
---------------
I had 3 reasonable machines, all on F26:

Server - 1.8Ghz Haswell-celeron dualcore
Desktop - 3.2GHz Haswell
Backup - 2.4GHz Core2Q

Backup runs rsync, and pulls from Server and Desktop using ssh.
Nothing fancy, it copies and shuts itself down.
When Backup was reading from Server, Server would have about

 - 30% cpu to rsync
 - 60% cpu to ssh

and deliver 100MB/s reliably. So does Desktop.


The bad state:
--------------
After one such rsync run, I upgraded Backup to F27.
When Backup pulls from Server, Server shows:

 - 99% cpu to rsync
 - 6% cpu to ssh

and it delivers **11MB/s**, one tenth of what it did before.
So, 30x higher cpu load per byte delivered.

So, somehow, the rsync running on F27, which by the way reports
the same version and capabilities as the one on F26, triggers
something in the spawned process that behaves differently.



On the server, the ssh-spawned rsync process looks the same whether
it is Backup or Desktop pulling from it:

On Server, with Backup as client, 11MB/s:
root     25042 34.4  0.0 124996  5620 ?        Rs   18:54   0:40 rsync
--server --sender -vlogDtpre.iLsfxC .
/bulk/mux/media/xbn-2017_10_29_010103.m.ts
/bulk/mux/media/xbn-2017_11_04_235600.m.ts
/bulk/mux/media/xbn-2017_11_12_005938.m.ts
/bulk/mux/media/xbn-2017_11_12_011442.m.ts
/bulk/mux/media/xbn-2017_11_12_015031.m.ts


On server, with Desktop as client, 100MB/s:
root     25152 31.9  0.0 122344  3000 ?        Rs   18:56   0:05 rsync
--server --sender -vlogDtpre.iLsfxC .
/bulk/mux/media/xbn-2017_10_29_010103.m.ts
/bulk/mux/media/xbn-2017_11_04_235600.m.ts
/bulk/mux/media/xbn-2017_11_12_005938.m.ts
/bulk/mux/media/xbn-2017_11_12_011442.m.ts
/bulk/mux/media/xbn-2017_11_12_015031.m.ts

The command being run on Backup or Desktop is:
rsync -av -e 'ssh -i id_ecdsa'  --exclude XA/ --exclude video2/
root@10.5.5.1:/bulk/mux/media/xbn* . --progress




Things I did:
-------------
Tried the still-installed F26 and F25 kernels
Desktop (F26) can rsync to and from Server(F26) at full speed.
All machines get 110MB/s when running iperf, all six ways.
The Sky2 nic in Backup is not spewing errors
iperf shows no dropped.
Swapped switchports between Desktop and Backup
Switch does not report errors

Things to do:
-------------
swap nics
upgrade a sacrificial F26 machine to F27 and try from that



/Kasper Pedersen

[Jakub Jelen]

Hello,
this might be related to 

https://fedoraproject.org/wiki/Changes/OpenSSH_Server_Crypto_Policy

Can you check what ciphers, macs were used in your Fedora 26 and what
is used now? We can probably blame the change of the default cipher,
from ChaCha20 to AES256, but I don't have the exact numbers.

Can you try to uncomment last line of /etc/sysconfig/sshd to overwrite
system-wide policy:

CRYPTO_POLICY=

If it has so significant performance impact, we should adjust the
policy to prefer ChaCha20.


Regards,
Jakub Jelen

On Thu, 2017-11-16 at 19:44 +0100, Kasper Pedersen wrote:
> I have been poking at this for some hours, and by now I could use
> a second opinion. Or clue. Thirteen black candles?
> 
> 
> Somehow, when I sit on a F27 machine and pull from a F26 machine
> using
> rsync, something extremely inefficient happens in the F26 machine.
> 
> If I sit on a F26 machine and pull from the F26 machine, it is fast.
> 
> 
> The good state:
> ---------------
> I had 3 reasonable machines, all on F26:
> 
> Server - 1.8Ghz Haswell-celeron dualcore
> Desktop - 3.2GHz Haswell
> Backup - 2.4GHz Core2Q
> 
> Backup runs rsync, and pulls from Server and Desktop using ssh.
> Nothing fancy, it copies and shuts itself down.
> When Backup was reading from Server, Server would have about
> 
>  - 30% cpu to rsync
>  - 60% cpu to ssh
> 
> and deliver 100MB/s reliably. So does Desktop.
> 
> 
> The bad state:
> --------------
> After one such rsync run, I upgraded Backup to F27.
> When Backup pulls from Server, Server shows:
> 
>  - 99% cpu to rsync
>  - 6% cpu to ssh
> 
> and it delivers **11MB/s**, one tenth of what it did before.
> So, 30x higher cpu load per byte delivered.
> 
> So, somehow, the rsync running on F27, which by the way reports
> the same version and capabilities as the one on F26, triggers
> something in the spawned process that behaves differently.
> 
> 
> 
> On the server, the ssh-spawned rsync process looks the same whether
> it is Backup or Desktop pulling from it:
> 
> On Server, with Backup as client, 11MB/s:
> root     25042 34.4  0.0 124996  5620 ?        Rs   18:54   0:40
> rsync
> --server --sender -vlogDtpre.iLsfxC .
> /bulk/mux/media/xbn-2017_10_29_010103.m.ts
> /bulk/mux/media/xbn-2017_11_04_235600.m.ts
> /bulk/mux/media/xbn-2017_11_12_005938.m.ts
> /bulk/mux/media/xbn-2017_11_12_011442.m.ts
> /bulk/mux/media/xbn-2017_11_12_015031.m.ts
> 
> 
> On server, with Desktop as client, 100MB/s:
> root     25152 31.9  0.0 122344  3000 ?        Rs   18:56   0:05
> rsync
> --server --sender -vlogDtpre.iLsfxC .
> /bulk/mux/media/xbn-2017_10_29_010103.m.ts
> /bulk/mux/media/xbn-2017_11_04_235600.m.ts
> /bulk/mux/media/xbn-2017_11_12_005938.m.ts
> /bulk/mux/media/xbn-2017_11_12_011442.m.ts
> /bulk/mux/media/xbn-2017_11_12_015031.m.ts
> 
> The command being run on Backup or Desktop is:
> rsync -av -e 'ssh -i id_ecdsa'  --exclude XA/ --exclude video2/
> root@10.5.5.1:/bulk/mux/media/xbn* . --progress
> 
> 
> 
> 
> Things I did:
> -------------
> Tried the still-installed F26 and F25 kernels
> Desktop (F26) can rsync to and from Server(F26) at full speed.
> All machines get 110MB/s when running iperf, all six ways.
> The Sky2 nic in Backup is not spewing errors
> iperf shows no dropped.
> Swapped switchports between Desktop and Backup
> Switch does not report errors
> 
> Things to do:
> -------------
> swap nics
> upgrade a sacrificial F26 machine to F27 and try from that