curl / Mailing Lists / curl-library / Single Mail

curl-library

Odd timer values

From: Dima Tisnek via curl-library <curl-library_at_cool.haxx.se>
Date: Tue, 21 Nov 2017 10:38:01 +0800

Hi list,

I'm using

And sometimes some of the timers seem uninitialized. Weirdly, which
timer(s) get odd values is stable across exact same invocations but
varies if I change header fields.

Was this seen before?

Here's an example:

$ curl -vv -w "@curl-timing-format" -H "Expect:" -H "Authorization:
Bearer jjj" https://httpbin.org/post -d
@/usr/local/google/home/dimaqq/Downloads/block-post -H "Content-Type:
application/json"
* Trying 54.243.68.217...
* TCP_NODELAY set
* Connected to httpbin.org (54.243.68.217) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use http/1.1
* Server certificate:
* subject: CN=httpbin.org
* start date: Nov 12 23:32:05 2017 GMT
* expire date: Feb 10 23:32:05 2018 GMT
* subjectAltName: host "httpbin.org" matched cert's "httpbin.org"
* issuer: C=US; O=Let's Encrypt; CN=Let's Encrypt Authority X3
* SSL certificate verify ok.
> POST /post HTTP/1.1
> Host: httpbin.org
> User-Agent: curl/7.55.0
> Accept: */*
> Authorization: Bearer jjj
> Content-Type: application/json
> Content-Length: 2560
>
* upload completely sent off: 2560 out of 2560 bytes
< HTTP/1.1 200 OK
< Connection: keep-alive
< Server: meinheld/0.6.1
< Date: Tue, 21 Nov 2017 02:31:04 GMT
< Content-Type: application/json
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Credentials: true
< X-Powered-By: Flask
< X-Processed-Time: 0.000755071640015
< Content-Length: 2946
< Via: 1.1 vegur
<
{
  "args": {},
  "data": "yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy
yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy
yy
yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy",
  "files": {},
  "form": {},
  "headers": {
    "Accept": "*/*",
    "Authorization": "Bearer jjj",
    "Connection": "close",
    "Content-Length": "2560",
    "Content-Type": "application/json",
    "Host": "httpbin.org",
    "User-Agent": "curl/7.55.0"
  },
  "json": null,
  "origin": "104.132.2.71",
  "url": "https://httpbin.org/post"
}
* Connection #0 to host httpbin.org left intact
    time_namelookup: 0.252952
       time_connect: 0.480264
    time_appconnect: 4295.929091
   time_pretransfer: 4295.929319
      time_redirect: 0.000000
 time_starttransfer: 1.194235
                    ----------
         time_total: 1.194530

                    ----------
DEBUG: time_redirect 0.000000 http_code: 200 size_header: 304
size_request: 2721 size_upload: 2560 size_download: 2946
num_connects: 1 num_redirects: 0 ssl_verify_result: 0
proxy_ssl_verify_result: 0 http_vers 1.1 xxxEND⏎

Another example:

    time_namelookup: 0.124698
       time_connect: 4295.317852
    time_appconnect: 4295.793704
   time_pretransfer: 4295.793914
      time_redirect: 0.000000
 time_starttransfer: 1.056099
                    ----------
         time_total: 1.056320

                    ----------
DEBUG: time_redirect 0.000000 http_code: 200 size_header: 303
size_request: 2740 size_upload: 2560 size_download: 2979
num_connects: 1 num_redirects: 0 ssl_verify_result: 0
proxy_ssl_verify_result: 0 http_version: 1.1

And another:

    time_namelookup: 0.509292
       time_connect: 4295.698049
    time_appconnect: 1.199310
   time_pretransfer: 1.199537
      time_redirect: 0.000000
 time_starttransfer: 1.427389
                    ----------
         time_total: 1.427612

                    ----------
DEBUG: time_redirect 0.000000 http_code: 200 size_header: 303
size_request: 2740 size_upload: 2560 size_download: 2979
num_connects: 1 num_redirects: 0 ssl_verify_result: 0
proxy_ssl_verify_result: 0 http_version: 1.1

Digging into 4295.xxxxxx values:
hex(int(4295.929319 * 10**6))
'0x1000eade7'
hex(int(4295.929091 * 10**6))
'0x1000ead03'

Here's my curl-timing-format:

    time_namelookup: %{time_namelookup}\n
       time_connect: %{time_connect}\n
    time_appconnect: %{time_appconnect}\n
   time_pretransfer: %{time_pretransfer}\n
      time_redirect: %{time_redirect}\n
 time_starttransfer: %{time_starttransfer}\n
                    ----------\n
         time_total: %{time_total}\n
\n
                    ----------\n
DEBUG:
  time_redirect %{time_redirect}
  http_code: %{http_code}
  size_header: %{size_header}
  size_request: %{size_request}
  size_upload: %{size_upload}
  size_download: %{size_download}
  num_connects: %{num_connects}
  num_redirects: %{num_redirects}
  ssl_verify_result: %{ssl_verify_result}
  proxy_ssl_verify_result: %{proxy_ssl_verify_result}
  http_version: %{http_version}
  xxx
END

Here's my curl --version
curl 7.55.0 (x86_64-pc-linux-gnu) libcurl/7.55.0 OpenSSL/1.0.2l
zlib/1.2.8 libidn2/2.0.2 libpsl/0.18.0 (+libidn2/0.16) libssh2/1.8.0
nghttp2/1.25.0 librtmp/2.3
Release-Date: 2017-08-09
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps
pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: AsynchDNS IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM
NTLM_WB SSL libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL

Thanks!
d.

-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html
Received on 2017-11-21