Skip to content

Logging depwarn cleanup #25239

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
c42f merged 3 commits into from
Dec 22, 2017
Merged

Logging depwarn cleanup #25239

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
cd6acb7
Fixes for logging deprecations + tests
c42f Dec 20, 2017
62df8bf
Add license headers + stdlib Logging precompile
c42f Dec 20, 2017
ac9e091
Silence depwarns in tests of deprecated functionality
c42f Dec 22, 2017
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 6 additions & 0 deletions base/client.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,12 @@ function repl_cmd(cmd, out)
end

function display_error(io::IO, er, bt)
if !isempty(bt)
st = stacktrace(bt)
if !isempty(st)
io = redirect(io, log_error_to, st[1])
end
end
Copy link
Member Author

@c42f c42f Dec 22, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@stevengj by the way, here's an answer to your question about log_error_to - for the moment I've reinstated it exactly as it was used inside display_error. I think it was a bit of a misfeature if used to capture REPL errors, but it's easy to preserve the behavior for now.

Copy link
Member

@stevengj stevengj Dec 22, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The point is, this will get removed when the deprecation is removed in 1.0, right?

Copy link
Member Author

@c42f c42f Dec 22, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Right. The user should get a depwarn if they ever manage to populate log_error_to.

print_with_color(Base.error_color(), io, "ERROR: "; bold = true)
# remove REPL-related frames from interactive printing
eval_ind = findlast(addr->Base.REPL.ip_matches_func(addr, :eval), bt)
Expand Down
2 changes: 2 additions & 0 deletions base/logging.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,5 @@
# This file is a part of Julia. License is MIT: https://julialang.org/license

module CoreLogging

import Base: isless, +, -, convert, show
Expand Down
4 changes: 4 additions & 0 deletions stdlib/Logging/src/Logging.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,7 @@
# This file is a part of Julia. License is MIT: https://julialang.org/license

__precompile__(true)

module Logging

# For now, simply import most names from Base - we don't want to fully
Expand Down
2 changes: 2 additions & 0 deletions stdlib/Test/src/logging.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,5 @@
# This file is a part of Julia. License is MIT: https://julialang.org/license

using Logging
import Logging: Info,
shouldlog, handle_message, min_enabled_level, catch_exceptions
Expand Down
153 changes: 153 additions & 0 deletions test/deprecation_exec.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,8 @@
# Tests for deprecated functionality.
#
# These can't be run with --depwarn=error, so currently require special
# treatment when run inside the test system.

using Test
using Logging

Expand Down Expand Up @@ -99,3 +104,151 @@ testlogs = testlogger.logs
@test testlogs[1].kwargs.caller.func == Symbol("top-level scope")
@test all(l.message == "f25130 message" for l in testlogs)
global_logger(prev_logger)


#-------------------------------------------------------------------------------
# BEGIN 0.7 deprecations

module LogTest
function bar(io)
info(io,"barinfo")
warn(io,"barwarn")
Base.display_error(io,"barerror",backtrace())
end
function pooh(io)
info(io,"poohinfo")
warn(io,"poohwarn")
Base.display_error(io,"pooherror",backtrace())
end
end
function foo(io)
info(io,"fooinfo")
warn(io,"foowarn")
Base.display_error(io,"fooerror",backtrace())
end

# Silence the flurry of depwarns for now.
with_logger(NullLogger()) do

@testset "Deprecated logging" begin

# Test info
@test contains(sprint(info, "test"), "INFO:")
@test contains(sprint(info, "test"), "INFO: test")
@test contains(sprint(info, "test ", 1, 2, 3), "INFO: test 123")
@test contains(sprint(io->info(io,"test", prefix="MYINFO: ")), "MYINFO: test")

# Test warn
@test contains(sprint(Base.warn_once, "test"), "WARNING: test")
@test isempty(sprint(Base.warn_once, "test"))

@test contains(sprint(warn), "WARNING:")
@test contains(sprint(warn, "test"), "WARNING: test")
@test contains(sprint(warn, "test ", 1, 2, 3), "WARNING: test 123")
@test contains(sprint(io->warn(io, "test", prefix="MYWARNING: ")), "MYWARNING: test")
@test contains(sprint(io->warn(io, "testonce", once=true)), "WARNING: testonce")
@test isempty(sprint(io->warn(io, "testonce", once=true)))
@test !isempty(sprint(io->warn(io, "testonce", once=true, key=hash("testonce",hash("testanother")))))
let bt = backtrace()
ws = split(chomp(sprint(io->warn(io, "test", bt = bt))), '\n')
bs = split(chomp(sprint(Base.show_backtrace, bt)), '\n')
@test contains(ws[1],"WARNING: test")
for (l,b) in zip(ws[2:end],bs[2:end])
@test contains(l, b)
end
end

