The second episode of PicCollage's server performance optimization journey! After finding a way to instrument NewRelic so that requests coming from GraphQL are separated by query, we are now able to see the performance details by query, and identify any elements that are doing more harm than good. Quickly enough, there's this particular query that stood out for us, because it triggers 26 trips to cache store everytime a request is sent for it.
26 trips to cache store for one request-that's a lot. The fact that it's to fetch the caches (as opposed to making database queries) still doesn't justify it. Our mission, then, is to reduce those 26 cache queries down to 1, while making sure we are still caching all the database queries and heavy calculations.
Inspecting Database Queries
But this article is not about how we refactored our code to allow a better caching strategy at the top level of GraphQL (that'd be in another article), but something that's just as important as how we did it. That is, how we test it.
How do we make sure a chunk of our code triggers the right amount of queries to database and/or cache store? Especially with the convenience of ORM (Object-Relational Mapping), it's easy to lose count of the actual queries we make to the database with our code (see the famous and semi-related n+1 queries problem).
In short, the database queries we are actually sending do not have a one-to-one relationship with the lines of code we write with our Active Record objects. To fetch the query count, therefore, we need to assert against something other than the times we invoke
SomeModel.where(some_condition). We need to find a way to assert against something more precise.
The Instrumentation API
As it turns out, Active Support, one of the core libraries that Rails depends on, has this nice thing called Instrumentation. This instrumentation API enables us to create hooks (events) and measure those hooks by subscription. The hooks can be certain actions inside an application or another piece of Ruby code.
As a thoughtful framework as it is, Rails provides several hooks already by default, including sql queries and cache read events. What does that mean? We can leverage this existing API to build our own database/cache query counter!
Our Database/Cache Query Counter
I'm not going to dive into the details of Instrumentation API details here because the documentation already explains it quite well. If not, the code snippet below will do the explanation.
TestHelper has two test helper methods:
assert_cache_queries. The logic translate as follows:
assert_db_queries, we subscribe to the event
'sql.active_record', and provide the API with two other arguments: what to do when this event happen (callback), and within what scope this event should be looked out for. The first argument is our
counter_f lambda, inside which we collect both the query names (
queries) and the actual hits (
actual_hits). The second argument is our test code, example of which is in the
ExampleTest class. At the end, we assert that the actual hits equal to our expected hits (also provided when invoking the method).
assert_cache_queries is pretty much the same as
assert_db_queries, only differing in the event name (
'cache_read.active_support') and the keys in the payload.
A refresher on Rails testing API: the third argument in
assert_equal method is the custom error message that will be printed if the assertion fails. Here we provide it with the actual queries sent. Super helpful. Strongly recommended.
Also, the two methods are designed as such that you can pass in an additional
debug: true option to always print out the actual queries regardless of the result of assertion.
These two setups turned out to be a great help in our effort to get a clearer picture of our application's interaction with the database and cache store. One step forward in our performance optimization journey!
Of course, wrapping them into test methods is just one example of how we can take advantage of Instrumentation API. Tweak it however you want. Happy exploring!
The credit for discovering this useful mechanism goes to Jaime. Thank you Jaime for writing the initial version 7 years ago :)