Logging vs. instrumentation

Re:Logging vs. instrumentation by vbezhenar on Monday February 08, 2016 @08:20AM (#11057887)

> In my opinion, my thesis from GopherCon 2014 still holds: services should only log actionable information. That includes serious, panic-level errors that need to be consumed by humans, or structured data that needs to be consumed by machines.

But what if I need some information to debug a problem in the future? I log some related information and when error happens, I can look to the logs and get that information. This might help to debug a problem. Ideally I would like to have a values for all variables at any moment of time. Practically I can't have it, but I can get some values, which, I think, are more important. So later, when I debug a problem, I'll have more information. And if I don't ever need that, no problem, disks are cheap and logs are small (if done properly, there's nothing worse than searching for a needle in a 100GB log file).

For my programs I developed a simple rules. Log everything important with DEBUG level (but it shouldn't be too much, don't log 10MB data for each HTTP request). Log everything that happens in the system at a "higher" level with INFO level (like "add record with text {}"). Log everything unusual with WARN level (like user validation failed). Log every unexpected but recoverable (application can serve other requests) error with ERROR level. Log unrecoverable error with FATAL level and shutdown application. Works fine for me. And TRACE level just for debug, it's usually turned off, so it might produce any amounts of data.

[ Parent | on HN ]

Re:Logging vs. instrumentation by allengeorge on Monday February 08, 2016 @08:37AM (#11057980)

I too thought that his logging recommendations were weak. Simply logging an error (even with context) doesn't tell you much about how you entered that state.

I follow these guidelines (similar to yours):

  - ERROR: Failed assertions, unrecoverable conditions
  - WARN: Exceptions (request is toast, but system works)
  - INFO: Important actions (entered a certain state)
  - DEBUG: Information associated with the actions above

Note that we too don't log full requests, etc. at DEBUG - that's way, way too much. If you really want to do that? TRACE, but that's usually important for the developers of those libraries. We're also lucky in that we use logback, so we can change the log level of the system at runtime very easily.

In production we usually run on INFO and above and the logs aren't overwhelming - though we're constantly trying to improve the quality and consistency of the messages.

[ Parent | on HN ]