Testing and Improving Database Performance Using FRAPI
So the other day, I spotted a MySQL query (InnoDB, 5.27 if you’re interested) which was feeling non-performant. I should also point out, that SQL and testing and improving database performance are really not my forte. So please try not to judge me too harshly.
It’s actually a really simple query, so easy to demonstrate here:
UPDATE tokens SET deletedat = '2021-06-29 10:58:06.105' WHERE ( tokens.expiresat < '2021-06-29 10:58:06.0' ) AND ( tokens.deletedat IS NULL )
Tokens Table
So in my tokens table, this query would soft delete (via the deletedat column) any row where the expiry had passed. This has been running just fine for a year or so. But recently has started taking a bit longer. This query was being triggered on most/all API requests. With the table now over 100,000 rows, it was taking between 70ms – 350ms on average. This for a simple UPDATE felt bad and in need of a bit of love.
The table has an id column as the primary key, but was a unique UUID, non-incrementing, for each row.
The obvious solution was an index, but it took me a little while to get the index correct. Indexing just expiresat still resulted in all 100k rows being examined as I’d ignored that deletedat was in the WHERE clause. After a few local tests, I managed to get an index that had deletedat and expiresat in it, examining a mere handful of rows, and executing in 2-8ms. So I was pretty confident in pushing this change to production.
Ben Nadel’s Book
Before I did, however, I decided to take a page out of Ben Nadel’s book. I would use the FusionReactor API to wrap my changes in a custom transaction. I won’t go into massive detail here, as Ben did a great job explaining it here alongside other posts in his blog. Basically, I ended up using his JavaAgentHelper.cfc and then simply wrapped the code I wanted to track:
FRstartedAt = getTickCount();
javaAgentHelper.segmentWrap("ExpireTokens", () => {
// My Model call which triggers the query
expiredTokens=model("token").deleteAll(instantiate=false, where="expiresAt < '#now()#'");
});
javaAgentHelper.metricAdd( "/custom/ExpireTokens", ( getTickCount() - FRstartedAt ) );
Advantages
This approach has a couple of really useful advantages.
Firstly, you can visually see the segment in the trace within FusionReactor (all database queries are logged anyway but this just makes it very clear which part you’re concerned with). So when scanning requests, you get something more helpful than just “JDBC Request”.
Secondly, as you’ve taken the time to wrap the code you’re interested in into a custom transaction, you can then build a custom graph via the metricAdd to track it over time. For me, this was really helpful to see if the performance gain was real in a production environment, and not just a fluke of local development. So I deployed the wrapped code first (even though the query was still under-performing) just so I could “before and after” the results.
It should be fairly obvious from the above the pre/post-deployment moment – and that’s where FusionReactor really helps. It gives you more confidence in the effectiveness of fixes going into production.
Now I’ve got this method ready to use in the code base, it’s pretty trivial to apply it to other problem areas. Not just when testing and improving database performance or queries!