Skip to content

Commit

Permalink
Reinstate statically computed log event ids (#29878)
Browse files Browse the repository at this point in the history
* fix bug and add tests

* Reinstate statically computed log record ids

Log ids are meant to identify the location of the message in the source
code and must be computed at compile time.

fix #28786, fix #28400; closes #29355.

* Clarify documentation regarding log record `id`
  • Loading branch information
c42f authored and fredrikekre committed Nov 1, 2018
1 parent 6a3a75a commit 51683c4
Show file tree
Hide file tree
Showing 4 changed files with 49 additions and 17 deletions.
24 changes: 11 additions & 13 deletions base/logging.jl
Original file line number Diff line number Diff line change
Expand Up @@ -222,17 +222,17 @@ macro error(exs...) logmsg_code((@_sourceinfo)..., :Error, exs...) end
@eval @doc $_logmsg_docs :(@error)

_log_record_ids = Set{Symbol}()
# Generate a unique, stable, short, human readable identifier for a logging
# statement. The idea here is to have a key against which log records can be
# filtered and otherwise manipulated. The key should uniquely identify the
# source location in the originating module, but should be stable across
# versions of the originating module, provided the log generating statement
# itself doesn't change.
function log_record_id(_module, level, message_ex)
# Generate a unique, stable, short, somewhat human readable identifier for a
# logging *statement*. The idea here is to have a key against which log events
# can be filtered and otherwise manipulated. The key should uniquely identify
# the source location in the originating module, but ideally should be stable
# across versions of the originating module, provided the log generating
# statement itself doesn't change.
function log_record_id(_module, level, message, log_kws)
modname = _module === nothing ? "" : join(fullname(_module), "_")
# Use (1<<31) to fit well within an (arbitriraly chosen) eight hex digits,
# as we increment h to resolve any collisions.
h = hash(string(modname, level, message_ex)) % (1<<31)
# Use an arbitriraly chosen eight hex digits here. TODO: Figure out how to
# make the id exactly the same on 32 and 64 bit systems.
h = UInt32(hash(string(modname, level, message, log_kws)) & 0xFFFFFFFF)
while true
id = Symbol(modname, '_', string(h, base = 16, pad = 8))
# _log_record_ids is a registry of log record ids for use during
Expand All @@ -249,7 +249,7 @@ end

# Generate code for logging macros
function logmsg_code(_module, file, line, level, message, exs...)
id = nothing
id = Expr(:quote, log_record_id(_module, level, message, exs))
group = nothing
kwargs = Any[]
for ex in exs
Expand Down Expand Up @@ -289,8 +289,6 @@ function logmsg_code(_module, file, line, level, message, exs...)
end
end

# Note that it may be necessary to set `id` and `group` manually during bootstrap
id = something(id, :(log_record_id(_module, level, $exs)))
if group == nothing
group = if isdefined(Base, :basename) && isa(file, String)
# precompute if we can
Expand Down
8 changes: 4 additions & 4 deletions stdlib/Logging/docs/src/index.md
Original file line number Diff line number Diff line change
Expand Up @@ -77,10 +77,10 @@ The system also generates some standard information for each event:

* The `module` in which the logging macro was expanded.
* The `file` and `line` where the logging macro occurs in the source code.
* A message `id` that is unique for each logging macro invocation. This is
very useful as a key for caching information or actions associated with an
event. For instance, it can be used to limit the number of times a message
is presented to the user.
* A message `id` that is a unique, fixed identifier for the *source code
statement* where the logging macro appears. This identifier is designed to be
fairly stable even if the source code of the file changes, as long as the
logging statement itself remains the same.
* A `group` for the event, which is set to the base name of the file by default,
without extension. This can be used to group messages into categories more
finely than the log level (for example, all deprecation warnings have group
Expand Down
20 changes: 20 additions & 0 deletions stdlib/Logging/test/runtests.jl
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,26 @@ import Logging: min_enabled_level, shouldlog, handle_message
handle_message(logger, Logging.Info, "msg", Base, :group, :asdf, "somefile", 1, maxlog=2)
@test shouldlog(logger, Logging.Info, Base, :group, :asdf) === false

# Check that maxlog works without an explicit ID (#28786)
buf = IOBuffer()
io = IOContext(buf, :displaysize=>(30,80), :color=>false)
logger = ConsoleLogger(io)
with_logger(logger) do
for i in 1:2
@info "test" maxlog=1
end
end
@test String(take!(buf)) ==
"""
[ Info: test
"""
with_logger(logger) do
for i in 1:2
@info "test" maxlog=0
end
end
@test String(take!(buf)) == ""

@testset "Default metadata formatting" begin
@test Logging.default_metafmt(Logging.Debug, Base, :g, :i, expanduser("~/somefile.jl"), 42) ==
(:blue, "Debug:", "@ Base ~/somefile.jl:42")
Expand Down
14 changes: 14 additions & 0 deletions test/logging.jl
Original file line number Diff line number Diff line change
Expand Up @@ -338,4 +338,18 @@ end
@test_logs (:warn, "a", Base) (@warn "a" _module=Base)
end

# Issue #28786
@testset "ID generation" begin
logs,_ = collect_test_logs() do
for i in 1:2
@info "test"
@info "test"
end
end
@test length(logs) == 4
@test logs[1].id == logs[3].id
@test logs[2].id == logs[4].id
@test logs[1].id != logs[2].id
end

end

0 comments on commit 51683c4

Please sign in to comment.