Why did that curl request take so long?

I’ve just discovered that you can get curl to report how long each part of a session took.

I set up a bash script

t=(--write-out "\n DNS Lookup:%{time_namelookup}s\n TCP Connect:%{time_connect}s\n TLS Handshake: %{time_appconnect}s\n Total Time: %{time_total}s\n")
...
curl -X PUT --header 'Content-Type: application/json' "${t[@]}"  ....

and in the output it gives

 DNS Lookup:0.000033s
 TCP Connect:0.003088s
 TLS Handshake: 0.322826s
 Total Time: 0.981765s

Note the \n in the text to give new lines.

For more details

see curl man page. –write-out.

You can specify an output file, stderr or stdout.

There are many parameters, the performance timing ones are

• time_appconnect: The time, in seconds, it took from the start until the SSL/SSH/etc connect/handshake to the remote host was completed.
• time_connect: The time, in seconds, it took from the start until the TCP connect to the remote host (or proxy) was completed.
• time_namelookup: The time, in seconds, it took from the start until the name resolving was completed.
• time_posttransfer:The time it took from the start until the last byte is sent by libcurl. In microseconds.
• time_pretransfer: The time, in seconds, it took from the start until the file transfer was just about to begin. This includes all pre-transfer commands and negotiations that are specific to the particular protocol(s) involved.
• time_queue: The time, in seconds, the transfer was queued during its run. This adds the queue time for each redirect step that may have happened. Transfers may be queued for significant amounts of time when connection or parallel limits are in place.
• time_redirect: The time, in seconds, it took for all redirection steps including name lookup, connect, pretransfer and transfer before the final transaction was started. “time_redirect” shows the complete execution time for multiple redirections.
• time_starttransfer: The time, in seconds, it took from the start until the first byte was received. This includes time_pretransfer and also the time the server needed to calculate the result.
• time_total: The total time, in seconds, that the full operation lasted.
• tls_earlydata: The amount of bytes that were sent as TLSv1.3 early data. This is 0 if this TLS feature was not used and negative if the data sent had been rejected by the server. The use of early data is enabled via the command line option “–tls-earlydata“.