Add generic function loggerstream

[fredrikekre]

Add generic function loggerstream to get the IO stream of the current logger. Sometimes you just wanna print something directly to the current logging stream, instead of going through @info etc. With this PR you can do e.g.

println(loggerstream(), "Hello, world!")

to print raw stuff to the loggerstream.

[iamed2]

What if a logger doesn't have an underlying IO?

[fredrikekre]

What if a logger doesn't have an underlying IO?

Return devnull or stdout maybe? Do you have a better approach to print raw data to the logger?

[andyferris]

Do you have...?

One idea might be another macro for unformatted logging, perhaps? I’m still wondering how this works when the logger emits structerd messages (e.g. maybe it writes rows to a table or something? Your RDBMS won’t handle an arbitrary stream of text...).

[iamed2]

I don't think loggers should have that feature but if it's important to you and others I think a better option could maybe be println(::Logger, stuff)? I'm interested in your use case, because this sounds to me like it would be served by printing to stdout or stderr.

Bypassing the logger's own output mechanisms would make it more difficult for non-stdlib logging libraries to work consistently.

[fredrikekre]

I'm interested in your use case

Sometimes you just wanna dump something to the logger stream to get it logged.

[iamed2]

Sometimes you just wanna dump something to the logger stream to get it logged.

Why that and not either printing to stdout or logging?

[andyferris]

Why is that not @info?

[fredrikekre]

I don't think loggers should have that feature but if it's important to you and others I think a better option could maybe be println(::Logger, stuff)?

That requires logger to implement all functions that take an IO though? (print, println, printstyled, show ....).

I'm interested in your use case

Mainly being able to control some formatting myself. For example to make Pkg print to the logging stream instead of stdout.

[andyferris]

Have you considered building Pkg a logger? I thought the philisophy of the new system allowed for a pretty federated system of loggers.

[andyferris]

There might be other advantages to building Pkg it's own logger - like it could save @debug-level logging information to a file in a standard location to help with diagonosing issues installing packages, etc.

[fredrikekre]

Have you considered building Pkg a logger?

Yes, that was my first idea. But IIUC that can only work for "top-level" applications. A user should be able to redirect the logger stream from Pkg. Case in point;

julia> using Logging

julia> pkglogger = ConsoleLogger(stdout);

julia> userlogger = NullLogger();

julia> function pkgfunction()
           with_logger(pkglogger) do
               @info "some pkginfo"
           end
       end
pkgfunction (generic function with 1 method)

julia> with_logger(userlogger) do
           pkgfunction()
       end
[ Info: some pkginfo

[andyferris]

Following on from that - what confuses me about this Issue most is that any given logger may be associated with any number (including zero) of output streams.

[andyferris]

Sure... of course a user could overide the default logger. We could potentially do something as simple as, say, having pkg> mode at the REPL invoke commands with a PkgLogger, or something.

Basically, I'd try to work with the philosophy of the new system instead of trying to circumvent the logger's control and understanding of its output streams.

[fredrikekre]

Sure... of course a user could overide the default logger.

But they can't? As I tried to show with the example, if Pkg has its own logger, then a user can't opt in to using their own logger.

Basically, I'd try to work with the philosophy of the new system instead of trying to circumvent the logger's control and understanding of its output streams.

Yea, I'm all for this, but as the system currently works it does not seem to be an option for packages to write their own loggers like this?

[iamed2]

This issue with coupling loggers to log output is why we made Memento. You're right that the system as it stands can't support those operations, which I agree are necessary.

That said, this PR's code pretends the loggers have properties they don't have. Either we should give them those properties (e.g., explicitly introduce a method for printing unformatted output) or change the design.

[fredrikekre]

I guess a package that implements their own logger can use something like:

function logger()
    state = current_task().logstate
    if state === nothing
        return PkgLogger()
    else
        return state.logger
    end
end

which then uses PkgLogger if a user have not set it explicitly.

[c42f]

Sorry, I didn't see this one! I don't think we can really have loggerstream for the reasons argued above — namely that a stream of log records is definitely not a stream of characters, and may not be backed by one in any meaningful sense. (The logger may be writing compressed binary key value pairs over the network for all you know :-) )

