Monday 9 September 2019

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



Sometimes when I run my application it gives me an error that looks like:



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)


People have referred to this as a "stack trace". What is a stack trace? What can it tell me about the error that's happening in my program?






About this question - quite often I see a question come through where a novice programmer is "getting an error", and they simply paste their stack trace and some random block of code without understanding what the stack trace is or how they can use it. This question is intended as a reference for novice programmers who might need help understanding the value of a stack trace.


Answer



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 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).


No comments:

Post a Comment

php - file_get_contents shows unexpected output while reading a file

I want to output an inline jpg image as a base64 encoded string, however when I do this : $contents = file_get_contents($filename); print &q...