Ведение журнала

Модуль Logging предоставляет способ записи истории и прогресса вычисления в виде журнала событий. События создаются путем вставки оператора ведения журнала в исходный код, например:

@warn "Abandon printf debugging, all ye who enter here!"
┌ Warning: Abandon printf debugging, all ye who enter here!
└ @ Main REPL[1]:1

Система предоставляет несколько преимуществ по сравнению с вставкой вызовов println() в исходный код. Во-первых, она позволяет контролировать видимость и представление сообщений, не редактируя исходный код. Например, в отличие от @warn выше

@debug "The sum of some values $(sum(rand(100)))"

по умолчанию не будет выводить ничего. Кроме того, очень удобно оставлять операторы отладки в исходном коде, так как система избегает оценки сообщения, если оно позже будет проигнорировано. В этом случае sum(rand(100)) и связанная обработка строк никогда не будут выполнены, если ведение журнала отладки не включено.

Во-вторых, инструменты ведения журнала позволяют присоединять произвольные данные к каждому событию в виде набора пар ключ-значение. Это позволяет захватывать локальные переменные и другие состояния программы для последующего анализа. Например, для присоединения локальной переменной массива A и суммы вектора v в качестве ключа s можно использовать

A = ones(Int, 4, 4)
v = ones(100)
@info "Some variables"  A  s=sum(v)

# output
┌ Info: Some variables
│   A =
│    4×4 Matrix{Int64}:
│     1  1  1  1
│     1  1  1  1
│     1  1  1  1
│     1  1  1  1
└   s = 100.0

Все макросы ведения журнала @debug, @info, @warn и @error обладают общими характеристиками, подробно описанными в документации для более общего макроса @logmsg.

Структура события журнала

Каждое событие генерирует несколько фрагментов данных, некоторые из которых предоставляются пользователем, а некоторые автоматически извлекаются. Сначала рассмотрим данные, определяемые пользователем:

• Уровень журнала — это широкая категория для сообщения, используемого для предварительного фильтрации. Существует несколько стандартных уровней типа LogLevel; также возможны пользовательские уровни. Каждый из них имеет свое назначение:

  • Logging.Debug (уровень журнала -1000) — информация, предназначенная для разработчика программы. Эти события отключены по умолчанию.
  • Logging.Info (уровень журнала 0) — общая информация для пользователя. Представьте себе это как альтернативу прямому использованию println.
  • Logging.Warn (уровень журнала 1000) означает, что что-то не так, и, вероятно, потребуется какое-то действие, но программа все еще работает.
  • Logging.Error (уровень журнала 2000) означает, что что-то не так, и маловероятно, что это будет исправлено, по крайней мере, этой частью кода. Часто этот уровень журнала не нужен, так как выброс исключения может передать всю необходимую информацию.

• Сообщение — это объект, описывающий событие. По соглашению AbstractString сообщения, передаваемые в качестве сообщений, предполагаются в формате Markdown. Другие типы будут отображаться с помощью print(io, obj) или string(obj) для текстового вывода и, возможно, show(io,mime,obj) для других мультимедийных дисплеев, используемых в установленной системе ведения журнала.

• Дополнительные пары ключ-значение позволяют присоединять произвольные данные к каждому событию. Некоторые ключи имеют общепринятое значение, которое может влиять на способ интерпретации события (см. @logmsg).

Система также генерирует некоторую стандартную информацию для каждого события:

• Место в коде, где макрос ведения журнала был развернут.
• Строка и столбец, где происходит макрос ведения журнала в исходном коде.
• Идентификатор сообщения id, который представляет собой уникальный, фиксированный идентификатор для выражения исходного кода, где появляется макрос ведения журнала. Этот идентификатор разработан для достаточно стабильной работы даже если исходный код файла изменяется, при условии, что само выражение ведения журнала остается неизменным.
• Группа group для события, которая по умолчанию устанавливается в имя файла без расширения. Это можно использовать для группирования сообщений в категории более точно, чем уровень журнала (например, все предупреждения об устаревании имеют группу :depwarn), или в логические группы в пределах или между модулями.

Обратите внимание, что некоторые полезные данные, такие как время события, по умолчанию не включены. Это связано с тем, что извлечение такой информации может быть дорогостоящим, и она также динамически доступна для текущего системы ведения журнала. Легко определить пользовательскую систему ведения журнала, чтобы дополнить данные события временем, трассировкой стека вызовов, значениями глобальных переменных и другой полезной информацией по мере необходимости.

Обработка событий журнала

Как видно из примеров, операторы ведения журнала не упоминают, куда отправляются события журнала или как они обрабатываются. Это ключевая особенность дизайна, которая делает систему составной и естественной для одновременного использования. Она достигается путем разделения двух разных задач:

