Logging better exception information in Java

Question

I am working on a largish Java web application with Spring, Hibernate, and some other libraries, including Apache log4j for logging. One of my ongoing projects is to rewrite a large number of exceptions in the legacy areas (which I didn't write!) of the code to give more sensible information. A typical exception block looks like this:

try {
  //Some Hibernate business here
}
catch (Exception e) {   //Yes, Exception. That's not just me being general. I find this especially frustrating.
  log4j.error("Fail to XXXXXX");   //again, real
  throw new MyException();
}

As you can guess, this makes for some challenging logs. I'm looking for a standard way to get better info out of these exceptions. Most of them wrap Hibernate calls, if that helps. Here's a typical block similar to one I just wrote:

try {
    myList.add( ((myClass) commonService.getRecordByTableId(myClass.class, ID)).toString() );
} catch (ServiceException e) {
    log4j.error("Failed to retrieve record from table myClass for id " + ID);
    e.printStackTrace();
}

Here I'm pulling a record from the database and adding it to a list. In the catch block I log what I think is a sensible message about what the try block is doing, and print a stack trace. So, my question: is there anything else I could/should be doing, in general, to get better information for diagnosing errors?

Guillaume · Accepted Answer · 2011-10-28 15:05:10Z

11

In exceptions handling, Logging and re-throwing is a popular anti-pattern. You shouldn't do that. You need to decide between catching the exception, then properly handling it (including logging), or not catching it and allowing it to pass to higher levels (or rethrow it / wrap it in a runtime exception if it was a checked exception).

If you do that (log + rethrow), then there's no way for the upstream code to know that you've already logged the exception, and so the same exception might get logged twice or more, depending how many layers the exception has to go through, and what layer arbitrarily decide to log and re-throw it. That will make reading the logs and undestanding them a complete nightmare.

Also you could argue that throwing and catching exceptions are costly operations, all this catching and rethrowing isn't helping your performance at runtime.

So if you choose to actually handle the exception, then swallowing it is not the right way (even if you log some message). At the very least, you need to log the trace:

log4j.error("Failed to retrieve record from table myClass for id " + ID, e);

answered Oct 28, 2011 at 15:05

Guillaume

22.9k15 gold badges59 silver badges70 bronze badges

Sign up to request clarification or add additional context in comments.

4 Comments

G_H Over a year ago

+1. Would give more points too, if I could. I'm so tired of seeing a stack trace with several "echoes" before it.

Guillaume Over a year ago

Yes, as am I. It's amazing how many "serious" developers consider logging and rethrowing to be a good enough handling for most exceptions.

andronikus Over a year ago

+1, good call. There's a lot about what has happened in this project that makes me very sad, and I'm trying to whip it into shape. :D

andronikus Over a year ago

Also, I love the word anti-pattern.

rsp · Accepted Answer · 2011-10-28 14:50:43Z

5

printStackTrace() does not add the trace to your log. Supplying the exception to log4j will print it to your logfile where the context makes sense:

log4j.error("Failed to retrieve record from table myClass for id " + ID, e);

answered Oct 28, 2011 at 14:50

rsp

23.4k6 gold badges59 silver badges72 bronze badges

Comments

vaughandroid · Accepted Answer · 2011-10-28 15:09:00Z

2

A couple of things in addition to what others have mentioned:

Make use of the different logging levels: info; warn; etc.
Following on from #1 I'd drop those printStackTrace() calls. If you want to log errors in the console, do it via the logger. That way you get the benefits of filtering levels even for the console.

answered Oct 28, 2011 at 15:09

vaughandroid

4,3741 gold badge30 silver badges34 bronze badges

Comments

Maurício Linhares · Accepted Answer · 2011-10-28 14:48:42Z

1

yep, in the very first block, it should be like this:

try {
  //Some Hibernate business here
}
catch (Exception e) {   //Yes, Exception.  That's not just me being general
  log4j.error("Fail to XXXXXX", e);   //again, real
  throw new MyException(e);
}

Java allows you to chain exceptions so you should do it. Also, when using Log4J you can also send the exception so it will print the exception stack trace in your logs too.

answered Oct 28, 2011 at 14:48

Maurício Linhares

40.4k15 gold badges127 silver badges160 bronze badges

Collectives™ on Stack Overflow

Logging better exception information in Java

4 Answers 4

4 Comments

Comments

Comments

Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

4 Answers 4

4 Comments

Comments

Comments

Comments

Your Answer

Sign up or log in

Post as a guest

Related