Welcome!

Java IoT Authors: Automic Blog, Liz McMillan, Elizabeth White, Pat Romanski, Roger Strukhoff

Related Topics: Java IoT

Java IoT: Article

Java Cover Story — Debugging JDBC with a Logging Driver

A new way to debug and solve DB problems

A couple of years ago I began developing in Java, and my first Java project required that I also learn SQL. Our project team was using mostly EJBs for database access, although for some performance-critical sections of the application we wrote the JDBC logic directly. A problem that we faced regularly was tracking the bind parameters to our PreparedStatements. Over the course of the project, all of the team members tried different techniques to determine what our JDBC statements were actually doing.

This article presents a solution that one of the developers created to help solve this problem. I took his original idea and extended it after I left that team to help my next company solve the same problem. The solution is a JDBC driver that uses log4j to print all SQL statements and any bound parameters to the application's log file.

Most JDBC developers have faced the problem of having to debug SQL statements in their applications. While this sounds like a relatively easy task, it's often error-prone, and results in code that is hard to maintain and that clutters otherwise clean application logic. An example of this type of logic is:

PreparedStatement ps = conn.prepareStatement("Select * from users " + "where id = ?");
log.debug("Select * from users where id = ?");
ps.setInt(1, x);
log.debug("1: " + x);

This solution has some obvious problems. The first problem is that you have duplicated all of the bind parameters and the SQL statement in the code. If either the SQL statement or the parameter that you want to bind to the statement changes, you must remember to update the log statement as well. If you forget to update either log statement, your log will be useless when you try to debug your next problem. Also, because of the performance of using log.debug, most people put those statements in an if block, making the code that much harder to read.

The next problem with this model is that you don't have a centralized location to enable debug logging. When a QA developer reports a bug that you have never seen in your dev testing, the best place to start is to enable more detailed logging to determine what is going wrong. With the above code, you must either enable all debug logging, which is often data overload, or you need to debug the problem enough to determine which class is causing the problem.

The final problem with this system is most important when using a system like Hibernate. Hibernate is an object-relational mapping tool that also defines its own SQL-like language, HQL. The problem with this is that in your Java code, you don't have access to the actual SQL statement that is executed; you only have the HQL statement. In a previous job, we had a problem like this. The SQL statement translated to:

Select * from Sessions where id = ? and subId = ? and user = ? and list = ?

The developer using this statement spent days poring over this query trying to determine why it wasn't returning any data when we expected a list with 10 elements in it. The final answer turned out to be that the final bind parameter was being passed in as NULL. Since the details of the SQL statement had been abstracted out by HQL, this problem wasn't clear. We discovered this by accident after reading the log file as a group. The rest of this article will focus on a better answer that would have shown us the problem immediately.

The Logging JDBC Driver
The idea behind this project has some concepts in common with aspect-oriented programming (AOP). The basic thought process is that there are some problems that are found throughout a project, and the solution to those problems shouldn't require programmers to remember to add special logic every time one of these problems comes up. Instead, the programming framework that you are using should create solutions to these problems for you. In this case, our problem is determining exactly what SQL queries are being run and with which parameters.

Working to our advantage with SQL queries, they all must go through a JDBC driver, so if we can find a way to log the correct information in the driver, the rest of the application won't have to change. That is the goal of the logdriver, available at www.rkbloom.net/logdriver under the Apache 2.0 License.

The driver currently logs comprehensive debug information for Statements, PreparedStatements, and CallableStatements and some important actions on the Connection. The primary data being logged is the SQL query and any bind parameters. There are two formats that can be used. The first separates the SQL from the bind parameters:

executing PreparedStatement: 'insert into ECAL_USER_APPT
(appt_id, user_id, accepted, scheduler, id) values (?, ?, ?, ?, null)'
     with bind parameters: {1=25, 2=49, 3=1, 4=1}

The second format is enabled by setting the system property replace.bindParams to either 1or true. This format tries its best to insert the bind parameters into the SQL query:

