How to log to file with a customized log format?

[world-peace]

I’m currently trying to build a logging demonstration using the JuliaLogging components (standard library + a few seemingly very standard packages).

• https://julialogging.github.io/

I may be wrong, however I think there are 3 parts to logging. This isn’t specific to Julia, this is more general and applies to any language, really.

1. Log data capturing (sources)
2. Log string (or otherwise - might be a binary string) formatting
3. Log sinks

Sources/data capture are some statements in code which specify the inputs. It could be as simple as a log message string, or it might include metadata, such as a module name, line number, or other data.

Formatters are things which take data from a source and structure it into some human or machine readable string.

Log sinks are devices which can accept string formatted logs and write or store them somewhere. Files, the console, or databases could be examples of this.

This is, in an approximate sense, how most logging frameworks are structured.

Julia’s logging tools might be structured like this, or it might be a bit different. I don’t have a solid understanding of how everything fits together yet. Please do let me know if my mental model is wrong.

What is relatively easy to understand are the sources. (Because these are fixes for any application.)

We have the macros

• @error
• @warn
• @info
• @debug

These macros expect a string to follow and then optionally, metadata. Some additional metadata is automatically provided, such as the module name, function name and line number.

These macros are all provided by the Logging package.

There are 11 other packages mentioned on JuliaLogging. This is where things get complicated. If I understand correctly, all of these things are supposed to interop together.

In regards to formatting, there is the LoggingFormats package. However, this appears to contain a predefined set of formats, which includes a tool for formatting logs in JSON format. The more general purpose FormatLogger is actually in LoggingExtras.

In this package, we also find the FileLogger, which is a sink.

Ok, so let’s accept that sources, formatting intermediaries and sinks are not separated into seperate packages but mixed together. Fine.

It seems I have all the pieces.

I want to be able to

@info "just a test!"

and have this write to a file, formatted using FormatLogger.

I’m somewhat lost as to how to take these “individual pieces” and put them together to achieve this.

Here’s some snippets of code where I’ve been testing out a few things.

using Logging
using LoggingExtras

function (@main)(args)
    println("hello world")

1. Just the standard stdout/stderr default log sink and format.

    @info "hello world - info"
    @warn "hello world - warning"

It will give you

