Hacker News Board Hacker News, browsed like a classic message board
Live data from Hacker News

Log by time, not by count

johnscolaro.xyz

Post reply on HN
Print view View original

51–60 of 109 posts

Re: Log by time, not by count

#51

Post by vorgol »

JohnScolaro wrote: post #10
AdieuToLogic wrote: post #2

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…

> I'm relatively new to working on this type of system.

> In the end, what's the difference between a log and a metric?

Don't let me put you down, but writing a logging advisory blog post when you don't know the difference between a log and a metric seems like a peculiar thing to do.

But I'm not shaming lack of knowledge, we all had to learn somehow.

Re: Log by time, not by count

#52

Post by kstrauser »

jabjq wrote: post #33
AdieuToLogic wrote: post #18

Earlier quoted context omitted.

> In the end, what's the difference between a log and a metric? Essentially, a log entry is the emission of state known by an individual code execution path at the point the log entry can be produced, whereas a metric is a measurement of a specific runtime execution performed by the system. For example, a log entry of: module_logger.info( f"Processed {num_events_processed_since_last_log} events." ) Emits a log entry…

You shouldn’t use f-strings with logging.

I know and understand the reasons for that rule, but it’s one of the first ones I disable in linters. The theoretical benefits in the context of the systems I work on aren’t worth the extra friction.

Re: Log by time, not by count

#53

Post by martin-t »

vorgol wrote: post #51
JohnScolaro wrote: post #10

Earlier quoted context omitted.

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…

> I'm relatively new to working on this type of system. > In the end, what's the difference between a log and a metric? Don't let me put you down, but writing a logging advisory blog post when you don't know the difference between a log and a metric seems like a peculiar thing to do. But I'm not shaming lack of knowledge, we all had to learn somehow.

IMO the reasonable compromise if write the post but make your experience level clear and make it clear you're effectively asking for advice.

Very few people do that though.

Re: Log by time, not by count

#54

Post by layer8 »

ot wrote: post #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 th…

That still means each thread will do its own separate log call every second (or whatever the period is) instead of all threads aggregating into a single log call.

Re: Log by time, not by count

#55

Post by jiehong »

haiku2077 wrote: post #20

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…

Following this advice, I've seen service where you could say the main function was to produce logs, and the actual response to the user was only a small part of the traffic generated.

What we really need is smart logging: only log the full span when an error is detected, otherwise no need for it. But it's not a very well supported case.

Re: Log by time, not by count

#56

Post by jonhohle »

AdieuToLogic wrote: post #2

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 enjoyed our metrics systems at Amazon’s and wrote one with a similar API at Okta and should really look at writing another one to open source.

One of the huge missing things in metrics systems, imho, is keeping granular metrics in the context of a business operation and then using late aggregation for trends. Last I looked nearly every metrics systems either logged individual events and and required processing for any rollup or aggregated too early and you couldn’t determine the effect on any individual operation/request. There’s a happy medium where you can get per-request counts, stats, and timing and still roll those up at the host/data center/region/granularity to get higher level trends.

Most metrics APIs are incompatible with this idea, however.

Re: Log by time, not by count

#57

Post by vanschelven »

the OP wrote "This is a simple concept, but I've never seen it written down before." Putting on my tin-foil hat:

Maybe that's because predictable log volume isn’t in the vendor’s interest. Time-based logging makes usage easier to reason about. Bursty, count-based logs? Much harder to estimate—much easier to monetize.

Re: Log by time, not by count

#58

Post by stackskipton »

As SRE/DevOps/Ops whatever, I'm screaming.

Metrics should be emitted in separate stream and never by logs outside corner cases. Logs should be used to determine WHY the system is having issues but never IS the system having issues.

Log alerting is a fools errand that looks like a great idea at start but quickly becomes a sand trap that will drive future people crazy and at scale, will overwhelm systems.

Why is log alerting bad idea?

Every log becomes a metric point that must be dealt with. Therefore, the logging system must be kept operational and error free. However, due to other problems below, this system quickly becomes a beast of it's own.

Logs are generally much bigger then KV of so there ends up being a ton of filtering going on in logging system, adding to the load.

Logging system probably does not understand rates so you end up writing gnarly queries to be like "Is this first unhandled exception?" in 10m or my 50th in 10m. Query in Prometheus is much much simpler.

Each language logging library handles things in different way so organization must be on point to either A) Keep log format the same between all different languages. B) Teach the logging system how to manipulate each log into format that can be handled by alerting system. Obviously A causes massive developer friction and B causes massive Ops friction.

Finally, I find people doing logging tend not handle exceptions as well because they can just trust logging system to alert them on specific problem and deal with it manually.

So for future Ops person who has to deal with your code, I'm begging you, import prometheus_client.

Re: Log by time, not by count

#59

Post by ot »

layer8 wrote: post #54
ot wrote: post #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 th…

That still means each thread will do its own separate log call every second (or whatever the period is) instead of all threads aggregating into a single log call.

No, the timer is still global (that's why you need the compare-and-swap). But the threads only need to do reads most of the time, and reads do not cause contention. Writes do.

It looks something like this (pseudocode):

    static std::atomic deadline{0};
    auto now = coarse_clock::now();
    auto curDeadline = deadline.load(std::memory_order_relaxed);
    if (now >= curDeadline &&
        deadline.compare_exchange_strong(curDeadline, now + period, std::memory_order_relaxed)) {
      // Actually log
    }

Re: Log by time, not by count

#60

Post by Baarsgaard »

jonhohle wrote: post #56
AdieuToLogic wrote: post #2

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 enjoyed our metrics systems at Amazon’s and wrote one with a similar API at Okta and should really look at writing another one to open source. One of the huge missing things in metrics systems, imho, is keeping granular metrics in the context of a business operation and then using late aggregation for trends. Last I looked nearly every metrics systems either logged individual events and and required processing for…

You're likely talking about "wide events" Which is essentially as many dimensions as possible attached to an event. I believe Meta was the one to develop an internal tool for handling this named Scuba.
Post reply on HN