18 ms·

Logging practices I follow

97 points by bubblehack3r 4y ago

marginalia_nu 4y ago
> Whatever service you are using for logging, it costs money, and a fast way to burn money is to log the entire json object that was relatively small on your dev env, but blew up on production. You could also, you know, run your own infrastructure and log to your heart's content.
- chaghalibaghali 4y ago
  There are still going to be time and effort costs involved in scaling that infrastructure as your log volume increases
  - marginalia_nu 4y ago
    You have to output a lot of logs before you fill up even a single large consumer-grade hard drive, especially given logs are typically compressed when rotated. It's usually only when you involve ELK or something like that your logs start to get big. Which in turn is typically necessitated by over-complicated distributed software design. If you're at the scale where this actually matters and you're serving millions or requests per second from a worldwide user-base, then affording storage for the logs really shouldn't be a problem anymore (idk, with the possible exception of Twitter)
    - KronisLV 4y ago
      > You have to output a lot of logs before you fill up even a single large consumer-grade hard drive, especially given logs are typically compressed when rotated. This is a good point - a RAID array of a few HDDs/SSDs scales surprisingly far and is cheaper than many of the cloud services out there, though whether you can or can't use either approach probably relies on compliance requirements and such. I will definitely add that logs can compress really well - to the point where it's been close to a year since I added Logrotate to a project that didn't have it before, for a pretty basic setup, and I haven't had the need to even look at how many archives are currently retained, given that the disk usage has changed very slightly. And that's for multiple systems that filled up the available storage in months previously. Of course, my personal gripe is that most of the logging solutions out there are rather complex - something like Graylog feels like one of the simpler self-hostable options while still being fully featured, but in my experience anything that runs ES is really resource hungry. Sometimes it feels like MariaDB/PostgreSQL would be good enough for most of the simpler low logging volume setups out there - if you don't want to manage logs as files, want to ship them somewhere, but don't want the receiving system to be too complex either.
    - jodrellblank 4y ago
      And what are you going to do when you need a human to read sixteen trillion bytes of compressed logs streamed off a single SATA disk? Once you face the fact that the performance of a single SATA disk means you can't search the logs in any quick time, and nobody can possibly read that much log data, so nobody will use it, you start to see it as a hoarding disorder not a useful tool.
      - marginalia_nu 4y ago
        It's not unheard of to need to retain years even decades worth of logs due to regulatory compliance. Nobody is reading them, they just need to exist. In that scenario you'll probably keep the current year or so fresh on a mechanical drive and past years on tape.
    - adra 4y ago
      Except you know when you.actually want to do something valuable with all those logs. You _should_ be creating logs (signals) to be valuable in some way (diagnostics, alerting, canaries statistics), etc. If you're just dumping logs into opaque blobs that are never looked at them sure write them to blobs to your heart's content and have fun hunting and pecking for reasons you're users are already screaming at you. That strategy is fine, but the limitations are clear. It's reactive.
      - marginalia_nu 4y ago
        Depends entirely on what and why you are logging. Is it audit logs for security or due to some regulatory requirement? Then huge blobs are fine. Desirable, even. Transaction logs for machine-loading so you're able to replay an application's state at any given moment in time? Yeah probably gonna end up with huge blobs again.
- NeckBeardPrince 4y ago
  You know that costs money, right?
  - marginalia_nu 4y ago
    Not as much as you'd think, and critically, the cost is largely disconnected from how you use the infra.
    - darkwater 4y ago
      If your infra is not on-prem, yes it will cost you more money as you are generating more and more and bigger logs.
      - marginalia_nu 4y ago
        You actually have to log a damn lot to actually fill up even a single 16 Tb drive with gzip-compressed logs which typically have something like 50x compression for log data. On top of that, mechanical hard drives are pretty cheap these days. Like it's a dozen dollars per terabyte, if not less. I don't know, you're either producing just absurd amounts of logs, on the order of a hundred gigabytes a day plain text, at which sure, I guess you could probably log a bit less. Either that or you're operating at a scale with many millions of users where you should have income and be able to afford it. ... well, either that, or you're being fleeced.
        giaour 4y ago
        When people complain about the cost of excessive logging, they are almost certainly not thinking in terms of how much a drive costs. Services like CloudWatch are an excellent way to burn through money, though it's usually the time series storage and ingestion costs that balloon out of control.
        partdavid 4y ago
        Well, also the kind of people who worry about this are not thinking in terms of "a terabyte", like GP. It's always easy to give advice when your experience has been at a toy level.
