Improve thread safety and logging metadata

* make `ComponentLogger` immutable with an atomic `min_level` cache
* protect rule updates and registry access with locks
* make `with_min_level` task-local to avoid affecting concurrent tasks
* delegate output synchronization to the underlying sink
* generate stable log record IDs using `Base.CoreLogging.log_record_id`
* tighten `@clogf` argument validation
* remove unused group-less helper overloads
* update docstrings for the new concurrency semantics

Author: abcdvvvv

src/ComponentLogging.jl

@@ -1,5 +1,6 @@
 module ComponentLogging
 using Logging
+using Threads: Atomic
 
 include("PlainLogger.jl")
 export PlainLogger
@@ -19,14 +20,16 @@ msg_to_tuple(x::Tuple) = x
 msg_to_tuple(x) = (x,)
 
 ## ComponentLogger
-mutable struct ComponentLogger{L<:AbstractLogger} <: AbstractLogger
-    const rules::Dict{RuleKey,LogLevel}
-    const sink::L
-    min::LogLevel
+struct ComponentLogger{L<:AbstractLogger} <: AbstractLogger
+    rules::Dict{RuleKey,LogLevel}
+    sink::L
+    lock::ReentrantLock
+    min_level::Atomic{Int32}
 end
 
 function ComponentLogger(rules::Dict{RuleKey,LogLevel}=Dict{RuleKey,LogLevel}((DEFAULT_SYM,) => Info); sink=ConsoleLogger(Debug))
-    return ComponentLogger(rules, sink, minimum(values(rules)))
+    rules = copy(rules)
+    return ComponentLogger(rules, sink, ReentrantLock(), minimum(values(rules)).level)
 end
 
 function ComponentLogger(nonstdrules::AbstractDict; sink=ConsoleLogger(Debug))
@@ -43,29 +46,28 @@ end
 function set_log_level!(logger::ComponentLogger, group, lvl::Union{Integer,LogLevel})
     grp = _tokey(group)
     lv = LogLevel(lvl)
-    old = get(logger.rules, grp, nothing)
-    logger.rules[grp] = lv
-    if lv < logger.min
-        logger.min = lv
-    elseif old !== nothing && old === logger.min && lv > logger.min
-        logger.min = minimum(values(logger.rules))
+    @lock logger.lock begin
+        old = get(logger.rules, grp, nothing)
+        minlvl = LogLevel(logger.min_level[])
+        if lv < minlvl
+            logger.min_level[] = lv.level
+            logger.rules[grp] = lv
+        else
+            logger.rules[grp] = lv
+            if old !== nothing && old === minlvl && lv > minlvl
+                logger.min_level[] = minimum(values(logger.rules)).level
+            end
+        end
     end
     return logger
 end
 
 set_log_level!(logger::ComponentLogger, group, on::Bool) =
     set_log_level!(logger, group, on ? 0 : 1)
 
-"Temporarily set the minimum level within a do-block; restore afterward even if an exception is thrown; no lock"
-function with_min_level(f::Function, logger::ComponentLogger, lvl::Union{Integer,LogLevel})
-    old_lvl = logger.min
-    logger.min = LogLevel(lvl)
-    try
-        f()
-    finally
-        logger.min = old_lvl
-    end
-end
+"Temporarily set the minimum level for the current task within a do-block; restore afterward even if an exception is thrown"
+with_min_level(f::Function, logger::ComponentLogger, lvl::Union{Integer,LogLevel}) =
+    task_local_storage(f, logger, LogLevel(lvl))
 
 @inline function _effective_level(rules::Dict{RuleKey,LogLevel}, group::Union{Symbol,RuleKey})::LogLevel
     path = _tokey(group) #::NTuple{N,Symbol}
@@ -92,32 +94,33 @@ end
     end
 end
 
-Logging.min_enabled_level(g::ComponentLogger) = g.min
+function Logging.min_enabled_level(g::ComponentLogger)::LogLevel
+    lvl = get(task_local_storage(), g, nothing)::Union{Nothing,LogLevel}
+    return lvl === nothing ? LogLevel(g.min_level[]) : lvl
+end
 
 Logging.shouldlog(g::ComponentLogger, level, _module, group, id) =
-    level >= _effective_level(g.rules, group)
+    @lock g.lock level >= _effective_level(g.rules, group)
 
 Logging.handle_message(logger::ComponentLogger, level::LogLevel, message, _module, group, id, file, line; kwargs...) =
     Logging.handle_message(logger.sink, level, message, _module, group, id, file, line; kwargs...)
 
 ## Module registry
