Live data from Hacker News

Log by time, not by count

johnscolaro.xyz

41–50 of 109 posts

Re: Log by time, not by count

#41

This post falls into a common trap; conflating logging with metrics. Log interesting things, where interesting is defined as context outside what the "happy path" execution performs. Collect and make available system metrics, such as invocation counts, processing time histograms, etc., to make available what the post uses log statements to disseminate same.

Thanks for taking the time to reply! I'm relatively new to working on this type of system (large scale, event driven) and half posted because I know there are people on HN way better than me at this, and was curious about their opinions. In the end, what's the difference between a log and a metric? Is one structured, and one unstructured? Is one a giant blob of text, and the other stored in a time series db? At the m…

Read the SRE book, maybe some of the highlight posts only. It will give you the right jargon and a lot of wisdom that you can then simplify for your use cases.

Re: Log by time, not by count

#42

This post falls into a common trap; conflating logging with metrics. Log interesting things, where interesting is defined as context outside what the "happy path" execution performs. Collect and make available system metrics, such as invocation counts, processing time histograms, etc., to make available what the post uses log statements to disseminate same.

> This post falls into a common trap; conflating logging with metrics.

This isn't as much "conflating" as it is constructing an ad hoc metrics subsystem that exports the metrics to the logs.

There's no theoretical difference between exposing a prometheus endpoint that's scraped every x seconds and printing the same data to the logs every x seconds.

Re: Log by time, not by count

#43

Best advice I ever got on logging: log all major logical branches within code (if/for) if "request" span multiple machine in cloud infrastructure, include request ID in all so logs can be grouped if possible make log level dynamically controlled, so grug can turn on/off when need debug issue (many!) if possible make log level per user, so can debug specific user issue - https://grugbrain.dev/ The only one I'll add is…

My colleagues love to log as little as possible and most of the projects I’ve seen still treat logs as files instead of event streams that could have some search and filtering and categorization and automated alerting. It’s kind of unfortunate, because for example there’d be pushback against logging branches in code etc., except for trace logs (that others wouldn’t add) that are also off most of the time when problem…

I've had colleagues try this. It rarely works. Logging every if end up introducing a huge amount of overhead, both in terms of processing power, but especially in terms of storage. You almost always end up having to filter based on some sort of log level that you then turn off by default in production.

The problem with that is that you're now required to reproduce the issue after turning on the logging, and if you already have a reproducer, why not just attach a real debugger?

The overlap of "we can reproduce" but "it has to run on the production server" ends up being practically zero.

Re: Log by time, not by count

#44

This post falls into a common trap; conflating logging with metrics. Log interesting things, where interesting is defined as context outside what the "happy path" execution performs. Collect and make available system metrics, such as invocation counts, processing time histograms, etc., to make available what the post uses log statements to disseminate same.

Filter and aggregate after you log your metrics, traces, log messages, etc.; not before.

You can worry about data retention, rollups, and other strategies for limiting data storage separately from the systems that emit the data.

At least with the right data stores. I kind of like what opensearch and elasticsearch do for this. In Elasticsearch you have a data stream. You configure it to roll over based on time or data size. Once rolled over, indices are read only; new data appends to the current one. You then can define life cycle policies to decide what to do with the old ones and e.g. move them to cold storage, transform them with rollups, and eventually delete them.

With application logging, you typically assign different log levels. Trace and debug are typically disabled in production (or should be). Info can be quite noisy. Warn tends to be repetitive (because developers tend to ignore warnings and will never fix them). Errors should be rare.

I have my system configured to start emailing me if errors get logged. An error means something is broken and needs to be fixed. Zero tolerance on errors. When an error happens, all the other log information provides me context. So there's value in retaining that. But only for a few days at best. Long enough to survive a weekend or things like Christmas. But after that it's just noise. I have a hard cut at about two weeks. Some places you need to store stuff longer for ass coverage reasons.

Data retention comes at a price of course. I've seen companies log ginormous amounts of data and ignoring all their errors. 30GB per day. Absolutely appalling. Me: it looks like your database layer is erroring non stop (constraint violations and worse); you might want to do something about that. Them, ah no that's just normal we just ignore it (php shop, incompetence was the norm). Me: so how do you know when something breaks?! Them: ......?!

My well paid consulting gig was beating some sense into this operation as one of the managers noticed they were spending hundreds of thousands per year on this nonsense. My fee was a rounding error on that. Easiest job ever. But kind of cringe worthy once I started looking into what they were actually doing and why. Mostly it's just, "yeah some guy set that up once and then we never looked at it and he left. What are you going to do?!". There was a lot of that with this company. Just absolutely nobody that even cared about the waste of resources or getting any meaningful feedback from their logging. If that's your team, you need to do something about it. That's your job and your not doing it well. If you need an external consultant to tell you, you might want to reflect on the notion of majorly shaking things up a bit.

Re: Log by time, not by count

#45
Logging is an exercise in solving problems of future you.

We don't log just to have records of everything, we log to solve future questions.

I'm working on a system that generates huge numbers of log entries and have settled on a short term solution to over log everything.

Once a log entry has persisted, I'm using it as a 'Bronze Layer' in a typical Medallion Model and will then filter that log data up into Silver and Gold layers so I can have billing, reporting, dashboard metrics being lifted out of the verbose logs.

Not sure what I'll do with the verbose Bronze Layer logs maybe cold store them somewhere, but it's interesting to experiment with progressive aggregation of logs to hopefully purge and dispose of the raw log data as fast as we can extract value.

Re: Log by time, not by count

#46
There is an additional benefit to throttling by time, it is a lot easier to do it efficiently in multithreaded environments.

If you log by count, you need a global counter for that event (you could do thread-local, but then your logging volume would depend on the number of threads). If the code path is hot (which may be the case if you want to throttle your logs) multiple threads will contend on the increment, and that can be very expensive.

If you log by time, you just need a load and a clock read (on Linux, `CLOCK_MONOTONIC_COARSE` is a handful of ns and the resolution is enough for this purpose), and only need synchronization (a compare-and-swap) when the timer expires, so threads virtually never interfere with each other.

Re: Log by time, not by count

#47
It should be both. A heartbeat monitor can log information at periodic events while warnings, errors and other high priority events are logged as soon as they occur. All log entries should be time-stamped regardless of the logging frequency.

Re: Log by time, not by count

#48

This post falls into a common trap; conflating logging with metrics. Log interesting things, where interesting is defined as context outside what the "happy path" execution performs. Collect and make available system metrics, such as invocation counts, processing time histograms, etc., to make available what the post uses log statements to disseminate same.

I built a system for collecting metrics via logs and has worked well for my apps when I don't want to set up a whole separate system for it.

Re: Log by time, not by count

#49

This post falls into a common trap; conflating logging with metrics. Log interesting things, where interesting is defined as context outside what the "happy path" execution performs. Collect and make available system metrics, such as invocation counts, processing time histograms, etc., to make available what the post uses log statements to disseminate same.

One exception to this is batch scripts and other cli tools with a clear start and end, like an installer, rsync, curl, dd, etc. Setting up metrics here is way overkill and the user may still be interested in the progress. Easiest made available through logs. Curses UI could be a nice middle ground but also very often overkill.
Post reply on HN