vinceguidry 4y ago
I fight log infra all the time. I can't win the fight against structured logging anymore, so I'm now fighting against type systems and allergies to global state to make log output available everywhere. If you're going to ram structured logging down devs' throats, then the least you can do is to make it easy enough to use. I don't want to have to pass a logging object everywhere. There's like two pieces of information you need in order to make a logger. Just write it to global state somewhere so I don't have to worry about it and can call it anywhere. I absolutely loathe reinventing global state by passing "context" objects and the like everywhere. It's the dumbest thing in the world but no one ever questions it.
- kevmo314 4y ago
  At least passing context objects everywhere is better than dynamic dependency injection. I'm in the "dump the logger in a global variable" boat too though.
  - TeMPOraL 4y ago
    I was somewhat in that boat too, until the first time I had to make several modules in the code log in a special way (that required some custom code), determined at runtime. Mostly I just wish more languages had Lisp-style dynamic binding / "special variables". Logging is one of the perfect use cases for dynamic scope - you'd have your normal logger object/configuration as the top-level value of a global, and then let-bind it whenever you need to alter its value for all code executed within that specific scope. Alas, about the only widely-used form of dynamic binding today is environment variables.
    - chriswarbo 4y ago
      I do this in Scala, via https://www.scala-lang.org/api/2.12.13/scala/util/DynamicVariable.html https://www.scala-lang.org/api/2.12.13/scala/util/DynamicVar... It's not perfect, since it uses JVM's thread-local storage under the hood; this can break when e.g. evaluating Futures in a ThreadPool. For variables which are rarely-overridden, like loggers, I do so with a wrapper that also switches the ExecutionContext to a new ThreadPool (urgh, multithreading...) PS: I do the same for env vars too ;) http://www.chriswarbo.net/blog/2021-04-08-env_vars.html http://www.chriswarbo.net/blog/2021-04-08-env_vars.html
charles_f 4y ago
One additional thing I like in structured logs is having some form of context level information be included eith your logs, so that you already know things like tenant id, user id, request id, and basic parameters of the request without having to rewrite all that everytime you get an exception. Unrelated: I live in the Pacific north west and I clicked on this expecting to find a list like "don't log old growth for timber, don't log the entire area", fun how your brain can associate a word with a concept and ignore the more context-relevant meaning.
- terran57 4y ago
  re: unrelated - I too thought this was a forest-related post.
- masklinn 4y ago
  Is there a structured form of tracing? Because I feel like this contextual information should easily be part of a trace.
  - adra 4y ago
    Logging is kinda a mess in general for contextualization. Most that support it use kV tupled appended to the log line itself. OpenTelemetry is probably the best hope of supporting a world with contextual logs, metrics, traces which imho is a good thing. OTEL logging does some opinionated things with message construction though, so caveat emptor.
    - tignaj 4y ago
      Otel logs aim to record the execution context in the logs. In languages when the context is implicitly passed (e.g. via thread-local storage / MDC in Java) Otel automatically injects trace id and span id in the logs emitted using your regular logging library (e.g. log4j). Then in your log backend you can make queries like "show me all log records of all services in my distributed system that were part of this particular user request". Disclosure: I am an Otel contributor, working on logs (work-in-progress, not for production use yet).
rekahrv 4y ago
Log frugality and log uniqueness are great concepts. +1 for mentioning both the financial and cognitive costs of excessive logging.
- theandrewbailey 4y ago
  Just as I suspected: logging a hundred equals signs (or other symbol) for every log entry turns out to be a bad idea.
Pxtl 4y ago
One question I always have about logging: how do I log valid and expected but prohibited actions? That is, the system is behaving as designed but the user is seeing an error message because they're using the system wrong, and I want to know how often this is happening?
- ambicapter 4y ago
  Sounds just like INFO to me. There's a difference between logging to users, logging to system administrators, and logging to developers.
- rollulus 4y ago
  Info, because it is not actionable.
- sofixa 4y ago
  There are dedicated tools such as Sentry for cases like this (well in general for error collection and management, but also cover this scenario). They capture all relevant environment, and can help you detect if users are "using it wrong" only on Safari or only since version x.y, indicating a problem elsewhere.
chaghalibaghali 4y ago
On the levelled logging point, I stopped using levels after switching from Java -> Go and haven't looked back: https://thomshutt.github.io/opinionated-logging-in-go.html https://thomshutt.github.io/opinionated-logging-in-go.html
- mattpallissard 4y ago
  This completely overlooks many things such as logs used as metrics or even just using them to reason about the state of your application. What if your application isn't throwing errors but some thing is still broke Or you're shipping bad data? IMO, the entire point of logs is to be able to ask questions of and reason about the current state of your application. If you're only logging errors that you can't recover from you may as well just throw and exception and restart.
  - giraffe_lady 4y ago
    > If you're only logging errors that you can't recover from you may as well just throw and exception and restart. Unironically tho this is a good decision if you design for it from the beginning crash-only software style. Most of what I log is INFO and WARN level because unexpected combinations of business-level state are where the real subtle nasty bugs are. Nil reference or whatever can just crash who cares.
    - adra 4y ago
      It absolutely matters. Reading messages from a message queue? Have users submitting some subtly bad edge case you've never organically seen? Just a crash-restart isn't saving you, and worse because you have a discipline of who cares, you probably have inadequate code helpers to diagnose the scenario that triggered your flaw. If you're business is dead simple, whatever but there's too much code in the world to be pumped into such a limited way of thinking.
