Logging

Das Logging-Modul bietet eine Möglichkeit, die Historie und den Fortschritt einer Berechnung als Protokoll von Ereignissen aufzuzeichnen. Ereignisse werden erstellt, indem eine Protokollierungsanweisung in den Quellcode eingefügt wird, zum Beispiel:

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

Das System bietet mehrere Vorteile gegenüber dem Verstreuen von println()-Aufrufen in Ihrem Quellcode. Erstens ermöglicht es Ihnen, die Sichtbarkeit und Präsentation von Nachrichten zu steuern, ohne den Quellcode bearbeiten zu müssen. Zum Beispiel im Gegensatz zu dem oben genannten @warn

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

wird standardmäßig keine Ausgabe erzeugen. Darüber hinaus ist es sehr günstig, Debug-Anweisungen wie diese im Quellcode zu belassen, da das System die Auswertung der Nachricht vermeidet, wenn sie später ignoriert wird. In diesem Fall wird sum(rand(100)) und die zugehörige String-Verarbeitung niemals ausgeführt, es sei denn, das Debug-Logging ist aktiviert.

Zweitens ermöglichen die Protokollierungswerkzeuge, beliebige Daten als eine Menge von Schlüssel-Wert-Paaren an jedes Ereignis anzuhängen. Dies ermöglicht es Ihnen, lokale Variablen und andere Programmzustände für eine spätere Analyse zu erfassen. Um beispielsweise die lokale Array-Variable A und die Summe eines Vektors v als den Schlüssel s anzuhängen, können Sie verwenden

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

Alle Protokollierungs-Makros @debug, @info, @warn und @error teilen gemeinsame Funktionen, die ausführlich in der Dokumentation für das allgemeinere Makro @logmsg beschrieben sind.

Log event structure

Jedes Ereignis generiert mehrere Datenstücke, einige werden vom Benutzer bereitgestellt und einige automatisch extrahiert. Lassen Sie uns zunächst die benutzerdefinierten Daten untersuchen:

• Das Protokollniveau ist eine breite Kategorie für die Nachricht, die für eine frühe Filterung verwendet wird. Es gibt mehrere Standardstufen des Typs LogLevel; benutzerdefinierte Stufen sind ebenfalls möglich. Jede ist in ihrem Zweck unterschiedlich:

  • Logging.Debug (Protokollebene -1000) ist eine Information, die für den Entwickler des Programms bestimmt ist. Diese Ereignisse sind standardmäßig deaktiviert.
  • Logging.Info (Protokollstufe 0) dient allgemeinen Informationen für den Benutzer. Betrachten Sie es als eine Alternative zur direkten Verwendung von println.
  • Logging.Warn (Protokollstufe 1000) bedeutet, dass etwas nicht stimmt und wahrscheinlich Maßnahmen erforderlich sind, aber dass das Programm vorerst weiterhin funktioniert.
  • Logging.Error (Protokollebene 2000) bedeutet, dass etwas nicht stimmt und es unwahrscheinlich ist, dass es wiederhergestellt werden kann, zumindest nicht von diesem Teil des Codes. Oft ist dieses Protokollebene nicht erforderlich, da das Auslösen einer Ausnahme alle benötigten Informationen übermitteln kann.

• Die Nachricht ist ein Objekt, das das Ereignis beschreibt. Nach Konvention werden AbstractStrings, die als Nachrichten übergeben werden, als im Markdown-Format angenommen. Andere Typen werden mit print(io, obj) oder string(obj) für textbasierte Ausgaben und möglicherweise show(io,mime,obj) für andere Multimedia-Anzeigen, die im installierten Logger verwendet werden, angezeigt.

• Optionale Schlüssel-Wert-Paare ermöglichen es, beliebige Daten an jedes Ereignis anzuhängen. Einige Schlüssel haben eine konventionelle Bedeutung, die die Art und Weise beeinflussen kann, wie ein Ereignis interpretiert wird (siehe @logmsg).

Das System generiert auch einige Standardinformationen für jedes Ereignis:

