diff --git a/base/logging.jl b/base/logging.jl index 9a8faebf9a797..715b43b5bff73 100644 --- a/base/logging.jl +++ b/base/logging.jl @@ -343,7 +343,7 @@ end # progressively less information. try msg = "Exception while generating log record in module $_module at $filepath:$line" - handle_message(logger, Error, msg, _module, group, id, filepath, line; exception=err) + handle_message(logger, Error, msg, _module, :logevent_error, id, filepath, line; exception=err) catch err2 try # Give up and write to STDERR, in three independent calls to diff --git a/base/sysimg.jl b/base/sysimg.jl index ab6906a7bd905..e8b57aaa39a50 100644 --- a/base/sysimg.jl +++ b/base/sysimg.jl @@ -472,7 +472,7 @@ isdefined(Core, :Inference) && Docs.loaddocs(Core.Inference.CoreDocs.DOCS) function __init__() # Base library init reinit_stdio() - global_logger(SimpleLogger(STDERR)) + global_logger(root_module(:Logging).ConsoleLogger(STDERR)) Multimedia.reinit_displays() # since Multimedia.displays uses STDOUT as fallback early_init() init_load_path() diff --git a/stdlib/Logging/src/ConsoleLogger.jl b/stdlib/Logging/src/ConsoleLogger.jl new file mode 100644 index 0000000000000..53c2b48f57f4b --- /dev/null +++ b/stdlib/Logging/src/ConsoleLogger.jl @@ -0,0 +1,119 @@ +# This file is a part of Julia. License is MIT: https://julialang.org/license + +""" + ConsoleLogger(stream=STDERR, min_level=Info; meta_formatter=default_metafmt, show_limited=true) + +Logger with formatting optimized for readability in a text console, for example +interactive work with the Julia REPL. + +Log levels less than `min_level` are filtered out. + +Message formatting can be controlled by setting keyword arguments: + +* `meta_formatter` is a function which takes the log event metadata + `(level, _module, group, id, file, line)` and produces a prefix and suffix + for the log message. The default is to prefix with the log level and add a + suffix containing the module, file and line location. +* `show_limited` limits the printing of large data structures to something + which can fit on the screen by setting the `:limit` `IOContext` key during + formatting. +""" +struct ConsoleLogger <: AbstractLogger + stream::IO + min_level::LogLevel + meta_formatter + show_limited::Bool + message_limits::Dict{Any,Int} +end +function ConsoleLogger(stream::IO=STDERR, min_level=Info; + meta_formatter=default_metafmt, show_limited=true) + ConsoleLogger(stream, min_level, meta_formatter, + show_limited, Dict{Any,Int}()) +end + +shouldlog(logger::ConsoleLogger, level, _module, group, id) = + get(logger.message_limits, id, 1) > 0 + +min_enabled_level(logger::ConsoleLogger) = logger.min_level + +# Formatting of values in key value pairs +showvalue(io, msg) = show(io, "text/plain", msg) +function showvalue(io, e::Tuple{Exception,Any}) + ex,bt = e + showerror(io, ex, bt; backtrace = bt!=nothing) +end +showvalue(io, ex::Exception) = showvalue(io, (ex,catch_backtrace())) + +function default_metafmt(level, _module, group, id, file, line) + ((level == Warn ? "Warning" : string(level))*':', + "@ $_module $(basename(file)):$line") +end + +function handle_message(logger::ConsoleLogger, 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 + color = level < Info ? Base.debug_color() : + level < Warn ? Base.info_color() : + level < Error ? Base.warn_color() : + Base.error_color() + buf = IOBuffer() + iob = IOContext(buf, logger.stream) + if logger.show_limited + iob = IOContext(iob, :limit=>true) + end + msglines = split(chomp(string(message)), '\n') + dsize = displaysize(logger.stream) + width = dsize[2] + prefix,suffix = logger.meta_formatter(level, _module, group, id, filepath, line) + length(prefix) == 0 || (prefix = prefix*" ") + length(suffix) == 0 || (suffix = " "*suffix) + singlelinewidth = 2 + length(msglines[1]) + length(prefix) + length(suffix) + issingleline = length(msglines) + length(kwargs) == 1 && singlelinewidth <= width + print_with_color(color, iob, issingleline ? "[ " : "┌ ", bold=true) + if length(prefix) > 0 + print_with_color(color, iob, prefix, bold=true) + end + print(iob, msglines[1]) + if issingleline + npad = (width - singlelinewidth) + else + println(iob) + for i in 2:length(msglines) + print_with_color(color, iob, "│ ", bold=true) + println(iob, msglines[i]) + end + valbuf = IOBuffer() + rows_per_value = max(1, dsize[1]÷(length(kwargs)+1)) + valio = IOContext(IOContext(valbuf, iob), + :displaysize=>(rows_per_value,dsize[2]-5)) + for (key,val) in pairs(kwargs) + print_with_color(color, iob, "│ ", bold=true) + print(iob, " ", key, " =") + showvalue(valio, val) + vallines = split(String(take!(valbuf)), '\n') + if length(vallines) == 1 + println(iob, " ", vallines[1]) + else + println(iob) + for line in vallines + print_with_color(color, iob, "│ ", bold=true) + println(iob, line) + end + end + end + print_with_color(color, iob, "└ ", bold=true) + npad = width - 2 - length(suffix) + end + if length(suffix) > 0 + print(iob, " "^npad) + print_with_color(:light_black, iob, suffix, bold=false) + end + print(iob, "\n") + write(logger.stream, take!(buf)) + nothing +end + diff --git a/stdlib/Logging/src/Logging.jl b/stdlib/Logging/src/Logging.jl index 00aef043ece1a..8e38277bd513c 100644 --- a/stdlib/Logging/src/Logging.jl +++ b/stdlib/Logging/src/Logging.jl @@ -39,7 +39,10 @@ export current_logger, global_logger, disable_logging, - SimpleLogger + SimpleLogger, + ConsoleLogger + +include("ConsoleLogger.jl") # The following are also part of the public API, but not exported: # diff --git a/stdlib/Logging/test/runtests.jl b/stdlib/Logging/test/runtests.jl index 1cf40077a1476..f0b39e840889e 100644 --- a/stdlib/Logging/test/runtests.jl +++ b/stdlib/Logging/test/runtests.jl @@ -1 +1,168 @@ -# TODO: Move SimpleLogger in here +using Logging + +import Logging: min_enabled_level, shouldlog, handle_message + +@noinline func1() = backtrace() + +@testset "Logging" begin + +@testset "ConsoleLogger" begin + # First pass log limiting + @test min_enabled_level(ConsoleLogger(DevNull, Logging.Debug)) == Logging.Debug + @test min_enabled_level(ConsoleLogger(DevNull, Logging.Error)) == Logging.Error + + # Second pass log limiting + logger = ConsoleLogger(DevNull) + @test shouldlog(logger, Logging.Info, Base, :group, :asdf) === true + handle_message(logger, Logging.Info, "msg", Base, :group, :asdf, "somefile", 1, maxlog=2) + @test shouldlog(logger, Logging.Info, Base, :group, :asdf) === true + handle_message(logger, Logging.Info, "msg", Base, :group, :asdf, "somefile", 1, maxlog=2) + @test shouldlog(logger, Logging.Info, Base, :group, :asdf) === false + + # Log formatting + function genmsg(level, message, _module, filepath, line; color=false, + meta_formatter=Logging.default_metafmt, show_limited=true, kws...) + buf = IOBuffer() + io = IOContext(buf, :displaysize=>(30,75), :color=>color) + logger = ConsoleLogger(io, Logging.Debug, + meta_formatter=meta_formatter, + show_limited=show_limited) + Logging.handle_message(logger, level, message, _module, :a_group, :an_id, + filepath, line; kws...) + String(take!(buf)) + end + + # Single line formatting, default metadata + @test genmsg(Logging.Debug, "msg", Main, "some/path.jl", 101) == + """ + [ Debug: msg @ Main path.jl:101 + """ + @test genmsg(Logging.Info, "msg", Main, "some/path.jl", 101) == + """ + [ Info: msg @ Main path.jl:101 + """ + @test genmsg(Logging.Warn, "msg", Main, "some/path.jl", 101) == + """ + [ Warning: msg @ Main path.jl:101 + """ + @test genmsg(Logging.Error, "msg", Main, "some/path.jl", 101) == + """ + [ Error: msg @ Main path.jl:101 + """ + + # Configurable metadata formatting + @test genmsg(Logging.Debug, "msg", Main, "some/path.jl", 101, + meta_formatter=(level, _module, group, id, file, line)-> + ("Foo!", "$level $_module $group $id $file $line")) == + """ + [ Foo! msg Debug Main a_group an_id some/path.jl 101 + """ + + # Empty message string + @test genmsg(Logging.Error, "", Main, "some/path.jl", 101) == + """ + [ Error: @ Main path.jl:101 + """ + @test genmsg(Logging.Error, "", Main, "some/path.jl", 101, a=1) == + replace(""" + ┌ Error: EOL + │ a = 1 + └ @ Main path.jl:101 + """, "EOL"=>"") + + # Long message line + @test genmsg(Logging.Error, "msg msg msg msg msg msg msg msg msg msg msg msg msg", Main, "some/path.jl", 101) == + """ + ┌ Error: msg msg msg msg msg msg msg msg msg msg msg msg msg + └ @ Main path.jl:101 + """ + + # Multiline messages + @test genmsg(Logging.Warn, "line1\nline2", Main, "some/path.jl", 101) == + """ + ┌ Warning: line1 + │ line2 + └ @ Main path.jl:101 + """ + + # Keywords + @test genmsg(Logging.Error, "msg", Base, "other.jl", 101, a=1, b="asdf") == + """ + ┌ Error: msg + │ a = 1 + │ b = "asdf" + └ @ Base other.jl:101 + """ + # Exceptions use showerror + @test genmsg(Logging.Info, "msg", Base, "other.jl", 101, exception=DivideError()) == + """ + ┌ Info: msg + │ exception = DivideError: integer division error + └ @ Base other.jl:101 + """ + # Attaching backtraces + bt = func1() + @test startswith(genmsg(Logging.Info, "msg", Base, "other.jl", 101, + exception=(DivideError(),bt)), + """ + ┌ Info: msg + │ exception = + │ DivideError: integer division error + │ Stacktrace: + │ [1] func1() at""") + + + # Keywords - limiting the amount which is printed + @test genmsg(Logging.Info, "msg", Main, "some/path.jl", 101, + a=fill(1.00001, 100,100), b=fill(2.00002, 10,10)) == + replace(""" + ┌ Info: msg + │ a = + │ 100×100 Array{Float64,2}: + │ 1.00001 1.00001 1.00001 1.00001 … 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ ⋮ ⋱ EOL + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ b = + │ 10×10 Array{Float64,2}: + │ 2.00002 2.00002 2.00002 2.00002 … 2.00002 2.00002 2.00002 + │ 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 + │ 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 + │ ⋮ ⋱ EOL + │ 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 + │ 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 2.00002 + └ @ Main path.jl:101 + """, "EOL"=>"") # EOL hack to work around git whitespace errors + # Limiting the amount which is printed + @test genmsg(Logging.Info, "msg", Main, "some/path.jl", 101, + a=fill(1.00001, 10,10), show_limited=false) == + """ + ┌ Info: msg + │ a = + │ 10×10 Array{Float64,2}: + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + │ 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 1.00001 + └ @ Main path.jl:101 + """ + + # Basic color test + @test genmsg(Logging.Info, "line1\nline2", Main, "some/path.jl", 101, color=true) == + """ + \e[1m\e[36m┌ \e[39m\e[22m\e[1m\e[36mInfo: \e[39m\e[22mline1 + \e[1m\e[36m│ \e[39m\e[22mline2 + \e[1m\e[36m└ \e[39m\e[22m \e[90m @ Main path.jl:101\e[39m + """ + +end + +end diff --git a/test/logging.jl b/test/logging.jl index 6ff43052091a8..95d9919c3abd0 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -84,7 +84,7 @@ end @testset "Log message exception handling" begin # Exceptions in message creation are caught by default - @test_logs (Error,) catch_exceptions=true @info "foo $(1÷0)" + @test_logs (Error,Test.Ignored(),Test.Ignored(),:logevent_error) catch_exceptions=true @info "foo $(1÷0)" # Exceptions propagate if explicitly disabled for the logger (by default # for the test logger) @test_throws DivideError collect_test_logs() do