How to Read and Understand the Java Stack Trace

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)

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 read the full stacktrace in Java where it says e.g. ... 23 more

The answer is simple, those lines are already in the stacktrace :)

 at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880)
at com.azurian.lce.usuarios.ConnectionManager.getConnection(ConnectionManager.java:65)
at com.azurian.lce.usuarios.db2.UsuarioDAOImpl.autenticar(UsuarioDAOImpl.java:101)
at com.azurian.lce.usuarios.UsuarioServiceImpl.autenticar(UsuarioServiceImpl.java:31)
at com.azurian.lce.web.admin.actions.LoginAction.execute(LoginAction.java:49)
at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:525)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:852)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
at java.lang.Thread.run(Unknown Source)

Basically, the following is happening in BasicDataSource#createDataSource():

try {
Class.forName(driverClassName); // Line 1130
} catch (ClassNotFoundException e) {
throw new SQLNestedException(e, "Cannot load JDBC driver class '" + driverClassName + "'"); // Line 1136
}

How do I read and understand stacktraces?

The application fails to load the activity com.emsprotocols.nycemsprotocols.ConnectivitCheck because of a NullPointerException:

java.lang.RuntimeException: Unable to start activity
ComponentInfo{com.emsprotocols.nycemsprotocols/com.emsprotocols.nycemsprotocols.ConnectivitCheck}:
java.lang.NullPointerException

The exception is raised in the onCreate method in line 21:

Caused by: java.lang.NullPointerException at

com.emsprotocols.nycemsprotocols.ConnectivityCheck.onCreate(ConnectivityCheck.java:21)

This is actualy one error, which is wrapped by another one (NullPointerException wrapped by RuntimeException)

Understanding the Java stack

Here you are catching Error and not Exception in which case your program would have crashed.

If you try this code (modified to add a static counter)

public class StackError {

static int i = 1;

public static void main(final String[] args) throws Exception {
System.out.print("1");
doAnything();
System.out.println("2");
}

private static void doAnything() {
try {
i++;
// System.out.println(i);
doAnything();
} catch (Error e) {
System.out.print("y"+i+"-");

}
}
}

Output

 1y6869-2

So, it has got stackerror 6869 times(changes for different runs) and the last value is printed. If you just print the y as you did earlier then it might the case that the output is getting bufferred and not getting flushed as it is not a println.



Update

The System.out.println internally calls the PrintStream which is buffered. You don't loose any data from the buffer, it gets all written to the output( terminal in your case) after it fills up, or when you explicitly call flush on it.

Coming back to this scenario, it depends on the internal dynamics of how much the stack is filled up and how many print statements were able to get executed from the catch in doAnything() and those number of characters were written to the buffer. In the main back it finnally get's printed with the number 2.

javadoc reference to buffered streams

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.

How do stack traces get generated?

Every thread will have its own stack. Each method call creates a stack frame. If something wrong happened in code of any method, that will propagated to caller method. This way JVM can trace which method generated error and what is the call hierarchy.

If you observe the stack trace properly, you will see the method where error occured at top and the hierarchy in bottom.

There is a great lecture in youtube by a Stanford professor to understand how does it work. I would suggest watching it.

NOTE: This is theory. If you would like to know how API works, @Peter Lawrey answer may help you.

How can I convert a stack trace to a string?

One can use the following method to convert an Exception stack trace to String. This class is available in Apache commons-lang which is most common dependent library with many popular open sources

org.apache.commons.lang.exception.ExceptionUtils.getStackTrace(Throwable)



Related Topics



Leave a reply



Submit