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

Модуль 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 сообщения, передаваемые в качестве сообщений, предполагаются в формате маркировки. Другие типы будут отображаться с использованием print(io, obj) или string(obj) для текстового вывода и, возможно, show(io,mime,obj) для других мультимедийных дисплеев, используемых в установленной программе ведения журнала.

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

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

• Строка, в которой был развернут макрос ведения журнала.
• Строка и столбец, где появляется макрос ведения журнала в исходном коде.
• Сообщение id — это уникальный, фиксированный идентификатор для утверждения исходного кода, где появляется макрос ведения журнала. Этот идентификатор предназначен для обеспечения достаточной стабильности даже при изменении исходного кода файла, пока само утверждение ведения журнала остается неизменным.
• Группа для события, которая по умолчанию устанавливается в базовое имя файла без расширения. Это можно использовать для группирования сообщений в более мелкие категории, чем уровень журнала (например, все предупреждения об устаревании имеют группу :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 invalid 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 invalid 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

Обработка событий с 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()

Logging.ConsoleLoggerТип

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

Logging.SimpleLoggerТип

SimpleLogger([stream,] min_level=Info)