# PR #16213
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(kind=:info)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "ERROR: \"fooerror\""]))

logging(kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn"]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn"]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn"]))

logging(kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar)
@test sprint(LogTest.bar) == ""
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest)
@test sprint(LogTest.bar) == ""
@test sprint(LogTest.pooh) == ""
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull)
@test sprint(LogTest.bar) == ""
@test sprint(LogTest.pooh) == ""
@test sprint(foo) == ""

logging()
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

end # @testset

end

# END 0.7 deprecations
2 changes: 2 additions & 0 deletions test/logging.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,5 @@
# This file is a part of Julia. License is MIT: https://julialang.org/license

using Base.CoreLogging
import Base.CoreLogging: BelowMinLevel, Debug, Info, Warn, Error,
handle_message, shouldlog, min_enabled_level
Expand Down
139 changes: 0 additions & 139 deletions test/misc.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,145 +2,6 @@

# Tests that do not really go anywhere else

# The following tests for deprecated functionality are disabled when --depwarn=error.
# TODO: Clean this up by reimplementing depwarn=error with a logger.
if Base.JLOptions().depwarn != 2

# Test info
@test contains(sprint(info, "test"), "INFO:")
@test contains(sprint(info, "test"), "INFO: test")
@test contains(sprint(info, "test ", 1, 2, 3), "INFO: test 123")
@test contains(sprint(io->info(io,"test", prefix="MYINFO: ")), "MYINFO: test")

# Test warn
@test contains(sprint(Base.warn_once, "test"), "WARNING: test")
@test isempty(sprint(Base.warn_once, "test"))

@test contains(sprint(warn), "WARNING:")
@test contains(sprint(warn, "test"), "WARNING: test")
@test contains(sprint(warn, "test ", 1, 2, 3), "WARNING: test 123")
@test contains(sprint(io->warn(io, "test", prefix="MYWARNING: ")), "MYWARNING: test")
@test contains(sprint(io->warn(io, "testonce", once=true)), "WARNING: testonce")
@test isempty(sprint(io->warn(io, "testonce", once=true)))
@test !isempty(sprint(io->warn(io, "testonce", once=true, key=hash("testonce",hash("testanother")))))
let bt = backtrace()
ws = split(chomp(sprint(io->warn(io, "test", bt = bt))), '\n')
bs = split(chomp(sprint(Base.show_backtrace, bt)), '\n')
@test contains(ws[1],"WARNING: test")
for (l,b) in zip(ws[2:end],bs[2:end])
@test contains(l, b)
end
end

# PR #16213
@eval module LogTest
function bar(io)
info(io,"barinfo")
warn(io,"barwarn")
Base.display_error(io,"barerror",backtrace())
end
function pooh(io)
info(io,"poohinfo")
warn(io,"poohwarn")
Base.display_error(io,"pooherror",backtrace())
end
end
function foo(io)
info(io,"fooinfo")
warn(io,"foowarn")
Base.display_error(io,"fooerror",backtrace())
end

@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:info)
@test all(contains.(sprint(LogTest.bar), ["WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(kind=:info)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "ERROR: \"fooerror\""]))

logging(kind=:warn)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn"]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull; kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn"]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn"]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn"]))

logging(kind=:error)
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))


logging(DevNull, LogTest, :bar)
@test sprint(LogTest.bar) == ""
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull, LogTest)
@test sprint(LogTest.bar) == ""
@test sprint(LogTest.pooh) == ""
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

logging(DevNull)
@test sprint(LogTest.bar) == ""
@test sprint(LogTest.pooh) == ""
@test sprint(foo) == ""

logging()
@test all(contains.(sprint(LogTest.bar), ["INFO: barinfo", "WARNING: barwarn", "ERROR: \"barerror\""]))
@test all(contains.(sprint(LogTest.pooh), ["INFO: poohinfo", "WARNING: poohwarn", "ERROR: \"pooherror\""]))
@test all(contains.(sprint(foo), ["INFO: fooinfo", "WARNING: foowarn", "ERROR: \"fooerror\""]))

end

# test assert() method
@test_throws AssertionError assert(false)
let res = assert(true)
Expand Down