Where I work, we have a number (let’s say around 100) of backend services that are used by front-end code to render our website. These services are usually centered around one part of our businesses – we have, for example, a service for managing users and getting information about them, another one for getting order information, etc. We have a lot of monitoring on these services, mostly through NewRelic, that makes us feel like we have pretty good visibility into them most of the time.
It isn’t uncommon for one of these services to have spikes in calls that range from a few minutes to a few hours – usually because of some batch process or maybe a spike in web traffic or something. Sometimes there is an interesting phenomenon that occurs – despite a large spike in traffic, response times appear to go DOWN. What is even more perplexing, every endpoint in the service seems to be responding slower due to the load, but overall response time appears to decrease.
It’s interesting to think about why this is the case. If you get a bunch of smart developers and operations people into a room, a bunch of theories will start to come out. Maybe the extra requests are keeping a specific thread hot and so there is less context switching? Maybe something is being cached and re-used repeatedly? Maybe an increase in L2 cache hits? And so on…
Some of these may have some element of truth to them, but it’s hard to imagine any of them improving response times by any measurable amount. The answer, it turns out (at least in every case I’ve looked into so far), is a little surprising to some people – the services aren’t actually responding faster, they are responding slower, and in some cases quite a bit slower. The way we report response times misleads us and makes us think otherwise, however.
To illustrate, let’s imagine a service that manages users, and that service has two endpoints: /read for getting information about a user, and /write for creating users. Our read endpoint is really fast and called quite frequently, but our write endpoint does more work and is much slower, but is called relatively infrequently. Assume that under normal circumstances, our read endpoint is called 100 times per minute and takes 10 ms to respond, whereas our write endpoint is called 5 times per minute and takes a whopping 500 ms to respond.
What is our mean response time? Well, ((100*10) + (5*500)) / 105 = 33 ms.
Now, what happens if our read traffic goes up by 10x for a minute, while the write traffic stays the same, and due to increased load, everything is 20% slower?
((1000*12) + (5*600)) / 1005 = 15 ms.
It looks like our response time has dropped in half, even though it has gotten 20% worse in reality. This is a fairly typical result.
There are two fairly easy criticisms you can make:
1) You shouldn’t be aggregating across endpoints
This is sort of fair, but at some point, you’ll have so many endpoints that doing so at that level makes it really hard to get useful information. It is also useful to aggregate at the service or process level because that is one of the data points you are using to gauge how they are doing and know when to scale them. Finally, we can have the same situation happen on a single endpoint – what if most of our users were really fast, but a small subset were power users who had a lot more data attached to them and thus loaded a lot more slowly? This is a scenario I’ve run into before.
2) The whole problem is that you are using the mean
This is also a good point – anyone with even a fairly basic background in statistics can tell you why using the mean may not be the best way to measure aggregate response times.
Using the median might make situations like this less likely (but you can still contrive examples of them), but hides data in its own way – it is easy, for example, for it to hide the fact that you have a number of really slow endpoints if you have slightly more fast ones.
Using percentiles or a histogram of response times avoid most of these problems, but require a lot more data to be kept around versus calculating the mean on the fly (i suspect this is why NewRelic shows the mean by default and only retains limited history of other metrics). Indeed, the 99% metric is the only one that has actually shown load times increasing when we’ve had these events in the past, although some of the spikes have been so large that even the 99% isn’t sensitive enough.
tl;dr Sometimes the way metrics are reported can be really misleading in extreme cases, and if something feels counterintuitive, sometimes it really isn’t exactly as it seems. I generally prefer to look at the 95/99% graph when I’m looking at a service – it tells you if you really have stuff you need to look into and often gives you an idea of what the future looks like for your service.
