Skip to content

Commit

Permalink
Fixes for logging during bootstrap (JuliaLang#25722)
Browse files Browse the repository at this point in the history
* Install SimpleLogger during bootstrap

This ensures bootstrap messages will be visible.

* Make SimpleLogger work earlier in bootstrap

* Remove uses of print_with_color
* Remove use of basename() - just print the whole path
* Remove special case single line log formatting - always print metadata
  on a new line.

* Move logging after task in bootstrap

current_task() is used to discover the logger, so this must come after
task.jl

* Propagate exceptions through SimpleLogger

A logging exception during bootstrap is probably an error - propagate
this through instead of catching it.
  • Loading branch information
c42f authored and JeffBezanson committed Jan 25, 2018
1 parent d4db28b commit e23b2ab
Show file tree
Hide file tree
Showing 3 changed files with 22 additions and 36 deletions.
34 changes: 11 additions & 23 deletions base/logging.jl
Original file line number Diff line number Diff line change
Expand Up @@ -378,7 +378,7 @@ end

LogState(logger) = LogState(LogLevel(min_enabled_level(logger)), logger)

_global_logstate = LogState(NullLogger()) # See __init__
_global_logstate = LogState(NullLogger())

function current_logstate()
logstate = current_task().logstate
Expand Down Expand Up @@ -479,39 +479,27 @@ shouldlog(logger::SimpleLogger, level, _module, group, id) =

min_enabled_level(logger::SimpleLogger) = logger.min_level

catch_exceptions(logger::SimpleLogger) = false

function handle_message(logger::SimpleLogger, level, message, _module, group, id,
filepath, line; maxlog=nothing, kwargs...)
# TODO: Factor out more complex things here into a separate logger in
# stdlib: in particular maxlog support + colorization.
if maxlog != nothing && maxlog isa Integer
remaining = get!(logger.message_limits, id, maxlog)
logger.message_limits[id] = remaining - 1
remaining > 0 || return
end
levelstr, color = level < Info ? ("Debug", Base.debug_color()) :
level < Warn ? ("Info", Base.info_color()) :
level < Error ? ("Warning", Base.warn_color()) :
("Error", Base.error_color())
buf = IOBuffer()
iob = IOContext(buf, logger.stream)
levelstr = level == Warn ? "Warning" : string(level)
msglines = split(chomp(string(message)), '\n')
if length(msglines) + length(kwargs) == 1
print_with_color(color, iob, "[ ", levelstr, ": ", bold=true)
print(iob, msglines[1], " ")
else
print_with_color(color, iob, "", levelstr, ": ", bold=true)
println(iob, msglines[1])
for i in 2:length(msglines)
print_with_color(color, iob, "", bold=true)
println(iob, msglines[i])
end
for (key,val) in pairs(kwargs)
print_with_color(color, iob, "", bold=true)
println(iob, " ", key, " = ", val)
end
print_with_color(color, iob, "", bold=true)
println(iob, "", levelstr, ": ", msglines[1])
for i in 2:length(msglines)
println(iob, "", msglines[i])
end
for (key,val) in pairs(kwargs)
println(iob, "", key, " = ", val)
end
print_with_color(:light_black, iob, "@ ", _module, " ", basename(filepath), ":", line, "\n")
println(iob, "@ ", _module, " ", filepath, ":", line)
write(logger.stream, take!(buf))
nothing
end
Expand Down
9 changes: 5 additions & 4 deletions base/sysimg.jl
Original file line number Diff line number Diff line change
Expand Up @@ -250,10 +250,6 @@ include("regex.jl")
include("show.jl")
include("arrayshow.jl")

# Logging
include("logging.jl")
using .CoreLogging

# multidimensional arrays
include("cartesian.jl")
using .Cartesian
Expand Down Expand Up @@ -313,6 +309,11 @@ include("lock.jl")
include("threads.jl")
include("weakkeydict.jl")

# Logging
include("logging.jl")
using .CoreLogging
global_logger(SimpleLogger(Core.STDERR, CoreLogging.Info))

# To limit dependency on rand functionality (implemented in the Random
# module), Crand is used in file.jl, and could be used in error.jl
# (but it breaks a test)
Expand Down
15 changes: 6 additions & 9 deletions test/logging.jl
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@

using Base.CoreLogging
import Base.CoreLogging: BelowMinLevel, Debug, Info, Warn, Error,
handle_message, shouldlog, min_enabled_level
handle_message, shouldlog, min_enabled_level, catch_exceptions

import Test: collect_test_logs, TestLogger
using Base.Printf: @sprintf
Expand Down Expand Up @@ -231,33 +231,30 @@ end
@test shouldlog(logger, Info, Base, :group, :asdf) === true
handle_message(logger, Info, "msg", Base, :group, :asdf, "somefile", 1, maxlog=2)
@test shouldlog(logger, Info, Base, :group, :asdf) === false
@test catch_exceptions(logger) === false

# Log formatting
function genmsg(level, message, _module, filepath, line; kws...)
io = IOBuffer()
logger = SimpleLogger(io, Debug)
handle_message(logger, level, message, _module, :group, :id,
filepath, line; kws...)
s = String(take!(io))
# Remove the small amount of color, as `Base.print_with_color` can't be
# simply controlled.
s = replace(s, r"^\e\[1m\e\[..m(.*)\e\[39m\e\[22m"m => s"\1")
# println(s)
s
String(take!(io))
end

# Simple
@test genmsg(Info, "msg", Main, "some/path.jl", 101) ==
"""
[ Info: msg @ Main path.jl:101
┌ Info: msg
└ @ Main some/path.jl:101
"""

# Multiline message
@test genmsg(Warn, "line1\nline2", Main, "some/path.jl", 101) ==
"""
┌ Warning: line1
│ line2
└ @ Main path.jl:101
└ @ Main some/path.jl:101
"""

# Keywords
Expand Down

0 comments on commit e23b2ab

Please sign in to comment.