Merge pull request #25239 from c42f/logging-cleanups

Logging depwarn cleanup
JuliaLang · Dec 22, 2017 · eec85b2 · eec85b2
2 parents 15c4673 + ac9e091
commit eec85b2
Show file tree

Hide file tree

Showing 7 changed files with 169 additions and 139 deletions.
diff --git a/base/client.jl b/base/client.jl
@@ -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
     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)

diff --git a/base/logging.jl b/base/logging.jl
@@ -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

diff --git a/stdlib/Logging/src/Logging.jl b/stdlib/Logging/src/Logging.jl
@@ -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

diff --git a/stdlib/Test/src/logging.jl b/stdlib/Test/src/logging.jl
@@ -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

diff --git a/test/deprecation_exec.jl b/test/deprecation_exec.jl
@@ -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
 
@@ -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
diff --git a/test/logging.jl b/test/logging.jl
@@ -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

diff --git a/test/misc.jl b/test/misc.jl
@@ -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)