Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Clearer API for custom log levels #33960

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Conversation

c42f
Copy link
Member

@c42f c42f commented Nov 27, 2019

This resolves #33418 by implementing something similar to #33418 (comment), but including various improvements which came up in the conversation.

The premise here is that log levels are a combination of two different things:

  • A log level is a label: This is a categorical concept, and is how we describe the different levels in the documentation.
  • A log level implies an importance or severity. This is an ordinal concept; levels can be compared according to < applied to their severities.

Here I've introduced an AbstractLogLevel as the appropriate supertype for user defined log levels, and added a severity function which can be applied to any log level to compute the (integer) severity. The print function is now recommended to compute log level labels from the level instance.

This is an improvement on using my_level = LogLevel(some_int) because it allows custom levels to be represented with an appropriate label in pretty printing, and allows various modules to define custom levels independently without risk of confusion in the logging backends. It's also an improvement over the previous (undocumented) convention of allowing any custom type for a level because the severity function is more clearly defined.

Detail

Add AbstractLogLevel as the supertype of all log level types.

Introduce "log level severity" including a severity function which
maps any user-defined log level to an integer log level severity. This
more cleanly separates out the ordinal notion of log severity from the
categorical aspects of the log level.

Log levels can be ordered by comparing their severities. This gives a
certian type of pre-order which is reflexive, transitive and total, but
not antisymmetric. This is the same as the ordering of complex numbers
by their magnitude.

Change to using print rather than show for formatting log levels for
display. This seems to resolve the old conundrum of "do we print Warn as
it appears in the program as "Warn" or in human-friendly form as
"Warning""?

The early (global) decision about log level filtering within the macro
is now lowered to shouldlog(level) which is more natural and more
customizable.

A bug in ConsoleLogger was fixed where custom log levels could not actually be used with it easily.

Compatibility

User defined log level types worked previously, but were undocumented and had a less sensible API. Nevertheless, I've attempted to include some fallback definitions so that this older pattern can continue to work. However, I have not depwarned these fallbacks yet because Logging is still released in lockstep with Base and this might make it hard for package authors to support both <=1.3 as well as 1.4 (/ 1.5 whenever this gets merged).

TODO

  • User manual documentation
  • Tutorial examples
  • Refine deprecated fallbacks to only those which are absolutely required.
  • Additional testing of deprecated fallbacks.
  • Additional testing of ConsoleLogger interaction with custom log levels

Add AbstractLogLevel as the supertype of all log level types.

Introduce "log level severity" including a `severity` function which
maps any user-defined log level to an integer log level severity. This
more cleanly separates out the ordinal notion of log severity from the
categorical aspects of the log level.

Log levels can be ordered by comparing their severities. This gives a
certian type of pre-order which is reflexive, transitive and total, but
not antisymmetric. This is the same as the ordering of complex numbers
by their magnitude.

Change to using `print` rather than `show` for formatting log levels for
display. This seems to resolve the old conundrum of "do we print Warn as
it appears in the program as "Warn" or in human-friendly form as
"Warning""?