[ Info: hello world - info
┌ Warning: hello world - warning
└ @ Main ~/work/tmp/JuliaLogging/main.jl:9

2. I managed to get logging to a file to work. For some reason, I needed a SimpleLogger?

    io_stream = open("example-log-stream.txt", "a")
    logger = SimpleLogger(io_stream, Debug)
    with_logger(logger) do
        @info "SimpleLogger info log"
        @warn "SimpleLogger warning log"
    end

This is the output

┌ Info: SimpleLogger info log
└ @ Main /home/user/work/tmp/JuliaLogging/main.jl:14
┌ Warning: SimpleLogger warning log
└ @ Main /home/user/work/tmp/JuliaLogging/main.jl:15

so I would guess that a SimpleLogger is a type of FormatLogger?

They both inherit from AbstractLogger, so this doesn’t seem to check out exactly.

Maybe a SimpleLogger is an alternative to a FormatLogger and defines a fixed format for logging?

3. I also managed to get FileLogger working. But this seems to be using the SimpleLogger format, despite none of the code specifying this.

    file_logger = FileLogger(io_stream)
    with_logger(file_logger) do
        @info "info to file_logger stream"
    end

Here’s the output

┌ Info: info to file_logger stream
└ @ Main /home/user/work/tmp/JuliaLogging/main.jl:31

which is suspiciously similar to the above.

The code ends with a final end for the end of function (@main)

end

The specific question I have is how do I plumb a FileLogger up to a FormatLogger?

To rephrase it slightly - how do I log to a file using a user-defined format?

More generally, I am somewhat lost when it comes to this (quite extensive) logging ecosystem. If anyone has any wisdom which can help me to understand it that would also be much appreciated.

[abraemer]

Here is an example that I used for some simulations:

using Logging
using LoggingExtras

function add_datetime_logger(logger)
    return TransformerLogger(logger) do log
        merge(log, (; message = "[$(Dates.now())]-#$(Threads.threadid()): $(log.message)"))
    end
end

function logger_for_params(params, minlevel = Logging.Info)
    logfile = datadir("logs", savename(params, "txt"))
    return MinLevelLogger(
        add_datetime_logger(
            TeeLogger(
                MinLevelLogger(ConsoleLogger(stdout), Logging.Warn),
                FileLogger(logfile))),
        minlevel)
end

This writes the log both to the console and to a file and prepends the current time and thread ID to the message. Also filters below the given minlevel (so excludes all “weaker” messages) .

I think this example might be sufficient for you to understand how to use these packages. If you need a more detailed explanation please ask

[world-peace]

Hard to tell from this but I think what your code suggests is something like this is possible:

logger = 
MinLevelLogger(
    TransformerLogger(
        TeeLogger(
            MinLevelLogger(
                ConsoleLogger(stdout), Logging.Warn),
            FileLogger("log-file.log"),
        )
    ),
    Logging.Info,
)

I suspected this might be the kind of thing which should be possible. Almost like a declaration of a chain of processing modules which process log events.

So I’m wondering. Can something like this be done?

f = (io, logdata)->println(io, "$(logdata._module)->{ [$(logdata.level)]~$(logdata.message)}")
logger = FileLogger(FormatLogger(f, io_stream, true))

This won’t compile. It’s not easy to figure out what the right syntax is from the docs.

[abraemer]

@world-peace

This won’t compile

If you state something like this, then it is always very helpful if you post the error

Using the help-mode in Julia’s REPL (accessible via ?) I found that likely you are using FormatLogger wrong. I think it should be: FormatLogger(f, io_stream; append=true)

help?> FormatLogger
search: FormatLogger FileLogger AbstractLogger ConsoleLogger TransformerLogger TeeLogger NullLogger current_logger

  FormatLogger(f::Function, io::IO=stderr; always_flush=true)

  Logger sink that formats the message and finally writes to io. The formatting function should be of the form
  f(io::IOContext, log_args::NamedTuple) where log_args has the following fields: (level, message, _module, group, id,
  file, line, kwargs). See LoggingExtras.handle_message_args for more information on what field is.

  Examples
  ≡≡≡≡≡≡≡≡

  julia> using Logging, LoggingExtras

  julia> logger = FormatLogger() do io, args
             println(io, args._module, " | ", "[", args.level, "] ", args.message)
         end;

  julia> with_logger(logger) do
             @info "This is an informational message."
             @warn "This is a warning, should take a look."
         end
  Main | [Info] This is an informational message.
  Main | [Warn] This is a warning, should take a look.

  ────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

  FormatLogger(f::Function, path::AbstractString; append=false, always_flush=true)

  Logger sink that formats the message and writes it to the file at path. This is similar to FileLogger except that it
  allows specifying the printing format.

  To append to the file (rather than truncating the file first), use append=true. If always_flush=true the stream is
  flushed after every handled log message.

[world-peace]

I don’t understand how to use it correctly.

Allow me to give a single example.

If a FormatLogger takes an io_stream as an argument, that would suggest it is incompatiable with a FileLogger.

Why? Because it needs to take some lower level IO object than a FileLogger.

Maybe that’s the wrong constructor to use? I looked at the others and couldn’t see any other forms of the constructor which would be relevant.

[abraemer]

As it says here in the docstring I posted

@abraemer

Logger sink that ...

A FormatLogger is a sink. A FileLogger is also a sink. So naturally you cannot combine them. A format logger formats the message and then writes them to the provided iostream (which can be an opened file). A FileLogger is more specialized and just writes everything it gets to a file directly. If you want to transform a message and then pass them on to different loggers downstream, you’ll need to use a
TransformerLogger like in the example code I posted.