What Is a Stack Trace, and How to Use It to Debug My Application Errors

What is a stack trace, and how can I use it to debug my application errors?

In simple terms, a stack trace is a list of the method calls that the application was in the middle of when an Exception was thrown.

Simple Example

With the example given in the question, we can determine exactly where the exception was thrown in the application. Let's have a look at the stack trace:

Exception in thread "main" java.lang.NullPointerException
at com.example.myproject.Book.getTitle(Book.java:16)
at com.example.myproject.Author.getBookTitles(Author.java:25)
at com.example.myproject.Bootstrap.main(Bootstrap.java:14)

This is a very simple stack trace. If we start at the beginning of the list of "at ...", we can tell where our error happened. What we're looking for is the topmost method call that is part of our application. In this case, it's:

at com.example.myproject.Book.getTitle(Book.java:16)

To debug this, we can open up Book.java and look at line 16, which is:

15   public String getTitle() {
16 System.out.println(title.toString());
17 return title;
18 }

This would indicate that something (probably title) is null in the above code.

Example with a chain of exceptions

Sometimes applications will catch an Exception and re-throw it as the cause of another Exception. This typically looks like:

34   public void getBookIds(int id) {
35 try {
36 book.getId(id); // this method it throws a NullPointerException on line 22
37 } catch (NullPointerException e) {
38 throw new IllegalStateException("A book has a null property", e)
39 }
40 }

This might give you a stack trace that looks like:

Exception in thread "main" java.lang.IllegalStateException: A book has a null property
at com.example.myproject.Author.getBookIds(Author.java:38)
at com.example.myproject.Bootstrap.main(Bootstrap.java:14)
Caused by: java.lang.NullPointerException
at com.example.myproject.Book.getId(Book.java:22)
at com.example.myproject.Author.getBookIds(Author.java:36)
... 1 more

What's different about this one is the "Caused by". Sometimes exceptions will have multiple "Caused by" sections. For these, you typically want to find the "root cause", which will be one of the lowest "Caused by" sections in the stack trace. In our case, it's:

Caused by: java.lang.NullPointerException <-- root cause
at com.example.myproject.Book.getId(Book.java:22) <-- important line

Again, with this exception we'd want to look at line 22 of Book.java to see what might cause the NullPointerException here.

More daunting example with library code

Usually stack traces are much more complex than the two examples above. Here's an example (it's a long one, but demonstrates several levels of chained exceptions):

javax.servlet.ServletException: Something bad happened
at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.example.myproject.ExceptionHandlerFilter.doFilter(ExceptionHandlerFilter.java:28)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.example.myproject.OutputBufferFilter.doFilter(OutputBufferFilter.java:33)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:943)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: com.example.myproject.MyProjectServletException
at com.example.myproject.MyServlet.doPost(MyServlet.java:169)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:30)
... 27 more
Caused by: org.hibernate.exception.ConstraintViolationException: could not insert: [com.example.myproject.MyEntity]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.id.insert.AbstractSelectingDelegate.performInsert(AbstractSelectingDelegate.java:64)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2329)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2822)
at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:71)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:268)
at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:321)
at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:204)
at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:130)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:210)
at org.hibernate.event.def.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:56)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:195)
at org.hibernate.event.def.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:50)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:93)
at org.hibernate.impl.SessionImpl.fireSave(SessionImpl.java:705)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:693)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:689)
at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:344)
at $Proxy19.save(Unknown Source)
at com.example.myproject.MyEntityService.save(MyEntityService.java:59) <-- relevant call (see notes below)
at com.example.myproject.MyServlet.doPost(MyServlet.java:164)
... 32 more
Caused by: java.sql.SQLException: Violation of unique constraint MY_ENTITY_UK_1: duplicate value(s) for column(s) MY_COLUMN in statement [...]
at org.hsqldb.jdbc.Util.throwError(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeUpdate(Unknown Source)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
at org.hibernate.id.insert.AbstractSelectingDelegate.performInsert(AbstractSelectingDelegate.java:57)
... 54 more

In this example, there's a lot more. What we're mostly concerned about is looking for methods that are from our code, which would be anything in the com.example.myproject package. From the second example (above), we'd first want to look down for the root cause, which is:

Caused by: java.sql.SQLException

However, all the method calls under that are library code. So we'll move up to the "Caused by" above it, and in that "Caused by" block, look for the first method call originating from our code, which is:

at com.example.myproject.MyEntityService.save(MyEntityService.java:59)

Like in previous examples, we should look at MyEntityService.java on line 59, because that's where this error originated (this one's a bit obvious what went wrong, since the SQLException states the error, but the debugging procedure is what we're after).

How to use a stack trace dump to debug an exception?

With just that stacktrace alone, you're probably not going to get very far. Those first 5 lines are stackframes, but there is no context likely due to lack of symbols.

If by trace dump, you mean memory dump, then you have a few options for debugging.

1) You can open the dump in Visual Studio - probably the easiest -- see here:
http://msdn.microsoft.com/en-us/library/d5zhxt22.aspx

