Test for no logs from multiple levels

[omus]

I encountered a scenario where I wanted to ensure my function which could emit different levels of logs under different conditions was not emitting any logging information under one specific scenario. For this test I needed to write:

@test_nolog LOGGER "warn" r".*" begin
    @test_nolog LOGGER "notice" r".*" begin
        @test_nolog LOGGER "info" r".*" begin
            f()
        end
    end
end

It would be nice to have a more straight-forward way of writing this.

[rofinn]

Would it make sense for @test_nolog to take a vector of pairs for each level => regex?

[omus]

I'm not sure I would require that power. I think what I want is:

@test_nolog LOGGER <code>

Which would validate that no logs are emitted from the executed code. Alternatively:

@test_nolog LOGGER ("warn", "notice", "info") <code>

could mean that no logs of that level are emitted. The one problem I see with this however is that we use a tuple in the message part to indicate an AND operation while this would indicate an OR.

[rofinn]

Looks like base does something closer to the pairs interface, but with tuples.

  If we also wanted to test the debug messages, these need to be enabled with the min_level keyword:

  @test_logs (:info,"Doing foo with n=2") (:debug,"Iteration 1") (:debug,"Iteration 2") min_level=Debug foo(2)

[rofinn]

Alright, looks like the base implementation is pretty hacky, so I'll just go with @test_nolog <logger> <msg> <expr> for now.

[omus]

I found myself wanting this again. I was in a scenario where I wanted to test for two different log messages but only call the function once:

@test_log LOGGER "warn" "one" begin
    @test_log LOGGER "warn" "two" begin
        slow_call()
    end
end

[omus]

I ended up writing this as a more generic way of testing for logs. It may be useful to do some iteration on this design:

using Memento: DefaultFormatter, Handler, Logger, Record, gethandlers, setpropagating!
using Test

struct RecordHandler{F} <: Handler{F}
    records::Vector{Record}
end

RecordHandler() = RecordHandler{DefaultFormatter}(Record[])

function RecordHandler(body::Function, logger::Logger)
    handler = RecordHandler()
    original_handlers = copy(gethandlers(logger))

    try
        logger.handlers = Dict{Any, Handler}()
        push!(logger, handler)

        setpropagating!(logger, false) do
            body()
        end
    finally
        logger.handlers = original_handlers
    end

    return handler
end

function Base.log(handler::RecordHandler, rec::Record)
    push!(handler.records, rec)
end

###

rh = RecordHandler(BidDelivery.LOGGER) do
    slow_call()
end

@test rh.records[1].level == "warn"
@test occursin("one", rc.records[1].msg)

@test rh.records[2].level == "warn"
@test occursin("two", rc.records[2].msg)

[rofinn]

Hmmm, that's pretty close to what already happens internally. I'm not sure how much I like the accessing of nested fields, but I wonder if we could break this up into 4 separate API changes... which could individually be useful in other circumstances.

1. A do-block syntax for all handlers which allows you to explicitly use a given handler for some chunk of code.
2. Introduce a cache/queue handler which allows you to hold records in memory. Possibly even letting you "replay" them later.
3. Simpler syntax for creating adhoc records (e.g., namedtuple?)
4. Support better equality/comparison methods for records and sets of records (e.g., partial equality, intersection)?