It would be very useful to have a mechanism that automatically adds thread- and process-id to log messages. Can this currently be implemented using a custom logger, or would this require changes to Julia’s logging system?
1 Like
Can you not just
@info Threads.threeadid()
I guess you want to have the threadid automatically inserted?
Yes, this should be transparent to the user, if possible. For once, for convenience, but also so that logging in third-party code will also be annotated with thread/process information automatically.
For now, I’m doing this by hand, but it’s been extremely valuable for debugging multi-threaded and/or distributed code.
Ok, turns out a custom logger can do this just fine - at least on Julia v1.2 and 1.3, handle_message()
is called on the same thread as the logging call, so handle_message()
can just use threadid()
. Worker info is added automatically as part of the print command(s):
# Requires Julia >= v1.2 (and ParallelProcessingTools.jl >= v0.4)
using Distributed
addprocs(2)
@everywhere begin
using Base.CoreLogging: AbstractLogger, LogLevel, Info, Debug, Warn, Error, global_logger
import Base.CoreLogging: shouldlog, min_enabled_level, handle_message
using Base.Threads: threadid
using Distributed: myid
# Mostly a copy of Base.CoreLogging.SimpleLogger, only
# `" (thread $(threadid())): "` has been added:
struct ProcThreadInfoLogger <: AbstractLogger
stream::IO
min_level::LogLevel
message_limits::Dict{Any,Int}
end
ProcThreadInfoLogger(stream::IO=stderr, level=Info) = ProcThreadInfoLogger(stream, level, Dict{Any,Int}())
shouldlog(logger::ProcThreadInfoLogger, level, _module, group, id) =
get(logger.message_limits, id, 1) > 0
min_enabled_level(logger::ProcThreadInfoLogger) = logger.min_level
catch_exceptions(logger::ProcThreadInfoLogger) = false
function handle_message(logger::ProcThreadInfoLogger, level, message, _module, group, id,
filepath, line; maxlog=nothing, kwargs...)
if maxlog !== nothing && maxlog isa Integer
remaining = get!(logger.message_limits, id, maxlog)
logger.message_limits[id] = remaining - 1
remaining > 0 || return
end
buf = IOBuffer()
iob = IOContext(buf, logger.stream)
levelstr = level == Warn ? "Warning" : string(level)
msglines = split(chomp(string(message)), '\n')
println(iob, "┌ ", levelstr, " (thread $(threadid())): ", msglines[1])
for i in 2:length(msglines)
println(iob, "│ ", msglines[i])
end
for (key, val) in kwargs
println(iob, "│ ", key, " = ", val)
end
println(iob, "└ @ ", something(_module, "nothing"), " ",
something(filepath, "nothing"), ":", something(line, "nothing"))
write(logger.stream, take!(buf))
nothing
end
end # @everywhere
# Activate:
@everywhere global_logger(ProcThreadInfoLogger(stderr, Debug))
# Test:
@debug "foo"
@everywhere using ParallelProcessingTools
@onprocs procs() @onthreads allthreads() @info 42 threadid()
1 Like