- alexdowad 4y ago
  Good point! Log levels are pretty useless most of the time. I would add that there can be value in having 2 log levels: verbose and non-verbose. It is helpful if you can selectively switch on verbose logging by user or by API endpoint. In one application which I maintain, when verbose logging is switched on for a particular user, TCP/UDP socket objects are automatically wrapped and packet captures are logged, only for packets sent/received while servicing that particular user's requests. This has been a lifesaver when debugging things like weird, transient authentication problems stemming from upstream providers.
invalidname 4y ago
I prefer this post which is more detailed: https://talktotheduck.dev/logging-best-practices-mdc-ingestion-and-scale https://talktotheduck.dev/logging-best-practices-mdc-ingesti...
groggo 4y ago
I was expecting something about sustainable forestry
benjaminpv 4y ago
Something I haven't seen discussed very widely: it feels like there's not only a balance needed in determine what to log vs what not to log, but also logging in a way that isn't a detriment to the readability of the code overall. Over time I've actually found myself logging less just because having to sorta mentally elide logging lines added to the cognitive overhead of reading & understanding code.
- 63 4y ago
  Depending on the language and framework you're using, there may be options for logging that's non-intrusive. For example, Spring Aspects and Python decorators. Clean logging is a very common problem that probably already has a lot of solutions if you go looking.
ryeguy_24 4y ago
Question...why no mention of "change" logs? I'm curious as to why I don't see change logs mentioned often as an important overlay to general system logging. I liken errors and debugs all related to heart beat and breathing rate but without information like "climbing stairs" or "changed medication", it may be hard to understand context or understand why new errors are being seen. The first question I would expect to ask when seeing logged issues, is what has changed recently that could be related to the new errors. Curious to hear thoughts on this? I actually built software/startup related to the logging of changes (architecture change/software change/server restarts) but just didn't get traction and curious to know why it's not more interesting to people.
- guhidalg 4y ago
  At $FORMER_EMPLOYER, we had a company-wide service that tracked changes of all kinds: source code changes, deployment changes, config changes, etc... It was useful because some changes are never reflected in YOUR logs, but they are reflected in someone else's logs. The systems that tried to do log change detection were all bad because the ML-driven clustering systems didn't produce interpretable information.
- adra 4y ago
  Because these are probably better expressed as metrics. A good observation platform will try to weave all of these concepts together to form that picture you're describing. Some observation providers call these events or annotations. Theres a difficult cognitive dissonance for looking at a logged event and know that it's unusual or not. Some signals are in fact positively correlated with a failure, and some times it's just noise. Good tooling hopefully makes the distinction of these two options as easy as possible.
mhd 4y ago
Unrelated to the content: I really like the phrasing of the title. Not "…you should follow", not the tired "best practices", simply "Things I do".
- switch007 4y ago
  I agree I also can’t stand: “You’re doing logging wrong” / “you’ve been doing logging wrong” But then again as an industry we seem to like confident bullshitters
- deleted 4y ago
  [deleted]
