Reinstate statically computed log event ids (#29878)

* 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`

(cherry picked from commit 51683c4)

Author: c42f

base/logging.jl

@@ -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
@@ -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
@@ -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

stdlib/Logging/docs/src/index.md

@@ -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

stdlib/Logging/test/runtests.jl

@@ -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")

test/logging.jl

@@ -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