LoggingExtras.jl

repository·master·Indexed 41 days ago

https://github.com/julialogging/loggingextras.jl

A compositional logging system for Julia that enables the construction of complex log routing, filtering, and transformation pipelines. It provides components such as TeeLogger for demultiplexing, ActiveFilteredLogger and EarlyFilteredLogger for message filtering, TransformerLogger for modifying log content, and specialized sinks like FileLogger, FormatLogger, and DatetimeRotatingFileLogger.

Tokens
3.7K
Snippets
13
Records
13
Agent score
50%

What's inside LoggingExtras.jl

  1. How compositional loggers work in LoggingExtras

    master

    LoggingExtras uses a compositional model where complex logging systems are built by combining simple, pure components. These components are categorized into four types:

    • Sinks: The endpoints of a log message (e.g., writing to a file or console). They only decide what to do with a message, not whether to accept it.
    • Filters: Wrappers that decide whether to pass a message to the underlying logger. They can be Early Filters (deciding before the message is computed) or Active Filters (deciding after the message is fully formed).
    • Transformers: Wrappers that modify log message content (like severity level or message text) before passing it on. They cannot block a message.
    • Tee: A hub (specifically TeeLogger) that receives one message and sends copies to multiple child loggers, allowing for complex routing.

    By composing these, you can create sophisticated routing (e.g., sending errors to a file while sending everything to the console).

    # Conceptual example of a composed logger
    ConsoleLogger(stream, min_level) =
        MinLevelLogger(
            ActiveFilteredLogger(max_log_filter,
                PureSinkConsoleLogger(stream)
            ),
            min_level
        )
  2. Use verbosity macros and `withlevel` for fine-grained control

    master

    LoggingExtras provides verbosity-aware macros that allow you to attach a numeric verbosity level to log messages. This is useful for complex functions where you want multiple levels of debug information.

    Available Macros:

    • @debugv N msg
    • @infov N msg
    • @warnv N msg
    • @errorv N msg

    Filtering Verbosity: Use LoggingExtras.withlevel(f, level; verbosity=N) to execute a block of code where only messages with a verbosity level $\le N$ are captured.

    using LoggingExtras
    
    function complex_user_call(; verbose=0)
        # Only logs with verbosity <= 'verbose' will be processed
        LoggingExtras.withlevel(Debug; verbosity=verbose) do
            @debugv 1 "a level 1 verbosity debug message"
            @debugv 2 "a more verbose level 2 debug message"
        end
    end
    
    # Usage:
    complex_user_call(verbose=1) # Only shows level 1
    complex_user_call(verbose=2) # Shows level 1 and 2
  3. Install and use LoggingExtras

    master

    To use LoggingExtras, load the package with using LoggingExtras. This also re-exports the standard Logging library.

    To apply a logger in a specific scope, use with_logger(logger) do ... end. To set a logger globally, use global_logger(logger). To retrieve the current logger (which may vary per task), use current_logger(), or use global_logger() for the global instance.

    using LoggingExtras
    
    # Use in a local scope
    with_logger(my_logger) do
        @info "Scoped message"
    end
    
    # Set globally
    global_logger(my_logger)
  4. Implement log rotation with `DatetimeRotatingFileLogger`

    master

    Use DatetimeRotatingFileLogger to automatically rotate log files based on a DateFormat. The logger will close the current file and open a new one whenever the filename (determined by the date/time pattern) changes.

    Key Features:

    • Filename Escaping: If your filename contains static parts (e.g., .log), you must escape them using raw"..." to prevent the DateFormat engine from interpreting them.
    • Rotation Callback: You can pass a rotation_callback::Function as a keyword argument to perform post-processing on a file immediately after it is rotated.
    • Custom Formatting: You can pass a formatter function as the first argument to control the output content.
    using LoggingExtras
    
    # Rotate logs based on minute-level precision
    # Note the use of raw"" to escape the .log extension
    rotating_logger = DatetimeRotatingFileLogger(pwd(), raw"\a\c\c\e\s\s-YYYY-mm-dd-HH-MM.\l\o\g")
    
    with_logger(rotating_logger) do
        @info("This goes in one file")
        sleep(61) # Wait for the next minute to trigger rotation
        @info("This goes in another file")
    end
  5. Custom log formatting with `FormatLogger`

    master

    The FormatLogger allows you to define exactly how log messages are structured by providing a formatting function: f(io::IO, log_args::NamedTuple).

    Arguments:

    • f: A function that takes an IO object and a NamedTuple containing log metadata (e.g., args.level, args.message, args._module).
    • io or filepath: The second argument can be a writable IO object or a string representing a file path.
    • append::Bool: Determines if the file is opened in append mode ("a") or truncate mode ("w").
    using LoggingExtras
    
    # Format logs to stdout with a custom pattern
    logger = FormatLogger() do io, args
        println(io, args._module, " | ", "[", args.level, "] ", args.message)
    end
    
    # Format logs to a file in append mode
    logger = FormatLogger("out.log"; append=true) do io, args
        println(io, args._module, " | ", "[", args.level, "] ", args.message)
    end
    
    with_logger(logger) do
        @info "This is an informational message."
    end
  6. Override minimum log levels with `LevelOverrideLogger`

    master

    The LevelOverrideLogger allows you to bypass the minimum log level of a wrapped logger. This is useful when you want to use a global logger as a sink but need to force a lower log level (like Debug) for a specific block of code.

    It is complementary to MinLevelFilterLogger: while the latter raises the minimum level, LevelOverrideLogger effectively lowers it by bypassing the wrapped logger's level checks.

    using LoggingExtras
    
    # Force Debug level even if the global logger is set to Info
    logger = LevelOverrideLogger(Debug, global_logger())
    
    with_logger(logger) do
        @debug "This message will log despite the global Info default."
    end
  7. Log to a file with `FileLogger`

    master

    The FileLogger is a convenience wrapper around Julia's SimpleLogger that allows you to specify a filename instead of an IO stream. It produces output similar to the REPL format.

    Configuration Options:

    • always_flush::Bool: Whether to flush the log to disk immediately (defaults to true).
    • append::Bool: Whether to append to the file or overwrite it (defaults to false).

    Note: If you need a specific format (like JSON), use FormatLogger instead.

    using LoggingExtras;
    
    # Overwrite by default
    logger = FileLogger("output.log")
    
    # Append to existing file
    logger = FileLogger("output.log"; append=true)
  8. Filter logs using EarlyFilteredLogger

    master

    The EarlyFilteredLogger runs earlier in the pipeline than ActiveFilteredLogger. It runs before the log message is computed, which is critical for performance if the message construction (e.g., calculating statistics) is expensive.

    Because it runs early, the filter function only has access to the level, _module, id, and group fields. It cannot see the actual message content.

    Example: Throttling repeated messages

    using Dates, LoggingExtras
    
    function make_throttled_logger(period)
        history = Dict{Symbol, DateTime}()
        EarlyFilteredLogger(global_logger()) do log
            if !haskey(history, log.id) || (period < now() - history[log.id])
                history[log.id] = now()
                return true
            else
                return false
            end
        end
    end
    
    throttled_logger = make_throttled_logger(Second(3))
    
    with_logger(throttled_logger) do
        for ii in 1:10
            sleep(1)
            @info "It happened" ii
        end
    end
    using Dates, LoggingExtras
    
    function make_throttled_logger(period)
        history = Dict{Symbol, DateTime}()
        EarlyFilteredLogger(global_logger()) do log
            if !haskey(history, log.id) || (period < now() - history[log.id])
                history[log.id] = now()
                return true
            else
                return false
            end
        end
    end
    
    throttled_logger = make_throttled_logger(Second(3));
    
    with_logger(throttled_logger) do
        for ii in 1:10
            sleep(1)
            @info "It happened" ii
        end
    end
  9. Filter by severity with MinLevelLogger

    master

    The MinLevelLogger is a specialized EarlyFilteredLogger that only allows messages to pass if their severity level is equal to or higher than a specified level.

    using LoggingExtras
    
    # Only allow Error level and above
    error_only_logger = MinLevelLogger(current_logger(), Logging.Error)
    
    with_logger(error_only_logger) do
        @info("You won't see this")
        @warn("won't see this either")
        @error("You will only see this")
    end
  10. Filter logs using ActiveFilteredLogger

    master

    The ActiveFilteredLogger wraps a logger and uses a filter function to decide whether to pass a message. The filter function is called with the full set of parameters of the log message (the complete log object), allowing you to filter based on the actual message content.

    Example: Filter messages starting with a specific string

    function yodawg_filter(log_args)
        startswith(log_args.message, "Yo Dawg!")
    end
    
    filtered_logger = ActiveFilteredLogger(yodawg_filter, global_logger())
    
    with_logger(filtered_logger) do
        @info "Boring message"      # Ignored
        @warn "Yo Dawg! it is bad" # Logged
    end
    function yodawg_filter(log_args)
        startswith(log_args.message, "Yo Dawg!")
    end
    
    filtered_logger = ActiveFilteredLogger(yodawg_filter, global_logger())
    
    with_logger(filtered_logger) do
        @info "Boring message"
        @warn "Yo Dawg! it is bad"
        @info "Another boring message"
        @info "Yo Dawg! it is all good"
    end
  11. Transform log messages with `TransformerLogger`

    master

    A TransformerLogger (used via the transformer_logger utility) allows you to intercept log messages and modify them before they reach the sink. This is useful for adding timestamps, changing log levels, or filtering content.

    The transformation function receives a log object (a NamedTuple) and should return a modified NamedTuple or the original one.

    using LoggingExtras, Dates
    
    # Example: Adding a timestamp to every log message
    const date_format = "yyyy-mm-dd HH:MM:SS"
    
    function timestamp_logger(logger)
        TransformerLogger(logger) do log
            merge(log, (; message = "$(Dates.format(now(), date_format)) $(log.message)"))
        end
    end
    
    # Apply to a logger
    logger = ConsoleLogger(stdout, Logging.Debug) |> timestamp_logger |> global_logger
  12. Modify log messages with TransformerLogger

    master

    The TransformerLogger allows you to modify log messages (content, level, or metadata) before they reach the next logger. You provide a transformation function that takes a named tuple of all log fields and returns a new, modified named tuple.

    Example: Truncating long messages

    using LoggingExtras
    
    truncating_logger = TransformerLogger(global_logger()) do log
        if length(log.message) > 128
            short_message = log.message[1:min(end, 125)] * "..."
            return merge(log, (;message=short_message))
        else
            return log
        end
    end
    
    with_logger(truncating_logger) do
        @info "the truncating logger only truncates long messages"
        @info "Like this one that is this is a long and rambling message, it just keeps going and going and going, and it seems like it will never end."
    end
    using LoggingExtras
    
    truncating_logger  = TransformerLogger(global_logger()) do log
        if length(log.message) > 128
            short_message = log.message[1:min(end, 125)] * "..."
            return merge(log, (;message=short_message))
        else
            return log
        end
    end;
    
    with_logger(truncating_logger) do
        @info "the truncating logger only truncates long messages"
        @info "Like this one that is this is a long and rambling message, it just keeps going and going and going,  and it seems like it will never end."
        @info "Not like this one, that is is short"
    end