executing PreparedStatement: insert into ECAL_USER_APPT
(appt_id, user_id, accepted, scheduler, id) values (25, 49, 1, 1, null)

Both formats have their advantages, but most of the time it's better to use the default format. The biggest argument against using the second format is that for string parameters the logging driver doesn't attempt to escape the string. While this isn't a security concern at all, it does make it harder to read the SQL and understand it correctly. The format is similar for CallableStatements, but the driver includes information about the type of the parameter.

Configuring the Logging Driver
Configuration of this driver is relatively straightforward. Instead of using your standard JDBC driver, configure your application to use net.rkbloom.logdriver.LogDriver, and your connection URL should be changed to use the following format:

jdbc:log:real_driver_class:real_jdbc_connection_string

If your original connection URL was "jdbc:oracle:thin:@ local-host:1521:FOOBAR", your new URL would be: "jdbc:log:com.oracle.jdbc.OracleDriver:oracle:thin:@localhost:1521:FOOBAR". The logdriver.jar file must be on your classpath, but so must the JAR file with the original JDBC driver. Under the covers, the logDriver will create an instance of your desired JDBC driver and call it for all operations. With just that change your application will be using the logDriver, but you won't see any log messages by default.

To enable logging, you must configure the logging system. The logDriver uses log4j for all logging, so you will need to configure your log4j.properties file to log all net.rk-bloom.logdriver classes to log in debug mode. The log-Driver uses debug mode for all logging because of the performance implications of doing so much logging. It would be possible to modify the driver to use either commons-logging or the java.util.logging, but I only use log4j, so I went for the easiest solution.

Advantages of the Driver
I have used this driver beyond just debugging my SQL queries when applications don't behave as I expect. When using Hibernate, I have found that many developers don't understand how many queries a simple query can invoke. By enabling the logDriver, I have been able to isolate performance problems in my Hibernate-based applications and use that information to modify my mapping files to reduce the number of SQL queries used.

Because the logDriver intercepts all SQL queries regardless of how they are invoked, I have found this solution to work better than the options that Hibernate provides. In most of my DB applications, I use a combination of either EJBs or Hibernate with direct JDBC calls. By moving the logging into a single location, I am able to track all SQL interaction with a single configuration change. This can be invaluable when QA reports a bug that can't be explained quickly.

Limitations with the System
For all of the benefits of the logDriver, there are a few limitations. First, you can't enable logging of SQL statements on a per-class basis. Ideally, you would be able to configure the logDriver to log queries for the Foo class, but not the Bar class. If the log statements were embedded in the classes, this would be possible with any of the logging systems; however, since the logging statements are in a common class, it can't be done natively. One possible solution to this is to include a configuration system for the logDriver that would allow the driver to inspect the call stack to determine if the logging statements should be executed. Because this system is intended for developers, it's easier to ask developers to isolate the methods called.

The second limitation is that this solution has a big impact on performance. The more DB operations you perform, the slower this driver performs. This makes sense, because logging is always a potential performance problem for Java applications, and the point of this solution is to log a lot of data. While logging can slow down the application, again this solution is intended for development, not production, so performance should not be a big consideration.

The final limitation is that we cannot log the results of the queries. The problem is that not all ResultSets are rewindable, so if we try to log the ResultSet, it is possible that we will consume the data, making it unusable for the application. While logging that data would be useful, the implications of doing so make it impractical.

Conclusion
I hope that I have shown you a new way to debug and solve DB problems in your Java applications. I would like to thank Jonathan Cobb for creating the original version of this driver, which inspired me to re-create it when I began to encounter similar problems.

More Stories By Ryan Bloom

Ryan Bloom is a development manager at Peopleclick, an HR software company. He has a history of open source development with the Apache Software Foundation, including working on Apache 2.0.

Comments (8) View Comments

Share your thoughts on this story.

Add your comment
You must be signed in to add a comment. Sign-in | Register

In accordance with our Comment Policy, we encourage comments that are on topic, relevant and to-the-point. We will remove comments that include profanity, personal attacks, racial slurs, threats of violence, or other inappropriate material that violates our Terms and Conditions, and will block users who make repeated violations. We ask all readers to expect diversity of opinion and to treat one another with dignity and respect.


