Relatively lower performance than OpenSSH

[HiFiPhile]

Hi,
Thanks for this great project !

I did some test in my environment and the transfer speed is much lower than OpenSSH.

Server
OS	Debian 10.2 x64
CPU	Ryzen5 3600
RAM	64GB ECC
Disk	3* Intel P4510 4TB RAID0
Ethernet	Mellanox ConnectX-3 40GbE

Client
OS	Windows 10 1909 x64
CPU	Threadripper 1920X
RAM	64GB ECC
Disk	Samsung 960EVO 1TB
Ethernet	Mellanox ConnectX-3 40GbE

Under Filezilla I can get 500MB/s with OpenSSH, but only about 200MB/s with sftpgo.

In both case I'm using AES256-CTR as cipher and SHA-256 as MAC, I've also tried AES128-CTR but nothing changes.

CPU usage of sftpgo is higher than OpenSSH:

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND 
 4527 sftp      20   0 1795576  52044   8628 R 133.5   0.6   2:12.13 sftpgo 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND 
27934 xxxxxx    20   0   17112   5360   4188 R  67.8   0.1   0:10.01 sshd                                                  
27942 xxxxxx    20   0   17112   5344   4176 R  27.4   0.1   0:12.52 sshd 

In both case I've got a maximum TCP window size of 4MB.

[drakkan]

Hi,

thanks for taking time to do this test, very appreciated.

I don't have a 40 gigabit ethernet card.

Since the first implementation I noticed, testing on localhost, that sftpgo is a bit slower and uses more CPU than openssh so I can confirm what you report but the difference is not so big in my tests (280MB/s OpenSSH, 230MB/s SFTPGo/SFTP, 250MB/s SFTPGo/SCP)

In real environments SFTPGo was able to completly saturate my network card, using more CPU than OpenSSH, but my test were limited to 1 gigabit ethernet cards.

Can you please test multiple parallel transfers and report if you are able to saturate your 40 gigabit network?

Can you repeat the same test using scp? SCP is implemented from scratch inside SFTPGo while for sftp we use pkg/sftp library. If scp will perform better I'll try to see if pkg/sftp can be improved.

Also please note that currently golang ssh implementation does not support zlib compression, so if OpenSSH uses compression the real transferred size is smaller than the one transferred using SFTPGo.

Anyway I get the same results using both sftpgo and the sample, very basic, implementation here:

https://github.com/pkg/sftp/tree/master/examples/go-sftp-server

so we need to improve pkg/sftp

[HiFiPhile]

I switched to Ubuntu 19.10 since scp sucks on Windows.

I've noticed a huge improvement between Filezilla 3.39 (in repo) and latest 3.46, maybe it's because :

3.42.0-beta1 (2019-04-21)
    Large refactoring of the socket code
    The thread pool from libfilezilla is now used for all worker threads

Parallel test

The speed under Windows was 2 streams.

Stream	SFTPGo MB/s	SFTPGo CPU%	OpenSSH MB/s	OpenSSH CPU%
1	125	137	380	97
2	210	227	600	190
3	260	228	700	276
4	330	336	810	344
8	387	430	950	400

SCP

I got 208MB/s vs 235MB/s, and it seems like spaces in path is not correctly handled, I've tried 3 types of escape, but scp returns immediately without transfer.

scp user@example.com:"'web/tmp/Master File 18 10 13.xls'" .
scp user@example.com:"web/tmp/Master\ File\ 18\ 10\ 13.xls" .
scp user@example.com:web/tmp/Master\\\ File\\\ 18\\\ 10\\\ 13.xls .

Me too I doubt it should be golang's sftp package issue, but since I'm not familier with Go I didn't look further.

[drakkan]

Thanks for reporting back, spaces in scp path is now fixed, this command

scp user@example.com:"web/tmp/Master\ File\ 18\ 10\ 13.xls" .

should work now. I'll try to fix the "'web/tmp/Master File 18 10 13.xls'" escape style too.

Regarding the performance issue I'll do some other tests myself (on localhost, I don't have a network as the your) and eventually I'll try to ask upstream.