• Das Modul, in dem das Logging-Makro erweitert wurde.
• Die Datei und Zeile, in der das Logging-Makro im Quellcode auftritt.
• Eine Nachricht id, die ein eindeutiger, fester Identifikator für die Quellcode-Anweisung ist, an der das Logging-Makro erscheint. Dieser Identifikator ist so konzipiert, dass er relativ stabil bleibt, selbst wenn sich der Quellcode der Datei ändert, solange die Logging-Anweisung selbst gleich bleibt.
• Eine Gruppe für das Ereignis, die standardmäßig auf den Basisnamen der Datei ohne Erweiterung gesetzt ist. Dies kann verwendet werden, um Nachrichten feiner in Kategorien als das Protokollniveau zu gruppieren (zum Beispiel haben alle Abwertungswarnungen die Gruppe :depwarn), oder um logische Gruppierungen über oder innerhalb von Modulen zu erstellen.

Beachten Sie, dass einige nützliche Informationen wie die Veranstaltungszeit standardmäßig nicht enthalten sind. Dies liegt daran, dass solche Informationen teuer zu extrahieren sein können und auch dynamisch dem aktuellen Logger zur Verfügung stehen. Es ist einfach, eine custom logger zu definieren, um Ereignisdaten mit der Zeit, dem Backtrace, Werten globaler Variablen und anderen nützlichen Informationen nach Bedarf zu ergänzen.

Processing log events

Wie Sie in den Beispielen sehen können, erwähnen die Protokollierungsanweisungen nicht, wohin Protokollereignisse gehen oder wie sie verarbeitet werden. Dies ist ein wichtiges Designelement, das das System zusammensetzbar und natürlich für die gleichzeitige Nutzung macht. Es erreicht dies, indem es zwei verschiedene Anliegen trennt:

• Das Erstellen von Protokollereignissen liegt in der Verantwortung des Modulentwicklers, der entscheiden muss, wo Ereignisse ausgelöst werden und welche Informationen enthalten sein sollen.
• Verarbeitung von Protokollereignissen — das heißt, Anzeige, Filterung, Aggregation und Aufzeichnung — ist das Anliegen des Anwendungsautors, der mehrere Module zu einer kooperierenden Anwendung zusammenbringen muss.

Loggers

Die Verarbeitung von Ereignissen erfolgt durch einen Logger, der das erste Stück benutzerkonfigurierbaren Codes ist, das das Ereignis sieht. Alle Logger müssen Untertypen von AbstractLogger sein.

Wenn ein Ereignis ausgelöst wird, wird der entsprechende Logger gefunden, indem nach einem aufgabenlokalen Logger mit dem globalen Logger als Fallback gesucht wird. Die Idee dabei ist, dass der Anwendungscode weiß, wie Protokollereignisse verarbeitet werden sollten und irgendwo ganz oben im Aufrufstapel existiert. Daher sollten wir durch den Aufrufstapel nach oben schauen, um den Logger zu entdecken – das heißt, der Logger sollte dynamisch scoping sein. (Dies ist ein Gegensatz zu Protokollierungsframeworks, bei denen der Logger lexikalisch scoping ist; explizit vom Modulautor bereitgestellt oder als einfache globale Variable. In einem solchen System ist es umständlich, das Protokollieren zu steuern, während man Funktionalität aus mehreren Modulen zusammensetzt.)

Der globale Logger kann mit global_logger gesetzt werden, und task-lokale Logger werden mit with_logger gesteuert. Neu gestartete Aufgaben erben den Logger der übergeordneten Aufgabe.

Es gibt drei Logger-Typen, die von der Bibliothek bereitgestellt werden. ConsoleLogger ist der Standard-Logger, den Sie beim Starten des REPL sehen. Er zeigt Ereignisse in einem lesbaren Textformat an und versucht, einfache, aber benutzerfreundliche Steuerung über Formatierung und Filterung zu bieten. NullLogger ist eine praktische Möglichkeit, alle Nachrichten nach Bedarf zu verwerfen; es ist das Logging-Äquivalent des devnull Streams. SimpleLogger ist ein sehr einfacher Textformatierungs-Logger, der hauptsächlich nützlich ist, um das Logging-System selbst zu debuggen.

