Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 2 commits into from
Oct 23, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/LoggingExtras.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
56 changes: 39 additions & 17 deletions src/verbosity.jl
Original file line number Diff line number Diff line change
@@ -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
Expand All @@ -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 = """
Expand All @@ -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.

Comment on lines +92 to +95
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am not conviced thsi is better than just using

with_logger(EarlyFilteredLogger(x->x.group==:Foo) do
...
end

Maybe we should instead be adding a

filter_group_logger(group) = EarlyFilteredLogger(x->x.group==group)

if it really is too long

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's really the convenience of having it bundled with the withlevel function. It's so onerous remembering the incantation to get the logger, set it to the new one, and then on top remember the LoggingExtras machinery to early filter. Bundling that all up into withlevel as the "one thing" I need to remember as a package dev is what makes this work really well.

!!! note

Expand All @@ -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
33 changes: 6 additions & 27 deletions test/runtests.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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

Expand Down
Loading