From your test results it seems that SFTPGo can easily saturate a gigabit connection while it has issues if you have more bandwidth, 8 streams are served at 3 gigabit/s

[HiFiPhile]

For gigabit connection it's totally fine. I can help you if you need more tests in high bandwidth condition.

[drakkan]

Hi, I did some profiling and the bottleneck seems the encryption, without specifying a cipher the default on my laptop is chacha20Poly1305ID and here is the profile results

Showing top 10 nodes out of 157
      flat  flat%   sum%        cum   cum%
    1620ms 21.15% 21.15%     1620ms 21.15%  golang.org/x/crypto/chacha20.quarterRound
    1340ms 17.49% 38.64%     1430ms 18.67%  syscall.Syscall
     400ms  5.22% 43.86%      400ms  5.22%  golang.org/x/crypto/poly1305.update
     390ms  5.09% 48.96%     2070ms 27.02%  golang.org/x/crypto/chacha20.(*Cipher).xorKeyStreamBlocksGeneric
     370ms  4.83% 53.79%      370ms  4.83%  runtime.epollwait
     370ms  4.83% 58.62%      370ms  4.83%  runtime.futex
     360ms  4.70% 63.32%      360ms  4.70%  runtime.procyield
     220ms  2.87% 66.19%      220ms  2.87%  runtime.memmove
     180ms  2.35% 68.54%      280ms  3.66%  runtime.scanobject
     180ms  2.35% 70.89%      180ms  2.35%  runtime.usleep

setting "ciphers": ["aes256-ctr"] I get a performance degradation:

Showing top 10 nodes out of 149
      flat  flat%   sum%        cum   cum%
    2550ms 25.91% 25.91%     2550ms 25.91%  crypto/sha256.block
    1540ms 15.65% 41.57%     1590ms 16.16%  syscall.Syscall
     980ms  9.96% 51.52%      980ms  9.96%  crypto/aes.encryptBlockAsm
     540ms  5.49% 57.01%      540ms  5.49%  runtime.futex
     350ms  3.56% 60.57%      350ms  3.56%  runtime.procyield
     330ms  3.35% 63.92%     1460ms 14.84%  crypto/cipher.(*ctr).refill
     250ms  2.54% 66.46%      470ms  4.78%  runtime.scanobject
     240ms  2.44% 68.90%      240ms  2.44%  runtime.epollwait
     230ms  2.34% 71.24%     1260ms 12.80%  runtime.findrunnable
     200ms  2.03% 73.27%      200ms  2.03%  runtime.memmove

while setting "ciphers": ["aes128-gcm@openssh.com"] I get the best performance and the encryption is not more the bottleneck:

Showing top 10 nodes out of 140
      flat  flat%   sum%        cum   cum%
    1290ms 31.01% 31.01%     1330ms 31.97%  syscall.Syscall
     240ms  5.77% 36.78%      240ms  5.77%  runtime.memmove
     230ms  5.53% 42.31%      320ms  7.69%  runtime.scanobject
     220ms  5.29% 47.60%      220ms  5.29%  crypto/aes.gcmAesEnc
     180ms  4.33% 51.92%      180ms  4.33%  runtime.epollwait
     170ms  4.09% 56.01%      170ms  4.09%  runtime.futex
     160ms  3.85% 59.86%      160ms  3.85%  syscall.Syscall6
     150ms  3.61% 63.46%      150ms  3.61%  runtime.procyield
     130ms  3.12% 66.59%      130ms  3.12%  runtime.memclrNoHeapPointers
     100ms  2.40% 68.99%      100ms  2.40%  golang.org/x/crypto/argon2.blamkaSSE

can you post your results using aes128-gcm@openssh.com? Anyway using the same cipher OpenSSH still performs better, but maybe this way you can get acceptable results for your use case.

Can you also better explain your use case? Thanks!

[HiFiPhile]

I've some interesting findings.

• Filezilla doesn't support aes128-gcm@openssh.com, even though it's listed as an fixed issue.
• It's possible that Filezilla does some tweaks if it detect OpenSSH server, because using sftp command I got only 200MB/s instead of 380MB/s.

Here we go for the aes128-gcm@openssh.com test

I didn't try to enable profiling, but the performance number is enough to make the difference.

