This was not the direction I thought it was going to go in. I thought this was going to be the idea that we should toss out log levels and instead consumers of logs should apply a level to it. An error for you may only be nice information for me. On top of that you can switch between behaviour (alarm vs doing nothing) using your monitoring software rather than code changes.
I made this decision in the Eliot (https://eliot.readthedocs.io) logging system. I dropped log levels altogether: just log everything, and consumer can decide. Right?
Except: software development is a process, and a process implemented by forgetful humans. A useful and often necessary part of the development process when adding logging to one’s code is thinking “will this log message destroy performance?” Requiring log levels of any sort reminds the developer that this is a concern. Lacking log levels it’s too easy to forget about performance impact of logging and just spew out way too much. (I have much more detailed version of this point in one of my Software Clown emails, if anyone cares I can dig it up and post it somewhere public.)
There are probably superior ways of reminding developers that logging has a cost, though. I quite like the post’s idea of expressing the developer’s original goal for adding the log message.
I think performance issues could be averted by requiring consumers to explicitly declare the level they’re interested in. If everyone is interested in WARN and higher then the library can skip all lower levels. I’m sure this introduces another set of challenges but it’s another tool in our toolboxes.
You’re right. Thanks for pointing this out. I was fixated on performance issues mentioned by @itamarst and completely ignored the fact he mentioned it in the context of dropping log levels.
Oftentimes the prerequisite to performance is the programmer thinking about performance when coding. Thus an API with noop log levels that immediately dropped the log levels on the floor would still have some value as a reminder to the human programmer that performance is something they need to consider.
On top of that you can switch between behaviour (alarm vs doing nothing) using your monitoring software rather than code changes.
Depends. Logging is very different across domains–I’m not going to have monitoring software for, say, game clients for my new hit Camper-Snipe–I’m going to run it at error output only and disable logging functions at compilation time, since instrumentation ain’t free. For e-commerce, I’m definitely going to have it. For healthcare, I really have to have it, but I also need to have an escape hatch in case the logging system goes bonkers and tries to DoS some other critical system.
I think we aren’t quite in so luxurious a world that unconditional logging is always the answer–when we can get away with it, though, it’s great.
I think it is possible to have unconditional logging in some cases. Some approaches:
Developer discipline, coupled with contextual logging so individual messages are cheaper (e.g. you know that the “added to cart” message was part of a particular user’s context, so you don’t need to log user identifier in every single log message). Eliot is designed with the hope that this is viable.
Sampling. Once you have a concept of context you can do things like “only store log messages for 1% of requests”. So you always get complete logs for any request that is chosen to have its logs kept, but most requests aren’t chosen. If log creation is cheap (often serialization of the messages is what is expensive) you can also do “only store log messages for those requests that trigger an error.”
That idea has some lurking traps. The most important of which is, now your log throughput rises directly in correlation with your chattiest log level and the product of (your worst problem requiring log debugging) * (the chattiness of the developer working on that problem). So for example you may now have a big stack trace inside multiple tight loops in production, which works fine in dev and staging.
I don’t disagree about behavior but log levels are useful as one of many attributes of the log record. I think the article weakly covers that the developer’s point of view isn’t the only one at play and that it’s dependent on context. Stating the obvious, logs serve multiple purposes:
during development, as a means to inform the programmer
during operation, as a means to monitor the running system
I think of logs in terms of records and events, which naturally moves me toward machine-parsable, human-readable structured logging that I annotate and process. The log structure and content is a (usually incomplete and implicit) contract between the producers and consumers. There are common examples (apache, nginx, syslog, graylog) but little consistency. Using libraries that impose structure helps with the necessary agreements and team standards.
I don’t think that this structure impairs grovelling at the terminal but it greatly improves the processing. I also think there is also a side benefit in that by virtue of being aware of the contract and expectations developers avoid generating [as much] crap. I know I do. If they do at least it’s filterable.
This was not the direction I thought it was going to go in. I thought this was going to be the idea that we should toss out log levels and instead consumers of logs should apply a level to it. An error for you may only be nice information for me. On top of that you can switch between behaviour (alarm vs doing nothing) using your monitoring software rather than code changes.
I made this decision in the Eliot (https://eliot.readthedocs.io) logging system. I dropped log levels altogether: just log everything, and consumer can decide. Right?
Except: software development is a process, and a process implemented by forgetful humans. A useful and often necessary part of the development process when adding logging to one’s code is thinking “will this log message destroy performance?” Requiring log levels of any sort reminds the developer that this is a concern. Lacking log levels it’s too easy to forget about performance impact of logging and just spew out way too much. (I have much more detailed version of this point in one of my Software Clown emails, if anyone cares I can dig it up and post it somewhere public.)
There are probably superior ways of reminding developers that logging has a cost, though. I quite like the post’s idea of expressing the developer’s original goal for adding the log message.
I think performance issues could be averted by requiring consumers to explicitly declare the level they’re interested in. If everyone is interested in
WARNand higher then the library can skip all lower levels. I’m sure this introduces another set of challenges but it’s another tool in our toolboxes.That’s exactly the ‘wrong abstraction’ that is being discussed.
You’re right. Thanks for pointing this out. I was fixated on performance issues mentioned by @itamarst and completely ignored the fact he mentioned it in the context of dropping log levels.
I’m trying to make a slightly different point.
Oftentimes the prerequisite to performance is the programmer thinking about performance when coding. Thus an API with noop log levels that immediately dropped the log levels on the floor would still have some value as a reminder to the human programmer that performance is something they need to consider.
Depends. Logging is very different across domains–I’m not going to have monitoring software for, say, game clients for my new hit Camper-Snipe–I’m going to run it at
erroroutput only and disable logging functions at compilation time, since instrumentation ain’t free. For e-commerce, I’m definitely going to have it. For healthcare, I really have to have it, but I also need to have an escape hatch in case the logging system goes bonkers and tries to DoS some other critical system.I think we aren’t quite in so luxurious a world that unconditional logging is always the answer–when we can get away with it, though, it’s great.
I think it is possible to have unconditional logging in some cases. Some approaches:
That idea has some lurking traps. The most important of which is, now your log throughput rises directly in correlation with your chattiest log level and the product of (your worst problem requiring log debugging) * (the chattiness of the developer working on that problem). So for example you may now have a big stack trace inside multiple tight loops in production, which works fine in dev and staging.
I don’t disagree about behavior but log levels are useful as one of many attributes of the log record. I think the article weakly covers that the developer’s point of view isn’t the only one at play and that it’s dependent on context. Stating the obvious, logs serve multiple purposes:
I think of logs in terms of records and events, which naturally moves me toward machine-parsable, human-readable structured logging that I annotate and process. The log structure and content is a (usually incomplete and implicit) contract between the producers and consumers. There are common examples (apache, nginx, syslog, graylog) but little consistency. Using libraries that impose structure helps with the necessary agreements and team standards.
I don’t think that this structure impairs grovelling at the terminal but it greatly improves the processing. I also think there is also a side benefit in that by virtue of being aware of the contract and expectations developers avoid generating [as much] crap. I know I do. If they do at least it’s filterable.
Short, sweet, and makes a lot of sense. Love it!
Man, I thought this was going to be trees or something.
I am sorry for this bad comment. I will try harder next time.
Your comment got the axe.
So many people think they are as hilarious as us.
Ohhh.
Okay.
I meant, a tree abstraction for logs, instead of levels. Maybe base priority on nesting of loggers, for example.
Something like pstree but each process can also expand to show it’s logs?
But also that this would be a way to manage priority – create a sub-sub-logger for stuff that matters less.