# Logging - handling repeated warnings

**URL:** https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014
**Category:** General Usage
**Tags:** warning
**Created:** [March 18, 2019, 11:42pm UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014 "2019-03-18T23:42:11Z")
**Posts on this page:** 10
**Page:** 1

<div class="post-metadata">

### Author: ![crbinz](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/crbinz/32/1919_2.png) [@crbinz](https://discourse.julialang.org/u/crbinz)
#### Post date: [March 18, 2019, 11:42pm UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/1 "2019-03-18T23:42:11Z")

</div>

My code calls a function in another module that emits warning when certain conditions are met. Often, if I’m not careful, that condition will be met for many thousands of calls, resulting in many thousands of repeated warnings being printed. How can I mitigate this? I’d like to only show the first instance, if possible.

I’ve read the [Logging section of the docs](https://docs.julialang.org/en/v1/stdlib/Logging/#Logging-1), and I know about `maxlog`, but it seems that doesn’t help me unless it’s my own code emitting the warning. Granted, I do not feel I have a very good grasp of how the new logging system works.

Here’s an example, not sure how helpful it is:

```nohighlight
julia> using EarthOrientation, Dates

julia> daterange = DateTime("2022-01-01T00:00"):Day(1):DateTime("2022-01-05")
2022-01-01T00:00:00:1 day:2022-01-05T00:00:00

julia> getxp.(daterange) # 5 warnings; would prefer just one
┌ Warning: No data available after 2020-02-29. The last valid value will be returned.
└ @ EarthOrientation ~/.julia/packages/EarthOrientation/sQYt3/src/EarthOrientation.jl:50
┌ Warning: No data available after 2020-02-29. The last valid value will be returned.
└ @ EarthOrientation ~/.julia/packages/EarthOrientation/sQYt3/src/EarthOrientation.jl:50
┌ Warning: No data available after 2020-02-29. The last valid value will be returned.
└ @ EarthOrientation ~/.julia/packages/EarthOrientation/sQYt3/src/EarthOrientation.jl:50
┌ Warning: No data available after 2020-02-29. The last valid value will be returned.
└ @ EarthOrientation ~/.julia/packages/EarthOrientation/sQYt3/src/EarthOrientation.jl:50
┌ Warning: No data available after 2020-02-29. The last valid value will be returned.
└ @ EarthOrientation ~/.julia/packages/EarthOrientation/sQYt3/src/EarthOrientation.jl:50
5-element Array{Float64,1}:
 0.021509
 0.021509
 0.021509
 0.021509
 0.021509

```

---

<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: [March 19, 2019, 2:57am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/2 "2019-03-19T02:57:56Z")

</div>

As a crude solution which will kill all warnings and other messages from the third party module `EarthOrientation`, you can attach a `NullLogger` while you call that code:

```julia
using Logging

result = with_logger(NullLogger()) do
    EarthOrientation.getxp(daterange)
end

```

This is definitely a little heavy handed though, because it gives no way for the parent application to turn these messages back on when using your module; in this sense it is a non-composable (though expedient!) solution.

I think a more composable solution would involve installing a log filter while you call `EarthOrientation.getxp()` which could do one of several things, but attaching an additional `maxlog=1` key to those specific log events would be the most straightforward. Then the log events would flow downstream to the application as we’d like.

I do have a prototype of a more general log filtering system over at [GitHub - c42f/MicroLogging.jl at cjf/log-filtering](https://github.com/c42f/MicroLogging.jl/tree/cjf/log-filtering) which would hopefully let you do this kind of thing easily. This is a good motivating use case, so thanks for asking the question 🙂

---

<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: [March 19, 2019, 6:24am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/3 "2019-03-19T06:24:14Z")

</div>

To illustrate a composable solution, here’s a log filter which adds a set of keywords to all log messages matching a pattern:

```julia
using Logging

mutable struct LogKeysFilter{Parent<:AbstractLogger,Pattern,NT<:NamedTuple} <: AbstractLogger
    parent::Parent
    pattern::Pattern
    extra_keys::NT
end

Logging.shouldlog(f::LogKeysFilter, args...) = Logging.shouldlog(f.parent, args...)
Logging.min_enabled_level(f::LogKeysFilter) = Logging.min_enabled_level(f.parent)
Logging.catch_exceptions(f::LogKeysFilter) = Logging.catch_exceptions(f.parent)

function Logging.handle_message(f::LogKeysFilter, level, message, _module, group, id,
                        filepath, line; kwargs...)
    if occursin(f.pattern, message)
        Logging.handle_message(f.parent, level, message, _module, group, id, filepath, line;
                               merge(values(kwargs), f.extra_keys)...)
    else
        Logging.handle_message(f.parent, level, message, _module, group, id, filepath, line; kwargs...)
    end
end

with_logkeys(f, pattern; extra_keys...) = with_logger(f, LogKeysFilter(current_logger(), pattern, values(extra_keys)))

```

Usage would look like

```julia
function verbose()
    for i=1:3
        @warn "Some verbose message"
    end
end

function do_stuff()
    verbose()
end

@info "Do stuff without filter"
do_stuff()

@info "Do stuff with filter"
with_logkeys("verbose message", maxlog=1) do
    do_stuff()
end

```

With result:

```julia
[ Info: Do stuff without filter
┌ Warning: Some verbose message
└ @ Main ~/logtest.jl:36
┌ Warning: Some verbose message
└ @ Main ~/logtest.jl:36
┌ Warning: Some verbose message
└ @ Main ~/logtest.jl:36

[ Info: Do stuff with filter
┌ Warning: Some verbose message
└ @ Main ~/logtest.jl:36

```

---

<div class="post-metadata">

### Author: ![crbinz](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/crbinz/32/1919_2.png) [@crbinz](https://discourse.julialang.org/u/crbinz)
#### Post date: [March 19, 2019, 12:49pm UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/4 "2019-03-19T12:49:21Z")

</div>

Awesome, this does exactly what I need. Thanks for putting that together.

---

<div class="post-metadata">

### Author: ![crbinz](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/crbinz/32/1919_2.png) [@crbinz](https://discourse.julialang.org/u/crbinz)
#### Post date: [March 20, 2019, 12:54am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/5 "2019-03-20T00:54:01Z")

</div>

Actually… can you think of a way to do this “globally” within a module? i.e. add `maxlog=1` to all log messages?

---

<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: [March 20, 2019, 5:04am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/6 "2019-03-20T05:04:47Z")

</div>

Yes if we generalize `LogKeysFilter` to accept `Module`s as log pattern matching criteria, we can globally install such a filter as follows:

```julia
global_logger(LogKeysFilter(global_logger(), EarthOrientation, (maxlog=1,)))

```

This requires the following generalization of `LogKeysFilter`:

```julia
using Logging

"""
    logmatch(pattern, level, message, _module, group, id, filepath, line; keywords...)

Return true if `pattern` matches the log event `(level,message, ...; keywords...)`.
"""
function logmatch
end

logmatch(pattern::Union{AbstractString,Regex}, level, message, _module, group, id, filepath, line; kws...) =
    occursin(pattern, message)
logmatch(pattern::Module, level, message, _module, group, id, filepath, line; kws...) =
    pattern == _module

mutable struct LogKeysFilter{Parent<:AbstractLogger,Pattern,NT<:NamedTuple} <: AbstractLogger
    parent::Parent
    pattern::Pattern
    extra_keys::NT
end

Logging.shouldlog(f::LogKeysFilter, args...) = Logging.shouldlog(f.parent, args...)
Logging.min_enabled_level(f::LogKeysFilter) = Logging.min_enabled_level(f.parent)
Logging.catch_exceptions(f::LogKeysFilter) = Logging.catch_exceptions(f.parent)

function Logging.handle_message(f::LogKeysFilter, level, message, _module, group, id,
                        filepath, line; kwargs...)
    if logmatch(f.pattern, level, message, _module, group, id, filepath, line; kwargs...)
        Logging.handle_message(f.parent, level, message, _module, group, id, filepath, line;
                               merge(values(kwargs), f.extra_keys)...)
    else
        Logging.handle_message(f.parent, level, message, _module, group, id, filepath, line; kwargs...)
    end
end

```

Note that fiddling with the global logger is by nature a global decision, and should generally be left to the application top level because having multiple modules trying to modify the global logger cannot compose in a systematic way.

---

<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: [March 20, 2019, 5:15am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/7 "2019-03-20T05:15:20Z")

</div>

By the way, thanks again for these questions. Having a bunch of these kind of practical use cases in mind builds the design confidence we need to go ahead with the next part of stdlib `Logging`. At the moment there’s frustratingly little backend filtering tooling because I’ve been a bit (overly?) cautious of baking in the wrong design.

---

<div class="post-metadata">

### Author: ![crbinz](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/crbinz/32/1919_2.png) [@crbinz](https://discourse.julialang.org/u/crbinz)
#### Post date: [March 20, 2019, 12:54pm UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/8 "2019-03-20T12:54:29Z")

</div>

This is great, thanks.

> [@c42f](#):
>
> Note that fiddling with the global logger is by nature a global decision, and should generally be left to the application top level because having multiple modules trying to modify the global logger cannot compose in a systematic way.

On that, is there a way to filter module-wide _without_ using a global logger? Usually the module calling `EarthOrientation` and generating all these warnings is my “top-level” application, but not always. I only asked about changing the `global_logger` because I wasn’t sure how else to accomplish what I want.

> [@c42f](#):
>
> By the way, thanks again for these questions. Having a bunch of these kind of practical use cases in mind builds the design confidence we need to go ahead with the next part of stdlib `Logging` .

No problem at all, glad my cluelessness can be of use to someone 😛. Thanks again for these very useful examples.

---

<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: [March 21, 2019, 6:34am UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/9 "2019-03-21T06:34:21Z")

</div>

> [@crbinz](#):
>
> On that, is there a way to filter module-wide _without_ using a global logger?

There’s the environment variable `JULIA_DEBUG` but I _really_ want to deprecate that and replace it with equivalent flexible and easy ways to configure the global logger.

Basically any global setting which configures logging is non-composable between modules in the sense that multiple modules may clash in attempting to configure such a global setting. This includes a global per-module verbosity stored in the module itself, an environment variable, the current global logger system, etc etc.

It sounds like you’d like a way to declare “always use these log filters when calling module A from module B”. Unfortunately I can’t see an effective composable way to get this kind of thing to work efficiently, without manually peppering the code with a lot of calls to `with_logger()`. Some options…

1. For isolated cases, manually pepper the code with `with_logger()`
2. Create a utility function in your module which makes configuring the global logger a bit easier.
3. Maybe configure your `.julia/config/startup.jl` to call this setup function, if it’s mainly personal interactive use you’re worried about.

I dunno. It seems kind of useful that some default logger config could be included with modules, but it’s unclear how that can configure what is essentially global state without either being noncomposable or making a system which is hopelessly inefficient. I wish I had a good answer to that problem.

---

<div class="post-metadata">

### Author: ![crbinz](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/crbinz/32/1919_2.png) [@crbinz](https://discourse.julialang.org/u/crbinz)
#### Post date: [March 21, 2019, 12:54pm UTC](https://discourse.julialang.org/t/logging-handling-repeated-warnings/22014/10 "2019-03-21T12:54:20Z")

</div>

Thanks again. I think, for now, that I’ll go with option 1/2, since it is mainly personal interactive use that’s driving this.