SCP

SCP is blasting..., it even hit other bottlenecks.

Stream	SFTPGo MB/s	SFTPGo CPU%	OpenSSH MB/s	OpenSSH CPU%
1	500	105	360	100
2	950	195	680	195
3	1350	284	980	285
4	1650	332	1100	372
8	2400	520	1550	616

SFTP

SFTP also got a huge boost.

Stream	SFTPGo MB/s	SFTPGo CPU%	OpenSSH MB/s	OpenSSH CPU%
1	260	173	340	102
2	420	254	640	208
3	500	297	800	300
4	580	333	1000	400
8	700	390	1450	648

Indeed aes128-gcm@openssh.com can massively improve the performance, but seems like there are some compatibility issues, Rebex SSH also not working.

[drakkan]

I've some interesting findings.

• Filezilla doesn't support aes128-gcm@openssh.com, even though it's listed as an fixed issue.

In my tests I used SFTP cli, I tested with Filezilla now and I see that it does not support aes gcm. chacha20-poly1305@openssh.com (that on my hw performs better than AES-CTR) seems not supported in filezilla too.

• It's possible that Filezilla does some tweaks if it detect OpenSSH server, because using sftp command I got only 200MB/s instead of 380MB/s.

In my tests on localhost, transferring a 1GB file, filezilla speed against OpenSSH is 190MB/s, agaist SFTPGo (forcing the same cipher, aes-256-ctr) is 160 MB/s

Here we go for the aes128-gcm@openssh.com test

I didn't try to enable profiling, but the performance number is enough to make the difference.

SCP

SCP is blasting..., it even hit other bottlenecks.

I tested SCP now and I confirm that my simple implementation outperforms OpenSSH if the cipher is not the bootleneck (for example aes128-gcm).

This means that pkg/sftp could be optimized in some way, but if we cannot use AES GCM the bottleneck will remain the encryption.

I did a quick test, on a virtual machine, using centos8 and the red hat (fips certified) go-toolset that replace golang crypto implementation with openssl but openssh still performs better when using aes ctr based ciphers. I could also try boringssl golang branch but I don't think this will perform much better than go-toolset from Red Hat.

Maybe for your use case a load balancer, such as haproxy, could help to balance the load between several backends.

Stream SFTPGo MB/s SFTPGo CPU% OpenSSH MB/s OpenSSH CPU%
1 500 105 360 100
2 950 195 680 195
3 1350 284 980 285
4 1650 332 1100 372
8 2400 520 1550 616

SFTP

SFTP also got a huge boost.

Stream SFTPGo MB/s SFTPGo CPU% OpenSSH MB/s OpenSSH CPU%
1 260 173 340 102
2 420 254 640 208
3 500 297 800 300
4 580 333 1000 400
8 700 390 1450 648
Indeed aes128-gcm@openssh.com can massively improve the performance, but seems like there are some compatibility issues, Rebex SSH also not working.

[HiFiPhile]

I've looked at this issue: https://github.com/golang/go/issues/20967
Seems like it hasn't been merged, I got a bad ctr speed.

$ go test -bench '(GCM|CTR).*1K' crypto/cipher
goos: linux
goarch: amd64
pkg: crypto/cipher
BenchmarkAESGCMSeal1K-8   	 5000000	       275 ns/op	3713.72 MB/s
BenchmarkAESGCMOpen1K-8   	 5000000	       282 ns/op	3623.19 MB/s
BenchmarkAESCTR1K-8       	 1000000	      1265 ns/op	 805.12 MB/s
PASS
ok  	crypto/cipher	4.867s

After applying the patch:

$ go test -bench '(GCM|CTR).*1K' crypto/cipher
goos: linux
goarch: amd64
pkg: crypto/cipher
BenchmarkAESGCMSeal1K-8   	 4340227	       277 ns/op	3702.23 MB/s
BenchmarkAESGCMOpen1K-8   	 4380684	       272 ns/op	3763.03 MB/s
BenchmarkAESCTR1K-8       	 4144329	       275 ns/op	3708.23 MB/s
PASS
ok  	crypto/cipher	4.797s

[drakkan]

