How do I debug latency issues using curl?

Resolution

There are many possible causes of latency so it's not possible to cover every cause - the following are some suggestions based on common misunderstandings that we see from time to time.

Network round trip times

The time taken to request a file from your local machine or network is likely to be in the order of 1ms. When hosting on Heroku, our datacenters are located in different regions and will almost certainly add some latency given the distances involved. As a very rough guide you can expect around 100ms of latency when accessing a US region app from the EU on a fast connection.

Request queueing times (especially when load testing)

This is not strictly a network latency issue but you should check for high request queueing times using the suggestions in this article if you are experiencing performance issues.

SSL Handshake times

(all examples use requests from an EU client to a US based app)

When making individual requests using a tool like curl or postman, it's not unusual for these to negotiate a new SSL connection for each request. The handshake process for SSL involves at least 3 network round trips (plus some processing time) meaning that the first request over SSL is often significantly slower than for subsequent request that reuse the connection.

To confirm this effect in curl you can use the following command (on Unix based systems) to measure the SSL handshake time:

$ curl -w "dns_resolution: %{time_namelookup}, tcp_established: %{time_connect}, ssl_handshake_done: %{time_appconnect}, TTFB: %{time_starttransfer}\n" -o /dev/null -s "https://sushi.herokuapp.com/"
dns_resolution: 0.067, tcp_established: 0.175, ssl_handshake_done: 0.598, TTFB: 0.708

All times are measured in seconds and additional info for each of the timing can be found on the curl manpage

The above shows that the SSL handshake took 423ms (ssl handshake minus tcp time) for this request.

To see the TTFB without the effect of an SSL handshake, the easiest method is to simply request the same URL twice via curl as this will reuse the existing connection:

$ curl -w "dns_resolution: %{time_namelookup}, tcp_established: %{time_connect}, ssl_handshake_done: %{time_appconnect}, TTFB: %{time_starttransfer}\n" -o /dev/null -s "https://sushi.herokuapp.com/" "https://sushi.herokuapp.com/"
dns_resolution: 1.525, tcp_established: 1.630, ssl_handshake_done: 2.027, TTFB: 2.136
dns_resolution: 0.000, tcp_established: 0.000, ssl_handshake_done: 0.000, TTFB: 0.110

We can see here that the subsequent request took 110ms to transfer the first byte - this is what the majority of connections from a web browser would experience. It's also worth noting that the connection is kept open between the client and the Heroku Routing layer, not the app server. Connection: close is always used between the router and the application backends (due to the high number of router backend instances), but the connection from the end-user client and the router will respect keep-alive (assuming a Content-Length or Encoding: chunked header is present). SSL termination happens at the routing layer so the benefits of re-using the connection are still present there.

DNS resolution issues

The speed of domain name lookups can vary due to several factors. Again, you can test this with curl using the time_namelookup parameter shown above.