Any reason not to always log stack traces?

Question

Encountered a frustrating problem in our application today which came down to an ArrayIndexOutOfBounds exception being thrown. The exception's type was just about all that was logged which is fairly useless (but, oh dear legacy app, we still love you, mostly). I've redeployed the application with a change which logs the stack trace on exception handling (and immediately found the root cause of the problem) and wondered why no one else did this before. Do you generally log the stack trace and is there any reason you wouldn't do this?

Bonus points if you can explain (why, not how) the rationale behind having to jump hoops in java to get a string representation of a stack trace!

Answer 1

Restrictions on logging are often pushed through when developers log too liberally and sysadmins discover that the app, once put under a production load, thrashes and fills the HD with huge log files. It can then be hard to convince them that you've seen the error of your ways and have reduced logging (or adjusted log levels) sufficiently but really need those remaining log entries.

Answer 2

• Some logs might contain sensitive data, log facilities are not necessarily secure enough to track that data in production.

• Logging to much can result in too much information, i.e. no information at all for the sysadmins. If their logs are filled up with debug messages, they won't be able to recognize suspicious patterns. (Years ago I saw a system logging all system calls for security reasons. There were so many logs, that nobody saw it when some unprivileged users started to become root.)

Best thing to do to log everything with appropriate log levels, and be able to set log levels in production (at least in Java not that a big issue).

Answer 3

I generally do log the stack trace, because it has information for troubleshooting/debugging the problem. It's the best think next to a minidump and often leads to a solution simply by code inspection and identifying the problem.

BTW, I agree with sibidiba about the potential information disclosure about your app internals a full stack exposes: the function names, along with the stack call sequence, can tell a lot to an educated reader. This is the reason why some products only log the symbol address on the stack, and rely on the devs to resolve the address to the name from internal pdbs.

But in I reckon that logging text into files containing 1 line of error and 14 lines of stack makes it very difficult to navigate the error logs. It also causes problem on high concurency apps because the lock on the log file is held longer (or worse, the log files get interleaved). Having encountered these problems my self many times, along with other issues in supporting and troubleshooting deployments of my own apps, led me to actually create a service for logging errors at bugcollect.com. When designing the error collection policies I chose to collect the stack dumps every time, and to use the stacks as part of the bucket keys (to group errors that happen on the same stack into same bucket).

Answer 4

For us it is very simple: If there is an unexpected exception thrown, we log the stack trace along with as telling a message as possible.

My guess is that the developer who wrote the original code in the question, simply wasn't experienced enough to know that it is not enough with just the message. I thought so too, once.

The reason why it is convoluted to get a stack trace as a string is because there is no StringPrintWriter in the JRE - I believe the line of thinking has been that they provide a lot of orthogonal building blocks which you then combine as needed. You have to assemble the needed PrintWriter yourself.

Answer 5

Please see these questions also

Logging in Java and in general: Best Practices?

Best practices for Java logging from multiple threads?

Important things here to consider

1. Handling Sensitive data
2. Compact exception messages and mailing those to appropriate fixers
3. Logging what is required. Because its logging expensive in terms space and time

Answer 6

Bonus points if you can explain (why, not how) the rationale behind having to jump hoops in java to get a string representation of a stack trace!

Shouldn't you just log the throwable instead of going through hoops to print the stacktrace? Like this: log.error("Failed to deploy!", ex). Given a throwable, Log4J will print both the error message obtained via getMessage() and the stack trace.

Answer 7

What I've seen a lot is code logging an exception like this:

LOG.error(ex);

Because log4j accepts an Object as the first argument, it will log the String representation of the Exception, which is often only the name of the class. This is usually just an oversight on the developer's part. It's better to log and error like this:

LOG.error("foo happened", ex);

..so that if configured properly, the logging framework will log the stack trace.