server processing time is negative

lidaobing commented 3 years ago

Body stored in: /var/folders/fh/5k0fl9xd06xgflnp5d90dz8m0000gn/T/tmpjIYObb

  DNS Lookup   TCP Connection   TLS Handshake   Server Processing   Content Transfer
[     2ms    |      194ms     |     92ms      |      -288ms       |      1255ms      ]
             |                |               |                   |                  |
    namelookup:2ms            |               |                   |                  |
                        connect:196ms         |                   |                  |
                                    pretransfer:288ms             |                  |
                                                      starttransfer:0ms              |
                                                                                 total:1255ms

lidaobing commented 3 years ago

$ httpstat --version httpstat 1.3.1

reorx commented 3 years ago

Hi, I need more information to diagnose this problem, please provide:

The complete command line command and HTTPSTAT_ env vars (if any) to reproduce the problem
The output of HTTPSTAT_METRICS_ONLY=true httpstat <your-url>, which is a JSON string
The curl version (curl --version) details

Question: is this behavior stable or unpredictable?

lidaobing commented 3 years ago

@reorx

I am sorry that I cannot provide a reproducible command because it's an internal website.

metric only result

{
"speed_download": 9810.0,
"speed_upload": 14.0,
"remote_port": "443",
"range_ssl": 92,
"range_dns": 1,
"local_ip": "192.168.7.88",
"range_connection": 386,
"time_redirect": 0,
"time_pretransfer": 479,
"local_port": "60368",
"range_transfer": 1839,
"time_appconnect": 479,
"time_starttransfer": 0,
"time_namelookup": 1,
"range_server": -479,
"time_connect": 387,
"time_total": 1839,
"remote_ip": "******"
}

curl

$ curl --version
curl 7.64.1 (x86_64-apple-darwin20.0) libcurl/7.64.1 (SecureTransport) LibreSSL/2.8.3 zlib/1.2.11 nghttp2/1.41.0
Release-Date: 2019-03-27
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp smb smbs smtp smtps telnet tftp
Features: AsynchDNS GSS-API HTTP2 HTTPS-proxy IPv6 Kerberos Largefile libz MultiSSL NTLM NTLM_WB SPNEGO SSL UnixSockets

and I am using Mac arm64

lidaobing commented 3 years ago

bug disappeared after swtich to the homebrew curl

PATH="/opt/homebrew/opt/curl/bin:$PATH" httpstat ...
...

Body stored in: /var/folders/fh/5k0fl9xd06xgflnp5d90dz8m0000gn/T/tmp2z3x7W

  DNS Lookup   TCP Connection   TLS Handshake   Server Processing   Content Transfer
[     2ms    |       0ms      |     125ms     |       516ms       |       39ms       ]
             |                |               |                   |                  |
    namelookup:2ms            |               |                   |                  |
                        connect:2ms           |                   |                  |
                                    pretransfer:127ms             |                  |
                                                      starttransfer:643ms            |
                                                                                 total:682ms

$ /opt/homebrew/opt/curl/bin/curl --version
curl 7.75.0 (arm-apple-darwin20.3.0) libcurl/7.75.0 (SecureTransport) OpenSSL/1.1.1j zlib/1.2.11 brotli/1.0.9 zstd/1.4.9 libidn2/2.3.0 libssh2/1.9.0 nghttp2/1.43.0 librtmp/2.3
Release-Date: 2021-02-03
Protocols: dict file ftp ftps gopher gophers http https imap imaps ldap ldaps mqtt pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz Metalink MultiSSL NTLM NTLM_WB SPNEGO SSL TLS-SRP UnixSockets zstd

reorx / httpstat

server processing time is negative #41