Request for clarification on the thread-safety (or lack thereof) of the Julia logging system

[simsurace]

I did not find any (recent) issues tracking this, so feel free to mark as a duplicate if there is one.

There were some recent messages across various Slack channels that implied that logging is somehow inherently thread-unsafe. I believe that a lot of people were confused/surprised by this. I repeatedly asked for clarification on Slack. I don't want to put further pressure on anyone in particular, but I feel like this should be clarified by someone qualified to do so.

[Moelf]

I think one of the more surprising thing is described by @vtjnash as:

Yes, the lowest level does, but at the slightly higher level, having any @log-type statements present in packages that might run in parallel (such as Pkg since the REPL now runs it using threads) may corrupt random memory and segfault (or merely corrupt) the program

[IanButterworth]

Attempts to add tests that demonstrate the issue here #57448

[IanButterworth]

We discussed this in the multithreading community call (link) and identified three potential threadsafety issues:

ConsoleLogger

1. maxlog (if specified) is implemented within handle_message using a Dict logger.message_limits without a lock to get/store counts.
   

   julia/base/logging/ConsoleLogger.jl

   Line 112 in 29da86b

   remaining = get!(logger.message_limits, id, Int(maxlog)::Int)

2. logger.stream isn't locked
   

   julia/base/logging/ConsoleLogger.jl

   Line 187 in 29da86b

   write(stream, take!(buf))

Global logger

3. Changing the global logger is done without a lock. A lock that calls to handle_message etc. should take.

   julia/base/logging/logging.jl

   Lines 605 to 623 in 29da86b

   	global _global_logstate::LogState
   	"""
   	global_logger()
   	Return the global logger, used to receive messages when no specific logger
   	exists for the current task.
   	global_logger(logger)
   	Set the global logger to `logger`, and return the previous global logger.
   	"""
   	global_logger() = _global_logstate.logger
   	function global_logger(logger::AbstractLogger)
   	prev = _global_logstate.logger
   	global _global_logstate = LogState(logger)
   	prev
   	end

[JamesWrigley]

Am I missing something or won't all of these lead to regular exceptions rather than segfaults?

[vtjnash]

Data races will lead to arbitrary UB, which will probably do pretty bad things (the best of which is to segfault)

[IanButterworth]

@vtjnash are there any other issues you're aware of?

[IanButterworth]

I've addressed a few things in #57591

For the global logger state, I've tried to force an issue to understand what could go wrong, but I've not been able to yet.
This succeeds.

using Logging
function logtest(n=1000)
    @sync begin
        terminate = Threads.Atomic{Bool}(false)
        Threads.@spawn while !terminate[]
            global_logger(ConsoleLogger(stdout))
        end
        Threads.@spawn for i in 1:n
            @info "$i $(sleep(0.1))"
        end
        terminate[] = true
    end
end