Документация Engee

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

Модуль 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).

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

  • Модуль (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. Пример для оболочек 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.

Примеры

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

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

# Загрузить модуль ведения журнала
julia> using Logging

# Открыть текстовый файл для записи
julia> io = open("log.txt", "w+")
IOStream(<file log.txt>)

# Создать простое средство ведения журнала
julia> logger = SimpleLogger(io)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# Зарегистрировать сообщение для задачи
julia> with_logger(logger) do
           @info("a context specific log message")
       end

# Записать все буферизованные сообщения в файл
julia> flush(io)

# Задать глобальное средство ведения журнала
julia> global_logger(logger)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# Теперь это сообщение также будет записано в файл
julia> @info("a global log message")

# Закрыть файл
julia> close(io)

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

Ниже приведен пример создания средства ведения журнала ConsoleLogger, пропускающего все сообщения, уровень ведения журнала которых больше или равен Logging.Debug.

julia> using Logging

# Создать средство ConsoleLogger, которое выводит все сообщения журнала с уровнем >= отладка в stderr
julia> debuglogger = ConsoleLogger(stderr, Logging.Debug)

# Включить средство ведения журнала отладки для задачи
julia> with_logger(debuglogger) do
           @debug "a context specific log message"
       end

# Задать глобальное средство ведения журнала
julia> global_logger(debuglogger)

Справка

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

# Logging.LoggingModule

Вспомогательные функции для захвата, фильтрации и представления потоков событий журнала. Обычно для создания событий журнала импортировать Logging не нужно; для этого стандартные макросы ведения журнала, такие как @info, автоматически экспортируются модулем Base и доступны по умолчанию.

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

# Logging.@logmsgMacro

@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 ...]

Создает запись журнала с информационным сообщением message. Для удобства определены четыре макроса ведения журнала @debug, @info, @warn и @error, которые работают со стандартными уровнями важности Debug, Info, Warn и Error. @logmsg позволяет задавать уровень (level) программным путем. Значением может быть любой уровень LogLevel или пользовательский тип уровня.

Аргумент message должен представлять собой выражение, результатом которого является удобочитаемая строка с описанием события журнала. Согласно соглашению эта строка при ее наличии должна иметь формат Markdown.

Необязательный список пар key=value поддерживает произвольные метаданные, определенные пользователем, которые передаются на сервере ведения журнала вместе с записью журнала. Если предоставлено только выражение value, представляющий его ключ будет сгенерирован с помощью Symbol. Например, x станет x=x, а foo(10) — Symbol("foo(10)")=foo(10). Для распаковки списка пар «ключ-значение» используйте обычный синтаксис распаковки: @info "blah" kws....

Некоторые ключи позволяют переопределять автоматически сгенерированные данные журнала:

  • _module=mod можно использовать для указания другого исходного модуля из исходного расположения сообщения.

  • _group=symbol можно использовать для переопределения группы сообщений (это производится от базового имени файла исходного кода).

  • _id=symbol можно использовать для переопределения автоматически сгенерированного уникального идентификатора сообщения. Полезно в случае, если необходимо очень тесно связывать сообщения, генерируемые для разных строк исходного кода.

  • _file=string и _line=integer можно использовать для переопределения явного исходного расположения сообщения журнала.

Некоторые пары «ключ-значение» имеют общепринятое значение:

  • maxlog=integer следует использовать в качестве указания серверу о том, что сообщение должно отображаться не более maxlog раз.

  • exception=ex следует использовать для передачи исключением с сообщением журнала, часто применяется с @error. Связанную обратную трассировку bt можно приложить с помощью кортежа exception=(ex,bt).

Примеры

@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.LogLevelType

LogLevel(level)

Важность или подробность записи журнала.

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

Примеры

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

# Logging.DebugConstant

Debug

Псевдоним для LogLevel(-1000).

# Logging.InfoConstant

Info

Псевдоним для LogLevel(0).

# Logging.WarnConstant

Warn

Псевдоним для LogLevel(1000).

# Logging.ErrorConstant

Error

Псевдоним для LogLevel(2000).

Обработка событий с помощью AbstractLogger

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

Реализуемые методы Краткое описание

Logging.handle_message

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

Logging.shouldlog

Ранняя фильтрация событий

Logging.min_enabled_level

Нижняя граница уровня ведения журнала принимаемых событий

Необязательные методы

Определение по умолчанию

Краткое описание

Logging.catch_exceptions

true

Перехватывает исключения во время оценки события

# Logging.AbstractLoggerType

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

# Logging.handle_messageFunction

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

Записывает сообщение в logger с уровнем level. Логическое расположение, в котором было создано сообщение, определяется аргументами _module и group, а исходное расположение — аргументами file и line. id — это произвольное уникальное значение (обычно Symbol), используемое в качестве ключа для определения оператора журнала при фильтрации.

# Logging.shouldlogFunction

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

Возвращает true, если logger принимает сообщение с уровнем level, сгенерированное для _module, group и с уникальным идентификатором журнала id.

# Logging.min_enabled_levelFunction

min_enabled_level(logger)

Возвращает минимальный активированный для logger уровень для предварительной фильтрации. Отфильтровываются все сообщения с этим или более низким уровнем.

# Logging.catch_exceptionsFunction

catch_exceptions(logger)

Возвращает true, если регистратор должен перехватывать исключения, которые происходят во время создания записи журнала. По умолчанию перехватываются сообщения.

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

Если вы хотите использовать журналы для аудита, эту возможность следует отключить для вашего типа регистратора.

# Logging.disable_loggingFunction

disable_logging(level)

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

Примеры

Logging.disable_logging(Logging.Info) # Отключает события отладки и информацию

Использование средств ведения журналов

Установка и проверка средства ведения журнала:

# Logging.global_loggerFunction

global_logger()

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

global_logger(logger)

Задает logger в качестве глобального регистратора и возвращает предыдущий глобальный регистратор.

# Logging.with_loggerFunction

with_logger(function, logger)

Выполняет функцию function, направляя все сообщения журнала в logger.

Пример

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

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

# Logging.current_loggerFunction

current_logger()

Возвращает регистратор для текущей задачи или глобальный регистратор, если связанного с задачей регистратора нет.

Средства ведения журналов, поставляемые с системой:

# Logging.NullLoggerType

NullLogger()

Регистратор, который отключает все сообщения и не создает выходных данных, — эквивалентен /dev/null.

# Logging.ConsoleLoggerType

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

Регистратор с форматированием, оптимизированным для удобства чтения в текстовой консоли, например при интерактивной работе с REPL Julia.

Уровни ведения журнала ниже min_level отфильтровываются.

Форматирование сообщений можно настраивать, задавая именованные аргументы:

  • meta_formatter — это функция, принимающая метаданные события журнала (level, _module, group, id, file, line) и возвращающая цвет (в формате, предназначенном для передачи в printstyled), префикс и суффикс для сообщения журнала. По умолчанию префиксом является уровень ведения журнала, а суффиксом — содержащий модуль, файл и номер строки.

  • show_limited ограничивает вывод больших структур данных размером экрана, задавая ключ :limit IOContext во время форматирования.

  • right_justify — это целочисленный столбец для выравнивания метаданных журнала по правому краю. По умолчанию значение равно нулю (метаданные помещаются в отдельную строку).

# Logging.SimpleLoggerType

SimpleLogger([stream,] min_level=Info)

Простейший регистратор для записи всех сообщений с уровнем не ниже min_level в stream. Если поток закрыт, сообщения с уровнем ведения журнала не ниже Warn будут записываться в stderr, а ниже — в stdout.