add logging() to redirect info/warn/error() #16213

bjarthur · 2016-05-05T15:16:28Z

this PR provides a mechanism by which info, warning, and error messages can be ~~organized hierarchically and~~ selectively redirected to an IO stream of your choice. ~~a keyword argument provided to warn identifies it's position within the hierarchy by subclassing a new abstract type Warning.~~ a new command logging() is used to maintain a ~~set of branches within the hierarchy~~ mapping between the kind of message, and optionally specific modules and/or functions, to a stream.

for example, given this module:

module Foo
    function bar()
        info("barinfo")
        warn("barwarn")
        error("barerror")
    end
    function pooh()
        info("poohinfo")
        warn("poohwarn")
        error("pooherror")
    end
end

the user could selectively mute warn() in pooh() by

julia> Foo.bar()
INFO: barinfo (Foo.bar)
WARNING: barwarn (Foo.bar)
ERROR: barerror
 in bar() at ./REPL[1]:5
 in eval(::Module, ::Any) at ./boot.jl:230

julia> Foo.pooh()
INFO: poohinfo (Foo.pooh)
WARNING: poohwarn (Foo.pooh)
ERROR: pooherror
 in pooh() at ./REPL[1]:10
 in eval(::Module, ::Any) at ./boot.jl:230

julia> logging(DevNull, Foo, :pooh, kind=:warn)

julia> Foo.bar()
INFO: barinfo (Foo.bar)
WARNING: barwarn (Foo.bar)
ERROR: barerror
 in bar() at ./REPL[1]:5
 in eval(::Module, ::Any) at ./boot.jl:230

julia> Foo.pooh()
INFO: poohinfo (Foo.pooh)
ERROR: pooherror
 in pooh() at ./REPL[1]:10
 in eval(::Module, ::Any) at ./boot.jl:230

julia>

bjarthur · 2016-05-06T13:51:08Z

version 2 is new and improved! can now just specify a particular module / function to mute; so Pkg code doesn't need to be modified to mute it.

StefanKarpinski · 2016-05-06T16:57:14Z

I'm willing to have this for now, although I really think we need a more general system for logging info messages, warnings, and errors and controlling where that output goes. "Squelching" is just logging to /dev/null.

tkelman · 2016-05-06T23:08:41Z

Kind of a strange name as well, is there precedent for this choice elsewhere?

bjarthur · 2016-05-07T15:14:01Z

version 3 is more general for info and warn as stefan requested. error forthcoming...

bjarthur · 2016-05-08T17:01:29Z

version 4 now redirects error too.

a few questions:

~~1. i'm having trouble typing some of the input args. see both redirect() and logging() in util.jl. can someone please explain why these don't work?~~

sprint() with error() throws an error, but works fine with info() or warn(). because of this there are no tests for redirecting error() yet. is there any easy way to make it behave the same?

~~3. both REPL.jl and client.jl define display_error() nearly identically. can this be made more succinct by having one call the other?~~

thanks.

timholy · 2016-05-08T21:41:57Z

For your first question, not sure without more information about the error. If it happens when julia is being built, then it's likely that this type doesn't yet exist at the time that util.jl is included. See sysimg.jl for the sequence.

I'm tentatively assigning @StefanKarpinski to be in charge of helping bring this to conclusion.

bjarthur · 2016-05-11T12:20:13Z

thanks @timholy . re-ordering sysimg.jl plus correcting a few stupid mistakes on my part fixed the typing problem.

now just need to figure out how to capture the output of error() in the tests...

tkelman · 2016-05-11T13:32:44Z

base/error.jl