2) You can open the dump using WinDBG
There's a bit of a learning curve, but it is a neat skill to have. I always point folks to Tess's blog to ramp on this. The posts are old, but still relevant:
http://blogs.msdn.com/b/tess/archive/2008/02/04/net-debugging-demos-information-and-setup-instructions.aspx

If I were handed this stacktrace, I wouldn't waste a ton of time trying to determine what it means. I'd repro the issue and capture a crash dump and use one of the techniques above to determine root cause.

How to read and understand the java stack trace?

Generally the exact reason for the Exception is at the first line of your Stack Trace, and for more information about the cause of that exception, you need to gradually move down, and the root cause can often be found somewhere near the bottom of the stack trace.

But in most cases, you can even get the cause of the exception from the first few lines..

So, in this case, your exception is at handleRequest method, and when you move downwards, those are the methods, which invoked your previous method (The one at above the current method in stack trace)

Java: what information in error stack trace do we typically not wish to show users?

You shouldn't show any of that gobbledygook to your users. It's meaningless to most of them and doesn't help you. As you suspect, it also exposes internals of your implementation that may suggest vulnerabilities that a malicious user might be able to use.

Instead, you should catch exceptions, log them, and show a more comprehensible error message to your users. You can use getMessage() to extract the message part of an exception. If the exception has no message, then show something like "no details available".

UPDATE:

I have some comments based on the question update. First, I would totally insulate the user from any of the internals of your system, both to be kind to the user and for security. (For instance, even knowing that you are using the java.sql package may suggest vulnerabilities to a clever hacker.) So do not use the exception message, the first line of the stack trace, or anything like that when displaying anything to the user.

Second, you should be mapping all errors from the exception level (at which they are experienced in your code) to messages that are at the right level of abstraction for the user. The proper way to do that would depend on the internals of your system and what the user might have been trying to do when the exception was raised. This might mean structuring your system into layers such that each layer that catches an exception translates it into an exception at a higher layer of abstraction. A Java exception can wrap another exceptions (the cause). For instance:

public boolean copyFile(File source, File destination) throws CopyException {
try {
// lots of code
return true;
} catch (IOException e) {
throw new CopyException("File copy failed", e);
}
}

Then this could be used at a higher level in a User class:

public boolean shareFile(File source, User otherUser) throws ShareException {
if (otherUser.hasBlocked(this) {
throw new ShareException("You cannot share with that user.");
}
try {
return copyFile(source, otherUser.getSharedFileDestination(source));
} catch (CopyException e) {
throw new ShareException("Sharing failed due to an internal error", e);
}
}

(I hope it's clear that the above code is meant to illustrate the idea of converting exceptions to higher levels of abstraction, not as a suggestion for code that you should use in your system.)

The reason that you want to handle things like this (instead of somehow massaging the message and/or stack trace) is that an exception (for instance an IOException with message "permission denied") may mean totally different things to the user (and to your system) in different contexts.

Tried to print stack trace using logback but stack trace is not printing

e.toString() will just print the error message.

If you want to print the complete stacktrace , use the error method :

LOGGER.error("Exception occurred",e)

https://logging.apache.org/log4j/2.x/log4j-api/apidocs/org/apache/logging/log4j/Logger.html#error-java.lang.String-java.lang.Throwable-

If you need to extract out full stack trace , checkout the following util method from apache common :

LOGGER.info("Exception : ",ExceptionUtils.getStackTrace(e));

https://commons.apache.org/proper/commons-lang/javadocs/api-2.6/org/apache/commons/lang/exception/ExceptionUtils.html#getFullStackTrace(java.lang.Throwable)

Silence Javascript stack traces in htmlunit

You have to customize the log configuration.
Please have a look at https://htmlunit.sourceforge.io/logging.html.



Related Topics



Leave a reply



Submit