This issue with coupling loggers to log output is why we made Memento. You're right that the system as it stands can't support those operations, which I agree are necessary.

Not exactly. The current system is mostly frontend (ie, the macros), with a very minimal backend (ConsoleLogger). The fact that it supports plugging in any backend (including Memento) means that it does support plugging in these things, but the user must implement it all themselves. Clearly that's not ideal and we should support composition of log filtering and appenders.

For the record I've been thinking a lot about composition of log filtering and I agree that the current model of installing an entirely new logger with with_logger() is kind of broken — as you've found here @fredrikekre there's something unnatural about the way it fails to compose properly. Rather than replacing the current logger completely, the default behavior should probably be more like "filter and forward to parent", but I've yet to wrap my head around exactly what to do.

The design difficulties largely come down to the task-centric design of the system which makes it rather different from other systems which exist already (eg, log4j and python's logging libs). This also means that having PARTR merged would help rather a lot in the next design iteration. Some parts (filters) can be concurrent, but some parts (appenders) need to have single threaded components...

[fredrikekre]

Should we open an issue about this then? The current system is only useful for end users, but pretty useless for packages.

[c42f]

Yes though I think we're at the stage where we really should split out stdlib/Logging into a new JuliaLang/Logging repo to collect the many disconnected design discussions.

[c42f]

The current system is only useful for end users, but pretty useless for packages

@fredrikekre I've been thinking a lot about how to make the logging system composable for consuming log records. Obviously I need use cases to motivate the design. Could you comment on the outcomes you were trying to achieve for Pkg with this change? I assume it was mostly about giving Pkg the ability to precisely format messages in a readable way? Is there some particular discussion over at Pkg or elsewhere which I should be reading?

[fredrikekre]

Could you comment on the outcomes you were trying to achieve for Pkg with this change? I assume it was mostly about giving Pkg the ability to precisely format messages in a readable way?

Yes, to be able to fully control the formatting basically. Right now Pkg just prints to stdout because we can't really use the logging system for pretty-printing.

Is there some particular discussion over at Pkg or elsewhere which I should be reading?

No.

[StefanKarpinski]

I'm not entirely sure that

• application -> logging system -> pretty console output

(where the application is Pkg in this case) is the right model here. That seems like it's going to force the logging system in the middle to do lots of kind of pointless and unfortunate things. Why not model it this way instead:

• application -> pretty console output
• application -> logging system (silent logging)

In other words, instead of trying to make the logging system produce arbitrary pretty output for the end user as a result of logging events, just produce the pretty output directly and log events at the same time silently. Yes, it's twice as much "event logging code" on the application side, but it should be easy enough to abstract that into a single call for each event that does both things.

I guess the main ask for that is that a given package should be able to say "I'm going to take care of letting the user know about events and problems, I just want silent logging as a record." Is that possible already, @c42f? At the per-package level?

[c42f]

@StefanKarpinski Filtering log events on a per-module level is definitely supported by the data model. We don't have anything explicit to inform downstream loggers that the messages should somehow be "silent", though just mutating the event stream by setting the level to Debug before passing it on would generally achieve that. I have been thinking of a new log event filter/map API called filterlogs, usage of which might look something like:

# filter/map log stream from `some_pkg_internals`; first display them to the user, then downgrade
# the level of those messages to debug. Then forward to whatever `current_logger` was installed
# further up the call stack.
filterlogs(DowngradeMessages((Pkg,Info)=>Debug)) ∘ DisplayPkgMessages()) do
    $some_pkg_internals()
end

The big question of course being where to put such a filterlogs invocation. I think it would be most apt inside the Pkg REPL mode (bracketing whatever is done in do_cmd?) This does mean that direct Pkg API calls would print Pkg events differently from the repl mode by default, but that seems somewhat appropriate to me.

Side note — I'm still feeling queasy about the categorical (type) vs ordinal (severity/verbosity) nature of log levels. Mutating the event category using filterlogs feels kind of wrong, but mutating the verbosity seems more appropriate and feels like it might compose naturally down the filter chain. Have been wondering if it would be better to turn @info into something like LogLevel(category=:info, verbosity=0), or whatever equivalent backward-compatible thing. Then you could have debug messages of various verbosities, without conflating "Debug" with a very particular verbosity setting.