Do not log
sobolevn.me
sobolevn.me
As greatly represented in this comment section, this article touches on maybe 1/10 of the usecases of logging...and than pretends that the opinion is applicable everywhere.
> And yes, you got it correctly: it sounds like a job for Sentry, not logging.
okay, I guess I will not write a log file for my Raspi bash script then and instead setup a third party service?
> We don’t really care about exceptions and how to handle them. We care about the business value that we provide with our app.
That's how you get shitty software which can be fixed relatively quickly regarding large scale black swan events (everything broken) and retains their annoying edge case bugs forever, slowly driving users away...
All the while, the arguments against logging seem to be the same against implementing, well anything. More things = more complexity. New things = new problems. By all means be aware of these pitfalls in the context of logging and anything else.
But as a whole, this article awfully smells like an unreasonably strong opinion wrapped in pseudo-intellectualism.
It's definitely a weird article.
I maintain an open source tool called dbcrossbar that automates data transfer between several kinds of databases. It uses multiple async streams to copy data, and it has a "backpressure" system that keeps every step of the transfer in sync. Usually it's very reliable, but if it goes wrong, then I need debugging tools.
We use the "slog" library for structured logging. This allows us to add extensive structured data to our logs, and to keep track of what's coming from where. We can increase or decrease the log level for each component individually.
And these logs are invaluable for debugging. Like, almost every time we have any problem at all, we all sit around saying, "Wow, we're so glad we have such good logging."
> okay, I guess I will not write a log file for my Raspi bash script then and instead setup a third party service?
They're not even exclusive. You can and should feed your logs into sentry. It can use low-sev logs as breadcrumbs and the high-sev logs as events: https://docs.sentry.io/platforms/python/logging/
Having extensive logging and sentry makes your sentry reports significantly better, it's not an either/or situation.
This is famously not true. When the system is working, “we”, as in the business, only care about the business value. The moment things break or get slow it’s all recriminations about “how could you let this happen?”
Then later it’s right back to, “why can’t you go faster?” until it happens again.
Admittedly, there's a blurry line here between logging and tracing, but the latter word generally evokes externally attaching additional tools. But that "far end" of tracing is frequently not what's needed... there's a reason logging systems have "info" and "debug" severities.
Either way good (i.e. configurable, low overhead) logging is worth its weight in gold.
Bosses notice exceptional events. As the team or cluster get bigger, they start happening closer together. Depending on context, any event that happens once a week or once a day will be characterized as happening “all the time” and that creates a new set of problems.
You need tools to head these off. And yes they are a pain but so is telling your boss, “we don’t know.”
That is one of the feelings I dislike the most as someone who takes pride in building quality software. It’s important to be honest when you don’t know why something is wrong, but even more important to minimize the number of times it happens. Logging is incredibly beneficial for the latter, and complements metrics + exception-tracking.
That includes rare conditions where you have to backtrack from error to root cause based on information already in the log. I worked for years on data replication and got into the habit of logging anything that might affect data integrity at INFO level to ensure it would be available to guide debugging.
Simple examples: where did you read config values from on startup? Log the file name including the full path. Rebooting? Log all steps in the boot sequence in detail. Retries of calls to remote components? Log that too--put in a counter to log every N failures so you don't flood the log. Transaction aborts? Log them as well using the same counter method. Extra credit: Use ring buffers to dump current transaction state on fatal errors.
If things are OK the log is fairly small.
This kind of logging is essential in transaction processing systems. You can't log every transaction because (at least in my case) there were billions of them. But you should log everything that gives insight into whether the system is meeting preconditions for safety and liveness. If you need more info you can turn on traces but this will at least give you an idea where [not] to look.
What is it? Performance?
No.
As a user of many programs I always find it very frustrating when some program does not work and produce no log information whatsoever.
As an engineer, I always write detailed and human-readable log entries with as much context as possible which is split into trace, debug, warning and info levels.
With trace level enabled it's typically possible to reconstruct program execution step-to-step, which is _invaluable_ when you need to debug some rare problem.
Even if logs are ephemeral and not persisted it's better to have logs for a run than not having logs at all.
Logging as a side effect is irrelevant if you look at your code from the pragmatic standpoint, from which program execution transparency matters more than some abstract elegancy.
For context, I mostly program in python. I could imagine compile-time loglevel settings could address the performance, though.
[1]: https://community.oracle.com/blogs/forax/2011/12/17/jsr-292-...
Might seem tedious, but in fact it's easily automated using snippets in the editor.
Also when I'm inserting trace statements during development it provides a great help since it's much easier to debug logic.
Regarding performance: I don't think that we need to worry about log performance. Most applications we have this days are not performance-bound to the logging. And all it takes to disable particular log level is single `if` in the code. Or a build flag in more extreme cases.
This ends up overlapping a lot with event sourcing: if you're doing event sourcing right, with every substantial business decision recorded as an event and your logic decomposed into lots of fine-grained transformations between event streams, then the event streams can be your logs: each successive event transformation either succeeds or fails, and if it fails then you have the input event and the small piece of code in which the failure occurred, so you shouldn't need any more. If a given transformation gets too complicated to debug, split it into two smaller transformations!
You still need alerting on failures, but again, that's something that's better done in a structured way, with proper stacktraces and business-relevant information.
* make logging an explicit part of your contracts
* Logging should be done right
There are some good parts. It's not all wrong or anything. But I don't think it's worth the read.
Maybe a good takeaway is: consider which monitoring systems might accomplish your business purpose better.
Also, I guess: a full-featured logging subsystem in a distributed system can be substantial. True but not too interesting because that's pretty obvious, often not needed, wouldn't normally be implemented from scratch any more than a monitoring system might be, etc.
Articles like this are often written by someone that manages a trivial or non-critical path system. They have strong feelings about logging because they lack other things to have strong feelings about.
This person seems confused in general. They say "don't log, send it to sentry". Sentry is logging. Sentry is usually configured as a logging destination. It just does some preprocessing on those logs to aggregate and enrich them.
I don't know anyone that fishes through text logs over ssh anymore. We use simple automations to roll everything up for convenient access.
Furthermore he overlooks other use cases for logging. Including analytics, fixing concurrency/heisenbugs, and a myriad of other problems that logging addresses.
Good points, though it's funny: In my day job I only ever fish through logs (not by ssh -- I don't have that much access to the systems).
But that's only because by the time it gets to me multiple levels of people (who really know what they are doing, BTW, so it doesn't happen often) have done everything else.
Further along he goes on to advocate for logging systems. And "business monitoring". What does he think drives these "business monitoring" thingy? Quick notification -- what's that? Like, an output of some kind, denoting a state? I think we call that logging.
Log everything, make sure it goes somewhere you can look at. Logging but not collecting is as good as writing to /dev/null.
It's also very helpful to identify performance issues when you have a flamegraph with interspersed log lines on a timeline.
No! Log it and still retry.
There are lots of reasons why might want to know later on if something failed the first time and then had to retry, for example when debugging possible timing issues.
> And yes, you got it correctly: it sounds like a job for Sentry, not logging.
Sentry is a form of logging. Also, sometimes you have potentially private data in local variables that you absolutely cannot risk sending to a service over the network; a log message allows you to be very careful with what information you reveal and what you don't reveal.
Which brings me to another use case for logging: sometimes you simply cannot report exact errors to customers (because they might leak the existence or nature of other customer's data), but if the customer contacts support, you absolutely want that information in the logs (even if just to decide if the vague error message was intentional or a bug).
Don't get me wrong, I'd love to live in a world where every action straight out succeeds or results in a bug ticket, but the real world is much more complicated, and logs do help making sense of that.
You will likely say this is a form of logging, and you’re right, but I think this is a better fit for a metric rather than a log.
“Something something retried at…” isn’t nearly as useful as the “the number of retries peaked at…”
Metrics are useful to get a general picture, and logging is useful when you try to find out in one specific instance what happened.
If you have a billion requests per day, you likely don't want logging for retries; if you have a small number of requests, many of them important enough to investigate individual errors, you absolutely want logs on what happened to each request.
Record retries: yes. Log them? Mmm, maybe not.
No I’m probably going to do what he had in the introduction and just dump major events or errors to a text file because it’s cheap, easy, and it’s usually all that’s needed to diagnose end user issues (I do desktop apps and can’t do any real time monitoring but on the other hand logs are perfect chronological records of the actions of one user on one document - not of just one system as is common for web apps).
It’s not that dumb logs are great, but they provide 50% of what you need at almost no cost.
If I were able to dream and could have the amount of thought and design that he describes in any part of my code - logging would be pretty far down the list of subsystems I’d refactor.
1. Logging the whole end-to-end chain allows us to view "whose fault" it is basically. We work in a microservices landscape and any request coming in the system goes through several teams. Pinpointing the team responsible for fixing their shit is important to get things up again.
2. Sometimes it happens that we (my team) drops the ball, we have some custom logging that traces the whole request through our application and we can quickly pinpoint what function failed or again whether it is a third party API call that failed or something.
For me, logging is very important, but perhaps there are better solutions available that I'm unaware of, always eager to learn and improve.
The false dichotomy between monitoring and logging here is so bizarre, they’re not mutually exclusive. When an alert wakes you up on a weekend, having a log statement with useful context is not going to kill you...
Also:
> Isn’t it a bit too hard?! Look, I just want to write strings into stdout. And then store it somewhere.
So do that? Why is the author pretending you need to use ELK stack?
And what about their example is “too hard”, if you’re deploying your own application that’s the least of your complications, and if you aren’t and already paying a premium for it, there’s plenty of managed ELK and ELK-like products (and I’d also be surprised if your managed deploy platform doesn’t already support you just logging to STDOUT)
In my mind, there are audit logs, to know what happened during an incident. You don't know what the incident will be, so you should log as much maybe-useful stuff as possible, and you only look at the logs if some incident requires attention.
There also logs to debug an issue that occurs in production but can't be diagnosed any other way. When a customer says "I clicked the log in button, but just saw a blank screen", and you have no other records, the logs will be handy.
Part of this is the old adage "Half of my X is wasted effort but I don't know which half" but there is still a class of log messages which should not exist.
What I'm talking about is when I'm too lazy to think how to handle a condition. What I sometimes do is half assed effort to handle and, "obviously", log it. This gives the false feeling that the condition is handled.
In reality now I have two problems: a poorly handled condition and possibly log spam.
That said, logging in general is great. I found a tricky resource leak by investigating logging rate anomalies.
I'm now working on an Elixir project but the way Elixir does logging is kind of dangerous. So you have a dynamically typed language that relies on unit testing in order ensure stuff works, then you have logging methods where the compiler will remove them depending on what log-level you have configured for your environment. Now run different log-levels for production and testing. What could go wrong? It seems insane that the framework would let you do this and not have a more sensible default like run the log methods but drop the output to the floor and you have to do a bit more work in order to make the log methods be completely removed.
I don't want to have to guess why your service is crashing. I'd much rather be able to jump in to the logs and find the exact exception information so I can fix it quickly.
All possible exceptions eliminated when calling doSomethingComplex(). Perhaps I'm missing something here and this overly broad language is more targeted than i've realized while reading... But that just sounds silly to my ears. And saying that making something type safe solves "all possible errors"... What am I missing?
How to take the information out of information technology.
or
How to have no clue about why an edge case crashed your systems.
sure, use third party services / applications to ease insights and additional steps like notifications, but not logging at all does not make any sense.
"And eliminate all possible exceptions that can happen here" that's including runtime exceptions?
"There are a lot of cases when we don’t care. Because of the retries, queues, or it might be an optional step that can be skipped" using different log levels perfectly indicates the importance of the exception.
"it sounds like a job for Sentry, not logging" afaik sentry is logging which makes me wonder whether the author is advocating a principle or a product...
I recently worked with a person who was anti-logging. His argument was that logging is only necessary when the code path is not easy to assume solely based on the input. This is true, of course, but his mistake was assuming it is possible to guarantee that level of predictability in non-trivial operations. It wasn't long before he was adding logging to his code to figure out an issue that occurred rarely and only in production.
In Python, instead of the example in the blog:
try:
do_something_complex(*args, **kwargs)
except MyException as ex:
logger.log(ex)
try:
do_something_complex(*args, **kwargs)
except MyException as ex:
logger.error(ex, exc_info=True)
Even cooler, every un-caught exception calls `sys.excepthook()`. The function is supposed to be monkey patched by anyone who wants to do something with uncaught exceptions, so you can do the following if you want to log all uncaught exceptions:
def exception_logger_hook(exc_type, exc_value, exc_traceback):
logger.error("Uncaught exception", exc_info=(exc_type, exc_value, exc_traceback))
sys.__excepthook__(exc_type, exc_value, exc_traceback)
sys.excephook = exception_logger_hook
Why not simply use logger.exception()?
try:
do_thing()
except Exception:
logger.exception("It broke.")
I'm sure there are also good reasons :)
Because real world is hard to change and everyone and their cat will continue to do logging in their own bad ways and won’t change that and logging is important for everyone.
DO LOG.
Deal with it.
Until you do. Then, instead of having access to it, you need to hope you can recreate it.
Meanwhile you can filter your logging such that the critical stuff still comes to you and the other stuff is sent into the ether and eventually GC'd
Log everything but focus on logs and metrics that matter most to customers (eg reliability and percentile latencies).
I'm fighting unseeded 'random.next', and 'file.read' in algorithms, so they can remain pure. But I won't ever forbid someone to use logs in a pure function. Sure, it doesn't make sense from a functional programming point of view, but let's be practical and realistic for five minutes : logs are the only thing you can count on to debug a crashing script quickly. The occasional "bug" thrown by your logging back end is not a big enough deal to forgo our hability to trace what's going on in a running program. Everything is running inside kubernetes anyway.
For example, if you have a micro services architecture in production in which many services might be accessed (or not) from a request of a particular origin, then you're going to want to "log" a unique identifier for that request and propagate it across all the systems so that you can tie them back to each other if needed.
Another example, you sell hardware to consumers. The hardware is composed of modules and components that all talk to each other (yep, it's a car), and how long those components and modules last is effected by environment variables (how you drive). You've got a couple of million of these things on the road. If you want to learn how to improve quality of your hardware, you need to "log" how your hardware performs in the environment that you don't control, so you can correlate failure with environment variables. Can't do that without "logging".
I wonder how you people handle that. Do you also log "good events", for example when nothing happened just to be able to see everything went well?
I was originally inclined to say this article was written by an amateur at best and at worst, an edgy contrarian with questionable intentions. It looks like the rather is somewhat the truth. The author is the author of the `returns` [1] python library, which aims to "make your functions return something meaningful, typed and safe" -- is this the end result? No logging?
Are we to live in some kind of statically typed utopia where users never do unexpected things, the domain model never changes on a dime, algorithms never have edge cases and software is all formally provable, easy to reason about, purely functional and stateless? I can almost assure you that management at any customer facing firm will disagree on whether logging is necessary or not, for reasons that are obvious for anyone who has ever talked to a customer in their life.
Not to wax philosophical and get overly personal for a second, but why does FP have this effect on some of its practitioners? Is what happens when you spend too much time in the cathedral of academia that you forget how eldritch monstrosities can be built and maintained in any style of code, with any sophistication of typing system or automated theorem prover or formal verification? That the problems often come in at the requirements level, and that much of the job of the engineer is honing, refining and disambiguating the requirements deeper than the business otherwise can? There is no escape at the code level, only at the organization level.
For problems that are difficult or impossible to reproduce, logs are all I have. Tracing and metrics and structured error reporting only get set up in places where errors are expected.
> I am fighting an “overlogging” culture. When logs are used just for no good reason. Because developers just do it without analyzing costs and tradeoffs.
The article would have been better if it started with the conclusion, and could have done with a good bit of editing, but outrageous claims do stimulate discussion.
Of the service management frameworks that handle service logging for you, some do not by default collect what is written to standard output, but they will all collect what is written to standard error. This is also the Unix convention of long-standing for diagnostic messages, going back to the very reason that standard error was invented in the first place.
One thing I would like to emphasize: You don't write software for software's sake. You write it to solve a problem, generally a business problem. If your software has a problem, that may also be a business problem. Don't make IT support solve business problems. Make the business solve them, and give the business tools to solve them.
Obviously you won't get there with the first release of your software, but it is the goal. If you find a problem in the logs, ask yourself: Am I masking a problem that the business needs to solve themselves? Does the software need to surface this?
https://github.com/Morgan-Stanley/hobbes/
The logging part is just a single self-contained header-only lib, so very easy to incorporate in existing systems.
Get 2 variants, one with logging and debugging and whatnot, which is used for alpha, beta, gamma / whatever version and the clean one that you release officially.
And yes, I'm aware that sometime a bug will creep only in the release version while in the debug version will not happen. What can I say, those are where your experience really is showing, so you can understand the root of the problem.
Storage is cheap, if there's no valid side effect (false alerts, performance hit, slow log searches) I want verbose logs, they can be rotated/archived later thanks.
At previous companies we setup logging to record all kinds of actions from end users, including possible errors/exceptions.
But as you figured, metrics are the end goal.
I've previously setup mtail to create metrics from log messages and that gives me 90% of what I may need from logs at a fraction of the cost, speed and time.
But logs are still useful for exploratory ad-hoc analysis, or the less common patterns which you're not monitoring or creating metrics for.
Cabin is a BYOL (bring your own logger) solution that normalizes logs by adding metadata and automatically strips/masks/purges passwords, credit cards, and sensitive fields from logs automatically. It works out of the box with any client-side or server-side JS environment, and has support for Koa and Express.
Log as if your life depended on being able to debug a single occurrence. If this causes a lot of output, you probably need to add more assertions to the code.
Sentry IS logging.
>>> Sentry is built on top of best practices like logging. However, this can cause confusion and signal-to-noise issues if you don’t understand the the difference between logging and error reporting.
Throughout your application you are likely logging many kinds of events. While these are commonly errors, you are probably logging a lot of debug information as well. This is the fundamental reason why logging has levels (e.g., debug, warning, error). When we abstract our crash reporting through logs, the challenge is to differentiate between actual errors and debug noise. >>> https://blog.sentry.io/2016/02/09/what-is-crash-reporting
Too many logs makes trying to find the relevant logs when debugging near-impossible. Too few makes trying to find the root cause near-impossible. They're both terrible. But finding the happy middle ground is also near-impossible.
Also, Sentry is logging, it just groups by a fingerprint.
That's not a reason to get rid of all logging though.
Also, Sentry is logging, so...?
If you must log then pipe the output into <????> which will store your log into a search system such that if you have a coordination id will bring logs from the various microservices together.
So what is ????
Log rotation, compression, disk space, getting FS space and making directories on large corporate networks is a pain. I also have to ssh around and compose logs. We also deal with servers in multiple timezones and most programmers are too dumb to put the TZ. Figuring out what TZ was ultimately used and sequencing it is stupid work. Yuck.
At my office the gdpr of logging is not well adopted. Logs are left in code really for debugging, to monitor a PR change in prod then forgotten later. You can see where that goes: waste
Also for a serious system with wide customer usage, the log should contain a errno like error (defined universe of errors with a set format), the use case, plus the details. Not whatever sprintf the programmer dreamed up.
The OP is also right here: logging is used as a bailout just in case thing because the programmer did not make a narrow contract in the method, service. Logging is used to find edge cases. That's not right.
Finally logs can be slow and some esp. c++ streams stuff may use mutexes.