The early (global) decision about log level filtering within the macro
is now lowered to `shouldlog(level)` which is more natural and more
customizable.
@c42f c42f added the logging The logging framework label Nov 27, 2019
@@ -97,16 +129,13 @@ The log level provides a key against which potential log records may be
filtered, before any other work is done to construct the log record data
structure itself.
"""
struct LogLevel
struct LogLevel <: AbstractLogLevel
level::Int32
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we just change this to Int?
Or make severity return an Int32
I feel like the overhead of converting it each time is not worth it.

elseif level == Error print(io, "Error")
elseif level == AboveMaxLevel print(io, "AboveMaxLevel")
else print(io, "LogLevel($(level.level))")
end
end

show(io::IO, level::LogLevel) = print(io, level == Warn ? "Warn" : level)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reasonable.

@@ -44,14 +45,18 @@ function handle_message end

Return true when `logger` accepts a message at `level`, generated for
`_module`, `group` and with unique log identifier `id`.

For very early filtering of custom log levels, users may override
`shouldlog(level)`.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a practical example other than severity(level) >= _min_enabled_severity[]?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Never mind. I guess one application might be some kind of "zero-cost @debug" like ToggleableAsserts.jl https://discourse.julialang.org/t/ann-toggleableasserts-jl/31291

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You got it, this is exactly what I had in mind!

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

By the way, this has been re-invented multiple times, for example https://discourse.julialang.org/t/defensive-programming-assert/8383/11?u=chris_foster :-D

@tkf
Copy link
Member

tkf commented Nov 28, 2019

I don't have time ATM to review this in detail (sorry). I just went through the OP and the code quickly but it looks good to me. For example, I think recommending print for configuring text output is a good way to go.

  • A log level is a label: This is a categorical concept, and is how we describe the different levels in the documentation.

It may be a super nit-picking (in the sense that this doesn't matter in writing the code and docs), but I find it strange to treat the categorical part as the main concept of log level. According to Merriam-Webster one of the meaning is:

a position in a scale or rank (as of achievement, significance, or value)

So, I think conceptualizing AbstractLogLevel primary as an ordered set make more sense. Also, its first job is shouldlog(level) which is defined in terms of severity(level). The categorical label part only matters at the very end when printing it as text.

@c42f
Copy link
Member Author

c42f commented Nov 28, 2019

Thanks @tkf I always appreciate your thoughtful and insightful input. I think we reached consensus in #33418, on the subject of print vs show and the naming of severity so those are the things I've implemented here (cf. especially the first part of your comment here: #33418 (comment)).

So, I think conceptualizing AbstractLogLevel primary as an ordered set make more sense. Also, its first job is shouldlog(level) which is defined in terms of severity(level).

By default this is true, but I have in mind some "interesting" uses for shouldlog(level). For example, it's one way to implement a SoftDepWarn mechanism in Base where we define shouldlog(::SoftDepWarnLevel) = false, and allow users who really want deprecations in 1.x to invert this. We may have severity(::SoftDepWarnLevel) = severity(Warn), but with soft depwarns nevertheless disabled and completely compiled away.

I was planning to use @oxinabox's write-up from the following comment as a starting point for the documentation: #33418 (comment)

@tkf
Copy link
Member

tkf commented Nov 29, 2019

I commented on log "level" because I thought maybe it makes sense to use some other concept instead of "level" if the log level is not really about ordering. But log level is a very familiar concept for those who used other logging systems so I am not sure if it is a good idea to invent something new here.

(BTW, SoftDepWarn sounds great! It is something I've been wanting for a while.)

@oxinabox
Copy link
Contributor

oxinabox commented Nov 29, 2019

re: depwarn, another way to implement it is:

LoggingExtras.EarlyFilteredLogger(current_logger()) do log
    # Only log deprecations not from Base (since they will be safe til Julia 2.0)
    # and not from DataFrames as we will update that another day.
    log.group=:depwarn && log._module !== Base && log._module !== DataFrames
end

That also compiles away.
And supports other criteria (e.g which modules to post from).
And doesn't require monkey-patching Base to configure it.

@c42f
Copy link
Member Author

c42f commented Dec 4, 2019

And supports other criteria (e.g which modules to post from).

Indeed, this approach has many benefits and of course we'll continue to support it.

That also compiles away

In what sense? I don't know of any way this could compile away. What I mean when I say "compile away" is that the compiler is able to optimize code like

if shouldlog(stuff...)
     more_logging_stuff
end

into something like

if false
     more_logging_stuff
end

via constant propagation / inlining etc, which then gets removed via dead code elimination.

That means that the result of shouldlog(stuff...) must be a known constant at compile time, which generally requires the type of the arguments stuff... to be known (unless the method table of shouldlog is trivial).

In your example stuff involves the logger, but the logger is only ever known to be of type AbstractLogger which forces dynamic dispatch.

@tkf
Copy link
Member

tkf commented Mar 6, 2020

How about setseverity function? I think you need this if you want to propagate the categorical information to the log handler while allowing the transformation pipeline to increment or decrement the log levels. This API can be optional with the default definition setseverity(_, level::Integer) = LogLevel(level).

@tkf
Copy link
Member

tkf commented Mar 9, 2020

Thinking about how to use log levels as filtering (ref JuliaLogging/ProgressLogging.jl#9, SciML/DiffEqBase.jl#450), I think it would be nice to have a way to declare the "default value" of shouldlog. Something like this

supportedby(level::AbstractLogLevel, logger) = true
supports(logger::AbstractLogger, level) = supportedby(level, logger)

with

real_shouldlog_used_by_the_macro(logger, level, _module, group, id) =
    supports(logger, level) && shouldlog(logger, level, _module, group, id)

Proposed API

supportedby(level::LevelType, logger)

This is an API for LevelType <: AbstractLogLevel. Only the owner of the type of the first argument can define this function. This is used for defining the default value of supports(logger, level).

Log record types which require particular log handlers (e.g., progress logging) are highly recommended to declare this to false.

Example:

module ProgressLogging
    Logging.supportedby(::ProgressLogLevel, _) = false
end

supports(logger::LoggerType, level)

This is an API for LoggerType <: AbstractLogger to explicitly declare that it supports level type. Only the owner of the type of the first argument can define this function. It defaults to supportedby(level, logger).

Example:

module TerminalLoggers
    Logging.supports(::TerminalLogger, ::ProgressLogLevel) = true
end

Notes

Note that we can't do this with current shouldlog as something like shouldlog(logger, level::ProgressLogLevel, _module, group, id) == false would cause method ambiguities.

I'm not 100% sure if we need to pass logger to supportedby(level, logger). But I thought it may be handy if you can call supports from supportedby; e.g., when a particular custom level type is a composition of two custom level types.

Alternative API: default_shouldlog(logger, level) and shouldlog(logger, level).

@c42f
Copy link
Member Author

c42f commented Jun 22, 2020

Oops, posted a half-done comment here by mistake!

Re-posting something more complete... this has been languishing because I'm not sure whether we should address the categorical nature of group at the same time. But after some helpful discussion with @tanmaykm I think maybe it's fine and I should push it through.

@JasonPries
Copy link
Contributor

Interested in this since the workaround referenced in #33418 no longer functions in 1.6.0 (see #38292).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
logging The logging framework
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Provide a clean way to add custom LogLevels
4 participants