Why does the TRACE level exist, and when should I use it rather than DEBUG?

Question

In Log4J, Slf4J and a couple other logging frameworks in Java, you have two "developper" level for logging:

• DEBUG
• TRACE

I understand what DEBUG does, because the explanation is clear:

The DEBUG Level designates fine-grained informational events that are most useful to debug an application.

But the TRACE level is not very specific about its use case:

The TRACE Level designates finer-grained informational events than the DEBUG

(Source: the log4J JavaDoc)

This does not tell me how or when to use TRACE. Interestingly, this is not a severity level defined in the syslog standard. Googling for the difference between TRACE and DEBUG only seem to return "use DEBUG, oh, and there is TRACE too". I couldn't find a specific use case for the TRACE level. The best I could find was this old wiki page debating the merit of the existence of the level.

This, as an architect, raises a lot of flags and questions in my head. If a young developer asked me to add TRACE to my architecture, I would bombard him with questions:

• What are some examples of information that should be logged with TRACE and not with DEBUG?
• What specific problem do I solve by logging that information?
• In those examples, what are the properties of the logged information that clearly discriminate between logging at the TRACE level rather than the DEBUG level?
• Why must that information go through the log infrastructure?
  • What are the benefits of persisting that information in a logs journals rather than just using System.out.println ?
  • Why is it better to use log for this rather than a debugger?
• What would be a canonical example of logging at the TRACE level?
  • What are the specific gains that have been made by logging at the TRACE level instead of DEBUG in the example?
  • Why are those gains important?
  • In reverse: What problems did I avoid by logging it at TRACE instead of DEBUG?
  • How else could I solve those problems? Why is logging at the TRACE level better than those other solutions?
• Should TRACE level log statement be left in the production code? Why?

But given that it is present in most major framework, I am guessing it is useful for something? So... what is TRACE for, and what distinguishes it from DEBUG?

Answer 1

What are example of information that should be logged with TRACE and not with DEBUG?

If I have an algorithm that goes through a bunch of steps, trace level will print info about each of those steps at the finest level. Things like the literal inputs and outputs of every step.

In general, trace will include all debug (just like debug includes all warnings and errors).

What specific problem do I solve by logging that information?

You need to debug something that outputs way too much data to log outside of a specific build when you're targeting that particular thing and do not care about errors or other logging info (since the volume of trace info will obscure them). In some loggers, you will turn a certain module up to trace level only.

In those examples, what are the properties of the logged information that clearly discriminate between logging at the TRACE level rather than the DEBUG level?

In general, trace level logging cannot be on for sustained periods because it degrades the performance of the application greatly, and/or creates an abundance of log data that is unsustainable due to disk/bandwidth constraints.

Debug level logging can usually be on for a longer period without making the app unusable.

Why does that information must go through the log infrastructure?

It doesn't have to. Some frameworks have a separate tracelogger.

Usually it ends up in the logs since traceloggers and normal loggers have similar needs with regards to writing to disk/network, error handling, log rotation, etc.

Why is it better to use log for this rather than a debugger?

Because the debugger might not be able to attach to the problem machine. You might not know enough to know where to even set breakpoints, or to step through code. You might not be able to reliably reproduce the error in a debugger, so use the logs to catch it "if it happens".

But they're just names. Like any other label, they're just names people put on things, and will usually mean different things to different people. And the label itself is less important than the meaty bits that the label refers to.

Answer 2

Here' my rule of thumb

error   you need        to do something
warn    you might need  to do something
info    you need        to log this in production
debug   you might need  to log this in production
trace   everything that is happening (no performance concerns)

The assumption behind this is that ops team will

• always have production set to log-level info
• might have production set to log-level debug
• never have production set to log-level trace

Armed with that assumption, here's how you, as a developer, can use the log levels...

Objective #1) not slowing down production performance too much

debug solves #1. It is you, as the developer, doing your best to balance information you might need in production with not having too much noise you slow down the machine. You are saying "it is a fine idea to constantly log this in production (if you want)."

Objective #2) having verbose information while developing

trace solves problem #2. You have absolutely no concern what impact it would have on a production machine, but you need that info right now while developing the code. You are saying "I make no promises that it's a good idea to always log this information in production."

---

Granted (as others have said), these things are arbitrary; so just make sure your development team (and ops/monitoring team -- because they are also users of your logging) agree on something.

Answer 3

Take special note that slf4j specifically recommends against using trace ( http://slf4j.org/faq.html#trace ):

In short, although we still discourage the use of the TRACE level because alternatives exist or because in many cases log requests of level TRACE are wasteful, given that people kept asking for it, we decided to bow to popular demand.

Personally, my expectation would be for trace to log everything (e.g., even stuff like "entered function MyFunc with arguments A,B,C at time Y"). The downside of this is that not only is this incredibly noisy but also it tends to cause disk space problems; I would expect such logging to be disabled during normal operations. The upside is that this gives you a level of info similar to what you would get when stepping through your program in cases where attaching a debugger may be less practical.

Generally, I find that trace is usually more effort than other approaches.

Answer 4

Debug levels in general are entirely arbitrary and can vary between languages, libraries, and companies.

That being said, here is how I have seen them used:

TRACE: used for showing logic-level program flow. Entered a function? Did an "if" statement choose the main or "else" branch? That is a candidate for trace. In other words, trace logging is generally used for specifying "you are here." This is useful in the context of other logging statement that might log an error or other information. Trace logging can help pinpoint the location, in the code, of the error or other event logged at a different level.

DEBUG: used for dumping variable state, specific error codes, etc. For example: a web service might return error code 809214, which could be logged while the application tells the user "communication failed." Imagine a developer receiving a log from a user's system long after the error occurred and wondering "why did the failure occur?" that is a good thing to log at the debug level. Another example might be if a bug keeps occurring in production but is hard to reproduce, debug log certain variables or events in the troublesome module to help tell developers the program state when the error occurs to help troubleshooting.

Normally one would configure the application to log at a given level (or higher). For example, trace is often the lowest level: logging at that level logs everything. Debug level would omit trace but include high levels (e.g. warnings and errors).

The benefit to segregating log levels is to control the amount logged. For a complex application, trace logging might potentially log a tremendous amount of data, much of it useless most of the time. It is best only to log critical information (maybe some startup information, then only errors) unless one is trying to nail down how to cause a bug. Furthermore, this is generally only useful in a production environment were debuggers and other development tools are not present.

There are no real limits on this, no rules saying you have to log a certain way. Only broad conventions that some libraries or applications may or may not follow.

Answer 5

I think Telastyn's excellent answer can be summarized to my short rule of thumb:

• DEBUG logging must be able to be used in production (but tends to still be off normally)
• TRACE logging is allowed to be such that using it in production (other than for a specific / short session) is infeasible

Answer 6

What would be a canonical example of logging at the TRACE level?

ENTRY/EXIT logs from a method. These logs help you trace the flow of the program and tend to be very useful when:

1. The program abruptly crashes - you know exactly which function it crashed in by looking at the last line of the log

2. Some rogue function silently fails by absorbing an exception

They warrant a separate TRACE level rather than just using DEBUG because enabling ENTRY/EXIT logs for every method in your code base is going to generate a tremendous amount of extra logs that are unreasonable to be always on, even in a DEBUG context.