4 ms·

My personal reason for having strong opinions on logging is that nearly every performance issue I have come across has had an easy win of 2x-3x improvement (sma

My personal reason for having strong opinions on logging is that nearly every performance issue I have come across has had an easy win of 2x-3x improvement (small sample size, to be fair) by simply disabling logs. Not that this tends to stick because people fear the lack of information that comes from not logging, but you need to be aware of exactly how expensive logging to a synchronized output is, and how expensive that serialization is compared to the rest of the critical path. People treat logging as if it's free, when the reality is that it very often has a significant impact on performance, exacerbated by the fact that it's treated as free. Add in the fact that today's distributed systems approaches add complexity to the logging paradigm and make it much harder (vs something like Jaeger/OTel) to understand the context of a single log message, and I would rather logging disappear almost entirely in favor of metrics (fast, coarse) and tracing (slower, fully contextualized), with some ability to fall back to just printing metrics and traces to stdout or other local debugging options as a fallback.

clappski 5y ago
> logging to a synchronized output There's your performance issue, logging doesn't need to be persisted or even processed by your main program thread or any thread/process actually doing the work. Who's logging straight to stdout or directly ::write'ing a file in a production application?
- dustymcp 5y ago
  Uh oh it got silent in here :)
- kcb 5y ago
  Many many people
  - andrewstuart2 5y ago
    Right, and depending on the actual buffer implementation when logs are buffered, given the massive volume of logging I've seen, it's likely not all that much better than synchronous because those buffers are going to fill quickly and need flushed frequently.
    - clappski 5y ago
      My comment wasn’t about buffered writing in a main thread, it was about moving the work out of your threads actually executing your program and having them push raw log actions into a queue for another thread to do the formatting and writes to file from. If you’re logging so much that you’re saturating a dedicated thread that just reads from a queue in shared memory, does log formatting and writes to a file then you have bigger problems than figuring out how to log because there isn’t going to be a solution that lets you log with a deterministic latency without skipping events or wrapping around your queue. Of course, the approach scales fine if you can have multiple log files per process - e.g. a normal log file and a message log or transaction log, because you can give each file its own queue and thread.
- wruza 5y ago
  Me, not write(2)’ing though, mostly because you don’t want to syscall-block every few bytes. Modern service managers redirect 1,2 into logging facilities (or just files if configured such way), and 1,2 are no different than 3+. As if there was a regular way for data to escape a program through non-fd (mmap/shm/fork doesn’t count). That said I’m not sure what context we are discussing. I work on nodejs apps now where blocking is a non-issue. I’d obviously think about it more in C’s fprintf() or a similar block-by-default environment. Edit: also, my area is fintech with $0.1-$1000 range per request, not telecom. I log everything because my employer can ask about everything, and it’s always money.
slaymaker1907 5y ago
Yes there is performance cost, but removing logs removes your ability to solve problems that happened in production. At best without logging you will have a snapshot of your program at the instant the problem was detected such as a process dump or even just a stack trace. Logs tell you what happened before and while things were breaking.
- outworlder 5y ago
  > but removing logs removes your ability to solve problems that happened in production No it doesn't. Distributed tracing can do a far better job. As do metrics.
  - marginalia_nu 5y ago
    Metrics tell you bupkis about what causes an error, they only tell you that something has gone wrong.
    - andrewstuart2 5y ago
      And that's exactly where tracing comes in. Except instead of writing a dozen log queries in your ELK/datadog/splunk/etc system and switching contexts that many times, you have a single view that centralizes who called whom when, and even aggregates text metadata that you may have chosen to include. In other words, logs, but you don't need "started xyz" because that's just the natural beginning of each span.
sesm 5y ago
I worked on a real-time telecom system, and had to debug issues that heavily depend on timing. Regular logging impacted performance and changed timing, but when we implemented logging properly we fixed this. Our solutions was in-memory ring buffer that stores only data and pointers to formatting functions, logs are formatted and printed on-demand.
- falcolas 5y ago
  A kindred soul. This is exactly my preferred approach to logging. A ring buffer gives you enough information to debug an issue when it occurs, and nothing otherwise. Visibility into programs running in environments you can’t access is unreasonably important, but any code that creates visibility will impact your performance, too. The “right” solution is to balance those two needs for your situation, which means there is no “right” solution for everybody.
xg15 5y ago
I get the idea, but then how would you decide when to enable tracing and in which area? IMO, the advantage of logging is that it some degree of information about actual failure events - in contrast, monitoring only gives you aggregated information and tracing is too expensive to be applied everywhere at any time.
- andrewstuart2 5y ago
  Tracing should be sampled at a rate that makes sense for the dollar impact of an error in the service, versus the dollar cost of your tracing system. $thousands per transaction? Sample 100%. Cheaper to refund a customer than debug the problem every time? Then sample. You'll have plenty of sampled traces with the bug/error shown as soon as the problem is expensive enough to matter. Metrics are great for demonstrating a problem exists (and alerting), and tracing is great for helping you understand how and why it happened once it's at a big enough scale to matter. Beyond that, with a lot of what's coming out of Open Telemetry, you can get fancier like sampling a higher percent of traces to a localized processor middleware that then filters out any traces you doesn't care about (e.g. dropping non-errors or low-quantile latencies).
  - xg15 5y ago
    Yeah, but once again, this requires you to already know there is an error, have a dollar impact calculated, etc. There is a lot of talk in this thread about the performance impact of logging. I don't see how sampling 100% wouldn't have a far greater performance impact.

