# Weird MethodError with custom logger

**URL:** <https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897>\
**Category:** General Usage\
**Tags:** question\
**Created:** [July 1, 2019, 3:13pm UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897 "2019-07-01T15:13:33Z")\
**Posts on this page:** 10\
**Page:** 1

<div class="post-metadata">

**Author:** ![cserteGT3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/csertegt3/32/8283_2.png) [@cserteGT3](https://discourse.julialang.org/u/cserteGT3)\
**Post date:** [July 1, 2019, 3:13pm UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/1 "2019-07-01T15:13:33Z")

</div>

I’m trying to construct a custom logger and getting a weird MethodError. For MWE, I copied [`SimpleLogger`](https://github.com/JuliaLang/julia/blob/55e36cc308b66d3472990a06b2797f9f9154ea0a/base/logging.jl#L502) and changed its name to `TestLogger`.  
Here’s the logger code (`testlog.jl`):

```julia
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
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.)

---

<div class="post-metadata">

**Author:** ![pixel27](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/pixel27/32/8902_2.png) [@pixel27](https://discourse.julialang.org/u/pixel27)\
**Post date:** [July 1, 2019, 5:13pm UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/2 "2019-07-01T17:13:04Z")

</div>

```julia
Base.CoreLogging.min_enabled_level(logger::TestLogger) = logger.min_level

```

That seems to work…

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

```

---

<div class="post-metadata">

**Author:** ![cserteGT3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/csertegt3/32/8283_2.png) [@cserteGT3](https://discourse.julialang.org/u/cserteGT3)\
**Post date:** [July 1, 2019, 7:55pm UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/3 "2019-07-01T19:55:59Z")

</div>

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

---

<div class="post-metadata">

**Author:** ![c42f](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/c42f/32/52842_2.png) [@c42f](https://discourse.julialang.org/u/c42f)\
**Post date:** [July 2, 2019, 12:26am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/4 "2019-07-02T00:26:53Z")

</div>

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:

```julia
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.

---

<div class="post-metadata">

**Author:** ![pixel27](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/pixel27/32/8902_2.png) [@pixel27](https://discourse.julialang.org/u/pixel27)\
**Post date:** [July 2, 2019, 12:29am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/5 "2019-07-02T00:29:15Z")

</div>

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.

---

<div class="post-metadata">

**Author:** ![c42f](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/c42f/32/52842_2.png) [@c42f](https://discourse.julialang.org/u/c42f)\
**Post date:** [July 2, 2019, 12:41am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/6 "2019-07-02T00:41:48Z")

</div>

Sure, the following works for me:

```julia
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

```

---

<div class="post-metadata">

**Author:** ![pixel27](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/pixel27/32/8902_2.png) [@pixel27](https://discourse.julialang.org/u/pixel27)\
**Post date:** [July 2, 2019, 12:45am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/7 "2019-07-02T00:45:17Z")

</div>

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

---

<div class="post-metadata">

**Author:** ![c42f](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/c42f/32/52842_2.png) [@c42f](https://discourse.julialang.org/u/c42f)\
**Post date:** [July 2, 2019, 3:47am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/8 "2019-07-02T03:47:41Z")

</div>

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.

---

<div class="post-metadata">

**Author:** ![c42f](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/c42f/32/52842_2.png) [@c42f](https://discourse.julialang.org/u/c42f)\
**Post date:** [July 2, 2019, 7:08am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/9 "2019-07-02T07:08:38Z")

</div>

Tab completion with `Logging` should be fixed by [https://github.com/JuliaLang/julia/pull/32473](https://github.com/JuliaLang/julia/pull/32473)

---

<div class="post-metadata">

**Author:** ![cserteGT3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/csertegt3/32/8283_2.png) [@cserteGT3](https://discourse.julialang.org/u/cserteGT3)\
**Post date:** [July 2, 2019, 7:37am UTC](https://discourse.julialang.org/t/weird-methoderror-with-custom-logger/25897/10 "2019-07-02T07:37:03Z")

</div>

> [@c42f](#):
>
> @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.

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