+Raise an `ErrorException` with the given message.
+
+See also `logging`.
+"""


the docstring should be attached to the signature that it corresponds to

bjarthur · 2016-05-18T11:37:18Z

i think this is ready to merge.

i tried my best to add tests for error, but there is no way that i can see to do this. it all works when tested by hand though.

are there any comments / suggestions to the API or implementation?

timholy · 2016-06-16T20:12:29Z

@StefanKarpinski, are you willing to mentor this one through?

StefanKarpinski · 2016-06-28T20:20:31Z

@JeffBezanson, what do you think about this?

tkelman · 2016-12-29T18:23:07Z

@Rory-Finnegan do you (or any of your colleagues interested in logging) have any opinions about this implementation or whether getting this version incorporated into base for 0.6 would be good/bad/neutral ? Thanks!

ViralBShah · 2016-12-30T03:40:57Z

@tanmaykm also uses Logging.jl a fair bit, and may have a perspective here.

rofinn · 2016-12-30T04:56:12Z

@tkelman I'm very interested in having nice flexible logging functionality in julia, but I'm mostly neutral regarding this implementation. I don't particularly like this solution and won't use this functionality myself, but I don't have any issue with providing this in base for now.

FWIW, I think Memento.jl will cover what I need/expect in terms of logging functionality for now. @noah79 you may find the table on this page useful.

bjarthur · 2016-12-30T16:22:28Z

this PR permits users to redirect info/warn/error messages in a particular module or function irrespective of whether the call uses a particular logging package. this was my principle design feature, and it is not possible without directly modifying Base. being able to silence any message, including those originating from Base, is huge.

tkelman · 2016-12-31T16:43:59Z

base/util.jl

+    if isempty(log_to)
+        return io
+    else
+        if length(log_to)==1 && in((nothing,nothing),keys(log_to))


why isn't this haskey ?

tkelman · 2016-12-31T16:45:33Z

base/util.jl

+
+Stream output of informational, warning, and/or error messages to `io`,
+overriding what was otherwise specified.  Optionally, divert stream only for
+module `m`, or specifically function `f` within `m`.  `kind` can also be


Instead of "also" I'd say "kind can be :all (the default), :info, :warn, or :error."

tkelman · 2016-12-31T16:55:51Z

test/misc.jl

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


shouldn't these include error once again?

tkelman · 2016-12-31T17:01:16Z

base/client.jl

+        bt = bt[1:eval_ind-1]
+    end
+    with_output_color(Base.error_color(), io) do io
+        showerror(IOContext(io, :limit => true), er, bt)


The version of this from REPL.jl had been setting :limit => true, but the old implementation in client.jl wasn't - what outputs are you now limiting that weren't before?

my assumption was that whoever added :limit => true to REPL.jl simply forgot to add it to client.jl as well. according to the IOContext docstring it simply truncates long containers with ellipses.

as an alternative, we could continue to keep maintaining two versions of display_error. i was just trying to remove some repetition figuring it'd make maintenance easier.

what used to determine which of the two would get called?

tkelman · 2016-12-31T17:04:56Z

test/pkg.jl

@@ -507,7 +507,7 @@ temp_pkg_dir() do

        ret, out, err = @grab_outputs Pkg.update("Example")
        @test ret === nothing && out == ""
-        @test contains(err, "INFO: Package Example: skipping update (pinned)...\n")
+        @test contains(err, "INFO: Package Example: skipping update (pinned)...")


do you know why these changed?

KristofferC · 2017-01-01T02:00:58Z

base/client.jl

+    if eval_ind != 0
+        bt = bt[1:eval_ind-1]
+    end
+    with_output_color(Base.error_color(), io) do io


This doesn't look right compared to whats in REPL.jl.

yet this line remains precisely what used to be in client.jl; i've left this line unchanged.

IIRC a few months ago the two copies of display_error (in client.jl and REPL.jl) were identical. there has been more than one occasion where someone changed one, but not the other, when i think they should've changed both, and either forgot to or were unaware of the other copy.

please let me know if i am wrong in thinking that the two copies should~~n't~~ behave identically. if this is not the case, then this PR should be modified so as not to delete the one in REPL.jl.

Previously the REPL.jl called Base.showerror. Now it calls this method which does not do the same thing as the one you deleted from REPL.jl. The result is that errors being printed to the REPL will now be different.

It looks like

julia/base/multi.jl

Line 1303 in 962583e

display_error(e, catch_backtrace())

is the only location which calls the client.jl version of display_error. Updating the client.jl to match REPL.jl would be the best way forward in my opinion.

it's a do-block. showerror is called in the next line.

I know. That do block is not present in REPL.jl.

i'm confused. can you be more precise in describing what you want changed?

julia v0.5.0 had no calls to with_output_color until you added it to both REPL.jl and client.jl. at some later point, it was deleted from REPL.jl but not client.jl. are you saying i should delete your change from the latter as well?

it still seems to me that if the goal is that the output should be the same, then there should just be a single function, and not two.

julia v0.5.0 had no calls to with_output_color until you added it to both REPL.jl and client.jl

No, that commit simply changed, :red -> Base.error_color(). It did not add or remove any do blocks.

In a later PR the do block was deleted from REPL.jl. I am saying you can do the same in client.jl.

bjarthur · 2017-01-01T22:53:25Z

the one test that fails appears to be spurious. is there a way to just re-do it and not all the others?

KristofferC · 2017-01-02T00:24:40Z

Restarted, failing worker. Previous failing log at https://gist.github.com/KristofferC/486937a09a0ef731ac2c2b2a3fb64ee4

bjarthur · 2017-01-02T02:32:05Z

thanks. how could i have done that myself?

KristofferC · 2017-01-02T02:59:31Z

You'd need member status for the repo.

tkelman · 2017-01-04T17:59:38Z

I'm inclined to merge this if no one objects in the next day or so.

kmsquire · 2017-01-05T05:22:56Z

As the author of Logging.jl, I'll chime in and say that silencing or redirecting info, warn, and/or error messages seems a reasonable thing to have, although it seems to me this is mostly to remove warts--e.g., to stop reams of deprecation warnings or other verbosity that should really be fixed, but for some reason the user is unable or unwilling to do so.

This implementation seems reasonable enough. It's a little verbose to silence or redirect things, and because of this, it probably won't be used much, but it's probably better to at least have this functionality.

I agree with the above statements that a fuller (extensible) logging module belongs in base, and that, except for lack of documentation, Memento.jl looks like an interesting implementation.

A couple of things I would love to see (but won't have any time to work on soon):

An interface using Log as the module prefix (mimicking Pkg). Log is short enough that it's not annoying to write always, and it sequesters the functions within a module so they don't pollute the programmer's namespace. Logging macros could be implemented using something like the methods in Logging.jl.
Stop error from throwing an exception (handled by 1.). It'll probably be annoying to deprecate this...)

rofinn · 2017-01-05T07:18:23Z

@kmsquire I realize that this is a bit off topic, but if you have specific documentation concerns feel free to open an issue. I realize that the README is a bit sparse, but I'd appreciate your feedback on what's missing on the hosted docs.

tkelman · 2017-01-05T14:03:06Z

Log would read a bit ambiguously with logarithm to me. An implementation big enough to be a package should probably stay that way, but if widely liked and used we could consider it for inclusion as a "default package." Modifications needed to base to better support that kind of logging module can be considered going forward, of course.

kmsquire · 2017-01-09T03:56:13Z

@bjarthur, congrats on your perseverance in getting this merged!

Off topic:

@Rory-Finnegan, sorry, I missed the link to the full docs at the top of the readme. Many packages Include an explicit pointer to the full docs (if they exist)--maybe you could add such a line? (I'd submit a PR, but I'm mostly off grid with no computer for the next week.)

colinfang · 2017-01-16T18:30:18Z

@Rory-Finnegan I should have found your Memento.jl earlier so that I didn't have to write MiniLogging.jl for my company.

bjarthur force-pushed the squelch branch 2 times, most recently from 08beb50 to ba7ad9d Compare May 6, 2016 13:42

bjarthur force-pushed the squelch branch from ba7ad9d to 86dc94b Compare May 7, 2016 15:08

bjarthur force-pushed the squelch branch 2 times, most recently from f0461ef to 4cde358 Compare May 8, 2016 16:39

bjarthur force-pushed the squelch branch from 4cde358 to a82ebbf Compare May 8, 2016 17:07

timholy assigned StefanKarpinski May 8, 2016

bjarthur force-pushed the squelch branch from a82ebbf to ea13a7e Compare May 11, 2016 12:16

bjarthur force-pushed the squelch branch from ea13a7e to d3767f7 Compare May 11, 2016 12:55

tkelman reviewed May 11, 2016
View reviewed changes

bjarthur force-pushed the squelch branch 3 times, most recently from 2a17ff8 to 9f9396e Compare May 17, 2016 22:10

bjarthur changed the title ~~RFC: add squelch() to mute warn()~~ add logging() to redirect info/warn/error() May 17, 2016

bjarthur force-pushed the squelch branch from 9f9396e to d09ad05 Compare July 26, 2016 18:06

timholy added the needs decision A decision on this change is needed label Sep 28, 2016

bjarthur force-pushed the squelch branch from 2645c26 to 692e06b Compare December 30, 2016 15:53

tkelman reviewed Dec 31, 2016

View reviewed changes

bjarthur force-pushed the squelch branch from 692e06b to 4594b49 Compare December 31, 2016 19:02

bjarthur closed this Jan 1, 2017

bjarthur reopened this Jan 1, 2017

KristofferC reviewed Jan 1, 2017

View reviewed changes

added logging() for redirection of info/warn/error messages

1bfcc8e

bjarthur force-pushed the squelch branch from 4594b49 to 1bfcc8e Compare January 1, 2017 21:55

tkelman merged commit 8d369bf into JuliaLang:master Jan 5, 2017

tkelman mentioned this pull request Feb 11, 2017

Basic logging in Base #13515

Closed

KristofferC mentioned this pull request Feb 15, 2017

means of suppressing ambiguity warnings #4895

Closed

rdeits mentioned this pull request May 4, 2017

Fix unit tests and deprecations on Julia v0.6 pluskid/Mocha.jl#230

Merged

add logging() to redirect info/warn/error() #16213

add logging() to redirect info/warn/error() #16213

Conversation

bjarthur commented May 5, 2016 • edited Loading

bjarthur commented May 6, 2016

StefanKarpinski commented May 6, 2016

tkelman commented May 6, 2016

bjarthur commented May 7, 2016

bjarthur commented May 8, 2016 • edited Loading

timholy commented May 8, 2016

bjarthur commented May 11, 2016

Choose a reason for hiding this comment

bjarthur commented May 18, 2016

timholy commented Jun 16, 2016

StefanKarpinski commented Jun 28, 2016

tkelman commented Dec 29, 2016

ViralBShah commented Dec 30, 2016

rofinn commented Dec 30, 2016 • edited Loading

bjarthur commented Dec 30, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

KristofferC Jan 1, 2017 • edited Loading

Choose a reason for hiding this comment

bjarthur Jan 1, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bjarthur commented Jan 1, 2017

KristofferC commented Jan 2, 2017

bjarthur commented Jan 2, 2017

KristofferC commented Jan 2, 2017

tkelman commented Jan 4, 2017

kmsquire commented Jan 5, 2017

rofinn commented Jan 5, 2017 • edited Loading

tkelman commented Jan 5, 2017

kmsquire commented Jan 9, 2017

colinfang commented Jan 16, 2017

bjarthur commented May 5, 2016 •

edited

Loading

bjarthur commented May 8, 2016 •

edited

Loading

rofinn commented Dec 30, 2016 •

edited

Loading

KristofferC Jan 1, 2017 •

edited

Loading

bjarthur Jan 1, 2017 •

edited

Loading

rofinn commented Jan 5, 2017 •

edited

Loading