Benutzerdefinierte Protokollierer sollten Überladungen für die Funktionen bereitstellen, die in der reference section beschrieben sind.

Early filtering and message handling

Wenn ein Ereignis eintritt, erfolgen einige Schritte der frühen Filterung, um zu vermeiden, dass Nachrichten generiert werden, die verworfen werden.

1. Das Nachrichtenprotokollniveau wird mit einem globalen Mindestniveau (festgelegt über disable_logging) überprüft. Dies ist eine grobe, aber äußerst kostengünstige globale Einstellung.
2. Der aktuelle Logger-Zustand wird überprüft und das Nachrichtenlevel wird mit dem minimalen Level des Loggers verglichen, das durch den Aufruf von Logging.min_enabled_level gefunden wurde. Dieses Verhalten kann über Umgebungsvariablen überschrieben werden (mehr dazu später).
3. Die Logging.shouldlog-Funktion wird mit dem aktuellen Logger aufgerufen und nimmt einige minimale Informationen (Level, Modul, Gruppe, ID) entgegen, die statisch berechnet werden können. Am nützlichsten ist, dass shouldlog eine Ereignis-ID übergeben wird, die verwendet werden kann, um Ereignisse frühzeitig basierend auf einem zwischengespeicherten Prädikat abzulehnen.

Wenn all diese Überprüfungen bestanden sind, werden die Nachricht und die Schlüssel-Wert-Paare vollständig ausgewertet und über die Logging.handle_message-Funktion an den aktuellen Logger übergeben. handle_message() kann zusätzliche Filterungen vornehmen, wie erforderlich, und das Ereignis auf dem Bildschirm anzeigen, in eine Datei speichern usw.

Ausnahmen, die beim Generieren des Protokollereignisses auftreten, werden standardmäßig erfasst und protokolliert. Dies verhindert, dass einzelne fehlerhafte Ereignisse die Anwendung zum Absturz bringen, was hilfreich ist, wenn selten verwendete Debug-Ereignisse in einem Produktionssystem aktiviert werden. Dieses Verhalten kann pro Logger-Typ angepasst werden, indem Logging.catch_exceptions erweitert wird.

Testing log events

Log events are a side effect of running normal code, but you might find yourself wanting to test particular informational messages and warnings. The Test module provides a @test_logs macro that can be used to pattern match against the log event stream.

Environment variables

Die Nachrichtenfilterung kann durch die Umgebungsvariable JULIA_DEBUG beeinflusst werden und dient als einfache Möglichkeit, das Debug-Logging für eine Datei oder ein Modul zu aktivieren. Das Laden von Julia mit JULIA_DEBUG=loading aktiviert @debug-Protokollnachrichten in loading.jl. Zum Beispiel in Linux-Shells:

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

Unter Windows kann dasselbe im CMD erreicht werden, indem zuerst set JULIA_DEBUG="loading" ausgeführt wird, und in Powershell über $env:JULIA_DEBUG="loading".

Ähnlich kann die Umgebungsvariable verwendet werden, um das Debug-Logging von Modulen, wie Pkg, oder Modulwurzeln zu aktivieren (siehe Base.moduleroot). Um alle Debug-Logs zu aktivieren, verwenden Sie den speziellen Wert all.

Um das Debug-Logging von der REPL aus zu aktivieren, setzen Sie ENV["JULIA_DEBUG"] auf den Namen des interessierenden Moduls. Funktionen, die in der REPL definiert sind, gehören zum Modul Main; das Logging für sie kann wie folgt aktiviert werden:

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

Verwenden Sie ein Komma als Trennzeichen, um das Debugging für mehrere Module zu aktivieren: JULIA_DEBUG=loading,Main.

Examples

Example: Writing log events to a file

Manchmal kann es nützlich sein, Protokollereignisse in eine Datei zu schreiben. Hier ist ein Beispiel, wie man einen aufgabenlokalen und globalen Logger verwendet, um Informationen in eine Textdatei zu schreiben:

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

