Deprecate verbosity macros (not compatible w/ juliac-compiled programs) (#94)

* Deprecate verbosity macros (not compatible w/ juliac-compiled programs)

Add convenience group keyword to withlevel to do early filtering on groups

Export withlevel

* Update src/verbosity.jl

Co-authored-by: Frames White <oxinabox@ucc.asn.au>

---------

Co-authored-by: Frames White <oxinabox@ucc.asn.au>

Author: quinnj

src/LoggingExtras.jl

@@ -11,7 +11,7 @@ import Base.CoreLogging:
 export TeeLogger, TransformerLogger, FileLogger,
     ActiveFilteredLogger, EarlyFilteredLogger, MinLevelLogger,
     DatetimeRotatingFileLogger, FormatLogger, LevelOverrideLogger,
-    @debugv, @infov, @warnv, @errorv, @logmsgv
+    @debugv, @infov, @warnv, @errorv, @logmsgv, withlevel
 
 ######
 # Re export Logging.jl from stdlib 

src/verbosity.jl

@@ -1,4 +1,4 @@
-function restore_callsite_source_position!(expr, src)
+function restore_callsite_source_position!(m, expr, src)
     @assert expr.head == :escape
     @assert expr.args[1].head == :macrocall
     @assert expr.args[1].args[2] isa LineNumberNode
@@ -7,7 +7,15 @@ function restore_callsite_source_position!(expr, src)
     # Logging.jl macros; otherwise, they would always report this (verbosity.jl)
     # file as the logging callsite
     expr.args[1].args[2] = src
-    return expr
+    ex = quote
+        LoggingExtras.deprecate_verbosity($(Meta.quot(m)))
+        $expr
+    end
+    return ex
+end
+
+function deprecate_verbosity(m)
+    Base.depwarn("Verbosity logging macros are deprecated as they are not compatible with juliac-compiled programs", m)
 end
 
 vlogmacrodocs = """
@@ -34,56 +42,57 @@ end
 
 "$vlogmacrodocs"
 macro debugv(verbosity::Int, msg, exs...)
-    return restore_callsite_source_position!(
+    return restore_callsite_source_position!(:debugv,
         esc(:($Base.@debug $msg _group=$(Verbosity(verbosity)) $(exs...))),
         __source__,
     )
 end
 
 "$vlogmacrodocs"
 macro infov(verbosity::Int, msg, exs...)
-    return restore_callsite_source_position!(
+    return restore_callsite_source_position!(:infov,
         esc(:($Base.@info $msg _group=$(Verbosity(verbosity)) $(exs...))),
         __source__,
     )
 end
 
 "$vlogmacrodocs"
 macro warnv(verbosity::Int, msg, exs...)
-    return restore_callsite_source_position!(
+    return restore_callsite_source_position!(:warnv,
         esc(:($Base.@warn $msg _group=$(Verbosity(verbosity)) $(exs...))),
         __source__,
     )
 end
 
 "$vlogmacrodocs"
 macro errorv(verbosity::Int, msg, exs...)
-    return restore_callsite_source_position!(
+    return restore_callsite_source_position!(:errorv,
         esc(:($Base.@error $msg _group=$(Verbosity(verbosity)) $(exs...))),
         __source__,
     )
 end
 
 "$vlogmacrodocs"
 macro logmsgv(verbosity::Int, level, msg, exs...)
-    return restore_callsite_source_position!(
+    return restore_callsite_source_position!(:logmsgv,
         esc(:($Base.@logmsg $level $msg _group=$(Verbosity(verbosity)) $(exs...))),
         __source__,
     )
 end
 
 """
-    LoggingExtras.withlevel(f, level; verbosity::Integer=0)
+    LoggingExtras.withlevel(f, level; verbosity::Integer=0, group::Union{Symbol, Nothing}=nothing)
 
 Convenience function like `Logging.with_logger` to temporarily wrap
 the current logger with a level filter while `f` is executed.
 That is, the current logger will still be used for actual logging, but
 log messages will first be checked that they meet the `level`
 log level before being passed on to be logged.
 
-For convenience, a `verbosity` keyword argument can be passed which also
-filters the "verbose logging" messages; see [`@debugv`](@ref), [`@infov`](@ref),
-[`@warnv`](@ref), [`@errorv`](@ref), and [`@logmsgv`](@ref).
+For convenience, a `group` keyword argument can be passed which also
+filters logging messages on the "group". By default, the group is the
+file name of the log macro call site, but can be overridden by passing
+the `_group` keyword argument to the logging macros.
 
 !!! note
 
@@ -95,11 +104,24 @@ filters the "verbose logging" messages; see [`@debugv`](@ref), [`@infov`](@ref),
     For more control directly construct the logger you want by making use of
     [`LevelOverrideLogger`](@ref) and then use `with_logger` to make it active.
 """
-function withlevel(f, level::Union{Int, LogLevel}=Info; verbosity::Integer=0)
-    with_logger(EarlyFilteredLogger(
-        args -> !(args.group isa Verbosity) || verbosity >= args.group.verbosity,
-        propagate_level_override(level, current_logger()))
-    ) do
-        f()
+function withlevel(f, level::Union{Int, LogLevel}=Info; verbosity::Integer=0, group::Union{Symbol, Nothing}=nothing)
+    if verbosity > 0
+        deprecate_verbosity(:withlevel)
+    end
+    verbosity > 0 && group !== nothing && throw(ArgumentError("Cannot specify both verbosity and group"))
+    if group === nothing
+        with_logger(EarlyFilteredLogger(
+            args -> !(args.group isa Verbosity) || verbosity >= args.group.verbosity,
+            propagate_level_override(level, current_logger()))
+        ) do
+            f()
+        end
+    else
+        with_logger(EarlyFilteredLogger(
+            args -> args.group === group,
+            propagate_level_override(level, current_logger())
+        )) do
+            f()
+        end
     end
 end

test/runtests.jl

@@ -255,14 +255,7 @@ end
     @test map(x -> x.level, logger.logs) == [Debug, Info]
 end
 
-@testset "Verbosity utilities" begin
-    logger = TestLogger(min_level=Info)
-    with_logger(logger) do
-        @infov 1 "info 1 message"
-    end
-    # if no verbosity filter is used, message is just like @info
-    @test !isempty(logger.logs)
-
+@testset "withlevel convenience" begin
     logger = TestLogger(min_level=Info)
     with_logger(logger) do
         LoggingExtras.withlevel(Debug) do
@@ -273,27 +266,13 @@ end
 
     logger = TestLogger(min_level=Info)
     with_logger(logger) do
-        LoggingExtras.withlevel(Debug; verbosity=1) do
-            @debugv 0 "debug 0 message"
-            @debugv 1 "debug 1 message"
-            @debugv 2 "debug 2 message"
-            # error message *also* isn't logged since
-            # level *and* verbosity must match
-            @errorv 2 "error 2 message"
-        end
-    end
-    @test length(logger.logs) == 2
-    @test logger.logs[1].group == LoggingExtras.Verbosity(0)
-    @test logger.logs[2].group == LoggingExtras.Verbosity(1)
-
-    logger = TestLogger(min_level=Info)
-    with_logger(logger) do
-        with_logger(MinLevelLogger(current_logger(), Info)) do
-            LoggingExtras.withlevel(Debug; verbosity=1) do
-                @debug "This should show up, even though it is behind 2 info level filters"
-            end
+        LoggingExtras.withlevel(Debug; group=:foo) do
+            @debug "debug message" _group=:foo
+            @debug "debug message" _group=:bar
         end
     end
+    @test logger.logs[1].level == Debug
+    # test that we filtered on only foo group log messages
     @test length(logger.logs) == 1
 end