I've looked at this issue: https://github.com/golang/go/issues/20967
Seems like it hasn't been merged, I got a bad ctr speed.

$ go test -bench '(GCM|CTR).*1K' crypto/cipher
goos: linux
goarch: amd64
pkg: crypto/cipher
BenchmarkAESGCMSeal1K-8   	 5000000	       275 ns/op	3713.72 MB/s
BenchmarkAESGCMOpen1K-8   	 5000000	       282 ns/op	3623.19 MB/s
BenchmarkAESCTR1K-8       	 1000000	      1265 ns/op	 805.12 MB/s
PASS
ok  	crypto/cipher	4.867s

After applying the patch:

$ go test -bench '(GCM|CTR).*1K' crypto/cipher
goos: linux
goarch: amd64
pkg: crypto/cipher
BenchmarkAESGCMSeal1K-8   	 4340227	       277 ns/op	3702.23 MB/s
BenchmarkAESGCMOpen1K-8   	 4380684	       272 ns/op	3763.03 MB/s
BenchmarkAESCTR1K-8       	 4144329	       275 ns/op	3708.23 MB/s
PASS
ok  	crypto/cipher	4.797s

Great! And how about sftpgo performance compiled against this patched Go version?

Here is a patch that save CPU profiling to /tmp/cpuprofile after you stop SFTPGo using CTRL+C

