Hard coded min level for `TransformerLogger`

[theogf]

I was surprised to see that

min_enabled_level(transformer::TransformerLogger) = BelowMinLevel

I don't understand why it is not

min_enabled_level(transformer::TransformerLogger) = min_enabled_level(transformer.logger)

[oxinabox]

Because each component in the compositional logging system serves one purpose.
The TransformerLogger transforms.
If you want to filter based on level, wrap it in a MinLevelLogger

[theogf]

That's fair, but following this logic I would expect TransformerLogger to leave min level of the logger it wraps untouched?

It feels to me like setting a hardcoded min level is an additional action from TransformerLogger?

[fredrikekre]

It feels to me like setting a hardcoded min level is an additional action from TransformerLogger?

Perhaps think of it like this: The default setting for a logger is BelowMinLevel, i.e. no filtering based on level so this isn't an extra action. If the wrapped logger filters based on another level it should be that logger who actually gets to do the filtering. With your suggestion the filtering would move up the chain.

[oxinabox]

That's fair, but following this logic I would expect TransformerLogger to leave min level of the logger it wraps untouched?

It does, doesn't it?

We check that here:

LoggingExtras.jl/src/CompositionalLoggers/transformer.jl

Line 27 in ed2c622

if comp_handle_message_check(transformer.logger, args...; kwargs...)

using:

LoggingExtras.jl/src/CompositionalLoggers/common.jl

Line 9 in ed2c622

(min_enabled_level(logger) <= level && shouldlog(logger, level, _module, group, id)) ||

and respect it.

I guess as an implementation detail we could have put that info into our min_enabled_level overload.
But it doesn't change behavour.

[theogf]

I am very confused now. I opened this issue cause I was surprise by the behavior of

with_logger(TransformLogger(identity, ConsoleLogger(Info))) do
  @debug "A"
  @info "B"
end

which returned both the @debug and @info.
But now that I tried again it behaves as I expected, returning the @info only...

[oxinabox]

Spooky.
I am going to close this for now.
Reopen, or open a new one if it reoccurs.

[theogf]

If I can ask a design question related to this.

When composing loggers (ignoring the Tee one), one can view it as a pipeline.

So we can have something like MinLevelLogger(TransformerLogger(identity, ConsoleLogger()), Debug).
However unlike function composition, the log argument is seen first by the outermost logger MinLevelLogger here.

What if in my code I would like to keep transform my logs based on the code path?

I wanted to do the following but it obviously does not work due to my issue above.

logger = MinLevelLogger(TransformerLogger(identity, ConsoleLogger()), Warn)

a = rand(1:2)
with_logger(TransformerLogger(log -> log._line = a, logger) do
  # .... more stuff
end

This will work, however all @debug statements will now be executed first and filtered later...
Is there another way to do this while keeping the early filtering happening?

[theogf]

I am very confused now. I opened this issue cause I was surprise by the behavior of

with_logger(TransformLogger(identity, ConsoleLogger(Info))) do
  @debug "A"
  @info "B"
end

which returned both the @debug and @info. But now that I tried again it behaves as I expected, returning the @info only...

Regarding this, I think I misremembered the behavior. What I had was

with_logger(TransformLogger(identity, ConsoleLogger(Info))) do
  @debug error("Oh no!")
  @info "B"
end

(where the error came from an external package)

So no 👻 yet :)

[oxinabox]

This will work, however all @debug statements will now be executed first and filtered later...
Is there another way to do this while keeping the early filtering happening?

Not currently.

I could imagine we could introduce an optimize_log_pipeline that reordered compositional loggers to move MinLevelLoggers and EarlyFilteredLoggers to be before ActiveFilteredLoggers and TransformerLoggers.
Which is semantically identical, but avoids executing the expressions in logs that might later be filtered.

Broadly speaking this is how our LevelOverrideLogger works.
It doesn't re-arrange but it does insert into non-top positioned in the pipeline.

LoggingExtras.jl/src/CompositionalLoggers/overridelogger.jl

Line 27 in ed2c622

# Propagating the constructor down to places it is needed