Origin of log entries misreported

[rufoa]

I just got this in my logs: 16-Jan-14 00:30:13 rufus-laptop.home DEBUG [slf4j-timbre.adapter] - Entry count for : https://api.twitter.com:443 : 0

The real origin is netty but it is being misreported as coming from slf4j-timbre.adapter itself.

Need to investigate why

[fzakaria]

Maybe we have to pass down the FQDN. I know that's common for log wrappers.

I know the API has support for it.

I'll post more info when I'm back at desk. On 13 Jan 2016 4:50 p.m., "rufoa" notifications@github.com wrote:

I just got this in my logs: 16-Jan-14 00:30:13 rufus-laptop.home DEBUG [slf4j-timbre.adapter] - Entry count for : https://api.twitter.com:443 : 0

The real origin is netty https://github.com/AsyncHttpClient/async-http-client/blob/e7798c8926ad020d3b1f845c44f0e12255fb02c0/client/src/main/java/org/asynchttpclient/netty/channel/DefaultChannelPool.java#L197 but it is being misreported as coming from slf4j-timbre.adapter itself.

Need to investigate why

— Reply to this email directly or view it on GitHub https://github.com/fzakaria/slf4j-timbre/issues/12.

[rufoa]

Actually I'm not sure timbre allows the FQN to be overridden - it seems to set it based on *ns*: https://github.com/ptaoussanis/timbre/blob/master/src/taoensso/timbre.cljx#L435

[rufoa]

@ptaoussanis: is it legit to use timbre middleware to overwrite the value of ?ns-str, in order to change the reported namespace a log event supposedly came from? Or is there a better way to do this that I've missed?

[ptaoussanis]

Hi @rufoa,

So to confirm: you have the correct namespace (which is different from the *ns* that Timbre is picking up), and you'd like to communicate the corrected namespace to Timbre?

Could you show me where in your code you're calling into Timbre exactly?

One possibility would be for me to mod https://github.com/ptaoussanis/timbre/blob/d132d443e5d31707d490f9f4a23a57caa34e1bac/src/taoensso/timbre.cljx#L424 to accept an optional ?merge-data data arg for merging at https://github.com/ptaoussanis/timbre/blob/d132d443e5d31707d490f9f4a23a57caa34e1bac/src/taoensso/timbre.cljx#L337

That way you could override any appender arguments (incl. :?ns-str) via log1-macro.

log1-macro's currently listed as an implementation detail but I'd be open to changing that if this helps, just let me know :-)

Cheers!

[rufoa]

So to confirm: you have the correct namespace (which is different from the ns that Timbre is picking up), and you'd like to communicate the corrected namespace to Timbre?

Yes, exactly

Could you show me where in your code you're calling into Timbre exactly?

please forgive me for the horrific looking macro!

https://github.com/fzakaria/slf4j-timbre/blob/f919e244c3395f547841e8aa9c753290dfeab09f/src/slf4j_timbre/adapter.clj#L26

That way you could override any appender arguments (incl. :?ns-str) via log1-macro.

Something along these lines would be ideal

Thanks!

[ptaoussanis]

No problem, will cut a new Timbre release a bit later today; just in the middle of some work on Sente-

[ptaoussanis]

Okay, taking a look at this now...

Question: is the default file and line info correct, or also something you'd like to replace?

[rufoa]

Question: is the default file and line info correct, or also something you'd like to replace?

It's not correct but I've figured out a way to grab the correct values from the call stack, so if there could be a way for me to supply this replacement info to Timbre that would be great

thanks for your work on this!

[rufoa]

@ptaoussanis thanks so much for making all the necessary changes to Timbre - I think I've got it all working!

slf4j log entries now look like this when passed to Timbre:

{ :?ns-str "com.ning.http.client.providers.netty.NettyConnectionsPool"
  :?file   "NettyConnectionsPool.java"
  :?line   91
   ...

and can be whitelisted/blacklisted by caller class name like native Timbre log entries can be by namespace.

[fzakaria]

@rufoa cool.

Did you do something similar to

StackTraceElement[] stackTraces = Thread.currentThread().getStackTrace();
    StackTraceElement stackTraceElement = stackTraces[1]; // one frame higher
    stackTraceElement.getLineNumber();

[ptaoussanis]

@rufoa Just a heads-up that I'm still tweaking the API; will let you know once it's stable and I've cut a stable release later today

Taking the opportunity to refactor a few other things while I'm in the codebase...

[rufoa]

@fzakaria Yes but I follow the chain up till it leaves our namespace because it bounces around a lot

[ptaoussanis]

@rufoa Okay, stable release info at https://github.com/ptaoussanis/timbre/releases - the API you want at https://github.com/ptaoussanis/timbre/blob/f5af6d5d80fcd154596d37e57b579fc5d653eebe/src/taoensso/timbre.cljx#L476

Should provide everything you need but just let me know if you run into any issues or have any questions.

Good luck! :-)