• Создание событий журнала — это задача автора модуля, который должен решить, где запускаются события и какую информацию включить.
• Обработка событий журнала — это задача автора приложения, которое должно объединить несколько модулей в работающее приложение.

Системы ведения журнала

Обработка событий выполняется системой ведения журнала, которая является первой настраиваемой частью кода, которая видит событие. Все системы ведения журнала должны быть подтипами AbstractLogger.

При возникновении события система находит соответствующую систему ведения журнала, ища локальную систему ведения журнала для задачи, с глобальной системой ведения журнала в качестве резервного варианта. Идея заключается в том, что код приложения знает, как обрабатывать события журнала и существует где-то в верхней части стека вызовов. Поэтому мы должны искать вверх по стеку вызовов, чтобы обнаружить систему ведения журнала — то есть система ведения журнала должна быть динамически глобальной. (Это отличие от систем ведения журналов, где система ведения журнала лексически глобальная; явно предоставлена автором модуля или как простая глобальная переменная. В такой системе неудобно управлять ведением журнала при объединении функциональности из нескольких модулей.)

Глобальная система ведения журнала может быть установлена с помощью global_logger, а локальные системы ведения журнала для задач — с помощью with_logger. Новые задачи наследуют систему ведения журнала родительской задачи.

Библиотека предоставляет три типа систем ведения журнала. ConsoleLogger — это система ведения журнала по умолчанию, которую вы видите при запуске REPL. Она отображает события в удобочитаемом текстовом формате и пытается предоставить простой, но удобный для пользователя контроль над форматированием и фильтрацией. NullLogger — удобный способ отбросить все сообщения, где это необходимо; это аналог потока devnull для ведения журнала. SimpleLogger — очень простая система ведения журнала с форматированием текста, которая полезна в основном для отладки самой системы ведения журнала.

Пользовательские системы ведения журнала должны содержать перегрузки для функций, описанных в разделе справочника.

Предварительная фильтрация и обработка сообщений

При возникновении события происходит несколько этапов предварительной фильтрации, чтобы избежать генерации сообщений, которые будут отброшены:

1. Проверяется уровень сообщения журнала относительно глобального минимального уровня (установленного с помощью disable_logging). Это грубая, но чрезвычайно быстрая глобальная настройка.
2. Проверяется текущее состояние системы ведения журнала, а уровень сообщения проверяется относительно минимального уровня системы ведения журнала, найденного при вызове Logging.min_enabled_level. Это поведение может быть переопределено с помощью переменных среды (подробнее об этом позже).
3. Вызывается функция Logging.shouldlog с текущей системой ведения журнала, принимающей минимальную информацию (уровень, модуль, группа, идентификатор), которая может быть вычислена статически. Самое полезное, что shouldlog передаёт событие id, что может использоваться для раннего отбрасывания событий на основе кэшированного предиката.

Если все эти проверки пройдены, сообщение и пары ключ-значение оцениваются полностью и передаются текущей системе ведения журнала через функцию Logging.handle_message. handle_message() может выполнить дополнительную фильтрацию по мере необходимости и отобразить событие на экране, сохранить его в файле и т. д.

Исключения, возникающие при генерации события журнала, по умолчанию перехватываются и регистрируются. Это предотвращает сбой приложения из-за отдельных ошибочных событий, что полезно при включении малоиспользуемых событий отладки в производственной системе. Это поведение может быть настраиваемо для каждого типа системы ведения журнала путём расширения Logging.catch_exceptions.

Тестирование событий журнала

События журнала являются побочным эффектом выполнения обычного кода, но вы можете захотеть протестировать конкретные информационные сообщения и предупреждения. Модуль Test предоставляет макрос @test_logs, который можно использовать для сопоставления шаблонов с потоком событий журнала.

Переменные среды

Фильтрация сообщений может быть настроена с помощью переменной среды JULIA_DEBUG, что служит простым способом включения ведения журнала отладки для файла или модуля. Загрузка julia с JULIA_DEBUG=loading активирует сообщения журнала @debug в loading.jl. Например, в оболочках Linux:

$ JULIA_DEBUG=loading julia -e 'using OhMyREPL'
┌ Debug: Rejecting cache file /home/user/.julia/compiled/v0.7/OhMyREPL.ji due to it containing an incompatible cache header
└ @ Base loading.jl:1328
[ Info: Recompiling stale cache file /home/user/.julia/compiled/v0.7/OhMyREPL.ji for module OhMyREPL
┌ Debug: Rejecting cache file /home/user/.julia/compiled/v0.7/Tokenize.ji due to it containing an incompatible cache header
└ @ Base loading.jl:1328
...

В Windows то же самое можно сделать в CMD, сначала запустив set JULIA_DEBUG="loading" и в Powershell через $env:JULIA_DEBUG="loading".

Аналогично, переменную среды можно использовать для включения ведения журнала отладки модулей, таких как Pkg, или корней модулей (см. Base.moduleroot). Для включения всего ведения журнала отладки используйте специальное значение all.

Чтобы включить ведение журнала отладки из REPL, установите ENV["JULIA_DEBUG"] в имя интересующего модуля. Функции, определенные в REPL, принадлежат модулю Main; ведение журнала для них можно включить следующим образом:

julia> foo() = @debug "foo"
foo (generic function with 1 method)

julia> foo()

julia> ENV["JULIA_DEBUG"] = Main
Main

julia> foo()
┌ Debug: foo
└ @ Main REPL[1]:1

Используйте разделитель запятых для включения отладки для нескольких модулей: JULIA_DEBUG=loading,Main.

Примеры

Пример: запись событий журнала в файл

Иногда бывает полезно записывать события логов в файл. Вот пример того, как использовать локальный и глобальный логгер для записи информации в текстовый файл:

# Load the logging module
julia> using Logging

# Open a textfile for writing
julia> io = open("log.txt", "w+")
IOStream(<file log.txt>)

# Create a simple logger
julia> logger = SimpleLogger(io)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# Log a task-specific message
julia> with_logger(logger) do
           @info("a context specific log message")
       end

# Write all buffered messages to the file
julia> flush(io)

# Set the global logger to logger
julia> global_logger(logger)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# This message will now also be written to the file
julia> @info("a global log message")

# Close the file
julia> close(io)

Пример: Включить сообщения уровня отладки

Вот пример создания ConsoleLogger, который пропускает все сообщения с уровнем лога выше или равным Logging.Debug.

julia> using Logging

# Create a ConsoleLogger that prints any log messages with level >= Debug to stderr
julia> debuglogger = ConsoleLogger(stderr, Logging.Debug)

# Enable debuglogger for a task
julia> with_logger(debuglogger) do
           @debug "a context specific log message"
       end

# Set the global logger
julia> global_logger(debuglogger)

Справочник

Модуль ведения логов

Logging.LoggingМодуль

Создание событий

Logging.@logmsgМакрос

@debug message  [key=value | value ...]
@info  message  [key=value | value ...]
@warn  message  [key=value | value ...]
@error message  [key=value | value ...]

@logmsg level message [key=value | value ...]

@debug "Verbose debugging information.  Invisible by default"
@info  "An informational message"
@warn  "Something was odd.  You should pay attention"
@error "A non fatal error occurred"

x = 10
@info "Some variables attached to the message" x a=42.0

@debug begin
    sA = sum(A)
    "sum(A) = $sA is an expensive operation, evaluated only when `shouldlog` returns true"
end

for i=1:10000
    @info "With the default backend, you will only see (i = $i) ten times"  maxlog=10
    @debug "Algorithm1" i progress=i/10000
end

Logging.LogLevelТип

LogLevel(level)

julia> Logging.LogLevel(0) == Logging.Info
true

Logging.DebugКонстанта

Debug

Logging.InfoКонстанта

Info

Logging.WarnКонстанта

Warn

Logging.ErrorКонстанта

Error

Logging.BelowMinLevelКонстанта

BelowMinLevel

Logging.AboveMaxLevelКонстанта

AboveMaxLevel

Обработка событий с AbstractLogger

Обработка событий контролируется путем переопределения функций, связанных с AbstractLogger:

Logging.AbstractLoggerТип

Logging.handle_messageФункция

handle_message(logger, level, message, _module, group, id, file, line; key1=val1, ...)

Logging.shouldlogФункция

shouldlog(logger, level, _module, group, id)

Logging.min_enabled_levelФункция

min_enabled_level(logger)

Logging.catch_exceptionsФункция

catch_exceptions(logger)

Logging.disable_loggingФункция

disable_logging(level)

Logging.disable_logging(Logging.Info) # Disable debug and info

Использование логгеров

Установка и проверка логгера:

Logging.global_loggerФункция

global_logger()

global_logger(logger)

Logging.with_loggerФункция

with_logger(function, logger)

function test(x)
    @info "x = $x"
end

with_logger(logger) do
    test(1)
    test([1,2])
end

Logging.current_loggerФункция

current_logger()

Регистраторы, поставляемые с системой:

Logging.NullLoggerТип

NullLogger()

Base.CoreLogging.ConsoleLoggerТип

ConsoleLogger([stream,] min_level=Info; meta_formatter=default_metafmt,
              show_limited=true, right_justify=0)

Logging.SimpleLoggerТип

SimpleLogger([stream,] min_level=Info)