What is the best way to pass log configs everywhere without a global var?

[crocket]

Logging libraries seem to rely on a global config. This looks like a dangerous state that could blow up.

I researched a little, and there seems to be reader monad and dependency injection, all of which feel awkard.

Is there not a decent approach to passing log config without a global var?

[Shantanu Kumar]

Logging calls are far too frequent to practically pass config as argument everywhere, hence some kind of shared implicit context is required. Which logging libraries are you dealing with? If you use Timbre[1], you can pass config using dynamic vars or altering global state. If you use Logback[2] or Log4j[3], you can set system properties using Java interop ahead of dynamically loading (by looking up ns/var entry points in) Clojure code.

[1] Timbre: https://github.com/ptaoussanis/timbre

[2] Logback: http://logback.qos.ch/

[3] Log4j: http://logging.apache.org/log4j/2.x/

Shantanu

[crocket]

I have a feeling that there is a better way to pass log config as
implicit argument or implicit context without a global var.
Perhaps, I'm being unreasonable, considering that logging itself is
not a pure operation that shouldn't do I/O.

[James Reeves]

One way to think of logging is that it's a way of monitoring a running process.

In an ideal world, we could simply log every memory interaction a process makes, and then analyse that log to discover how the process is performing. In practice that's infeasible, but it does provide a clue as to how we should think about logging.

Consider logging as a way of manually marking points of interest in an application. From this point of view it makes sense that these markers should be global in scope, for the same reason that vars are.

However, I do think that we should separate how we monitor out code from how those logs are actually outputted. I've been working on some ideas along those lines, but nothing I'm entirely happy with, yet.

- James

[crocket]

How those logs are outputted is stored in a global state called log
configuration. So, I think the separation was done.
How else do you want to separate that?

> --
> You received this message because you are subscribed to the Google
> Groups "Clojure" group.
> To post to this group, send email to clo...@googlegroups.com
> Note that posts from new members are moderated - please be patient with your
> first post.
> To unsubscribe from this group, send email to
> clojure+u...@googlegroups.com
> For more options, visit this group at
> http://groups.google.com/group/clojure?hl=en
> ---
> You received this message because you are subscribed to a topic in the
> Google Groups "Clojure" group.
> To unsubscribe from this topic, visit
> https://groups.google.com/d/topic/clojure/9YiGAp6axcY/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to
> clojure+u...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.

[Mikera]

If you are using stuartsierra/component, it makes sense to have logging as a component within your overall system configuration.

I've found this to be a very useful approach in general: you can swap in / out different loggers for testing, you avoid a global var, it makes for really easy reloading at the REPL or running multiple concurrent versions etc.

[James Reeves]

On 27 July 2015 at 05:25, crocket <crocka...@gmail.com> wrote:

How those logs are outputted is stored in a global state called log
configuration. So, I think the separation was done.
How else do you want to separate that?

Traditionally, logging code is written something like:

    (log/info "HTTP request to" (:request-method req) (:uri req))

So the priority of the log (info) and the formatting of the log line is inlined into the source code.

A less complected piece of code would separate out what we want to monitor (req) from how we monitor it. So inline we just write:

    (monitor/monitor req :ring/request)

This monitors the variable req and associates it with the namespaced keyword :ring/request. In our logging namespace, we can then later define how we want to report on that monitor:

    (monitor/add-reporter

     :ring/request

     (fn [req] (log/info "HTTP request to" (:request-method req) (:uri req))))

This separates *what* we want to monitor from *how* we eventually log it. It means we can do things like define a set of useful monitoring points in a library, and then in a separate application decide on what's important.

- James

[crocket]

Can I see your proof of concept on github? Is it just an idea?

[Colin Yates]

I don’t have a proof of concept either but if somebody is going to put some effort into writing a new library I had a great idea they could incorporate. Continuing the ‘decomplecting’ that James started, the other thing that is decomplected (or actually not addressed at all) is _why_ we want logging to be produced. For me, I often want to see WARNING and above all the time and only see INFO and below if something interesting happened. ‘Interesting’ typically being an exception happened.

My notion was to add an adapter which at some point (e.g. around the use-case service/transaction boundary) started collecting all the logs in-memory and if the service executed correctly would simply drop the INFO and below messages. However, if the service aborted (e.g. threw an Exception) only then would the INFO and below logs get written to disk.

It’s so simple and useful I can’t believe nobody else has already written it. My excuse is good old time. Clojure, Agents, robert-hooke - couldn’t be easer.

You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+u...@googlegroups.com.

[Gary Verhaegen]

Have you guys looked at dire?

https://github.com/MichaelDrogalis/dire/blob/master/README.md

it could be used to take decomplection one step further, by not defining monitoring things inline at all. A library author could define additional logging namespace(s) with fns that load different levels of logging.

[James Reeves]

On 27 July 2015 at 08:28, crocket <crocka...@gmail.com> wrote:

Can I see your proof of concept on github? Is it just an idea?

Well, my first attempt at this was Inquest: https://github.com/weavejester/inquest

The idea of Inquest was to (ab)use alter-var-root to insert monitoring into existing functions, but I quickly discovered that there were quite a few anonymous functions I would like to monitor, as well as specific variables inside functions. I played around with ways of wrapping functions to inject monitoring of arguments and return values, but in the end it felt too clumsy and complicated.

So instead, I've been considering a macro like:

    (monitor key & body)

For example, if you wrote:

    (let [x 10] (monitor :user/example (inc x)))

This would produce messages that look like this:

    {:tag :user/example

     :timestamp 468822291902146

     :thread-id 1502

     :namespace user

     :event :enter

     :form (inc x)

     :locals {x 10}}

    {:tag :user/example

     :timestamp 468822291902261

     :thread-id 1502

     :namespace user

     :event :exit

     :form (inc x)

     :locals {x 10}

     :return 11

     :duration 115}

 

These messages would be passed to any listeners interested in the tag :user/example. If there were no appropriate listeners, the macro would execute the code without any additional wrapping. I've also been considering having the listeners declare ahead of time what keys they're interested in, as some keys might be expensive to generate (e.g. a :stacktrace key).

The upshot is that you'd get a whole bunch of information that you could then narrow down to produce any output you happen to want. If you're not interested in listening to a particular monitor, then there's minimal performance impact (perhaps around 50ns).

- James