Hi

we have found that curl, when compiled with libnss as the TLS backend
is significantly slower than if OpenSSL is used. For example, when
requesting

https://s3.amazonaws.com/page.archive.nytimes.com/1907/12/03/index.js?%i

10 times in parallel, curl with libnss takes typically 2.5s, but only
0.6s when OpenSSL is used. Strangely enough, if one waits at least 60s
between tests, libnss sometimes takes just over 11s. Since the curl
tool does use parallel requests, but recycles connections instead, it
typically runs in < 1s with both OpenSSL and NSS.

If one takes a look at a tcpdump taken while the requests are running,
it is obvious why libnss is slow. While the TCP connections are opened
in parallel both with OpenSSL and NSS, only OpenSSL sends TLS Client
Hello messages immediately after the TCP connections are established,
while NSS on the other hand only sends a single Client Hello and then
usually waits for the HTTP response before the next TLS handshake is
started.

I've seen the slow curl+nss effect both with the libraries from CentOS
7.1, as well as with a self-built, fresh curl 7.45, and both with a
slightly modified version of
http://curl.haxx.se/libcurl/c/multi-app.html and from within PHP.

The entire slowness is independent of NSS_SDB_USE_CACHE=yes/no. I can
provide tcpdumps or the slightly modified example C code if that is of
any help.

The last connection that gets handled has a ~1.8s gap after the TCP
Window Update before curl sends the Client hello. The CPU on the
client is far from 100% busy during this time:

No. Time Source Destination
Protocol Length Info
      1 0.000000 172.18.51.183 54.231.64.128 TCP
  74 48066→443 [SYN] Seq=0 Win=14600 Len=0 MSS=1460 SACK_PERM=1
TSval=1013587882 TSecr=0 WS=128
     23 0.092606 54.231.64.128 172.18.51.183 TCP
  66 443→48066 [SYN, ACK] Seq=0 Ack=1 Win=8190 Len=0 MSS=1440
WS=64 SACK_PERM=1
     24 0.092614 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=1 Ack=1 Win=14720 Len=0
     35 0.185492 54.231.64.128 172.18.51.183 TCP
  60 [TCP Window Update] 443→48066 [ACK] Seq=1 Ack=1 Win=14848
Len=0
    140 1.952365 172.18.51.183 54.231.64.128 TLSv1
  188 Client Hello
    144 2.045093 54.231.64.128 172.18.51.183 TCP
  60 443→48066 [ACK] Seq=1 Ack=135 Win=15872 Len=0
    145 2.045137 54.231.64.128 172.18.51.183 TLSv1
  1494 Server Hello
    146 2.045157 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=135 Ack=1441 Win=17536 Len=0
    147 2.045215 54.231.64.128 172.18.51.183 TCP
  1494 [TCP segment of a reassembled PDU]
    148 2.045238 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=135 Ack=2881 Win=20480 Len=0
    149 2.045328 54.231.64.128 172.18.51.183 TCP
  1270 [TCP segment of a reassembled PDU]
    150 2.045355 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=135 Ack=4097 Win=23424 Len=0
    151 2.045573 54.231.64.128 172.18.51.183 TLSv1
  121 Certificate
    152 2.045601 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=135 Ack=4164 Win=23424 Len=0
    153 2.051866 172.18.51.183 54.231.64.128 TLSv1
  380 Client Key Exchange, Change Cipher Spec, Encrypted Handshake
Message
    160 2.149268 54.231.64.128 172.18.51.183 TLSv1
  113 Change Cipher Spec, Encrypted Handshake Message
    161 2.149555 172.18.51.183 54.231.64.128 TLSv1
  224 Application Data, Application Data
    166 2.263605 54.231.64.128 172.18.51.183 TLSv1
  464 Application Data, Application Data
    167 2.263654 54.231.64.128 172.18.51.183 TLSv1
  240 Application Data, Application Data
    168 2.263812 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [ACK] Seq=631 Ack=4819 Win=29184 Len=0
    169 2.263879 172.18.51.183 54.231.64.128 TLSv1
  91 Encrypted Alert
    170 2.263893 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [FIN, ACK] Seq=668 Ack=4819 Win=29184 Len=0
    192 2.356740 54.231.64.128 172.18.51.183 TLSv1
  91 Encrypted Alert
    193 2.356749 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [RST] Seq=669 Win=0 Len=0
    204 2.356812 54.231.64.128 172.18.51.183 TCP
  60 443→48066 [FIN, ACK] Seq=4856 Ack=669 Win=17920 Len=0
    205 2.356816 172.18.51.183 54.231.64.128 TCP
  54 48066→443 [RST] Seq=669 Win=0 Len=0

I've finally managed to grab a tcpdump of one of those 11s
multi-requests, and it looks like not even the TCP connections are
opened in parallel in that case, but instead two connections are
handled completely sequentially (i.e. starting with SYN via TLS
handshake and data, and ending with FIN ACK) until, after around 8s,
the remaining 8 requests are started in parallel and processed
sequentially in the same manner as with those 2.4s requests.

Is this a known problem with libnss? Are there workarounds?

regards,

rainer

-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
Received on 2015-11-16