Logging levels - Logback - rule-of-thumb to assign log levels

I mostly build large scale, high availability type systems, so my answer is biased towards looking at it from a production support standpoint; that said, we assign roughly as follows:

  • error: the system is in distress, customers are probably being affected (or will soon be) and the fix probably requires human intervention. The "2AM rule" applies here- if you're on call, do you want to be woken up at 2AM if this condition happens? If yes, then log it as "error".

  • warn: an unexpected technical or business event happened, customers may be affected, but probably no immediate human intervention is required. On call people won't be called immediately, but support personnel will want to review these issues asap to understand what the impact is. Basically any issue that needs to be tracked but may not require immediate intervention.

  • info: things we want to see at high volume in case we need to forensically analyze an issue. System lifecycle events (system start, stop) go here. "Session" lifecycle events (login, logout, etc.) go here. Significant boundary events should be considered as well (e.g. database calls, remote API calls). Typical business exceptions can go here (e.g. login failed due to bad credentials). Any other event you think you'll need to see in production at high volume goes here.

  • debug: just about everything that doesn't make the "info" cut... any message that is helpful in tracking the flow through the system and isolating issues, especially during the development and QA phases. We use "debug" level logs for entry/exit of most non-trivial methods and marking interesting events and decision points inside methods.

  • trace: we don't use this often, but this would be for extremely detailed and potentially high volume logs that you don't typically want enabled even during normal development. Examples include dumping a full object hierarchy, logging some state during every iteration of a large loop, etc.

As or more important than choosing the right log levels is ensuring that the logs are meaningful and have the needed context. For example, you'll almost always want to include the thread ID in the logs so you can follow a single thread if needed. You may also want to employ a mechanism to associate business info (e.g. user ID) to the thread so it gets logged as well. In your log message, you'll want to include enough info to ensure the message can be actionable. A log like " FileNotFound exception caught" is not very helpful. A better message is "FileNotFound exception caught while attempting to open config file: /usr/local/app/somefile.txt. userId=12344."

There are also a number of good logging guides out there... for example, here's an edited snippet from JCL (Jakarta Commons Logging):

  • error - Other runtime errors or unexpected conditions. Expect these to be immediately visible on a status console.
  • warn - Use of deprecated APIs, poor use of API, 'almost' errors, other runtime situations that are undesirable or unexpected, but not necessarily "wrong". Expect these to be immediately visible on a status console.
  • info - Interesting runtime events (startup/shutdown). Expect these to be immediately visible on a console, so be conservative and keep to a minimum.
  • debug - detailed information on the flow through the system. Expect these to be written to logs only.
  • trace - more detailed information. Expect these to be written to logs only.

My approach, i think coming more from an development than an operations point of view, is:

  • Error means that the execution of some task could not be completed; an email couldn't be sent, a page couldn't be rendered, some data couldn't be stored to a database, something like that. Something has definitively gone wrong.
  • Warning means that something unexpected happened, but that execution can continue, perhaps in a degraded mode; a configuration file was missing but defaults were used, a price was calculated as negative, so it was clamped to zero, etc. Something is not right, but it hasn't gone properly wrong yet - warnings are often a sign that there will be an error very soon.
  • Info means that something normal but significant happened; the system started, the system stopped, the daily inventory update job ran, etc. There shouldn't be a continual torrent of these, otherwise there's just too much to read.
  • Debug means that something normal and insignificant happened; a new user came to the site, a page was rendered, an order was taken, a price was updated. This is the stuff excluded from info because there would be too much of it.
  • Trace is something i have never actually used.

This may also tangentially help, to understand if a logging request (from the code) at a certain level will result in it actually being logged given the effective logging level that a deployment is configured with. Decide what effective level you want to configure you deployment with from the other Answers here, and then refer to this to see if a particular logging request from your code will actually be logged then...

For examples:

  • "Will a logging code line that logs at WARN actually get logged on my deployment configured with ERROR?" The table says, NO.
  • "Will a logging code line that logs at WARN actually get logged on my deployment configured with DEBUG?" The table says, YES.

from logback documentation:

In a more graphic way, here is how the selection rule works. In the following table, the vertical header shows the level of the logging request, designated by p, while the horizontal header shows effective level of the logger, designated by q. The intersection of the rows (level request) and columns (effective level) is the boolean resulting from the basic selection rule. enter image description here

So a code line that requests logging will only actually get logged if the effective logging level of its deployment is less than or equal to that code line's requested level of severity.