-const _REGISTRY_LOCK = ReentrantLock()
-const _REGISTRY = IdDict{Module,AbstractLogger}()
+const _RegistryLock = ReentrantLock()
+const _Registry = IdDict{Module,AbstractLogger}()
 
 function set_module_logger(mod::Module, logger::AbstractLogger)::String
-    lock(_REGISTRY_LOCK) do
-        _REGISTRY[mod] = logger
-    end
+    @lock _RegistryLock _Registry[mod] = logger
     string(mod) * " <- " * string(typeof(logger))
 end
 
 "Get the logger for the calling module; if unbound, fallback through parent modules; error at the top"
 function get_logger(mod::Module)
-    lock(_REGISTRY_LOCK) do
+    @lock _RegistryLock begin
         m = mod
         while true
-            if haskey(_REGISTRY, m)
-                return _REGISTRY[m]
+            if haskey(_Registry, m)
+                return _Registry[m]
             end
             pm = parentmodule(m)
             if pm === m   # reached the top (e.g. Base/Core/Main)
@@ -268,14 +271,15 @@ function _print_tree(io::IO, rules::Dict{RuleKey,LogLevel};
 end
 
 function Base.show(io::IO, ::MIME"text/plain", logger::ComponentLogger)
+    rules, minlvl = @lock logger.lock (copy(logger.rules), LogLevel(logger.min_level[]))
     println(io, "ComponentLogger")
     print(io, " sink:\t")
     println(io, nameof(typeof(logger.sink)))
     print(io, " min:\t")
-    _print_level(io, logger.min)
+    _print_level(io, minlvl)
     println(io)
-    println(io, " rules:\t", length(logger.rules))
-    _print_tree(io, logger.rules)
+    println(io, " rules:\t", length(rules))
+    _print_tree(io, rules)
 end
 
 include("helpers.jl")

src/docstrings.jl

@@ -33,12 +33,11 @@ A logger that delegates to an underlying sink (`AbstractLogger`) while applying
 component-based minimum level rules. Rules are defined on paths of symbols
 (`NTuple{N,Symbol}`). A lookup walks up the path and falls back to `(:__default__,)`.
 
+- `rules`: mapping from `NTuple{N,Symbol}` to `LogLevel`. If no explicit
+  `(:__default__,)` rule exists, lookup falls back to `Info`.
 - `sink`: the underlying `AbstractLogger` that actually handles messages.
-- `rules`: mapping from `NTuple{N,Symbol}` to `LogLevel`. The default entry
-  `((DEFAULT_SYM,), Info)` is created automatically when needed.
-
-The effective minimum level is the minimum of all values in `rules`, cached in
-the `min` field for fast checks.
+- `lock`: protects concurrent access to `rules`.
+- `min_level`: atomic cache of the minimum value in `rules` for fast checks.
 """
 ComponentLogger
 
@@ -49,15 +48,17 @@ Set or update the minimum level for a specific component `group` on `logger`.
 `group` may be a `Symbol` or a `NTuple{N,Symbol}` tuple; `lvl` can be `LogLevel` or `Integer`.
 If `lvl` is a `Bool`, it is treated as a simple switch: `true` sets the rule to `Info` and
 `false` sets it to `LogLevel(1)` (which disables the default `clogenabled(logger, group)` check).
-Updates the internal `min` cache appropriately.
+Updates `rules` under `logger.lock` and keeps the atomic `min_level` cache consistent.
 """
 set_log_level!
 
 """
     with_min_level(f, logger, lvl)
 
-Temporarily set `logger.min` to `lvl` while executing `f()`, restoring the
-original value afterward even if an exception is thrown.
+Temporarily override the minimum enabled level for the current task while
+executing `f()`. The override is task-local, so it does not modify `logger.min_level`
+or affect other concurrent tasks. Nested overrides are restored correctly, including
+when `f()` throws an exception.
 """
 with_min_level
 
@@ -232,8 +233,8 @@ clogf(:core, 0) do
 end
 set_log_level(:core, 1000)
 with_min_level(2000) do
-    # Temporarily raise the global minimum level (fast early rejection).
-    clog(:core, 0, "suppressed by global min")
+    # Temporarily raise the current task's minimum level (fast early rejection).
+    clog(:core, 0, "suppressed by the task-local minimum")
 end
 ```
 

src/helpers.jl

@@ -17,10 +17,6 @@ clog(logger::AbstractLogger, group::Union{Symbol,RuleKey}, message...;
     _module=nothing, id=nothing, file=nothing, line=nothing, kwargs...) =
     clog(logger, group, Info, message...; _module, id, file, line, kwargs...)
 
-# clog(logger::AbstractLogger, level::Union{Integer,LogLevel}, message...;
-#     _module=nothing, id=nothing, file=nothing, line=nothing, kwargs...) =
-#     clog(logger, (DEFAULT_SYM,), level, message...; _module, id, file, line, kwargs...)
-
 ## clogenabled
 function clogenabled(logger::AbstractLogger, group::Union{Symbol,RuleKey}, level::Union{Integer,LogLevel})::Bool
     grp = _tokey(group)
@@ -31,9 +27,6 @@ end
 clogenabled(logger::AbstractLogger, group::Union{Symbol,RuleKey}) =
     clogenabled(logger, group, Info)
 
-# clogenabled(logger::AbstractLogger, level::Union{Integer,LogLevel}) =
-#     clogenabled(logger, (DEFAULT_SYM,), level)
-
 ## clogf
 @inline function clogf(f::F, logger::AbstractLogger, group::Union{Symbol,RuleKey}, level::Union{Integer,LogLevel}; _module=nothing, file=nothing, line=nothing)::Nothing where {F<:Function}
     grp = _tokey(group)
@@ -107,14 +100,17 @@ macro clog(args...)
 
     msg_tuple = Expr(:tuple, map(esc, msg_ps)...)
     mod, file, line = Base.CoreLogging.@_sourceinfo
+    id = Base.CoreLogging.log_record_id(mod, lvl_ex, Expr(:tuple, msg_ps...),
+        (Expr(:(=), :_group, grp_ast),))
     return :(
         let CL = ComponentLogging,
             _lg = ComponentLogging.get_logger($mod),
             _lvl = ComponentLogging.LogLevel($(esc(lvl_ex))),
-            _grp = $grp_ast
+            _grp = $grp_ast,
+            _id = $(QuoteNode(id))
 
-            if CL._enabled(_lg, _lvl, _grp; _module=$mod, id=nothing)
-                CL.Logging.handle_message(_lg, _lvl, $msg_tuple, $mod, _grp, nothing, $file, $line)
+            if CL._enabled(_lg, _lvl, _grp; _module=$mod, id=_id)
+                CL.Logging.handle_message(_lg, _lvl, $msg_tuple, $mod, _grp, _id, $file, $line)
             end
             nothing
         end
@@ -158,29 +154,33 @@ macro clogf(args...)
             error("@clogf: group must be a literal Symbol like :core or a tuple of literal Symbols like (:a,:b)")
         end
         grp_ast = is_sym_lit(args[1]) ? Expr(:tuple, args[1]) : args[1]
-        n >= 3 || error("@clogf: with group, need (group, level, expr)")
+        n == 3 || error("@clogf: with group, need exactly (group, level, expr)")
         lvl_ex = args[2]
         body_ex = args[3]
     else
+        n == 2 || error("@clogf: need exactly (level, expr) or (group, level, expr)")
         lvl_ex = args[1]
         body_ex = args[2]
     end
 
     mod, file, line = Base.CoreLogging.@_sourceinfo
+    id = Base.CoreLogging.log_record_id(mod, lvl_ex, body_ex,
+        (Expr(:(=), :_group, grp_ast),))
     return :(
         let CL = ComponentLogging,
             _lg = ComponentLogging.get_logger($mod),
             _lvl = ComponentLogging.LogLevel($(esc(lvl_ex))),
-            _grp = $grp_ast
+            _grp = $grp_ast,
+            _id = $(QuoteNode(id))
 
-            if CL._enabled(_lg, _lvl, _grp; _module=$mod, id=nothing)
+            if CL._enabled(_lg, _lvl, _grp; _module=$mod, id=_id)
                 _msg = $(esc(body_ex))
                 if _msg isa Function
                     _msg = _msg()
                 end
                 if _msg !== nothing
                     CL.Logging.handle_message(_lg, _lvl, CL.msg_to_tuple(_msg),
-                        $mod, _grp, nothing, $file, $line)
+                        $mod, _grp, _id, $file, $line)
                 end
             end
             nothing