clappski 5y ago

> logging to a synchronized output There's your performance issue, logging doesn't need to be persisted or even processed by your main program thread or any thread/process actually doing the work. Who's logging straight to stdout or directly ::write'ing a file in a production application?

dustymcp 5y ago
Uh oh it got silent in here :)
kcb 5y ago
Many many people
- andrewstuart2 5y ago
  Right, and depending on the actual buffer implementation when logs are buffered, given the massive volume of logging I've seen, it's likely not all that much better than synchronous because those buffers are going to fill quickly and need flushed frequently.
  - clappski 5y ago
    My comment wasn’t about buffered writing in a main thread, it was about moving the work out of your threads actually executing your program and having them push raw log actions into a queue for another thread to do the formatting and writes to file from. If you’re logging so much that you’re saturating a dedicated thread that just reads from a queue in shared memory, does log formatting and writes to a file then you have bigger problems than figuring out how to log because there isn’t going to be a solution that lets you log with a deterministic latency without skipping events or wrapping around your queue. Of course, the approach scales fine if you can have multiple log files per process - e.g. a normal log file and a message log or transaction log, because you can give each file its own queue and thread.
wruza 5y ago
Me, not write(2)’ing though, mostly because you don’t want to syscall-block every few bytes. Modern service managers redirect 1,2 into logging facilities (or just files if configured such way), and 1,2 are no different than 3+. As if there was a regular way for data to escape a program through non-fd (mmap/shm/fork doesn’t count). That said I’m not sure what context we are discussing. I work on nodejs apps now where blocking is a non-issue. I’d obviously think about it more in C’s fprintf() or a similar block-by-default environment. Edit: also, my area is fintech with $0.1-$1000 range per request, not telecom. I log everything because my employer can ask about everything, and it’s always money.

slaymaker1907 5y ago

Yes there is performance cost, but removing logs removes your ability to solve problems that happened in production. At best without logging you will have a snapshot of your program at the instant the problem was detected such as a process dump or even just a stack trace. Logs tell you what happened before and while things were breaking.

outworlder 5y ago
> but removing logs removes your ability to solve problems that happened in production No it doesn't. Distributed tracing can do a far better job. As do metrics.
- marginalia_nu 5y ago
  Metrics tell you bupkis about what causes an error, they only tell you that something has gone wrong.
  - andrewstuart2 5y ago
    And that's exactly where tracing comes in. Except instead of writing a dozen log queries in your ELK/datadog/splunk/etc system and switching contexts that many times, you have a single view that centralizes who called whom when, and even aggregates text metadata that you may have chosen to include. In other words, logs, but you don't need "started xyz" because that's just the natural beginning of each span.

sesm 5y ago

I worked on a real-time telecom system, and had to debug issues that heavily depend on timing. Regular logging impacted performance and changed timing, but when we implemented logging properly we fixed this. Our solutions was in-memory ring buffer that stores only data and pointers to formatting functions, logs are formatted and printed on-demand.

falcolas 5y ago
A kindred soul. This is exactly my preferred approach to logging. A ring buffer gives you enough information to debug an issue when it occurs, and nothing otherwise. Visibility into programs running in environments you can’t access is unreasonably important, but any code that creates visibility will impact your performance, too. The “right” solution is to balance those two needs for your situation, which means there is no “right” solution for everybody.

xg15 5y ago

I get the idea, but then how would you decide when to enable tracing and in which area? IMO, the advantage of logging is that it some degree of information about actual failure events - in contrast, monitoring only gives you aggregated information and tracing is too expensive to be applied everywhere at any time.

andrewstuart2 5y ago
Tracing should be sampled at a rate that makes sense for the dollar impact of an error in the service, versus the dollar cost of your tracing system. $thousands per transaction? Sample 100%. Cheaper to refund a customer than debug the problem every time? Then sample. You'll have plenty of sampled traces with the bug/error shown as soon as the problem is expensive enough to matter. Metrics are great for demonstrating a problem exists (and alerting), and tracing is great for helping you understand how and why it happened once it's at a big enough scale to matter. Beyond that, with a lot of what's coming out of Open Telemetry, you can get fancier like sampling a higher percent of traces to a localized processor middleware that then filters out any traces you doesn't care about (e.g. dropping non-errors or low-quantile latencies).
- xg15 5y ago
  Yeah, but once again, this requires you to already know there is an error, have a dollar impact calculated, etc. There is a lot of talk in this thread about the performance impact of logging. I don't see how sampling 100% wouldn't have a far greater performance impact.