insight 
As Java developers we regularly have problems with applications running slowly due to an inefficient database query. Often there is little logging to help track down which query is causing the problem. Log4jdbc can help out here. Log4jdbc is a Java library that can log your database queries and how long they take. It can also log warnings and errors when queries are too slow based on thresholds.
Set up log4jdbc to log slow queries
Let’s look at how to set up log4jdbc in an application so that slow queries are logged. Note that log4jdbc supports logging frameworks log4j and slf4j. Here we will use the u003ca href=u0022https://github.com/qos-ch/logbacku0022 target=u0022_blanku0022 rel=u0022noopener noreferreru0022u003elogbacku003c/au003e implementation of slf4j.rnu003colu003ern tu003cliu003eAdd this dependency to your pom.xml configuration file:u003c/liu003ernu003c/olu003ernu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 712wu0022 alt=u0022Logging slow queries using log4jdbc – 1u0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-1-1.jpg 712wu0022 /u003eu003c/figureu003ernu003c/figureu003ern2. Add this to logback.xml file:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 354w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 708wu0022 alt=u0022Logging slow queries using log4jdbc – 2u0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 354w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-2-1.jpg 708wu0022 /u003eu003c/figureu003ernu003c/figureu003ern3. Change your JDBC URLrnrnInsert “log4jdbc:” into the normal JDBC URL that you are using. For example, change this:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 712wu0022 alt=u0022Logging slow queries using log4jdbc – 3 au0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-a-1.jpg 712wu0022 /u003eu003c/figureu003ernu003c/figureu003ernto this:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 711wu0022 alt=u0022Logging slow queries using log4jdbc – 3 bu0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-3-b-1.jpg 711wu0022 /u003eu003c/figureu003ernu003c/figureu003ern4. Set the JDBC driver class to u003cstrongu003esf.log4jdbc.sql.jdbcapi.DriverSpyu003c/strongu003e in your application. Note that log4jdbc supports almost all major drivers; check the u003ca href=u0022http://code.google.com/p/log4jdbc/u0022 target=u0022_blanku0022 rel=u0022noopener noreferreru0022u003elog4jdbc documentationu003c/au003e for a list of supported drivers. For example, change:rnu003cfigure class=u0022clearfixu0022u003eu003c/figureu003ernu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 712wu0022 alt=u0022Logging slow queries using log4jdbc – 4 au0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 178w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 356w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-a-1.jpg 712wu0022 /u003eu003c/figureu003ernu003c/figureu003erninto:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 354w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 708wu0022 alt=u0022Logging slow queries using log4jdbc – 4 bu0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 354w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-4-b-1.jpg 708wu0022 /u003eu003c/figureu003ernu003c/figureu003ern5. Log4jdbc does have a bug that we need to work around. See u003ca href=u0022https://github.com/brunorozendo/log4jdbc-log4j2/issues/43u0022 target=u0022_blanku0022 rel=u0022noopener noreferreru0022u003ehttps://github.com/brunorozendo/log4jdbc-log4j2/issues/43u003c/au003e for the bug in question. The problem is that when logging just slow queries (rather than all queries) the class name and line number of the slow query are not logged. To fix that here we make a copy of class Slf4jSpyLogDelegator from the library. This class can be retrieved from u003ca href=u0022https://repo1.maven.org/maven2/org/bgee/log4jdbc-log4j2/log4jdbc-log4j2-jdbc4.1/1.16/log4jdbc-log4j2-jdbc4.1-1.16-sources.jaru0022 target=u0022_blanku0022 rel=u0022noopener noreferreru0022u003ehttps://repo1.maven.org/maven2/org/bgee/log4jdbc-log4j2/log4jdbc-log4j2-jdbc4.1/1.16/log4jdbc-log4j2-jdbc4.1-1.16-sources.jaru003c/au003e . Rename it to jdbc.sqltiming.ModifiedSpyLogDelegator. Note that it must be in a different package than your normal application package. Method buildSqlTimingDump contains the following:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 353w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 706wu0022 alt=u0022Logging slow queries using log4jdbc – 5u0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 177w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 353w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-5-1.jpg 706wu0022 /u003eu003c/figureu003ernu003c/figureu003ernThe change is to remove the if statement; so perform the out.append statements unconditionally.rnrnThose are all of the code changes needed.rnrnWhen running the application include the following three parameters:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 179w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 359w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 717wu0022 alt=u0022Logging slow queries using log4jdbc – 6u0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 179w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 359w, https://vxcompany.com/wp-content/uploads/Logging-slow-queries-using-log4jdbc-6-1.jpg 717wu0022 /u003eu003c/figureu003ernu003c/figureu003ernThe first parameter refers to the class that we have just modified. The second parameter represents the package structure of the application so change that to match your package structure. The third parameter is the threshold for warning about a slow query and is set here to 2 minutes (120,000 milliseconds). Change that to the desired threshold.rnrnThat’s it. Next time the application starts up and a query is too slow then a warning will be logged. For testing purposes, to see warnings being logged, set the threshold temporarily to something like 1ms.
The log message
Here is a typical log message produced by log4jdbc:rnu003cfigure class=u0022clearfixu0022u003ernu003cfigure class=u0022clearfixu0022u003eu003cimg src=u0022https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpgu0022 srcset=u0022https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 193w, https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 386w, https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 772wu0022 alt=u0022The log message – 1u0022 width=u0022100%u0022 height=u0022autou0022 data-srcset=u0022https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 193w, https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 386w, https://vxcompany.com/wp-content/uploads/The-log-message-1-1.jpg 772wu0022 /u003eu003c/figureu003ernu003c/figureu003ernNote that the logged query is actual SQL and not Hibernate HQL. Also, the values of the query parameters are present; when Hibernate logs a query (by setting its show_sql parameter to true) it is without parameters, just a list of question marks. So, the query logged by log4jdbc is complete and can easily be executed in a SQL tool and an explain plan run on it to figure out why it is slow.rnrnThe class name and line number are also logged (in this case class EmployeeDAOImpl and line number 40). In this way it is easy to see from where in the Java code this query was executed.rnrnFinally, the response time is logged, in this case 300,000 milliseconds (5 minutes).rnrnu003cstrongu003eFurthermoreu003c/strongu003ernu003culu003ern tu003cliu003eAn additional feature of log4jdbc is an error threshold. So, log a warning about a certain lower threshold (say 2 minute) and log an error at a higher threshold (say 4 minutes) with parameter -Dlog4jdbc.sqltiming.error.threshold=240000.u003c/liu003ern tu003cliu003eWarnings in a log file need to be noticed. A handy way to do that is to set up a u003ca href=u0022https://www.elastic.co/products/kibanau0022 target=u0022_blanku0022 rel=u0022noopener noreferreru0022u003eKibanau003c/au003e board that displays the warnings and errors in your log file.u003c/liu003ernu003c/ulu003ernu003cstrongu003eReferencesu003c/strongu003ernhttp://log4jdbc.brunorozendo.com/