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

Модуль 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; также возможны пользовательские уровни. Каждый из них имеет разную цель:

  • Debug предназначена для разработчика программы.

  Эти события отключены по умолчанию.

  • Info предназначена для общей информации для пользователя.

  Представьте это как альтернативу прямому использованию println.

  • Warn означает, что что-то не так, и, вероятно, требуется действие

  , но пока программа все еще работает.

  • Error означает, что что-то не так, и, скорее всего, это не удастся исправить,

  по крайней мере, этой частью кода. Зачастую этот уровень журнала не нужен, так как выброс исключения может передать всю необходимую информацию.

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

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

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

• Файл module, в котором был расширен макрос ведения журнала.
• Строка file и line места расположения макроса ведения журнала в исходном коде.
• Сообщение 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:

$ 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
...

Аналогичным образом, переменная окружения может использоваться для включения отладочного ведения журнала модулей, таких как 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

Запись событий журнала в файл

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

# 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)

Справочник

Модуль ведения журнала

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

Обработка событий с 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=stderr, min_level=Info; meta_formatter=default_metafmt,
              show_limited=true, right_justify=0)

Logging.SimpleLoggerТип

SimpleLogger(stream=stderr, min_level=Info)