Most Recent Comments
Good grief 04/28/06 08:42:04 PM EDT

P6Spy has done this for years, is completely open source, and has support tools. Why on earth do people not bother to resarch these things - and how on earth did this article get past the editors

SYS-CON Australia News Desk 04/28/06 12:09:49 PM EDT

A couple of years ago I began developing in Java, and my first Java project required that I also learn SQL. Our project team was using mostly EJBs for database access, although for some performance-critical sections of the application we wrote the JDBC logic directly. A problem that we faced regularly was tracking the bind parameters to our PreparedStatements. Over the course of the project, all of the team members tried different techniques to determine what our JDBC statements were actually doing.

SYS-CON India News Desk 04/27/06 02:25:42 PM EDT

A couple of years ago I began developing in Java, and my first Java project required that I also learn SQL. Our project team was using mostly EJBs for database access, although for some performance-critical sections of the application we wrote the JDBC logic directly. A problem that we faced regularly was tracking the bind parameters to our PreparedStatements. Over the course of the project, all of the team members tried different techniques to determine what our JDBC statements were actually doing.

JDJ News Desk 04/27/06 01:49:21 PM EDT

A couple of years ago I began developing in Java, and my first Java project required that I also learn SQL. Our project team was using mostly EJBs for database access, although for some performance-critical sections of the application we wrote the JDBC logic directly. A problem that we faced regularly was tracking the bind parameters to our PreparedStatements. Over the course of the project, all of the team members tried different techniques to determine what our JDBC statements were actually doing.

Vajee Uddin 04/21/06 02:39:55 AM EDT

I have implemented spy6log for logging the JBDC statements executed. It not only logs the queries but also the resultsets.

Check this out. I would like to know you comments and views on this tool.

Shilpa 04/19/06 03:50:23 PM EDT

Hi, I tried using the LogDriver and it did not work for me. The problem i faced is that it was not able to get a connection. I was using jdbc:log:oracle.jdbc.driver.OracleDriver:oracle:thin as the URL for database connection. It did not seem to work. Is there any formal documentation available for the Logdriver? Please let me know. It would be great if I get it working. Thanks.

William Louth 04/18/06 09:43:57 PM EDT

JDBInsight (now a sub component of JXInsight) has been in production at some very large J2EE sites for the last 3 years. Honestly there was simply no need for another logging driver especially as most implementations are extremely primitive only performing System.out calls.

You should have checked out the following links to see the tooling that is required for enterprise production systems in both test and production modes.

http://www.jinspired.com/products/jxinsight/new-in-2.1.html
http://www.jinspired.com/products/jxinsight/new-in-2.5.html
http://www.jinspired.com/products/jxinsight/new-in-3.0.html
http://www.jinspired.com/products/jxinsight/new-in-3.1.html
http://www.jinspired.com/products/jxinsight/new-in-3.2.html
http://www.jinspired.com/products/jxinsight/new-in-4.0.html
http://www.jinspired.com/products/jxinsight/new-in-4.1.html

William Louth
JXInsight Product Architect
JInspired

"J2EE tuning, testing and tracing with JXInsight"
http://www.jinspired.com

Thorbjørn 04/18/06 07:06:34 AM EDT

Is there any particular reason that you chose to write your own instead of using the p6spy driver which AFAIK does the same?

