diff --git a/Project.toml b/Project.toml index 2fcd887..b7048da 100644 --- a/Project.toml +++ b/Project.toml @@ -1,15 +1,13 @@ name = "LoggingFormats" uuid = "98105f81-4425-4516-93fd-1664fb551ab6" -version = "1.3.0" +version = "1.4.0" [deps] JSON3 = "0f8b85d8-7281-11e9-16c2-39a750bddbf1" Logging = "56ddb016-857b-54e1-b83d-db4d58db5568" -StructTypes = "856f2bd8-1eba-4b0a-8007-ebc267875bd4" [compat] JSON3 = "1" -StructTypes = "1" julia = "1" [extras] diff --git a/src/LoggingFormats.jl b/src/LoggingFormats.jl index 72ecc37..32ab0f3 100644 --- a/src/LoggingFormats.jl +++ b/src/LoggingFormats.jl @@ -1,6 +1,8 @@ module LoggingFormats -import Logging, JSON3, StructTypes +import Logging, JSON3 + +const STANDARD_KEYS = (:level, :msg, :module, :file, :line, :group, :id) ############### ## Truncated ## @@ -56,16 +58,6 @@ lvlstr(lvl::Logging.LogLevel) = lvl >= Logging.Error ? "error" : lvl >= Logging.Info ? "info" : "debug" -struct JSONLogMessage{T} - level::String - msg::String - _module::Union{String,Nothing} - file::Union{String,Nothing} - line::Union{Int,Nothing} - group::Union{String,Nothing} - id::Union{String,Nothing} - kwargs::Dict{String,T} -end transform(::Type{String}, v) = string(v) transform(::Type{Any}, v) = v @@ -74,8 +66,16 @@ maybe_stringify_exceptions((e, bt)::Tuple{Exception,Any}) = sprint(Base.display_ maybe_stringify_exceptions(e::Exception) = sprint(showerror, e) maybe_stringify_exceptions(v) = v -function JSONLogMessage{T}(args) where {T} - JSONLogMessage{T}( +unclash_key(k) = k in STANDARD_KEYS ? Symbol("_", k) : k + +function to_namedtuple(::Type{T}, args; nest_kwargs) where {T} + kw = (k => transform(T, maybe_stringify_exceptions(v)) for (k, v) in args.kwargs) + if nest_kwargs + kw = (:kwargs => Dict{String, T}(string(k) => transform(T, maybe_stringify_exceptions(v)) for (k, v) in args.kwargs),) + else + kw = (unclash_key(k) => transform(T, maybe_stringify_exceptions(v)) for (k, v) in args.kwargs) + end + standard_message = NamedTuple{STANDARD_KEYS}(( lvlstr(args.level), args.message isa AbstractString ? args.message : string(args.message), args._module === nothing ? nothing : string(args._module), @@ -83,30 +83,59 @@ function JSONLogMessage{T}(args) where {T} args.line, args.group === nothing ? nothing : string(args.group), args.id === nothing ? nothing : string(args.id), - Dict{String,T}(string(k) => transform(T, maybe_stringify_exceptions(v)) for (k, v) in args.kwargs) - ) + )) + return merge(standard_message, kw) end -StructTypes.StructType(::Type{<:JSONLogMessage}) = StructTypes.OrderedStruct() -StructTypes.names(::Type{<:JSONLogMessage}) = ((:_module, :module), ) +""" + JSON(; recursive=false, nest_kwargs=true) + +Creates a `JSON` format logger. If `recursive=true`, any custom arguments will be recursively serialized as JSON; otherwise, the values will be treated as strings. If `nest_kwargs` is true (the default), all custom keyword arguments will be under the `kwargs` key. Otherwise, they will be inlined into the top-level JSON object. In the latter case, if the key name clashes with one of the standard keys (`$STANDARD_KEYS`), it will be renamed by prefixing it with a `_`. + +## Examples + +```julia +julia> using LoggingFormats, LoggingExtras + +julia> with_logger(FormatLogger(LoggingFormats.JSON(; recursive=false), stderr)) do + @info "hello, world" key=Dict("hello" => true) +end +{"level":"info","msg":"hello, world","module":"Main","file":"REPL[3]","line":2,"group":"REPL[3]","id":"Main_ffce16b4","kwargs":{"key":"Dict{String, Bool}(\"hello\" => 1)"}} + +julia> with_logger(FormatLogger(LoggingFormats.JSON(; recursive=true), stderr)) do + @info "hello, world" key=Dict("hello" => true) +end +{"level":"info","msg":"hello, world","module":"Main","file":"REPL[4]","line":2,"group":"REPL[4]","id":"Main_ffce16b5","kwargs":{"key":{"hello":true}}} + +julia> with_logger(FormatLogger(LoggingFormats.JSON(; recursive=true, nest_kwargs=false), stderr)) do + @info "hello, world" key=Dict("hello" => true) +end +{"level":"info","msg":"hello, world","module":"Main","file":"REPL[5]","line":2,"group":"REPL[5]","id":"Main_ffce16b6","key":{"hello":true}} +``` +""" struct JSON <: Function recursive::Bool + nest_kwargs::Bool end -JSON(; recursive=false) = JSON(recursive) +JSON(; recursive=false, nest_kwargs=true) = JSON(recursive, nest_kwargs) function (j::JSON)(io, args) if j.recursive - logmsg = JSONLogMessage{Any}(args) + logmsg = to_namedtuple(Any, args; nest_kwargs=j.nest_kwargs) try JSON3.write(io, logmsg) catch e - fallback_msg = JSONLogMessage{String}(args) - fallback_msg.kwargs["LoggingFormats.FormatError"] = sprint(showerror, e) + if j.nest_kwargs + fallback_msg = to_namedtuple(String, args; nest_kwargs=true) + fallback_msg.kwargs["LoggingFormats.FormatError"] = sprint(showerror, e) + else + fallback_msg = (; to_namedtuple(String, args; nest_kwargs=false)..., Symbol("LoggingFormats.FormatError") => sprint(showerror, e)) + end JSON3.write(io, fallback_msg) end else - logmsg = JSONLogMessage{String}(args) + logmsg = to_namedtuple(String, args; nest_kwargs=j.nest_kwargs) JSON3.write(io, logmsg) end println(io) diff --git a/test/runtests.jl b/test/runtests.jl index 1f8653e..57b850d 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -98,60 +98,98 @@ end @test json.kwargs.x == "[1, 2, 3]" @test json.kwargs.y == "(1, 2)" - # `recursive=true` + + # nest_kwargs=false io = IOBuffer() - with_logger(FormatLogger(JSON(; recursive=true), io)) do + with_logger(FormatLogger(JSON(; nest_kwargs=false), io)) do y = (1, 2) - @info "info msg" x = [1, 2, 3] y = Dict("hi" => Dict("hi2" => [1,2])) + @info "info msg" x = [1, 2, 3] y end json = JSON3.read(seekstart(io)) @test json.level == "info" @test json.msg == "info msg" @test json.module == "Main" @test json.line isa Int - @test json.kwargs.x == [1, 2, 3] - @test json.kwargs.y == Dict(:hi => Dict(:hi2 => [1,2])) + # not tucked under `kwargs` + @test json.x == "[1, 2, 3]" + @test json.y == "(1, 2)" - # Fallback to strings + + # With clash + io = IOBuffer() + with_logger(FormatLogger(JSON(; nest_kwargs=false), io)) do + @info "info msg" line = [1, 2, 3] + end + json = JSON3.read(seekstart(io)) + @test json.level == "info" + @test json.msg == "info msg" + @test json.module == "Main" + @test json.line isa Int + # key was renamed to prevent clash: + @test json._line == "[1, 2, 3]" + + # `recursive=true` io = IOBuffer() with_logger(FormatLogger(JSON(; recursive=true), io)) do - y = (1, 2) - @info "info msg" x = [1, 2, 3] y = Dict("hi" => NaN) + @info "info msg" x = [1, 2, 3] y = Dict("hi" => Dict("hi2" => [1,2])) end json = JSON3.read(seekstart(io)) @test json.level == "info" @test json.msg == "info msg" @test json.module == "Main" @test json.line isa Int - @test json.kwargs.x == "[1, 2, 3]" - y = json.kwargs.y - must_have = ("Dict", "\"hi\"", "=>", "NaN") - @test all(h -> occursin(h, y), must_have) # avoid issues with printing changing with versions - @test json.kwargs[Symbol("LoggingFormats.FormatError")] == "NaN not allowed to be written in JSON spec" + @test json.kwargs.x == [1, 2, 3] + @test json.kwargs.y == Dict(:hi => Dict(:hi2 => [1,2])) + + # Fallback to strings + for nest_kwargs in (true, false) + io = IOBuffer() + with_logger(FormatLogger(JSON(; recursive=true, nest_kwargs=nest_kwargs), io)) do + @info "info msg" x = [1, 2, 3] y = Dict("hi" => NaN) + end + json = JSON3.read(seekstart(io)) + @test json.level == "info" + @test json.msg == "info msg" + @test json.module == "Main" + @test json.line isa Int + if nest_kwargs + @test json.kwargs.x == "[1, 2, 3]" + @test json.kwargs[Symbol("LoggingFormats.FormatError")] == "NaN not allowed to be written in JSON spec" + y = json.kwargs.y + else + @test json.x == "[1, 2, 3]" + @test json[Symbol("LoggingFormats.FormatError")] == "NaN not allowed to be written in JSON spec" + y = json.y + end + must_have = ("Dict", "\"hi\"", "=>", "NaN") + @test all(h -> occursin(h, y), must_have) # avoid issues with printing changing with versions + end # Test logging exceptions - for recursive in (false, true) + for recursive in (false, true), nest_kwargs in (true, false) # no stacktrace io = IOBuffer() - with_logger(FormatLogger(JSON(; recursive=recursive), io)) do + with_logger(FormatLogger(JSON(; recursive=recursive, nest_kwargs=nest_kwargs), io)) do @error "Oh no" exception = ArgumentError("no") end logs = JSON3.read(seekstart(io)) @test logs["msg"] == "Oh no" - @test logs["kwargs"]["exception"] == "ArgumentError: no" + ex = nest_kwargs ? logs["kwargs"]["exception"] : logs["exception"] + @test ex == "ArgumentError: no" # non-standard exception key io = IOBuffer() - with_logger(FormatLogger(JSON(; recursive=recursive), io)) do + with_logger(FormatLogger(JSON(; recursive=recursive, nest_kwargs=nest_kwargs), io)) do @error "Oh no" ex = ArgumentError("no") end logs = JSON3.read(seekstart(io)) @test logs["msg"] == "Oh no" - @test logs["kwargs"]["ex"] == "ArgumentError: no" + ex = nest_kwargs ? logs["kwargs"]["ex"] : logs["ex"] + @test ex == "ArgumentError: no" # stacktrace io = IOBuffer() - with_logger(FormatLogger(JSON(; recursive=recursive), io)) do + with_logger(FormatLogger(JSON(; recursive=recursive, nest_kwargs=nest_kwargs), io)) do try throw(ArgumentError("no")) catch e @@ -161,10 +199,10 @@ end logs = JSON3.read(seekstart(io)) @test logs["msg"] == "Oh no" - @test occursin("ArgumentError: no", logs["kwargs"]["exception"]) + ex = nest_kwargs ? logs["kwargs"]["exception"] : logs["exception"] + @test occursin("ArgumentError: no", ex) # Make sure we get a stacktrace out: - @test occursin(r"ArgumentError: no\nStacktrace:\s* \[1\]", - logs["kwargs"]["exception"]) + @test occursin(r"ArgumentError: no\nStacktrace:\s* \[1\]", ex) end end