Example: Enable debug-level messages

Hier ist ein Beispiel für die Erstellung eines ConsoleLogger, das alle Nachrichten mit einem Protokolllevel höher oder gleich Logging.Debug durchlässt.

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)

Reference

Logging module

Creating events

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

@logmsg niveau nachricht [key=value | value ...]

Erstellen Sie einen Protokolleintrag mit einer informativen `Nachricht`.  Zur Vereinfachung sind vier Protokollierungs-Makros `@debug`, `@info`, `@warn` und `@error` definiert, die auf den standardmäßigen Schweregraden `Debug`, `Info`, `Warn` und `Error` protokollieren.  `@logmsg` ermöglicht es, `niveau` programmgesteuert auf jeden `LogLevel` oder benutzerdefinierte Protokollebene zu setzen.

`Nachricht` sollte ein Ausdruck sein, der zu einem String ausgewertet wird, der eine für Menschen lesbare Beschreibung des Protokollereignisses ist.  Üblicherweise wird dieser String als Markdown formatiert, wenn er präsentiert wird.

Die optionale Liste von `key=value`-Paaren unterstützt beliebige benutzerdefinierte Metadaten, die als Teil des Protokolleintrags an das Protokollierungssystem weitergegeben werden.  Wenn nur ein `value`-Ausdruck bereitgestellt wird, wird ein Schlüssel, der den Ausdruck darstellt, unter Verwendung von [`Symbol`](@ref) generiert. Zum Beispiel wird `x` zu `x=x`, und `foo(10)` wird zu `Symbol("foo(10)")=foo(10)`.  Um eine Liste von Schlüssel-Wert-Paaren zu splatten, verwenden Sie die normale Splattingsyntax, `@info "blah" kws...`.

Es gibt einige Schlüssel, die es ermöglichen, automatisch generierte Protokolldaten zu überschreiben:

  * `_module=mod` kann verwendet werden, um ein anderes Ursprungsmodul als den Quellort der Nachricht anzugeben.
  * `_group=symbol` kann verwendet werden, um die Nachrichten-Gruppe zu überschreiben (dies wird normalerweise aus dem Basisnamen der Quelldatei abgeleitet).
  * `_id=symbol` kann verwendet werden, um die automatisch generierte eindeutige Nachrichtenkennung zu überschreiben.  Dies ist nützlich, wenn Sie Nachrichten, die an verschiedenen Quellzeilen generiert wurden, sehr eng miteinander verknüpfen müssen.
  * `_file=string` und `_line=integer` können verwendet werden, um den scheinbaren Quellort einer Protokollnachricht zu überschreiben.

Es gibt auch einige Schlüssel-Wert-Paare, die eine konventionelle Bedeutung haben:

  * `maxlog=integer` sollte als Hinweis an das Backend verwendet werden, dass die Nachricht nicht mehr als `maxlog`-Mal angezeigt werden sollte.
  * `exception=ex` sollte verwendet werden, um eine Ausnahme mit einer Protokollnachricht zu transportieren, oft verwendet mit `@error`. Ein zugehöriger Backtrace `bt` kann unter Verwendung des Tupels `exception=(ex,bt)` angehängt werden.

# Beispiele

LogLevel(level)

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

Debug

Info

Warn

Fehler

BelowMinLevel

AboveMaxLevel

Processing events with AbstractLogger

Die Ereignisverarbeitung wird durch das Überschreiben von Funktionen gesteuert, die mit AbstractLogger verknüpft sind:

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

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

min_enabled_level(logger)

catch_exceptions(logger)

disable_logging(level)

Logging.disable_logging(Logging.Info) # Deaktiviert Debug- und Informationsprotokolle

Using Loggers

Logger-Installation und -Inspektion:

global_logger()

global_logger(logger)

with_logger(function, logger)

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

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

current_logger()

Logger, die mit dem System geliefert werden:

NullLogger()

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

SimpleLogger([stream,] min_level=Info)