I keep seeing people in the Go community suggesting that there’s no need for error levels when logging. Often this idea is pushed through memes like “You don’t need levels if you’re only logging errors”.
Perhaps I see this in the Go community because Go’s standard logging API has no support for levels. I think Go’s logging is woefully inadequate. I’ve tried levelless logging, and it doesn’t work for me.
It seems as if a lot of the hate for levels comes from the idea that they are for filtering, and that the only filter that matters is “Do I need to care about this?” If that’s your view, then it totally makes sense to only log errors.
I have some sympathy for that, because the only real filtering I do is whether DEBUG logs are turned on or off. However, I see error level as useful information for a human reader.
For example, suppose I see this log message:
Connection to REDACTED-IDENTIFIER-HERE closed: reading length: EOF
There’s really not much more the application can log than it has already logged. It had a connection to some identified server, and when it read data it got an EOF. Yet on its own, that information doesn’t tell me enough. Is the EOF being read something normal which I should expect to see in my logs, or does it indicate an error? Did the program recover from the problem, or did it crash? Those questions can be answered if the log message is given a level.
In this case, the program was SyncThing, and it did indeed use leveled logging. The level of that message was INFO, so I know that Syncthing didn’t crash because of the EOF, the problem was dealt with, and it’s something I should expect to happen under normal circumstances. I could argue about whether INFO is the right level for that particular message, but the fact that some level indication was useful seems indisputable.
Still, a lot of people don’t seem to see any need for log levels. So here’s a list of the log levels I use, with a description of what each is for, and three concrete examples of something that would be logged at each level.
The error logging level is used to indicate that the message concerns a failure the system was unable to deal with. Examples:
- Can’t make a connection to the data store.
- Out of memory.
- Can’t store data due to a relational constraint violation.
The warning level is for indicating that the logged situation shouldn’t have happened, but the system dealt with it. Warnings are logged because they may be of interest subsequently, when tracking down a performance problem or the root causes of an error. Examples:
- Received a cookie with an invalid digital signature indicating tampering.
- Web Service call failed and had to be retried.
- A value which should have been found in cache wasn’t, and had to be regenerated from disk.
The info level is used to indicate that the logged message concerns the overall state of the application, or other information useful for monitoring and reporting. Examples:
- Application has started up successfully and is ready to accept requests.
- Application has been told to shut down by an administrator.
- Current number of active user sessions is…
The debug level is used to indicate that the information may be useful for debugging, but that you will generally want to exclude it from the log unless the application is placed into debug mode. Examples:
- URL of database being opened.
- Raw SQL query sent to database.
- Headers from HTTP request.
Another factor which may influence my logging practices is that, being an old-school programmer, I generally feel that logging is a better debugging tool than fancy interactive debuggers. Sure, debuggers have their place, but if I had to choose between a debugger but no logs, or logs but no debugger, I’d take the latter every time.
There are some log levels I do agree are pointless, though:
FATAL just means an ERROR which caused a crash. If a system crash won’t be logged for you automatically but you can predict that one is imminent (but not do anything useful about it), just log that fact at ERROR level. For example, a complex multi-threaded system might log something like “ERROR: Heartbeat thread failed, system will now inevitably deadlock and crash”.
FINE / FINER / FINEST
Java logging offers three different levels of DEBUG logging. I have never found this useful. Either I’m debugging, in which case I want all my debug messages, or I’m not debugging, in which case I don’t want any of them. I assume it was intended to allow the quantity of log messages to be dialed back, but in Java you can filter by package.
Another Java silliness. This isn’t a severity level, it’s where the information in the log message came from. It’s just
DEBUG: Config says…,
INFO: Configured to use database on… or whatever.
Almost all my debug messages are tracing code flow or value changes. TRACE is just DEBUG minus information about initial configuration.