Fork me on GitHub
#observability
<
2020-06-16
>
jumar04:06:59

I've just read https://juxt.pro/blog/posts/logging.html and I'm wondering whether people tend to pass logger instance as an explicit argument. I haven't seen that used much - it looks reasonable but I feel it unnecessarily bloats functions signatures.

seancorfield05:06:02

I've seen it in some non-Clojure projects but I haven't yet seen any Clojure projects that pass a logger "object" via the argument chain (although perhaps there are Component-based projects where a logger subcomponent is part of the overall "system" being passed in?).

seancorfield05:06:29

I like the clojure.tools.logging approach: code that wants to log can require that just like any other namespace and then invoke the macros defined in it. The implementation used is controllable externally, via a JVM option, or you can accept the default based on what c.t.l finds on the classpath.

plexus06:06:07

It's common in Java, I think in Clojure people tend to use macros that create a logger behind the scenes based on the namespace. That's also what pedestal.log and Glögi do, although they also allow specifying a specific logger. If you're using goog.log or one of the Java libs directly you'll have to create your own loggers, I've seen Figwheel do that.

jumar08:06:54

Great, thanks for the info! How do you deal with logging common "context" (like request-id)? With timbre, we use with-context and wrap the handler invocation with it - something like this:

(log/with-context (add-user-data-to-context user-id {:request-id (generate-request-id)})
        (handler request))

plexus09:06:40

On the java level this is done through something called MDC (mapped diagnostic context). Pedestal-log has a with-context macro as well, it uses this MDC under the hood. Not sure if Timbre does so as well.

plexus09:06:52

not too familiar with the details of MDC, but it's basically a way of setting context like this on a per-thread basis which logging frameworks can then pick up

lukasz14:06:56

http://Aviso.io logging lib has a nice way of using the MDC with clojure.tools.logging: https://cljdoc.org/d/io.aviso/logging/0.3.2/api/io.aviso.logging.mdc

emccue18:06:26

in general i would say you could do context like that with dynamic vars

emccue18:06:41

that feels like what they are for

emccue18:06:58

iff you need to roll something like that yourself

lukasz18:06:42

Interesting - I haven't used dynamic vars for anything beyond global config in 3rd party libs. Our request handlers/consumers always pass a context map so the MCD is set based on that

seancorfield19:06:38

I remember reading about MDC when we first switched to log4j2 and thinking "Hmm, that might come in handy" but clearly I have since forgotten about it, so thanks for the reminder @jumar! The CloseableThreadContext in log4j2 would work very nicely with Clojure's with-open -- something like this:

(with-open [ctc (org.apache.logging.log4j.CloseableThreadContext/putAll {"map" "of", "clojure" "data"})]
  (do-stuff-that-logs :things))

seancorfield19:06:03

(as long as you have %X in your log appender pattern)

ataggart19:06:10

Yup, MDC is just java working around the lack of binding.

ataggart19:06:58

"Context" is also handy when emitting metrics.

conormcd20:06:01

It's mildly annoying that MDC is usually Map<String,String> and not Map<String,Object> since the latter would allow for more interesting options when emitting structured logs.

seancorfield20:06:46

@conormcd Given that you'd have to stringize the keys in a Clojure map before calling .putAll(), you might as well pr-str (or just str) the value as well...

conormcd20:06:24

Yeah, it's the decoding back to, say a number for JSON encoding for transport to a log collector that's irritating.

noisesmith20:06:24

or use a json encoder for the data you'd put under the value

conormcd20:06:43

It's all fixable, just not nicely.

noisesmith20:06:46

but that might not be as nice for your json logger API, right