Logging JDBC requests and their parameters in an existing application

In the publication, we will look at how you can implement logging of jdbc operations into an existing application without rebuilding and recompiling it. This will make it possible to log query parameters that the program fills, and many other aspects of working with jdbc.

Well, if you have the opportunity to add log4jdbc to the application assembly.

com.googlecode.log4jdbclog4jdbc1.2

And use net.sf.log4jdbc.DriverSpy when creating the connection.

If this is not possible, then aspectj-scripting will help you with logging jdbc operations.

SonarQube remains the experimental program, as in articles about hawt.io/h2 and CRaSH-ssh . In these articles, the configuration process and the principle of aspectj-scripting were discussed in more detail and step-by-step instructions are given.

To log jdbc operations, change the sonar jvm startup parameters:
sonar.web.javaAdditionalOpts = -javaagent: aspectj-scripting-1.0-agent.jar -Dorg.aspectj.weaver.loadtime.configuration = config: file: h2_jdbc.xml

jvm accessibility is also required aspectj scripting agent and h2_jdbc.xml configuration file:

com.github.igorsuhorukov.JdbcLogAROUNDexecution(* org.apache.commons.dbcp.BasicDataSource.getConnection())
		log4jdbcresultUrls = com.github.smreed.dropship.MavenClassLoader.forMavenCoordinates("com.googlecode.log4jdbc:log4jdbc:1.2").getURLs();
		slf4jresultUrls = com.github.smreed.dropship.MavenClassLoader.forMavenCoordinates("org.slf4j:slf4j-simple:1.6.0").getURLs();
		resultUrls = new java.net.URL[log4jdbcresultUrls.length + slf4jresultUrls.length];
		System.arraycopy(log4jdbcresultUrls, 0, resultUrls, 0, log4jdbcresultUrls.length);
		System.arraycopy(slf4jresultUrls, 0, resultUrls, log4jdbcresultUrls.length, slf4jresultUrls.length);
		log4jdbcLoader = new java.net.URLClassLoader(resultUrls, Thread.currentThread().getContextClassLoader());
		log4jdbcLoader.loadClass("net.sf.log4jdbc.ConnectionSpy");
		currentLoader = java.lang.Thread.currentThread().getContextClassLoader();
		java.lang.Thread.currentThread().setContextClassLoader(log4jdbcLoader);
		res = new net.sf.log4jdbc.ConnectionSpy(joinPoint.proceed());
                java.lang.Thread.currentThread().setContextClassLoader(currentLoader);
		res;
            

This aspect allows you to intercept the getConnection () call of the BasicDataSource class from the common-dbcp library and return the ConnectionSpy wrapper to connect to the database. At the same time, classes from log4jdbc become available in the application by creating your class loader from maven artifacts in the local repository. aspectj-scripting loads the artifacts com.googlecode.log4jdbc: log4jdbc: 1.2 and org.slf4j: slf4j-simple: 1.6.0 based on the configuration you specified above. This works because we passed two additional parameters when starting jvm: " -javaagent " to start the aspectj-scripting agent and -Dorg.aspectj.weaver.loadtime.configuration to pass the configuration to it. And aspectj agent instrumented application classes when they are loaded.

The following loggers are available in the log4jdbc library:

• jdbc.sqlonly - Logs only SQL
• jdbc.sqltiming - Logs SQL and runtime
• jdbc.audit - Logs all JDBC API calls except working with ResultSet
• jdbc.resultset - All calls to the ResultSet are logged
• jdbc.connection - Logging open and close connections, useful for finding connection leaks

In conclusion, I will give a few examples from the logs of SonarQube, the web part of which is written in ruby ​​and runs in jruby:

[jdbc.connection] 2. Connection opened
[jdbc.connection] 81. Connection closed
[jdbc.sqltiming] select * from schema_migrations {executed in 4 msec}
[jdbc.audit] 7. PreparedStatement. setString (1, “sonar.core.id”) returned
[jdbc.audit] 9. PreparedStatement .setTimestamp (1, 2015-08-09 18: 49: 08.205) returned
[jdbc.audit] 9. PreparedStatement. setFetchSize (200) returned
[jdbc.audit] 14. Connection. prepareStatement(update metrics set best_value = ?, delete_historical_data = ?, description = ?, direction = ?, domain = ?, enabled = ?, hidden = ?, short_name = ?, optimized_best_value = ?, origin = ?, qualitative = ?, val_type = ?, user_managed = ?, worst_value =? where id =?) returned net.sf.log4jdbc.PreparedStatementSpy@6e22c0e5
[jdbc.resultset] 2. ResultSet. getMetaData () returned rsMeta0: columns = 1
[jdbc.resultset] 2. ResultSet. getType () returned 1003
[ jdbc.sqlonly ] select ar.id from analysis_reports ar where ar.report_status = 'PENDING' and not exists (select 1 from analysis_reports ar2 where ar.project_key = ar2.project_key and ar2.report_status = 'WORKING' ) order by ar.created_at asc, ar.id asc

The example described in the article, you can see in the screencast:



So, we were able to modify the configuration of jvm SonarQube so that all calls to the Jdbc API application with their parameters are recorded in its log file. I hope this publication is useful to you and you will find other ways to apply aspect-oriented programming for existing java programs