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

Модуль 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 Array{Int64,2}:
│     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).

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

• Файл, в котором был развернут макрос ведения журнала.
• Строка и столбец, где произошёл макрос ведения журнала в исходном коде.
• Уникальный, фиксированный идентификатор сообщения 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)

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