Weird MethodError with custom logger

General Usage
1

I’m trying to construct a custom logger and getting a weird MethodError. For MWE, I copied SimpleLogger and changed its name to TestLogger.
Here’s the logger code (testlog.jl):

using Logging
using Logging: Info

# TestLogger


"""
    TestLogger(stream=stderr, min_level=Info)
Simplistic logger for logging all messages with level greater than or equal to
`min_level` to `stream`.
"""
struct TestLogger <: AbstractLogger
    stream::IO
    min_level::LogLevel
    message_limits::Dict{Any,Int}
end
TestLogger(stream::IO=stderr, level=Info) = TestLogger(stream, level, Dict{Any,Int}())

shouldlog(logger::TestLogger, level, _module, group, id) =
    get(logger.message_limits, id, 1) > 0

min_enabled_level(logger::TestLogger) = logger.min_level

catch_exceptions(logger::TestLogger) = false

function handle_message(logger::TestLogger, level, message, _module, group, id,
                        filepath, line; maxlog=nothing, kwargs...)
    if maxlog != nothing && maxlog isa Integer
        remaining = get!(logger.message_limits, id, maxlog)
        logger.message_limits[id] = remaining - 1
        remaining > 0 || return
    end
    buf = IOBuffer()
    iob = IOContext(buf, logger.stream)
    levelstr = level == Warn ? "Warning" : string(level)
    msglines = split(chomp(string(message)), '\n')
    println(iob, "┌ ", levelstr, ": ", msglines[1])
    for i in 2:length(msglines)
        println(iob, "│ ", msglines[i])
    end
    for (key, val) in kwargs
        println(iob, "│   ", key, " = ", val)
    end
    println(iob, "└ @ ", something(_module, "nothing"), " ",
            something(filepath, "nothing"), ":", something(line, "nothing"))
    write(logger.stream, take!(buf))
    nothing
end

And if I try to use it:

julia> include("testlog.jl")
handle_message (generic function with 1 method)

julia> global_logger(SimpleLogger())
ConsoleLogger(Base.TTY(Base.Libc.WindowsRawSocket(0x00000000000002b8) open, 0 bytes waiting), Info, Logging.default_metafmt, true, 0, Dict{Any,Int64}())

julia> global_logger(TestLogger())
ERROR: MethodError: no method matching min_enabled_level(::TestLogger)
Closest candidates are:
  min_enabled_level(::Test.TestLogger) at C:\cygwin\home\Administrator\buildbot\worker\package_win64\build\usr\share\julia\stdlib\v1.1\Test\src\logging.jl:34
  min_enabled_level(::ConsoleLogger) at C:\cygwin\home\Administrator\buildbot\worker\package_win64\build\usr\share\julia\stdlib\v1.1\Logging\src\ConsoleLogger.jl:43
  min_enabled_level(::SimpleLogger) at logging.jl:520
  ...
Stacktrace:
 [1] Base.CoreLogging.LogState(::TestLogger) at .\logging.jl:374
 [2] global_logger(::TestLogger) at .\logging.jl:469
 [3] top-level scope at none:0

julia> min_enabled_level(TestLogger())
Info

julia> versioninfo()
Julia Version 1.1.1
Commit 55e36cc308 (2019-05-16 04:10 UTC)
Platform Info:
  OS: Windows (x86_64-w64-mingw32)
  CPU: Intel(R) Core(TM) i7-3632QM CPU @ 2.20GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-6.0.1 (ORCJIT, ivybridge)

The weird is that the code is the same as the SimpleLogger and the errored method exists and works if I call it on it’s own.
Is this a bug or am I missing something? Or it has changed from v1.1.1 to #master? (I didn’t checked latter yet.)

2 
Base.CoreLogging.min_enabled_level(logger::TestLogger) = logger.min_level

That seems to work…

julia> global_logger(TestLogger())
ConsoleLogger(Base.TTY(RawFD(0x0000001a) open, 0 bytes waiting), Info, Logging.default_metafmt, true, 0, Dict{Any,Int64}())
1 Like
3

Thank you! I should have paid more attention to te error message.

4

The fact that these methods come from CoreLogging is an implementation detail which you shouldn’t really depend on. It’s better if you do the following instead:

Logging.min_enabled_level(logger::TestLogger) = logger.min_level

@cserteGT3 to explain a bit more, this isn’t specific to Logging, but rather a misunderstanding about how you extend methods. If you don’t prefix a new method with the originating module of the function (or explicitly import the function) you create an entirely new function with a separate method table rather than extending the existing function.

This goes for shouldlog, catch_exceptions, etc: you need to prefix those with Logging. or they won’t be added to the proper method table and won’t get called properly by the logging system.

5 Likes
5

Are you sure that works? That is what I tried first, and it didn’t seem to take affect. I ended up having to read the code around global_logger to see that min_enabled_level was defined in Base.CoreLogging.

6

Sure, the following works for me:

using Logging
using Logging: Info, Warn

"""
    TestLogger(stream=stderr, min_level=Info)
Simplistic logger for logging all messages with level greater than or equal to
`min_level` to `stream`.
"""
struct TestLogger <: AbstractLogger
    stream::IO
    min_level::LogLevel
    message_limits::Dict{Any,Int}
end
TestLogger(stream::IO=stderr, level=Info) = TestLogger(stream, level, Dict{Any,Int}())

Logging.shouldlog(logger::TestLogger, level, _module, group, id) =
    get(logger.message_limits, id, 1) > 0

Logging.min_enabled_level(logger::TestLogger) = logger.min_level

Logging.catch_exceptions(logger::TestLogger) = false

function Logging.handle_message(logger::TestLogger, level, message, _module, group, id,
                                filepath, line; maxlog=nothing, kwargs...)
    if maxlog != nothing && maxlog isa Integer
        remaining = get!(logger.message_limits, id, maxlog)
        logger.message_limits[id] = remaining - 1
        remaining > 0 || return
    end
    buf = IOBuffer()
    iob = IOContext(buf, logger.stream)
    levelstr = level == Warn ? "Warning" : string(level)
    msglines = split(chomp(string(message)), '\n')
    println(iob, "┌ ", levelstr, ": ", msglines[1])
    for i in 2:length(msglines)
        println(iob, "│ ", msglines[i])
    end
    for (key, val) in kwargs
        println(iob, "│   ", key, " = ", val)
    end
    println(iob, "└ @ ", something(_module, "nothing"), " ",
            something(filepath, "nothing"), ":", something(line, "nothing"))
    write(logger.stream, take!(buf))
    nothing
end
7

:expressionless: I don’t understand…it’s working now…I swear it wasn’t before…probably a disconnect between the head and the keyboard…sorry.

8

No problem! If you do find the need to mention CoreLogging in your own code, I think that’s a bug in the stdlib. Actually I see that tab completion is broken for the symbols from Logging; I’ll try to fix that.

9

Tab completion with Logging should be fixed by https://github.com/JuliaLang/julia/pull/32473

2 Likes
10

Thank you for the explanation! And also for the fix of the tab completion. I didn’t understand why it’s not working.

1 Like