|
| 1 | +# Logging |
| 2 | + |
| 3 | +## Overview |
| 4 | + |
| 5 | +Logging is a crucial tool for debugging, monitoring, and understanding the behavior of your applications. ClimaComms extends Julia's built-in logging functionality (provided by [`Logging.jl`](https://docs.julialang.org/en/v1/stdlib/Logging/)) to work seamlessly in distributed computing environments, particularly with MPI. |
| 6 | + |
| 7 | +### Julia's Logging System |
| 8 | + |
| 9 | +Julia's standard library provides a flexible logging system through `Logging.jl`. Key concepts include: |
| 10 | + |
| 11 | +- **Logger**: An object that handles log messages, determining how they are formatted and where they are sent |
| 12 | +- **Log Level**: Indicates the severity/importance of a message |
| 13 | +- **Log Record**: Contains the message and associated metadata (level, module, line number, etc.) |
| 14 | + |
| 15 | +The default logger in Julia (as of v1.11) is `Logging.ConsoleLogger()`, which prints messages to the console. You can check your current logger using: |
| 16 | + |
| 17 | +```julia |
| 18 | +using Logging; current_logger() |
| 19 | +``` |
| 20 | + |
| 21 | +## ClimaComms Logging Features |
| 22 | + |
| 23 | +ClimaComms builds upon Julia's logging system by providing specialized loggers for distributed computing. |
| 24 | + |
| 25 | +To set any of the loggers below as the global logger, use `Logging.global_logger(logger)`: |
| 26 | + |
| 27 | +```julia |
| 28 | +using ClimaComms, Logging |
| 29 | + |
| 30 | +ctx = ClimaComms.context() |
| 31 | +logger = ClimaComms.OnlyRootLogger(ctx) |
| 32 | +global_logger(logger) |
| 33 | +``` |
| 34 | + |
| 35 | +### OnlyRootLogger |
| 36 | + |
| 37 | +`OnlyRootLogger(context)` returns a logger that silences non-root processes. |
| 38 | +If using MPI, this logger is enabled on the first [`ClimaComms.init`](@ref) call. |
| 39 | + |
| 40 | +### FileLogger |
| 41 | + |
| 42 | +`FileLogger(context, log_dir)` writes to `stdout` and to a file `log_dir/output.log` simultaneously. |
| 43 | +If using MPI, the `FileLogger` separates logs by MPI process into different files, so that process `i` will write to the `rank_$i.log` file in the `$log_dir` directory, where `$log_dir` is of your choosing. |
| 44 | +In this case, `$log_dir/output.log` is a [symbolic link](https://en.wikipedia.org/wiki/Symbolic_link) to the root process logs. |
| 45 | +In other words, you can always look at `$log_dir/output.log` for the output. Logging to `stdout` can be disabled by setting the keyword argument `log_stdout = false`. |
| 46 | +```julia |
| 47 | +using ClimaComms, Logging |
| 48 | +ctx = ClimaComms.context() |
| 49 | +logger = ClimaComms.FileLogger(ctx, "logs") |
| 50 | + |
| 51 | +with_logger(logger) do |
| 52 | + @warn "Memory usage high" # Written to rank-specific log file |
| 53 | +end |
| 54 | +``` |
| 55 | +This will output the following in both the REPL and `logs/rank_1.log`: |
| 56 | +```julia |
| 57 | +┌ Warning: Memory usage high |
| 58 | +└ @ Main REPL[6]:2 |
| 59 | +``` |
| 60 | + |
| 61 | + |
| 62 | +### MPILogger |
| 63 | + |
| 64 | +`MPILogger(context)` adds an MPI rank prefix to all log messages: |
| 65 | + |
| 66 | +```julia |
| 67 | +using ClimaComms, Logging |
| 68 | +ctx = ClimaComms.context() |
| 69 | +logger = MPILogger(ctx) |
| 70 | + |
| 71 | +with_logger(logger) do |
| 72 | + @info "Processing data..." # Output: [P1] Info: Processing data... |
| 73 | +end |
| 74 | +``` |
| 75 | + |
| 76 | +## Log Levels |
| 77 | + |
| 78 | +Julia provides four standard log levels, in order of increasing severity: |
| 79 | + |
| 80 | +1. `Debug`: Detailed information for debugging |
| 81 | +2. `Info`: General information about program execution |
| 82 | +3. `Warn`: Warnings about potential issues |
| 83 | +4. `Error`: Error conditions that might still allow the program to continue |
| 84 | + |
| 85 | +See [Julia documentation](https://docs.julialang.org/en/v1/stdlib/Logging/#Log-event-structure) for more detailed information. |
| 86 | + |
| 87 | +You can define custom log levels using `LogLevel`: |
| 88 | + |
| 89 | +```julia |
| 90 | +const Trace = LogLevel(-1000) # Lower number = less severe |
| 91 | +@macroexpand @logmsg Trace "Very detailed trace message" |
| 92 | +``` |
| 93 | + |
| 94 | +To disable all log messages at log levels equal to or less than a given `LogLevel`, use [`Logging.disable_logging(level)`](https://docs.julialang.org/en/v1/stdlib/Logging/#Logging.disable_logging). |
| 95 | + |
| 96 | +## Filtering Log Messages |
| 97 | + |
| 98 | +[LoggingExtras.jl](https://github.com/JuliaLogging/LoggingExtras.jl) provides powerful filtering capabilities through the `EarlyFilteredLogger(filter, logger)`, which takes two arguments: |
| 99 | + |
| 100 | +- `filter(log_args)` is a function which takes in `log_args` and returns a Boolean determining if the message should be logged. `log_args` is a NamedTuple with fields `level`, `_module`, `id` and `group`. Example `filter` functions are provided below in the Common Use Cases. |
| 101 | +- `logger` is any existing logger, such as `Logging.ConsoleLogger()` or `MPILogger(ctx)`. |
| 102 | + |
| 103 | +### Common Use Cases |
| 104 | + |
| 105 | +#### How do I save log output to stdout and a file simultaneously? |
| 106 | + |
| 107 | +`ClimaComms.FileLogger` logs to files and stdout simultaneously. |
| 108 | +For full customization, `LoggingExtras.TeeLogger(loggers)` composes multiple loggers, allowing for multiple loggers at once as shown below. |
| 109 | + |
| 110 | +```julia |
| 111 | +using Logging, LoggingExtras |
| 112 | + |
| 113 | +io = open("simulation.log", "w") |
| 114 | +loggers = (Logging.ConsoleLogger(stdout), Logging.ConsoleLogger(io)) |
| 115 | +tee_logger = LoggingExtras.TeeLogger(loggers) |
| 116 | + |
| 117 | +with_logger(tee_logger) do |
| 118 | + @warn "Log to stdout and file" |
| 119 | +end |
| 120 | + |
| 121 | +close(io) |
| 122 | +``` |
| 123 | + |
| 124 | +#### How do I filter out warning messages? |
| 125 | + |
| 126 | +```@example |
| 127 | +using Logging, LoggingExtras |
| 128 | +
|
| 129 | +function no_warnings(log_args) |
| 130 | + return log_args.level != Logging.Warn |
| 131 | +end |
| 132 | +
|
| 133 | +filtered_logger = EarlyFilteredLogger(no_warnings, Logging.current_logger()) |
| 134 | +
|
| 135 | +with_logger(filtered_logger) do |
| 136 | + @warn "Hide this warning" |
| 137 | + @info "Display this message" |
| 138 | +end |
| 139 | +``` |
| 140 | + |
| 141 | +#### How do I filter out messages from certain modules? |
| 142 | + |
| 143 | +We can create a custom filter that returns `false` if a log message originates from a list of excluded modules. |
| 144 | + |
| 145 | +The same pattern can be reversed to filter messages only coming from certain modules. |
| 146 | +``` |
| 147 | +using Logging, LoggingExtras |
| 148 | +
|
| 149 | +module_filter(excluded_modules) = log_args -> |
| 150 | + !(log_args._module in excluded_modules) |
| 151 | +
|
| 152 | +ModuleFilteredLogger(excluded) = |
| 153 | + EarlyFilteredLogger(module_filter(excluded), Logging.current_logger()) |
| 154 | +# To test this logger: |
| 155 | +module TestModule |
| 156 | + using Logging |
| 157 | + function log_something() |
| 158 | + @info "This message will appear" |
| 159 | + end |
| 160 | +end |
| 161 | +
|
| 162 | +excluded = (Main, Base) |
| 163 | +with_logger(ModuleFilteredLogger(excluded)) do |
| 164 | + @info "Hide this message" |
| 165 | + TestModule.log_something() |
| 166 | +end |
| 167 | +``` |
| 168 | +```julia |
| 169 | +[ Info: This message will appear |
| 170 | +``` |
0 commit comments