tobylvp 4y ago
I think all of this sounds fine in theory, but the reality is that most logged information will not be needed - ever. Exactly what information is needed when can be difficult to predict. So, if a developer feels something might be important, they should probably log it. Within reason, I think it is better to have it and not need it than to need it and not have it. It seems the author is putting a heavy emphasis on trying to create readable logs. Finding the signal in the noise. I am biased, but I think this is a failure of the tools used to read the logs rather than the logs themselves. This is why I wrote LogViewPlus (https://www.logviewplus.com/ https://www.logviewplus.com/).
- NegativeK 4y ago
  > Within reason, I think it is better to have it and not need it than to need it and not have it. Log retention starts to mess with what's considered reasonable. For example, despite the fact that it'd be actually legitimately useful to store 180 days of pcaps, that's just cost prohibitive.
- ilyt 4y ago
  Same applies to metrics, if it moves, log it, especially with semi-recent TSDBs allowing to store a metric ton of metric in very litte space (well, aside from Mimir from Grafana that managed to fail that lesson...) > It seems the author is putting a heavy emphasis on trying to create readable logs. Finding the signal in the noise. I am biased, but I think this is a failure of the tools used to read the logs rather than the logs themselves. This is why I wrote LogViewPlus (https://www.logviewplus.com/ https://www.logviewplus.com/). Well, it's failure on many levels. "informational" logs, like say your traditional access.log are mostly used for metrics/analytics but also server as context to any warning or error that app returns during processing of the request. But at same time you kinda want them to have be encoded in something more structured than "a piece of formatted text" (say, a JSON line), while at the same this approach reduces glancability of logs to near zero. On other side having hundreds lines of code just to decode logs into something searchable is also pretty bad and most importantly very fragile to code changes. "Just do everything in machine format then send it to collector" like Jaeger (with bonus being ability to do distributed tracing) is a solution but very obese one and needs every app supporting distributed tracing
ryandrake 4y ago
One thing I'd add is the ability to tag certain data or certain loglines as containing personal information so that they can be scrubbed before transmitting or storing the logs. You don't want things like credit card numbers, government id numbers, home addresses, and so on sitting out there in your logs, available to any developer reading a bug report (or available to everyone, when your company has a data breach). You'd log these things during development, skipping the scrubbing step, while the prod logs get scrubbed.
bob1029 4y ago
We use SQLite for logging all the things. This sidesteps entire rabbit colonies worth of issues - especially with regard to downstream parsing & reporting. I have found the extra structure and familiar semantics make it a lot easier to talk about what we log, how we log it and why.
- hckr1292 4y ago
  Can you saw more about this? I've never heard of anything like this and can't figure out if its genius or silly. Things I'm curious about: * Are you working on a SAAS product or embedded/IoT project or hobby project? * How do you aggregate the SQLite logs together from disparate machines? Seems like you probably can't use fluentbit/filebeat/etc. * Where do you query these logs? * How do you structure these logs? (timestamp, machine, message) or something with more columns? * Are you able to capture stacktraces? I _love_ the idea of leveraging SQLite for this kind of scenario and possibly skipping a lot of messy plumbing or pricy vendors, but I'm uncertain how this works.
  - bob1029 4y ago
    We ship a B2B product that spools to a log.db when running on client machines. We built in-house tooling that is tailored to obtaining and analyzing copies of these databases. Stack traces, user actions, 3rd party logs, et. al. are meticulously tracked in a schema we thought most appropriate for our business.
0x457 4y ago
Should add that log messages should answer questions like: - What happened - When it happened? - Where it happened? - Why it happened? - What's the next step? If your log doesn't answer at least the first 3 questions, then it's useless. If you don't answer "why", then you should think harder whether that is useful or not. If I had a cent for every time I see "Something went wrong" optionally followed by stack trace that is nearly entirely in 3rd party code with zero information to correlate it with anything - I would have retired to homestead ages ago.
- spyspy 4y ago
  Also, who did it?
kkfx 4y ago
Personally since few yeas I feel more and more issues with logs: - most devs have lost the concept of logging levels, considering normal spitting out crappy giants backtraces and wall of meaningless text; - most devs have lost the idea of "being quiet" or "frugality", also have NEVER tried to read logs like an application user who do not have nor want to pass gazillion of lines of sources often crappily arranged. In the classic *nix world skimming log for "alerting patterns" was easy, for modern crapplications it's a bit of a nightmare. Similarly using logs for debug and mere health check is sometimes useless since many messages should at maximum be debug level logs, others are meaningless and even looking at them from the sources does NOT clarify until you read much more.
david38 4y ago
Lots of logs can be replaced by metrics. People go crazy with logs.
- partdavid 4y ago
  Very much (e.g. timing data, counts like success and error counts and operations should be metrics). If not metrics, then traces. If not metrics or traces, then business events (e.g. like alerts, audit records). Almost everything that people put in logs actually belongs somewhere else, in my opinion. Which is evidenced by so much of log processing being about turning logs back into whatever it was they were supposed to be in the first place (metrics, distributed traces and business events).
  - cpach 4y ago
    Excuse an old cave man, but in what way does traces and metrics replace logs?
    - adra 4y ago
      "Operation xyz completed in 15.445 seconds." This can be expressed as a metric (or a trace) so that the "operation_xyz_completed" is a metric and 15.445 seconds is evaluated as a metric data point. The result is an easily chart to graph the average, p99, whatever of the operation to gauge if this is normal or exceptional. It's dead simple to alert on metrics as well often, so it helps to unlock alerting. Log alerts are valid but often more limiting without a bunch of parsing or being really naive.
      - ilyt 4y ago
        Well, you usually want metric and trace of it, at the very least if it fails
- adra 4y ago
  Because by and large, a bunch of technologies have very spotty support for metrics, and almost always involve third party systems. Logs are dumb simple. I'm not saying metrics aren't valuable (quite the opposite), but getting started in metrics usually involves some level of institutional investment.
yabones 4y ago
One thing that's an absolute must: Put an ISO-8601 timestamp at the very beginning of every line in your log. No apache format, no "sun" or "jan" or other words. ISO only. Seriously. If the timestamp is in a weird format (or, god help you, multiple formats since some libraries log shit in a special way), it'll be just about impossible to tell when things actually happened instead of just when the logging server saw them. In a perfect world these would be milliseconds apart, but lots of bad stuff can happen. Your log-grepping-guy will thank you.
w10-1 4y ago
The key is that the person writing the log message is in no position to judge whether it's right. The measure of logs is whether you can put them in front of a smart but unfamiliar persons and have them figure out what's happening. At a minimum, they should understand generally what's happening and specifically what each message is saying (though perhaps not its significance). (i.e., same as when writing code)

97 points by bubblehack3r 4y ago

> Whatever service you are using for logging, it costs money, and a fast way to burn money is to log the entire json object that was relatively small on your dev env, but blew up on production. You could also, you know, run your own infrastructure and log to your heart's content.

chaghalibaghali 4y ago
There are still going to be time and effort costs involved in scaling that infrastructure as your log volume increases
- marginalia_nu 4y ago
  You have to output a lot of logs before you fill up even a single large consumer-grade hard drive, especially given logs are typically compressed when rotated. It's usually only when you involve ELK or something like that your logs start to get big. Which in turn is typically necessitated by over-complicated distributed software design. If you're at the scale where this actually matters and you're serving millions or requests per second from a worldwide user-base, then affording storage for the logs really shouldn't be a problem anymore (idk, with the possible exception of Twitter)
  - KronisLV 4y ago
    > You have to output a lot of logs before you fill up even a single large consumer-grade hard drive, especially given logs are typically compressed when rotated. This is a good point - a RAID array of a few HDDs/SSDs scales surprisingly far and is cheaper than many of the cloud services out there, though whether you can or can't use either approach probably relies on compliance requirements and such. I will definitely add that logs can compress really well - to the point where it's been close to a year since I added Logrotate to a project that didn't have it before, for a pretty basic setup, and I haven't had the need to even look at how many archives are currently retained, given that the disk usage has changed very slightly. And that's for multiple systems that filled up the available storage in months previously. Of course, my personal gripe is that most of the logging solutions out there are rather complex - something like Graylog feels like one of the simpler self-hostable options while still being fully featured, but in my experience anything that runs ES is really resource hungry. Sometimes it feels like MariaDB/PostgreSQL would be good enough for most of the simpler low logging volume setups out there - if you don't want to manage logs as files, want to ship them somewhere, but don't want the receiving system to be too complex either.
  - jodrellblank 4y ago
    And what are you going to do when you need a human to read sixteen trillion bytes of compressed logs streamed off a single SATA disk? Once you face the fact that the performance of a single SATA disk means you can't search the logs in any quick time, and nobody can possibly read that much log data, so nobody will use it, you start to see it as a hoarding disorder not a useful tool.
    - marginalia_nu 4y ago
      It's not unheard of to need to retain years even decades worth of logs due to regulatory compliance. Nobody is reading them, they just need to exist. In that scenario you'll probably keep the current year or so fresh on a mechanical drive and past years on tape.
  - adra 4y ago
    Except you know when you.actually want to do something valuable with all those logs. You _should_ be creating logs (signals) to be valuable in some way (diagnostics, alerting, canaries statistics), etc. If you're just dumping logs into opaque blobs that are never looked at them sure write them to blobs to your heart's content and have fun hunting and pecking for reasons you're users are already screaming at you. That strategy is fine, but the limitations are clear. It's reactive.
    - marginalia_nu 4y ago
      Depends entirely on what and why you are logging. Is it audit logs for security or due to some regulatory requirement? Then huge blobs are fine. Desirable, even. Transaction logs for machine-loading so you're able to replay an application's state at any given moment in time? Yeah probably gonna end up with huge blobs again.
NeckBeardPrince 4y ago
You know that costs money, right?
- marginalia_nu 4y ago
  Not as much as you'd think, and critically, the cost is largely disconnected from how you use the infra.
  - darkwater 4y ago
    If your infra is not on-prem, yes it will cost you more money as you are generating more and more and bigger logs.
    - marginalia_nu 4y ago
      You actually have to log a damn lot to actually fill up even a single 16 Tb drive with gzip-compressed logs which typically have something like 50x compression for log data. On top of that, mechanical hard drives are pretty cheap these days. Like it's a dozen dollars per terabyte, if not less. I don't know, you're either producing just absurd amounts of logs, on the order of a hundred gigabytes a day plain text, at which sure, I guess you could probably log a bit less. Either that or you're operating at a scale with many millions of users where you should have income and be able to afford it. ... well, either that, or you're being fleeced.
      - giaour 4y ago
        When people complain about the cost of excessive logging, they are almost certainly not thinking in terms of how much a drive costs. Services like CloudWatch are an excellent way to burn through money, though it's usually the time series storage and ingestion costs that balloon out of control.
        partdavid 4y ago
        Well, also the kind of people who worry about this are not thinking in terms of "a terabyte", like GP. It's always easy to give advice when your experience has been at a toy level.

vinceguidry 4y ago

I fight log infra all the time. I can't win the fight against structured logging anymore, so I'm now fighting against type systems and allergies to global state to make log output available everywhere. If you're going to ram structured logging down devs' throats, then the least you can do is to make it easy enough to use. I don't want to have to pass a logging object everywhere. There's like two pieces of information you need in order to make a logger. Just write it to global state somewhere so I don't have to worry about it and can call it anywhere. I absolutely loathe reinventing global state by passing "context" objects and the like everywhere. It's the dumbest thing in the world but no one ever questions it.

kevmo314 4y ago
At least passing context objects everywhere is better than dynamic dependency injection. I'm in the "dump the logger in a global variable" boat too though.
- TeMPOraL 4y ago
  I was somewhat in that boat too, until the first time I had to make several modules in the code log in a special way (that required some custom code), determined at runtime. Mostly I just wish more languages had Lisp-style dynamic binding / "special variables". Logging is one of the perfect use cases for dynamic scope - you'd have your normal logger object/configuration as the top-level value of a global, and then let-bind it whenever you need to alter its value for all code executed within that specific scope. Alas, about the only widely-used form of dynamic binding today is environment variables.
  - chriswarbo 4y ago
    I do this in Scala, via https://www.scala-lang.org/api/2.12.13/scala/util/DynamicVariable.html https://www.scala-lang.org/api/2.12.13/scala/util/DynamicVar... It's not perfect, since it uses JVM's thread-local storage under the hood; this can break when e.g. evaluating Futures in a ThreadPool. For variables which are rarely-overridden, like loggers, I do so with a wrapper that also switches the ExecutionContext to a new ThreadPool (urgh, multithreading...) PS: I do the same for env vars too ;) http://www.chriswarbo.net/blog/2021-04-08-env_vars.html http://www.chriswarbo.net/blog/2021-04-08-env_vars.html

charles_f 4y ago

One additional thing I like in structured logs is having some form of context level information be included eith your logs, so that you already know things like tenant id, user id, request id, and basic parameters of the request without having to rewrite all that everytime you get an exception. Unrelated: I live in the Pacific north west and I clicked on this expecting to find a list like "don't log old growth for timber, don't log the entire area", fun how your brain can associate a word with a concept and ignore the more context-relevant meaning.

terran57 4y ago
re: unrelated - I too thought this was a forest-related post.
masklinn 4y ago
Is there a structured form of tracing? Because I feel like this contextual information should easily be part of a trace.
- adra 4y ago
  Logging is kinda a mess in general for contextualization. Most that support it use kV tupled appended to the log line itself. OpenTelemetry is probably the best hope of supporting a world with contextual logs, metrics, traces which imho is a good thing. OTEL logging does some opinionated things with message construction though, so caveat emptor.
  - tignaj 4y ago
    Otel logs aim to record the execution context in the logs. In languages when the context is implicitly passed (e.g. via thread-local storage / MDC in Java) Otel automatically injects trace id and span id in the logs emitted using your regular logging library (e.g. log4j). Then in your log backend you can make queries like "show me all log records of all services in my distributed system that were part of this particular user request". Disclosure: I am an Otel contributor, working on logs (work-in-progress, not for production use yet).

rekahrv 4y ago

Log frugality and log uniqueness are great concepts. +1 for mentioning both the financial and cognitive costs of excessive logging.

theandrewbailey 4y ago
Just as I suspected: logging a hundred equals signs (or other symbol) for every log entry turns out to be a bad idea.

Pxtl 4y ago

One question I always have about logging: how do I log valid and expected but prohibited actions? That is, the system is behaving as designed but the user is seeing an error message because they're using the system wrong, and I want to know how often this is happening?

ambicapter 4y ago
Sounds just like INFO to me. There's a difference between logging to users, logging to system administrators, and logging to developers.
rollulus 4y ago
Info, because it is not actionable.
sofixa 4y ago
There are dedicated tools such as Sentry for cases like this (well in general for error collection and management, but also cover this scenario). They capture all relevant environment, and can help you detect if users are "using it wrong" only on Safari or only since version x.y, indicating a problem elsewhere.

chaghalibaghali 4y ago

On the levelled logging point, I stopped using levels after switching from Java -> Go and haven't looked back: https://thomshutt.github.io/opinionated-logging-in-go.html https://thomshutt.github.io/opinionated-logging-in-go.html

mattpallissard 4y ago
This completely overlooks many things such as logs used as metrics or even just using them to reason about the state of your application. What if your application isn't throwing errors but some thing is still broke Or you're shipping bad data? IMO, the entire point of logs is to be able to ask questions of and reason about the current state of your application. If you're only logging errors that you can't recover from you may as well just throw and exception and restart.
- giraffe_lady 4y ago
  > If you're only logging errors that you can't recover from you may as well just throw and exception and restart. Unironically tho this is a good decision if you design for it from the beginning crash-only software style. Most of what I log is INFO and WARN level because unexpected combinations of business-level state are where the real subtle nasty bugs are. Nil reference or whatever can just crash who cares.
  - adra 4y ago
    It absolutely matters. Reading messages from a message queue? Have users submitting some subtly bad edge case you've never organically seen? Just a crash-restart isn't saving you, and worse because you have a discipline of who cares, you probably have inadequate code helpers to diagnose the scenario that triggered your flaw. If you're business is dead simple, whatever but there's too much code in the world to be pumped into such a limited way of thinking.
alexdowad 4y ago
Good point! Log levels are pretty useless most of the time. I would add that there can be value in having 2 log levels: verbose and non-verbose. It is helpful if you can selectively switch on verbose logging by user or by API endpoint. In one application which I maintain, when verbose logging is switched on for a particular user, TCP/UDP socket objects are automatically wrapped and packet captures are logged, only for packets sent/received while servicing that particular user's requests. This has been a lifesaver when debugging things like weird, transient authentication problems stemming from upstream providers.

invalidname 4y ago

I prefer this post which is more detailed: https://talktotheduck.dev/logging-best-practices-mdc-ingestion-and-scale https://talktotheduck.dev/logging-best-practices-mdc-ingesti...

groggo 4y ago

I was expecting something about sustainable forestry

benjaminpv 4y ago

Something I haven't seen discussed very widely: it feels like there's not only a balance needed in determine what to log vs what not to log, but also logging in a way that isn't a detriment to the readability of the code overall. Over time I've actually found myself logging less just because having to sorta mentally elide logging lines added to the cognitive overhead of reading & understanding code.

63 4y ago
Depending on the language and framework you're using, there may be options for logging that's non-intrusive. For example, Spring Aspects and Python decorators. Clean logging is a very common problem that probably already has a lot of solutions if you go looking.

ryeguy_24 4y ago

Question...why no mention of "change" logs? I'm curious as to why I don't see change logs mentioned often as an important overlay to general system logging. I liken errors and debugs all related to heart beat and breathing rate but without information like "climbing stairs" or "changed medication", it may be hard to understand context or understand why new errors are being seen. The first question I would expect to ask when seeing logged issues, is what has changed recently that could be related to the new errors. Curious to hear thoughts on this? I actually built software/startup related to the logging of changes (architecture change/software change/server restarts) but just didn't get traction and curious to know why it's not more interesting to people.

guhidalg 4y ago
At $FORMER_EMPLOYER, we had a company-wide service that tracked changes of all kinds: source code changes, deployment changes, config changes, etc... It was useful because some changes are never reflected in YOUR logs, but they are reflected in someone else's logs. The systems that tried to do log change detection were all bad because the ML-driven clustering systems didn't produce interpretable information.
adra 4y ago
Because these are probably better expressed as metrics. A good observation platform will try to weave all of these concepts together to form that picture you're describing. Some observation providers call these events or annotations. Theres a difficult cognitive dissonance for looking at a logged event and know that it's unusual or not. Some signals are in fact positively correlated with a failure, and some times it's just noise. Good tooling hopefully makes the distinction of these two options as easy as possible.

mhd 4y ago

Unrelated to the content: I really like the phrasing of the title. Not "…you should follow", not the tired "best practices", simply "Things I do".

switch007 4y ago
I agree I also can’t stand: “You’re doing logging wrong” / “you’ve been doing logging wrong” But then again as an industry we seem to like confident bullshitters
deleted 4y ago
[deleted]

tobylvp 4y ago

I think all of this sounds fine in theory, but the reality is that most logged information will not be needed - ever. Exactly what information is needed when can be difficult to predict. So, if a developer feels something might be important, they should probably log it. Within reason, I think it is better to have it and not need it than to need it and not have it. It seems the author is putting a heavy emphasis on trying to create readable logs. Finding the signal in the noise. I am biased, but I think this is a failure of the tools used to read the logs rather than the logs themselves. This is why I wrote LogViewPlus (https://www.logviewplus.com/ https://www.logviewplus.com/).

NegativeK 4y ago
> Within reason, I think it is better to have it and not need it than to need it and not have it. Log retention starts to mess with what's considered reasonable. For example, despite the fact that it'd be actually legitimately useful to store 180 days of pcaps, that's just cost prohibitive.
ilyt 4y ago
Same applies to metrics, if it moves, log it, especially with semi-recent TSDBs allowing to store a metric ton of metric in very litte space (well, aside from Mimir from Grafana that managed to fail that lesson...) > It seems the author is putting a heavy emphasis on trying to create readable logs. Finding the signal in the noise. I am biased, but I think this is a failure of the tools used to read the logs rather than the logs themselves. This is why I wrote LogViewPlus (https://www.logviewplus.com/ https://www.logviewplus.com/). Well, it's failure on many levels. "informational" logs, like say your traditional access.log are mostly used for metrics/analytics but also server as context to any warning or error that app returns during processing of the request. But at same time you kinda want them to have be encoded in something more structured than "a piece of formatted text" (say, a JSON line), while at the same this approach reduces glancability of logs to near zero. On other side having hundreds lines of code just to decode logs into something searchable is also pretty bad and most importantly very fragile to code changes. "Just do everything in machine format then send it to collector" like Jaeger (with bonus being ability to do distributed tracing) is a solution but very obese one and needs every app supporting distributed tracing

ryandrake 4y ago

One thing I'd add is the ability to tag certain data or certain loglines as containing personal information so that they can be scrubbed before transmitting or storing the logs. You don't want things like credit card numbers, government id numbers, home addresses, and so on sitting out there in your logs, available to any developer reading a bug report (or available to everyone, when your company has a data breach). You'd log these things during development, skipping the scrubbing step, while the prod logs get scrubbed.

bob1029 4y ago

We use SQLite for logging all the things. This sidesteps entire rabbit colonies worth of issues - especially with regard to downstream parsing & reporting. I have found the extra structure and familiar semantics make it a lot easier to talk about what we log, how we log it and why.

hckr1292 4y ago
Can you saw more about this? I've never heard of anything like this and can't figure out if its genius or silly. Things I'm curious about: * Are you working on a SAAS product or embedded/IoT project or hobby project? * How do you aggregate the SQLite logs together from disparate machines? Seems like you probably can't use fluentbit/filebeat/etc. * Where do you query these logs? * How do you structure these logs? (timestamp, machine, message) or something with more columns? * Are you able to capture stacktraces? I _love_ the idea of leveraging SQLite for this kind of scenario and possibly skipping a lot of messy plumbing or pricy vendors, but I'm uncertain how this works.
- bob1029 4y ago
  We ship a B2B product that spools to a log.db when running on client machines. We built in-house tooling that is tailored to obtaining and analyzing copies of these databases. Stack traces, user actions, 3rd party logs, et. al. are meticulously tracked in a schema we thought most appropriate for our business.

0x457 4y ago

Should add that log messages should answer questions like: - What happened - When it happened? - Where it happened? - Why it happened? - What's the next step? If your log doesn't answer at least the first 3 questions, then it's useless. If you don't answer "why", then you should think harder whether that is useful or not. If I had a cent for every time I see "Something went wrong" optionally followed by stack trace that is nearly entirely in 3rd party code with zero information to correlate it with anything - I would have retired to homestead ages ago.

spyspy 4y ago
Also, who did it?

kkfx 4y ago

Personally since few yeas I feel more and more issues with logs: - most devs have lost the concept of logging levels, considering normal spitting out crappy giants backtraces and wall of meaningless text; - most devs have lost the idea of "being quiet" or "frugality", also have NEVER tried to read logs like an application user who do not have nor want to pass gazillion of lines of sources often crappily arranged. In the classic *nix world skimming log for "alerting patterns" was easy, for modern crapplications it's a bit of a nightmare. Similarly using logs for debug and mere health check is sometimes useless since many messages should at maximum be debug level logs, others are meaningless and even looking at them from the sources does NOT clarify until you read much more.

david38 4y ago

Lots of logs can be replaced by metrics. People go crazy with logs.

partdavid 4y ago
Very much (e.g. timing data, counts like success and error counts and operations should be metrics). If not metrics, then traces. If not metrics or traces, then business events (e.g. like alerts, audit records). Almost everything that people put in logs actually belongs somewhere else, in my opinion. Which is evidenced by so much of log processing being about turning logs back into whatever it was they were supposed to be in the first place (metrics, distributed traces and business events).
- cpach 4y ago
  Excuse an old cave man, but in what way does traces and metrics replace logs?
  - adra 4y ago
    "Operation xyz completed in 15.445 seconds." This can be expressed as a metric (or a trace) so that the "operation_xyz_completed" is a metric and 15.445 seconds is evaluated as a metric data point. The result is an easily chart to graph the average, p99, whatever of the operation to gauge if this is normal or exceptional. It's dead simple to alert on metrics as well often, so it helps to unlock alerting. Log alerts are valid but often more limiting without a bunch of parsing or being really naive.
    - ilyt 4y ago
      Well, you usually want metric and trace of it, at the very least if it fails
adra 4y ago
Because by and large, a bunch of technologies have very spotty support for metrics, and almost always involve third party systems. Logs are dumb simple. I'm not saying metrics aren't valuable (quite the opposite), but getting started in metrics usually involves some level of institutional investment.

yabones 4y ago

One thing that's an absolute must: Put an ISO-8601 timestamp at the very beginning of every line in your log. No apache format, no "sun" or "jan" or other words. ISO only. Seriously. If the timestamp is in a weird format (or, god help you, multiple formats since some libraries log shit in a special way), it'll be just about impossible to tell when things actually happened instead of just when the logging server saw them. In a perfect world these would be milliseconds apart, but lots of bad stuff can happen. Your log-grepping-guy will thank you.

w10-1 4y ago

The key is that the person writing the log message is in no position to judge whether it's right. The measure of logs is whether you can put them in front of a smart but unfamiliar persons and have them figure out what's happening. At a minimum, they should understand generally what's happening and specifically what each message is saying (though perhaps not its significance). (i.e., same as when writing code)