No namespace info for tools.logging signals

[AlexChalk]

Hi, thanks for all your work on this! I've tried a few different ways to limit ring.logger output like the following to errors, but none of the below filter the log entries:

2024-05-23T20:13:00.759634816Z INFO LOG me :taoensso.telemere/tools-logging - {:request-method :get, :uri "/health", :server-name "localhost", :ring.logger/type :finish, :status 200, :ring.logger/ms 50}

(t/set-min-level! nil "ring.logger" :error)
(t/set-min-level! nil "ring.logger*" :error)
(t/set-min-level! nil "ring.logger.*" :error)
(t/set-min-level! nil "taoensso.telemere/tools-logging" :error)
(t/set-min-level! nil "taoensso.telemere/tools-logging*" :error)
(t/set-min-level! nil "taoensso.telemere/tools-logging.*" :error)
(t/set-min-level! nil "my.app*" :error)

I have this issue with other libraries too, e.g. (t/set-min-level! nil "org.eclipse.jetty" :error) doesn't filter jetty logs.

(t/set-min-level! :error) works fine. Can you advise me on where I'm going wrong?

[ptaoussanis]

@AlexChalk Hi Alex, you're very welcome!

So your syntax for set-min-level! looks good, but from observing the :taoensso.telemere/tools-logging id - the problem is likely this:

tools.logging unfortunately doesn't capture namespace information - so the signals you're trying to filter actually have a nil namespace.

When you create a signal directly with Telemere (i.e. with a Telemere API call in your code), it's able to capture callsite information like your namespace and line number. You can see this by checking the signal content:

(select-keys (t/with-signal (t/log! "My message")) [:ns :line]) => {:ns "my-namespace", :line 416})

So in this case we can set a minimum level with a namespace pattern and have it behave as expected:

(t/set-min-level! nil "my-namespace" :error)
(t/with-signal (t/log! "My message")) ; => nil (insufficient level: `:info` < `:error`)

The problem in your case is that your signals aren't actually being created by Telemere API calls in the Jetty code, etc. Instead, org.eclipse.jetty is calling the tools.logging API which doesn't capture namespace information in the first place. All it's capturing is the level and message, which are then redirected to Telemere.

So by the time Telemere knows about the logging call, all it has is the level and message. It doesn't have callsite information; not even the namespace.

Unfortunately that's one of the disadvantages of logging facades like tools.logging or SLF4J. They offer the flexibility to choose a backend, but the big downside is that they then force the lowest-common-denominator feature set on every backend. In this case no namespaces.

How to work around this?

Options are a little limited, since we're fundamentally constrained by what external libraries are doing (org.eclipse.jetty not collecting ns info, etc.).

One way might be to invert your logic:

• You know that your own Telemere signals will have a namespace.
• All interop signals (generated via tools.logging or SLF4J, etc.) will not have a namespace.

So you could potentially do something like this:

(set-min-level! :error) ; Set high default min level
(set-min-level! nil "taoensso.telemere*" :info) ; Set lower min level for your code

Unfortunately that'll mean effectively setting an :error level for ALL logs outside your application (not just from the org.eclipse.jetty ns). But that might be a decent-enough compromise in some cases?

Sorry about the confusion on this! Your expectation that this'd work is totally reasonable. I'll update the relevant docs to help warn about the limitations of interop, and I'll give some more thought to what else (if anything) I might be able to do from Telemere's end to make it easier to work around these limitations.

[AlexChalk]

Thanks for the detailed info @ptaoussanis!

You might want to look at how logback (https://logback.qos.ch/) implements this, as I'm able to configure separate log levels for org.eclipse.jetty etc. using that. However, it requires me to write xml, which is why I was trying telemere 😅.

Example working logback config in case it's helpful:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="10 seconds">
    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type
             ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <charset>UTF-8</charset>
            <pattern>%date{ISO8601} [%thread] %-5level %logger{36} - %msg %n</pattern>
        </encoder>
    </appender>
    <logger name="org.apache.http" level="warn" />
    <logger name="org.xnio.nio" level="warn" />
    <logger name="com.zaxxer.hikari" level="warn" />
    <logger name="org.eclipse.jetty" level="info" />
    <logger name="ring.logger" level="info" />
    <root level="DEBUG">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

[ptaoussanis]

You might want to look at how logback (https://logback.qos.ch/) implements this, as I'm able to configure separate log levels for org.eclipse.jetty etc. using that.

That's actually super helpful, thank you! I'll look into this for the next beta. If the logger name is indeed provided like it seems to be there, then that should be sufficient to support the kind of namespace filtering you want.

Will come back to you here once this is ready 👍

[ptaoussanis]

@AlexChalk Just pushed beta14 which includes this change so that:

1. Logger names are now used as namespaces for SLF4J and tools.logging signals.
2. These now have dedicated :kind (:slf4j, :tools.logging) to make it easier to set kind-specific min levels.

Hopefully that addresses the current issue?

[AlexChalk]

@ptaoussanis yep, (t/set-min-level! nil "ring.logger*" :error) now works, thanks so much!

[ptaoussanis]

Great, thanks for the confirmation. And thanks again for pinging about this!