How Plumbr will help you
The screenshot above is taken from Plumbr and exposes the root cause for the slow JDBC call. The user experience was impacted in the firstname.lastname@example.org JVM, which happens to be one of our own production JVMs. What Plumbr has captured is that the specific JDBC call took 14 seconds to complete. As seen, during the last seven days there were 1,357 occurrences of the very same query being too slow.
The information needed to fix the problem is embedded in the following two blocks. First of these exposes the SQL statement executed in the database, equipped with exact parameters set for the prepared statement: The information needed to fix the problem is embedded in the following two blocks. First of these exposes the SQL statement executed in the database, equipped with exact parameters set for the prepared statement:
SELECT ap.* FROM AlertPolicy ap LEFT JOIN ... WHERE ... AND ap.hidden=0 AND ap.type='HEALTH'
The block next to it exposes the call stack in the source code, zooming in to the exact line where the statement was executed:
com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery()N/A* org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement():688 org.springframework.jdbc.core.JdbcTemplate.execute():629 ... org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query():199 eu.plumbr.portal.alert.AlertPolicyDao.getAlertPolicies():83
As seen from above, the call to eu.plumbr.portal.alert.AlertPolicyDao.getAlertPolicies():83 as the location in our business code. In addition, Plumbr exposes you the full view of the transaction where this particular slow JDBC call participated. Opening the transaction link in the header exposes you the following information:
From the above it is clear that in addition of just being a slow query to execute, the very same query is actually executed four times during a single transaction, introducing the second problem to solve.
Slow JDBC calls are slow due to poorly constructed queries, resulting in computationally expensive operations being carried out in database. This time the query was slow due to different reasons, solutions for which included:
- Batching the four similar calls to a single query, removing the need for additional roundtrips to database.
- Adding a missing index on the Alert table field “created”. This sped up the query three-fold.
- Additional gains were achieved when replacing the “LEFT JOIN” construct with “IN (...)” operator, reducing the latency even more.
When getting exposure to Slow JDBC Calls by Plumbr, the generic sequence of optimization steps should include
- Copying the query exposed to the database client of your choice
- Exposing statement's execution plan, revealing hints for optimizations, such as the cost and cardinality of each operation
- Following the optimization hints and rerunning the query to verify results
- Performing additional steps, such as adding required indexes or changing the data structures in extreme cases.