Java Debugging

What the trace is saying

Start at the first line. The type is the category of failure. The text after the colon is the message someone passed to the constructor, or a default such as / by zero. Then read the frames of the stack trace from top to bottom.

Exception in thread "main" java.lang.NullPointerException: Cannot invoke "Item.price()" because "item" is null
    at OrderService.total(OrderService.java:18)
    at Checkout.submit(Checkout.java:42)
    at Main.main(Main.java:7)

Line 18 of OrderService dereferenced item. Checkout.submit called total from line 42, and main called submit. The null was created or passed in one of those callers. The frame at the top tells you the line that could not continue. The frames under it tell you how the program arrived there with that value.

Library frames sit above yours when the library is what threw. Keep moving down to the first file you maintain. That line is the call you made. The frames above explain how the library reacted. The frames below explain who asked you to make the call.

A cause, and a suppressed extra

When a layer wraps a failure, the log grows a Caused by section. The outer type is the one the catch block handled or rethrew. The cause is the throwable that was passed into the constructor. If that one has a cause of its own, the log continues. Follow the chain to the bottom before you decide what broke.

demo.ConfigLoadException: Could not load config.txt
    at App.loadConfig(App.java:20)
    at App.main(App.java:8)
Caused by: java.nio.file.NoSuchFileException: config.txt
    at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
    ...

Here the application said the config failed to load. The cause says the file is absent. Fixing the wrapper's message would not create the file. A suppressed section is the other attachment you will see, usually from try-with-resources: the primary exception happened in the body, and close failed afterward. Both matter. They are not two names for the same link. The page on try-with-resources shows how the second one gets attached.

Pausing on a line

A print of two variables is enough when you already know which line is suspicious. It becomes a poor tool when the failure depends on a value three calls away, or when the line runs thousands of times and you need the one case that breaks. A breakpoint pauses the thread there, under a debugger in IntelliJ IDEA, Eclipse, or the Java debugger in an editor.

Set it on the line that uses the suspicious value, not on every line of the method. When the thread stops, read the locals. Step over to watch this method move from line to line. Step into when the wrong value comes back from a call and you need to see that call compute it. If the method is hit constantly, a condition on the breakpoint, such as orderId == 42, keeps the other calls running.

Reproduce the failure with a fixed input before you change the code. A stack trace plus the arguments that produced it is a test you can keep. After the fix, that test is what tells you the same throw did not come back.

What a log line needs

System.out.println of a single word tells you a catch block ran. It drops the type, the message, and the trace. Printing e.getMessage() keeps the message and still drops the frames. Pass the throwable itself to the logger so the trace is stored with the line.

catch (IOException e) {
    logger.error("Could not load config for {}", environment, e);
}

Name the operation and the identifier you will search for later: the environment, the order id, the path. Omit secrets. A token, a password, or a full card number in a log line is a second incident sitting beside the first. Log at the layer that handles the failure or at the boundary where it leaves the service. Logging the same exception in every method on the way up produces several traces of one fault and makes the next reader think several things broke.