views:

379

answers:

6

Background

In my current project - a server product with no GUI front-end, I'm trying to write in better error handling support. Errors currently are outputted to the logs and are typically not read by users.

We use PostgreSQL as our database backend and we access it using direct JDBC calls and DAOs via a database pooler. Most database related exceptions are wrapped in a generic DatabaseException class that implements RuntimeException and attempts to pull out debugging and state information from the exception it was passed. In our particular case, it will access the underlying PostgreSQL database driver - PSQLException. So far this approach has worked well for getting more verbose information about what caused the database error, with the notable exception described below.

Furthermore, since we have very specific performance and legacy support requirements we have a lot of custom SQL magic that makes the following the stack trace back a bit more time intensive but not impossible or difficult.

Problem Described

I have noticed that when we get a SQLException as a result of a faulty SQL statement, the driver's implementation does not return the SQL statement that caused the error. After doing a little searching, I found out that there is a way to drop the PostgreSQL driver into a debug mode on startup and have it display properties about its internal query. However, it is undesirable for us to run the driver in debug mode in our production environment (and honestly I haven't been able to figure out how to get it into the freakin mode!).

Question

Has anyone else dealt with this same issue before and found a solution? If not, is there some OOP pattern out there for storing query information before execution and then assigning that information to the exception thrown? Or do most developers just feel that they don't need the full query to troubleshoot database issues? Honestly, I don't need it because I have the full stack trace and I can look up the invoking query, but it definitely speeds up my debugging by having it be the first thing that I see in the error logs.

A: 

The stacktrace can point you to the DAO method that caused the problem, isn't that the case?

Edit after comment: If your SQL query is complex and dynamically generated from previous parts of the code then you could log (level TRACE or DEBUG) these statements before executing them. In the logging configuration you could enable logs only for the DAO(s).

cherouvim
For the case of DAO methods that approach works fairly well. However, in the case of some of our more complex SQL statements invoked via JDBC it is a little more complicated because we get a trace to the execute method and we then have to work are we back to where the statement/prepare was defined.
Elijah
+1  A: 

I am assuming that when you make the call to execute the query you have the statement, and you receive the Exception, so at that point you have both. It seems like you could do your analysis there.

However, maybe you're catching things further up. So, what you might do is on your own custom subclass of Exception, DatabaseException, add a triggeringSQLStatement member with a getter and setter, and then at the place where you attempt to execute the statement, catch the original Exception from PostgreSQL, create a new DatabaseException, set the triggeringSQLStatement to be the statement you just executed, and call initCause() on the DatabaseException to set the Exception caught from PostgreSQL as the cause of your exception; then throw your DatabaseException and the calling code which catches it will have an object that prints out a very decent stack trace of what happened plus provides access to the SQL statement that caused the problem. For more information on this approach, you might want to research Java Exception chaining. Even if you don't use all of what I just described, I think you should definitely be using Java Exception chaining already.

If there's not a spot anywhere in the code where you have access to both the SQL statement that caused the problem and the Exception that gets thrown, I'd be very curious as to why, and how that is possible. And I'd suggest you redesign your code so that you do have such a spot.

Edit: Since you're wanting to see the SQL statement first thing in the log, you could probably also override your DatabaseException's toString() method (or other appropriate methods; I'm not sure what gets called when an Exception is printed out) to print out the included SQL statement, assuming you included it as I described above.

skiphoppy
+2  A: 

I used to add the SQL query in my custome Exception object when ever there is an SQLException. In the code where ever I am logging the exception details in log file, I used to log the SQL also.

Bhushan
Its better to log the parameters as well. +1
Adeel Ansari
A: 

Why not add a file logger around all JDBC calls (log4j)?

Whenever you make a SQL call you log the SQL and how long it took to execute. Simple stuff.

We do this for any call to an external system E.g. SOAP calls, RMI, Corba, etc. Its proved invaluable almost every day and if it affects performance.. I haven't noticed!

If you have security concerns i.e. don't want it to go to a log file on a client machine, you could use a SocketAppender and send it to a remote machine for centralised logging purposes. This won't be totally secure but would stop the casual snooper.

Fortyrunner
+1  A: 

The easiest way to do this I think is to use a third party product like p6spy. It gets in between your jdbc driver and your database and reports the exact queries that are run. It's very easy to run on demand as it's implemented as another JDBC driver that will delegate to your actual JDBC driver. Very powerful tool that I can't imagine working without.

http://www.p6spy.com/

bwobbones
A: 

Another solution to spy on the queries you are executing is pgFouine which analyses and reports on the logs generated by Postgres

j pimmel