Where the Time Goes

The load test says p95 is over two seconds at 500 readers. It does not say why. A load test measures from the outside. It records that a request went in, that a response came out, and how much time passed between the two. To find out where that time went, you have to measure from the inside.

Profiling is recording how long each step of handling a request takes, on the running application, under load. In the previous chapter, I mentioned profiling in the context of deciding between denormalizing the author’s name or keeping the join. It is the same activity, applied to the whole request instead of one query.

What a reader’s request does

Take the request to open a published post. HopPress does the following:

  1. Receives the request and reads the post ID from the URL.
  2. Borrows a connection from the connection pool and runs the query for that post.
  3. Waits for the database to return the row.
  4. Renders the page from the row and a template.
  5. Sends the page back.

These are the steps that matter for the performance model we use here. A reader does not sign in, so there is no call to the identity provider. There is no analytics, so nothing is written to a log or database. For a reader, HopPress is a program that reads one row from a database and turns it into a page. That is why this chapter, like the last one, looks at the database as the place to make the application faster.

What the profile shows

Suppose we profiled the application and found the following:

Steps 1 and 5 take a fraction of a millisecond and do not change with load. Step 4, rendering, takes a few milliseconds of processor time and does not change with load either. Step 2 is fast once the connection pool is in place.

Step 3 takes most of the time, and it grows with load. The query itself is a primary key lookup, which takes well under a millisecond once the row is in memory. The part that grows is the waiting. One database serves every reader’s query. At 50 readers it keeps up. At 500, queries arrive faster than it can finish them, and each one waits behind the ones ahead of it.

The list of published posts is the more expensive query. It returns many rows instead of one, every reader runs it before opening a post, and under load it waits in the same queue.

The rule

You should focus on the bottleneck, the step that takes most of the time. You cannot optimize everything, and if you optimize a step that is not the bottleneck, the effort is wasted.

For HopPress, we assume the profile shows that the bottleneck is the database: waiting for the database to return a row. The rest of this chapter looks at ways to make that wait shorter.