I have a toolkit that helps me to do my job. It is not easy to earn a place in my toolkit because I want that my tools make my life easier.
This means that they must be easy to use (or easy to learn). Unfortunately the world is full of useful development tools that are not easy to use or easy to learn.
Luckily for me, there are exceptions to this rule and today I will identify one such exception.
JProfiler has been my trusted friend and ally for many years. I like its user interface that looks good and it is (in my opinion) quite easy to use. But more importantly, I like JProfiler because it has saved my skin many times during these years.
This blog post describes three disasters that I solved with JProfiler. Let’s get started.
Disclaimer: This is a sponsored post, but I recommend only products which I use myself. Also, This post was written me by and all these scenarios are real. Some of the details have been changed to protect the people involved.
1. The Dreadful N+1 SELECTs Problem
I was asked to take a look at a search function that was very slow. I started by taking a quick look at the code and found out that it fetched a list of entities from the database by using Hibernate, converted these entities into DTOs, and returned the search results.
Because I noticed that these entities had a lot of one-to-one relationships and all of them were loaded eagerly, I configured Hibernate to write the invoked SQL statements to the log and tested the search function. The outcome of my test was shocking. Hibernate invoked so many SQL statements that it was obvious that this search function was suffering from the N+1 SELECTs problem.
Before I started to fix this problem, I wanted to know what information is fetched from the database and how long it takes to fetch that information. Once again, the easiest to way to get this information was to use JProfiler. JProfiler has a built-in JPA/Hibernate probe that is able to give me the information I need.
After I got the data, I fixed the problem by using the combination of lazy fetching and joins (this function was later replaced with an implementation that used SQL). Also, it’s important to understand that when you fix a problem like this, you have to make many incremental changes and profile your code after every change. This way you can ensure that you don’t make the situation worse.
2. The “Unexpected” Memory Issue
One project had a batch job that processed a lot of entities inside a single transaction. The problem was that batch job very slow and took too much memory. In fact, sometimes it crashed because the JVM ran out of memory.
When I started to investigate this problem, I knew what was wrong. The problem was that the batch job was updating too many entities inside a single transaction, and since the we used Hibernate, Hibernate had to:
- Keep track of all these changes.
- Persist these changes to the database when the transaction was committed.
It was obvious that I could fix the problem by modifying the batch job to use many small transactions. However, I didn’t know how small transactions I should use. Because I wanted to make a decision that is based on facts, I had to test different transaction sizes and measure how much memory the batch job takes.
I started JProfiler and started looking for the “best” transaction size by using its VM heap telemetry view. It took me some time, but I was able to select the transaction size that solved the problem (at least for the time being).
3. The Slow Find By Id Method
I had implemented a simple service method that fetched the information of an entity from the database by using its id as a search criteria. The problem was that this method was extremely slow, and I couldn’t understand why.
The entity didn’t have relationships that could have caused the N+1 selects problem and the invoked query was so simple that should have been very fast. It was time to fire up JProfiler.
When I investigated this issue, I followed these steps:
- I used the JPA/Hibernate probe and found out that invoking the database query took only a few milliseconds.
- I searched the slow method invocations and identified the culprit. The entity in question had 6 DateTime fields, and I persisted them into the database by using Jadira UserTypes. The problem was that converting the column values of timestamp columns into DateTime objects took too long. If I remember correctly, creating those objects took 0.6 seconds (I am not 100% about the exact time).
I fixed this problem by replacing the DateTime fields with Date fields and modifying the getter methods to return new DateTime objects. This was an easy fix, but without JProfiler I probably would have blamed Hibernate about this problem, called it a “feature”, and moved on.
The Moral of This Story
Donald Knuth once wrote that premature optimization is the root of all evil. Although I agree with him, I also think that is extremely easy to use this quote as an excuse for not doing our job.
It is surprisingly easy to write “clean code” that looks fast when it is run in the development environment. If we believe that premature optimization really is the root of all evil, the odds are that we commit our code to version control and move on to our next task.
Also, if our code has performance issues when it is run in the production environment, we solve this problem by stating that they are caused by technical debt. We don’t want to take a look at this problem because we know that fixing it will take a lot of time. Thus, we take the easy way out.
However, this kind of behavior is unprofessional and quite frankly, only idiots act like this because we have an easy way to ensure that our code is problem free:
We should start a profiler and take a good look at our code BEFORE we commit it to the version control system.
Do you agree with me?
