On Thursday 30 June 2016 10:34:59 Daniel Stenberg wrote:
> On Wed, 29 Jun 2016, Tim Rühsen wrote:
> > So my question goes... what is 'wrong' with that version of curl. Or what
> > did I oversee - maybe some special options ?
>
> Data point: I tried several different resolver and TLS build options and
> they mostly show a difference no matter what. It seems to be generic.
>
> I ran both command lines with 'strace -tt' and that turns out highly
> interesting. It shows one particular gap in time that I can't see a
> motivation for. I typically looks something like this:
>
> 10:28:58.687457 sendto(4, "\26\3\3\0
> \351\25\234H\324\222cY\301\254XC\375h(C\350\213\331\322J\311:Q\235g\f"...,
> 37, MSG_NOSIGNAL, NULL, 0) = 37
> 10:28:58.687479 recvfrom(4, 0xd8585b, 5, 0, 0, 0) = -1 EAGAIN (Resource
> temporarily unavailable)
> 10:28:58.687496 poll([{fd=4, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}],
> 1, 0) = 0 (Timeout)
> 10:28:58.687513 poll([{fd=4, events=POLLIN}], 1, 181) = 1 ([{fd=4,
> revents=POLLIN}])
>
> *** See a huge gap in time here. 45 millseconds doing nothing, for a 1500
> bytes response body over a <3ms RTT connection...!
>
> 10:28:58.732615 poll([{fd=4, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}],
> 1, 0) = 1 ([{fd=4, revents=POLLIN|POLLRDNORM}])
> 10:28:58.732794 recvfrom(4, "\26\3\3\0\316", 5, 0, NULL, NULL) = 5
> 10:28:58.732960 recvfrom(4,
> "\4\0\0\312\0\1\211\300\0\304\2w\0\2341\357\364d\303\334\273\371=\3\\\251\33
> 3\321\225\217?N"..., 206, 0, NULL, NULL) = 206
>
> Worth checking out in more detail I think!

Maybe it's related or not... saw a similar gap here with wireshark (part of
curl's TLS handshake):

     20 2016-06-30 10:11:31.115 192.1.11.218 216.58.209.100
TLSv1.2 141 Client Key Exchange
     21 2016-06-30 10:11:31.191 216.58.209.100 192.1.11.218
TCP 66 443 → 44094 [ACK] Seq=3506 Ack=337 Win=43648 Len=0 TSval=1
044002737 TSecr=632528
     22 2016-06-30 10:11:31.191 192.1.11.218 216.58.209.100
TLSv1.2 109 Change Cipher Spec, Encrypted Handshake Message
     23 2016-06-30 10:11:31.226 216.58.209.100 192.1.11.218
TCP 66 443 → 44094 [ACK] Seq=3506 Ack=380 Win=43648 Len=0 TSval=1
044002772 TSecr=632547
     24 2016-06-30 10:11:31.226 216.58.209.100 192.1.11.218
TLSv1.2 320 New Session Ticket, Change Cipher Spec, Encrypted Handshak
e Message
     25 2016-06-30 10:11:31.227 192.1.11.218 216.58.209.100
TLSv1.2 175 Application Data

'Client Key Exchange' and 'Change Cipher Spec, Encrypted Handshake Message'
are sent as two packets. Curl has to wait for a long time (76ms) to get an
answer for 'Client Key Exchange'.
Wget does this as one packet and receives an immediate (RTT = 35ms here in the
office) answer.

Tim

-------------------------------------------------------------------
List admin: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html