@ThingsExpo Stories
Nordstrom is transforming the way that they do business and the cloud is the key to enabling speed and hyper personalized customer experiences. In his session at 21st Cloud Expo, Ken Schow, VP of Engineering at Nordstrom, discussed some of the key learnings and common pitfalls of large enterprises moving to the cloud. This includes strategies around choosing a cloud provider(s), architecture, and lessons learned. In addition, he covered some of the best practices for structured team migration an...
Recently, REAN Cloud built a digital concierge for a North Carolina hospital that had observed that most patient call button questions were repetitive. In addition, the paper-based process used to measure patient health metrics was laborious, not in real-time and sometimes error-prone. In their session at 21st Cloud Expo, Sean Finnerty, Executive Director, Practice Lead, Health Care & Life Science at REAN Cloud, and Dr. S.P.T. Krishnan, Principal Architect at REAN Cloud, discussed how they built...
In his session at 21st Cloud Expo, Raju Shreewastava, founder of Big Data Trunk, provided a fun and simple way to introduce Machine Leaning to anyone and everyone. He solved a machine learning problem and demonstrated an easy way to be able to do machine learning without even coding. Raju Shreewastava is the founder of Big Data Trunk (www.BigDataTrunk.com), a Big Data Training and consulting firm with offices in the United States. He previously led the data warehouse/business intelligence and B...
In his Opening Keynote at 21st Cloud Expo, John Considine, General Manager of IBM Cloud Infrastructure, led attendees through the exciting evolution of the cloud. He looked at this major disruption from the perspective of technology, business models, and what this means for enterprises of all sizes. John Considine is General Manager of Cloud Infrastructure Services at IBM. In that role he is responsible for leading IBM’s public cloud infrastructure including strategy, development, and offering m...
With tough new regulations coming to Europe on data privacy in May 2018, Calligo will explain why in reality the effect is global and transforms how you consider critical data. EU GDPR fundamentally rewrites the rules for cloud, Big Data and IoT. In his session at 21st Cloud Expo, Adam Ryan, Vice President and General Manager EMEA at Calligo, examined the regulations and provided insight on how it affects technology, challenges the established rules and will usher in new levels of diligence arou...
The 22nd International Cloud Expo | 1st DXWorld Expo has announced that its Call for Papers is open. Cloud Expo | DXWorld Expo, to be held June 5-7, 2018, at the Javits Center in New York, NY, brings together Cloud Computing, Digital Transformation, Big Data, Internet of Things, DevOps, Machine Learning and WebRTC to one location. With cloud computing driving a higher percentage of enterprise IT budgets every year, it becomes increasingly important to plant your flag in this fast-expanding busin...
Smart cities have the potential to change our lives at so many levels for citizens: less pollution, reduced parking obstacles, better health, education and more energy savings. Real-time data streaming and the Internet of Things (IoT) possess the power to turn this vision into a reality. However, most organizations today are building their data infrastructure to focus solely on addressing immediate business needs vs. a platform capable of quickly adapting emerging technologies to address future ...
No hype cycles or predictions of a gazillion things here. IoT is here. You get it. You know your business and have great ideas for a business transformation strategy. What comes next? Time to make it happen. In his session at @ThingsExpo, Jay Mason, an Associate Partner of Analytics, IoT & Cybersecurity at M&S Consulting, presented a step-by-step plan to develop your technology implementation strategy. He also discussed the evaluation of communication standards and IoT messaging protocols, data...
22nd International Cloud Expo, taking place June 5-7, 2018, at the Javits Center in New York City, NY, and co-located with the 1st DXWorld Expo will feature technical sessions from a rock star conference faculty and the leading industry players in the world. Cloud computing is now being embraced by a majority of enterprises of all sizes. Yesterday's debate about public vs. private has transformed into the reality of hybrid cloud: a recent survey shows that 74% of enterprises have a hybrid cloud ...
22nd International Cloud Expo, taking place June 5-7, 2018, at the Javits Center in New York City, NY, and co-located with the 1st DXWorld Expo will feature technical sessions from a rock star conference faculty and the leading industry players in the world. Cloud computing is now being embraced by a majority of enterprises of all sizes. Yesterday's debate about public vs. private has transformed into the reality of hybrid cloud: a recent survey shows that 74% of enterprises have a hybrid cloud ...
DevOps at Cloud Expo – being held June 5-7, 2018, at the Javits Center in New York, NY – announces that its Call for Papers is open. Born out of proven success in agile development, cloud computing, and process automation, DevOps is a macro trend you cannot afford to miss. From showcase success stories from early adopters and web-scale businesses, DevOps is expanding to organizations of all sizes, including the world's largest enterprises – and delivering real results. Among the proven benefits,...
@DevOpsSummit at Cloud Expo, taking place June 5-7, 2018, at the Javits Center in New York City, NY, is co-located with 22nd Cloud Expo | 1st DXWorld Expo and will feature technical sessions from a rock star conference faculty and the leading industry players in the world. The widespread success of cloud computing is driving the DevOps revolution in enterprise IT. Now as never before, development teams must communicate and collaborate in a dynamic, 24/7/365 environment. There is no time to wait...
Cloud Expo | DXWorld Expo have announced the conference tracks for Cloud Expo 2018. Cloud Expo will be held June 5-7, 2018, at the Javits Center in New York City, and November 6-8, 2018, at the Santa Clara Convention Center, Santa Clara, CA. Digital Transformation (DX) is a major focus with the introduction of DX Expo within the program. Successful transformation requires a laser focus on being data-driven and on using all the tools available that enable transformation if they plan to survive ov...
SYS-CON Events announced today that T-Mobile exhibited at SYS-CON's 20th International Cloud Expo®, which will take place on June 6-8, 2017, at the Javits Center in New York City, NY. As America's Un-carrier, T-Mobile US, Inc., is redefining the way consumers and businesses buy wireless services through leading product and service innovation. The Company's advanced nationwide 4G LTE network delivers outstanding wireless experiences to 67.4 million customers who are unwilling to compromise on qua...
SYS-CON Events announced today that Cedexis will exhibit at SYS-CON's 21st International Cloud Expo®, which will take place on Oct 31 - Nov 2, 2017, at the Santa Clara Convention Center in Santa Clara, CA. Cedexis is the leader in data-driven enterprise global traffic management. Whether optimizing traffic through datacenters, clouds, CDNs, or any combination, Cedexis solutions drive quality and cost-effectiveness. For more information, please visit https://www.cedexis.com.
SYS-CON Events announced today that Google Cloud has been named “Keynote Sponsor” of SYS-CON's 21st International Cloud Expo®, which will take place on Oct 31 – Nov 2, 2017, at the Santa Clara Convention Center in Santa Clara, CA. Companies come to Google Cloud to transform their businesses. Google Cloud’s comprehensive portfolio – from infrastructure to apps to devices – helps enterprises innovate faster, scale smarter, stay secure, and do more with data than ever before.
SYS-CON Events announced today that Vivint to exhibit at SYS-CON's 21st Cloud Expo, which will take place on October 31 through November 2nd 2017 at the Santa Clara Convention Center in Santa Clara, California. As a leading smart home technology provider, Vivint offers home security, energy management, home automation, local cloud storage, and high-speed Internet solutions to more than one million customers throughout the United States and Canada. The end result is a smart home solution that sav...
SYS-CON Events announced today that Opsani will exhibit at SYS-CON's 21st International Cloud Expo®, which will take place on Oct 31 – Nov 2, 2017, at the Santa Clara Convention Center in Santa Clara, CA. Opsani is the leading provider of deployment automation systems for running and scaling traditional enterprise applications on container infrastructure.
SYS-CON Events announced today that Nirmata will exhibit at SYS-CON's 21st International Cloud Expo®, which will take place on Oct 31 – Nov 2, 2017, at the Santa Clara Convention Center in Santa Clara, CA. Nirmata provides a comprehensive platform, for deploying, operating, and optimizing containerized applications across clouds, powered by Kubernetes. Nirmata empowers enterprise DevOps teams by fully automating the complex operations and management of application containers and its underlying ...
SYS-CON Events announced today that Opsani to exhibit at SYS-CON's 21st Cloud Expo, which will take place on October 31 through November 2nd 2017 at the Santa Clara Convention Center in Santa Clara, California. Opsani is creating the next generation of automated continuous deployment tools designed specifically for containers. How is continuous deployment different from continuous integration and continuous delivery? CI/CD tools provide build and test. Continuous Deployment is the means by which...