Noisy Netty logs show up after adopting this library about slf4j-timbre HOT 15 CLOSED

Finally (sorry!) resolved in version "0.3.15"

Big thanks to everyone who helped sort this out

from slf4j-timbre.

Thanks for the input @runejuhl. I've added a pull request now which respects TIMBRE_LEVEL and defaults to :info.

The reason for defaulting to :info is that so many java libraries adds tons of debug output, and I would rather not have to specify -J-DTIMBRE_LEVEL=:info when running all my tools.deps plugins.

Thanks for the library @rufoa and hope you have time to review the pull request.

from slf4j-timbre.

Just tried export TIMBRE_LEVEL=":warn" as well... nope

from slf4j-timbre.

Thanks for the thorough report!

This looks similar to #21 (comment)

Strange that none of those things you tried worked. I assumed they would resolve this but I never actually checked at the time

from slf4j-timbre.

I think taoensso.timbre/-elide? and/or taoensso.timbre/may-log? might be misbehaving when used with our lib

This should cause our tests to fail but it doesn't:

$ TIMBRE_LEVEL=':warn' lein midje
Compile-time (elision) Timbre level: :warn
nil
All checks (114) succeeded.

from slf4j-timbre.

Good that you post that, I was about to create a new issue (which would need a separate repo/repro):

logs that are successfully re-routed via slf4j-timbre are unconditionally logged, i.e. :min-level is ignored.

For proof I added <<<<level>>>> to a custom output-fn. It shows that Timbre is receiving correct level values, but ignoring them for some reason.

18-12-22 15:37:36 INFO <<<<<:info>>>>>[datomic.process-monitor:43] - {:MetricsReport {:lo 1, :hi 1, :sum 1, :count 1}, :AvailableMB 6360.0, :event :metrics, :pid 30261, :tid 56}
18-12-22 15:37:36 DEBUG <<<<<:debug>>>>>[datomic.process-monitor:44] - {:event :metrics/report, :phase :begin, :pid 30261, :tid 56}
18-12-22 15:37:36 DEBUG <<<<<:debug>>>>>[datomic.process-monit...

from slf4j-timbre.

It looks like Timbre's compile-time elision is not working with slf4j-timbre.

This is because:

• Logging calls are elided at macro-expansion time based on the value of TIMBRE_LEVEL
• Because slf4j-timbre is AOT compiled, macro-expansion of slf4j-timbre.adapter occured when I compiled my project (using my value of TIMBRE_LEVEL), rather than when you compile your project

Unfortunately this project requires AOT. I will try to find another solution.

from slf4j-timbre.

So when TIMBRE_LEVEL is set at compile-time (of slf4j-timbre), our tests fail properly, as expected. The value of TIMBRE_LEVEL at runtime is ignored. This explains #32 (comment)

$ lein clean

$ TIMBRE_LEVEL=':warn' lein compile
Compiling slf4j-timbre.adapter
Compile-time (elision) Timbre level: :warn
Compiling slf4j-timbre.factory
Compiling slf4j-timbre.static-logger-binder
Compiling slf4j-timbre.static-marker-binder
Compiling slf4j-timbre.static-mdc-binder

$ lein midje
FAIL at (t_adapter.clj:43)
...

from slf4j-timbre.

Any progress on this? I figure an improvement would at least be to set the AOT compiled default level to info?

from slf4j-timbre.

It should be possible to filter out Jetty (and other noisy libraries) using the :ns-blacklist option in timbre: https://github.com/ptaoussanis/timbre#configuration

One of my projects has the following in an :ns-blacklist config option, loaded at runtime:

{:ns-blacklist ["com.zaxxer.hikari.pool.*"
                "io.netty.*"
                "org.apache.http.*"
                "org.eclipse.jgit.util.FS"]}

Seems to work fine. It's quite heavy handed, but that particular blacklist is used only for some configurations -- it's probably not something that should be enabled globally...

from slf4j-timbre.

My problem is that loads of logging happen during execution of tools.deps plugins such as deps-ancient and pack.alpha where I do not have the option to set anything at runtime.

from slf4j-timbre.

Ah, gotcha. Then I'm not of much use, sorry. I'm not even sure how I'd go about it... Hope you find a solution!

from slf4j-timbre.

Thanks -- and thanks for trying to help!

I'm not very ventured in slf4j-implementation land, but I figure that it would be possible to set the default timbre log level to :info (or what is present in TIMBRE_LEVEL).

Personally when binding slf4j I would like the default level to be :info.

from slf4j-timbre.

I updated factory.clj to be:

(ns slf4j-timbre.factory
	(:gen-class
		:name com.github.fzakaria.slf4j.timbre.TimbreLoggerFactory
		:implements [org.slf4j.ILoggerFactory]
		:state state
		:init init)
	(:require slf4j-timbre.adapter
						[taoensso.timbre :as timbre])
	(:import
		(com.github.fzakaria.slf4j.timbre TimbreLoggerFactory TimbreLoggerAdapter)))

(defonce bootstrapped (atom false))

(defn -init
	[]
	(when-not @bootstrapped
	  (reset! bootstrapped true)
		(let [lvl (System/getProperty "TIMBRE_LEVEL" ":info")]
			(timbre/set-level! (keyword (subs lvl 1)))))
	[[] (atom {})])

This seems to work fine for me. I will make a pull request.

from slf4j-timbre.

Personally when binding slf4j I would like the default level to be :info.

That seems like a good compromise IMO, but I'd make sure it was possible to override the default log level easily. That way it'd avoid the worst of too verbose logs, and users that want to see everything can adjust it to their needs.

from slf4j-timbre.