diff --git a/main.go b/main.go
index 1604364..8cb075b 100644
--- a/main.go
+++ b/main.go
@@ -4,6 +4,9 @@
 package main // import "github.com/drakkan/sftpgo"
 
 import (
+	"os"
+	"runtime/pprof"
+
 	"github.com/drakkan/sftpgo/cmd"
 	_ "github.com/go-sql-driver/mysql"
 	_ "github.com/lib/pq"
@@ -11,5 +14,11 @@ import (
 )
 
 func main() {
+	f, _ := os.Create("/tmp/cpuprofile")
+	defer f.Close()
+	if err := pprof.StartCPUProfile(f); err != nil {
+		return
+	}
+	defer pprof.StopCPUProfile()
 	cmd.Execute()
 }
diff --git a/service/service.go b/service/service.go
index fa50ec9..43f754e 100644
--- a/service/service.go
+++ b/service/service.go
@@ -122,6 +122,13 @@ func (s *Service) Wait() {
 	if s.PortableMode != 1 {
 		registerSigHup()
 	}
+	sig := make(chan os.Signal, 1)
+	signal.Notify(sig, os.Interrupt, syscall.SIGTERM)
+	go func() {
+		<-sig
+		logger.InfoToConsole("stopping service")
+		s.Stop()
+	}()
 	<-s.Shutdown
 }

[drakkan]

Hi,

I applied and tested that patch myself, this only give a small performance improvement, the bottleneck is now MAC, when using aes gcm mode the mac is implicit, from sftp -vvvv output:

debug1: kex: server->client cipher: aes128-gcm@openssh.com MAC: <implicit> compression: none

while for aes ctr:

debug1: kex: server->client cipher: aes256-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none

so we need a way to improve golang sha2 performance.

We could try to path crypto/ssh

https://github.com/golang/crypto/blob/master/ssh/mac.go#L12

to use, for example, this sha2 implementation:

https://github.com/minio/sha256-simd

[HiFiPhile]

Wow we came up to the same thing ! I just finished my test and saw you ended up with the same conclusion.
With the AES patch I got only 10-20% gain, the bottleneck is indeed the sha256.

(pprof) top10
Showing nodes accounting for 1.01mins, 78.26% of 1.29mins total
Dropped 372 nodes (cum <= 0.01mins)
Showing top 10 nodes out of 139
      flat  flat%   sum%        cum   cum%
  0.48mins 37.63% 37.63%   0.48mins 37.63%  crypto/sha256.block
  0.29mins 22.86% 60.49%   0.30mins 23.47%  syscall.Syscall
  0.04mins  3.50% 63.99%   0.04mins  3.50%  runtime.memmove
  0.04mins  3.40% 67.39%   0.04mins  3.40%  crypto/aes.fillEightBlocks
  0.04mins  3.02% 70.41%   0.04mins  3.06%  syscall.Syscall6
  0.03mins  2.10% 72.51%   0.05mins  3.93%  runtime.scanobject
  0.03mins  2.05% 74.56%   0.03mins  2.05%  runtime.procyield
  0.02mins  1.65% 76.20%   0.02mins  1.65%  runtime.memclrNoHeapPointers
  0.01mins  1.10% 77.30%   0.01mins  1.10%  runtime.futex
  0.01mins  0.96% 78.26%   0.02mins  1.43%  runtime.findObject

https://github.com/minio/sha256-simd gave me a decent result:

go test -bench=.
goos: linux
goarch: amd64
pkg: github.com/minio/sha256-simd
BenchmarkHash/SHA_/8Bytes-8   	16587733	        73.7 ns/op	 108.54 MB/s
BenchmarkHash/SHA_/1K-8       	 1861538	       623 ns/op	1642.56 MB/s
BenchmarkHash/SHA_/8K-8       	  268082	      4666 ns/op	1755.55 MB/s
BenchmarkHash/SHA_/1M-8       	    2126	    565327 ns/op	1854.81 MB/s
BenchmarkHash/SHA_/5M-8       	     408	   2888687 ns/op	1814.97 MB/s
BenchmarkHash/SHA_/10M-8      	     208	   5668807 ns/op	1849.73 MB/s
BenchmarkHash/AVX2/8Bytes-8   	 4695985	       252 ns/op	  31.74 MB/s
BenchmarkHash/AVX2/1K-8       	  383493	      2955 ns/op	 346.54 MB/s
BenchmarkHash/AVX2/8K-8       	   55555	     22888 ns/op	 357.92 MB/s
BenchmarkHash/AVX2/1M-8       	     435	   2776574 ns/op	 377.65 MB/s
BenchmarkHash/AVX2/5M-8       	      70	  15389700 ns/op	 340.67 MB/s
BenchmarkHash/AVX2/10M-8      	      38	  31855830 ns/op	 329.16 MB/s
BenchmarkHash/AVX_/8Bytes-8   	 5304136	       223 ns/op	  35.85 MB/s
BenchmarkHash/AVX_/1K-8       	  386608	      2947 ns/op	 347.47 MB/s
BenchmarkHash/AVX_/8K-8       	   52936	     23003 ns/op	 356.12 MB/s
BenchmarkHash/AVX_/1M-8       	     394	   2833284 ns/op	 370.09 MB/s
BenchmarkHash/AVX_/5M-8       	      86	  13979228 ns/op	 375.05 MB/s
BenchmarkHash/AVX_/10M-8      	      37	  29248603 ns/op	 358.50 MB/s
BenchmarkHash/SSSE/8Bytes-8   	 5321602	       211 ns/op	  37.96 MB/s
BenchmarkHash/SSSE/1K-8       	  385484	      3087 ns/op	 331.67 MB/s
BenchmarkHash/SSSE/8K-8       	   53042	     22051 ns/op	 371.50 MB/s
BenchmarkHash/SSSE/1M-8       	     427	   2939882 ns/op	 356.67 MB/s
BenchmarkHash/SSSE/5M-8       	      81	  14189059 ns/op	 369.50 MB/s
BenchmarkHash/SSSE/10M-8      	      42	  28117345 ns/op	 372.93 MB/s
BenchmarkHash/GEN_/8Bytes-8   	 5327409	       220 ns/op	  36.44 MB/s
BenchmarkHash/GEN_/1K-8       	  495444	      2496 ns/op	 410.18 MB/s
BenchmarkHash/GEN_/8K-8       	   62418	     19018 ns/op	 430.74 MB/s
BenchmarkHash/GEN_/1M-8       	     522	   2396453 ns/op	 437.55 MB/s
BenchmarkHash/GEN_/5M-8       	     100	  11852390 ns/op	 442.35 MB/s
BenchmarkHash/GEN_/10M-8      	      49	  24008253 ns/op	 436.76 MB/s
PASS
ok  	github.com/minio/sha256-simd	40.496s

While the original version is quite slower:

go test -bench=. crypto/sha256
goos: linux
goarch: amd64
pkg: crypto/sha256
BenchmarkHash8Bytes-8   	 6154984	       195 ns/op	  41.01 MB/s
BenchmarkHash1K-8       	  485937	      2491 ns/op	 411.05 MB/s
BenchmarkHash8K-8       	   61125	     18626 ns/op	 439.81 MB/s
PASS
ok  	crypto/sha256	3.976s

[drakkan]

Hi,

I forked golang crypto and replaced sha256 implementation with sha256-simd but still sha256 is the bottleneck:

    2520ms 29.79% 29.79%     2520ms 29.79%  github.com/minio/sha256-simd.blockAvx2
    1650ms 19.50% 49.29%     1660ms 19.62%  syscall.Syscall
     390ms  4.61% 53.90%      390ms  4.61%  syscall.Syscall6
     360ms  4.26% 58.16%      360ms  4.26%  crypto/aes.fillEightBlocks
     320ms  3.78% 61.94%      320ms  3.78%  runtime.epollwait
     300ms  3.55% 65.48%      300ms  3.55%  runtime.futex
     230ms  2.72% 68.20%      230ms  2.72%  runtime.usleep
     220ms  2.60% 70.80%      400ms  4.73%  runtime.scanobject
     210ms  2.48% 73.29%      210ms  2.48%  runtime.procyield
     190ms  2.25% 75.53%      190ms  2.25%  runtime.memmove

my laptop only support AVX2, can you please try it on your hw? Based on the benchmark you posted above it should support SHA extension.

Here is a patch to replace the default golang sha256 with sha256-simd

diff --git a/go.mod b/go.mod
index 729c251..2adf5c9 100644
--- a/go.mod
+++ b/go.mod
@@ -43,3 +43,5 @@ require (
 )
 
 replace github.com/eikenb/pipeat v0.0.0-20190316224601-fb1f3a9aa29f => github.com/drakkan/pipeat v0.0.0-20200123131427-11c048cfc0ec
+
+replace golang.org/x/crypto v0.0.0-20200128174031-69ecbb4d6d5d => github.com/drakkan/crypto v0.0.0-20200211081002-cc78d71334be

[HiFiPhile]

Hi,
In my case SHA256 performance improved a lot, I think it's correctly using SHA instructions.

(pprof) top10
Showing nodes accounting for 121.92s, 72.52% of 168.11s total
Dropped 465 nodes (cum <= 0.84s)
Showing top 10 nodes out of 159
      flat  flat%   sum%        cum   cum%
    48.27s 28.71% 28.71%     49.83s 29.64%  syscall.Syscall
    20.99s 12.49% 41.20%     20.99s 12.49%  github.com/minio/sha256-simd.blockSha
    15.34s  9.12% 50.32%     15.47s  9.20%  syscall.Syscall6
    10.17s  6.05% 56.37%     10.17s  6.05%  runtime.memmove
     7.28s  4.33% 60.70%      7.28s  4.33%  crypto/aes.fillEightBlocks
     6.78s  4.03% 64.74%      6.78s  4.03%  runtime.memclrNoHeapPointers
     4.07s  2.42% 67.16%      4.07s  2.42%  runtime.futex
     3.91s  2.33% 69.48%      6.60s  3.93%  runtime.scanobject
     3.33s  1.98% 71.47%      3.33s  1.98%  runtime.procyield
     1.78s  1.06% 72.52%      1.78s  1.06%  crypto/cipher.xorBytesSSE2

Combine both the AES and SHA patch, speed is increased by more than 60%.

Stream	Patched MB/s	Patched CPU%	Original MB/s	Original CPU%	Gain %
1	210	145	125	137	60
2	350	250	210	227	66
3	510	310	260	228	96
4	560	370	330	336	70
8	625	420	387	430	61

[drakkan]

Great! So we are now closer to OpenSSH performances, and what about SCP? thanks!

[HiFiPhile]

SCP out performs OpenSSH inaes128-ctr, looks like your scp implementation works great !

Stream	SFTPGo MB/s	SFTPGo CPU%	OpenSSH MB/s	OpenSSH CPU%
1	380	108	384	103
2	750	215	720	205
3	1100	312	1050	300
4	1350	410	1250	395
8	2100	610	1850	712