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

Logging practices I follow

16elt.com

Post reply on HN
Print view View original

61–70 of 81 posts

Re: Logging practices I follow

#61

Post by adra »

giraffe_lady wrote: post #37
mattpallissard wrote: post #23

Earlier quoted context omitted.

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 fro…

> 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.

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.

Re: Logging practices I follow

#62

Post by tignaj »

adra wrote: post #48
masklinn wrote: post #45

Earlier quoted context omitted.

Is there a structured form of tracing? Because I feel like this contextual information should easily be part of a trace.

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.

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).

Re: Logging practices I follow

#63

Post by bob1029 »

hckr1292 wrote: post #38
bob1029 wrote: post #31

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.

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? (tim…

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.

Re: Logging practices I follow

#64

Post by sofixa »

Pxtl wrote: post #11

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?

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.

Re: Logging practices I follow

#65

Post by chriswarbo »

TeMPOraL wrote: post #14
kevmo314 wrote: post #9

Earlier quoted context omitted.

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.

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 le…

I do this in Scala, via 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

Re: Logging practices I follow

#66

Post by chriswarbo »

alexdowad wrote: post #43
chaghalibaghali wrote: post #12

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

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 fo…

> It is helpful if you can selectively switch on verbose logging by user or by API endpoint.

We currently use two log levels:

- When 'debug = true', debug logs are printed immediately (like a DEBUG log level)

- When 'debug = false', debug logs go into a buffer: if the request-handler succeeds, its debug buffer gets discarded. If it catches an exception, the buffer gets printed.

This avoids the main problem of log levels, which is having to guess up-front which level we might want (and inevitably get it wrong, and have to try re-creating a problem with more verbose logging!)

Re: Logging practices I follow

#67

Post by w10-1 »

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)

Re: Logging practices I follow

#68

Post by TeMPOraL »

chriswarbo wrote: post #65
TeMPOraL wrote: post #14

Earlier quoted context omitted.

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 le…

I do this in Scala, via 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…

That's a neat post, thanks for sharing! I didn't realize Scala had dynamic variables.

As for the HN comment that prompted your blog article, I did a double-take reading it, because I could've sworn I wrote the exact same thing around the same time - turns out I did, though on a different thread :).

Re: Logging practices I follow

#69

Post by spyspy »

0x457 wrote: post #34

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 t…

Also, who did it?

Re: Logging practices I follow

#70

Post by alexdowad »

chriswarbo wrote: post #66
alexdowad wrote: post #43

Earlier quoted context omitted.

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 fo…

> It is helpful if you can selectively switch on verbose logging by user or by API endpoint. We currently use two log levels: - When 'debug = true', debug logs are printed immediately (like a DEBUG log level) - When 'debug = false', debug logs go into a buffer: if the request-handler succeeds, its debug buffer gets discarded. If it catches an exception, the buffer gets printed. This avoids the main problem of log lev…

Nice! It sounds like you would do well to capture the debug output if a request handler takes an unusually long time to return (not just if an uncaught exception occurs).
Post reply on HN