====== std.log — Logging ======

→ [[lyx_-_programmiersprache:units|Zurück zur Unit-Übersicht]]

Logging mit fünf Leveln (DEBUG, INFO, WARN, ERROR, FATAL), umschaltbarem Ausgabeziel (stdout oder Datei), optionalem Zeitstempel, ANSI-Farben und einem Callback zum Weiterleiten an externe Systeme. Zusätzlich eine einfache JSON-Zeilenausgabe (''log_info_kv'') für maschinelle Auswertung.

Einsatzbereiche: Serverdienste, Hintergrundjobs, CLI-Werkzeuge, Produktions-Diagnose.

**Autor:** Andreas Röne\\
**Copyright:** 2024–2025 Andreas Röne\\
**Quelle:** ''std/log.lyx''

<WRAP alert>
**Zwei Ausgabewege — nur einer respektiert die Konfiguration.**\\
''log_emit'' ist der konfigurierbare Weg: Level-Filter, Datei-Sink, Zeitstempel. Die Kurzfunktionen ''log_info''/''log_debug''/''log_warn''/''log_error''/''log_fatal'' schreiben dagegen **immer** und **immer nach stdout** — sie ignorieren ''set_log_level'' und ''log_set_file''. Details unter [[#Fallstricke]]. Für alles außer Wegwerf-Skripten: ''log_emit'' verwenden.
</WRAP>

===== Import =====

<code lyx>
import std.log;
</code>

----

===== Konstanten =====

^ Name ^ Typ ^ Wert ^ Bedeutung ^
| ''LOG_LEVEL_DEBUG'' | ''int64'' | 0 | Detailinformation für die Fehlersuche |
| ''LOG_LEVEL_INFO'' | ''int64'' | 1 | Normaler Betriebsablauf (**Voreinstellung**) |
| ''LOG_LEVEL_WARN'' | ''int64'' | 2 | Auffälligkeit, Betrieb läuft weiter |
| ''LOG_LEVEL_ERROR'' | ''int64'' | 3 | Fehlgeschlagene Operation |
| ''LOG_LEVEL_FATAL'' | ''int64'' | 4 | Abbruchbedingung — ''log_fatal'' beendet den Prozess |

Die Zahlenwerte sind geordnet: ''log_emit'' verwirft alles unterhalb des gesetzten Levels. ''set_log_level(LOG_LEVEL_WARN)'' lässt also WARN, ERROR und FATAL durch.

----

===== Funktionen =====

==== Ausgabe (konfigurierbar) ====

^ Signatur ^ Beschreibung ^
| ''log_emit(level: int64, msg: pchar): void'' | Zentrale Ausgabe. Prüft den Level-Filter, setzt optional Zeitstempel und Farbe, schreibt Präfix ''[LEVEL] '' plus Nachricht und Zeilenumbruch auf das aktuelle Ziel |
| ''log_debugf(msg: pchar, n: int64): void'' | Wie ''log_emit(LOG_LEVEL_DEBUG, …)'', hängt ''n'' als Dezimalzahl an die Nachricht |
| ''log_infof(msg: pchar, n: int64): void'' | dito für INFO |
| ''log_warnf(msg: pchar, n: int64): void'' | dito für WARN |
| ''log_errorf(msg: pchar, n: int64): void'' | dito für ERROR |
| ''log_info_kv(event: pchar, key: pchar, value: pchar): void'' | Schreibt eine JSON-Zeile ''{"level":"info","event":"…","key":"value"}'' direkt auf das Ziel |

==== Konfiguration ====

^ Signatur ^ Beschreibung ^
| ''set_log_level(level: int64): void'' | Setzt die Filterschwelle für ''log_emit'' und die ''log_*f''-Funktionen |
| ''get_log_level(): int64'' | Liest die aktuelle Filterschwelle |
| ''log_level_to_string(level: int64): pchar'' | Level-Name; unbekannte Werte ergeben ''UNKNOWN'' |
| ''log_set_file(path: pchar): bool'' | Schaltet auf Datei um (angehängt, ''0644'' bei Neuanlage). Leerer Pfad schaltet zurück auf stdout. ''false'' bei Öffnungsfehler |
| ''log_set_timestamp(enabled: bool): void'' | Stellt dem Präfix ''[&lt;Unix-Sekunden&gt;] '' voran |
| ''log_set_color(enabled: bool): void'' | Soll ANSI-Farben nach Level einschalten — **derzeit wirkungslos**, siehe [[#Fallstricke]] |

==== Kurzfunktionen (ungefiltert, immer stdout) ====

^ Signatur ^ Beschreibung ^
| ''log_debug(msg: pchar): void'' | Schreibt ''[DEBUG] msg'' auf stdout und ruft den Callback |
| ''log_info(msg: pchar): void'' | dito für INFO |
| ''log_warn(msg: pchar): void'' | dito für WARN |
| ''log_error(msg: pchar): void'' | dito für ERROR |
| ''log_fatal(msg: pchar): void'' | dito für FATAL — ruft anschließend ''exit(1)'' |
| ''log_debug_if(cond: bool, msg: pchar): void'' | Ruft ''log_debug'' nur wenn ''cond'' wahr ist |
| ''log_info_if(cond: bool, msg: pchar): void'' | dito |
| ''log_warn_if(cond: bool, msg: pchar): void'' | dito |
| ''log_error_if(cond: bool, msg: pchar): void'' | dito |
| ''log_section_enter(name: pchar): void'' | Gibt ''name'' als INFO aus |
| ''log_section_exit(name: pchar): void'' | Gibt ''name'' als INFO aus — **von ''enter'' nicht unterscheidbar** |
| ''log_app_start(name: pchar): void'' | Drei Zeilen Startbanner — ''name'' wird **nicht** ausgegeben |
| ''log_app_end(code: int64): void'' | Abschlussbanner; ''code == 0'' ergibt Erfolgsmeldung, sonst Fehlermeldung |

==== Callback ====

^ Signatur ^ Beschreibung ^
| ''register_log_callback(fn_ptr: int64): void'' | Registriert einen Handler ''fn(pchar): void'' |
| ''unregister_log_callback(): void'' | Entfernt den Handler |
| ''has_log_callback(): bool'' | Ob ein Handler gesetzt ist |
| ''invoke_log_callback(msg: pchar): void'' | Ruft den Handler direkt; ohne Handler passiert nichts |

Der Handler wird von den **Kurzfunktionen** gerufen, **nicht** von ''log_emit''.

----

===== Beispiele =====

==== Level-gefilterte Ausgabe ====

<code lyx>
import std.log;

fn main(): int64 {
    set_log_level(LOG_LEVEL_INFO);

    log_emit(LOG_LEVEL_DEBUG, "Verbindungspool initialisiert");   // gefiltert
    log_emit(LOG_LEVEL_INFO,  "Server lauscht auf Port 8080");
    log_emit(LOG_LEVEL_WARN,  "Zertifikat laeuft in 14 Tagen ab");
    log_emit(LOG_LEVEL_ERROR, "Datenbank nicht erreichbar");

    PrintLn("aktives Level: ", log_level_to_string(get_log_level()));
    return 0;
}
</code>

Ausgabe:

<code>
[INFO] Server lauscht auf Port 8080
[WARN] Zertifikat laeuft in 14 Tagen ab
[ERROR] Datenbank nicht erreichbar
aktives Level: INFO
</code>

==== Datei-Sink, Zeitstempel, Zahlen und JSON-Zeile ====

<code lyx>
import std.log;

fn main(): int64 {
    set_log_level(LOG_LEVEL_INFO);

    if (log_set_file("dienst.log")) {
        log_set_timestamp(true);
        log_emit(LOG_LEVEL_INFO, "Dienst gestartet");
        log_infof("aktive Verbindungen: ", 17);
        log_info_kv("request", "pfad", "/api/v1/status");
        log_emit(LOG_LEVEL_ERROR, "Upstream-Timeout");
        log_set_timestamp(false);
        log_set_file("");                       // zurueck auf stdout
        PrintLn("geschrieben nach dienst.log");
    } else {
        PrintLn("Log-Datei nicht schreibbar");
    }
    return 0;
}
</code>

Inhalt von ''dienst.log'':

<code>
[1786640183] [INFO] Dienst gestartet
[1786640183] [INFO] aktive Verbindungen: 17
{"level":"info","event":"request","pfad":"/api/v1/status"}
[1786640183] [ERROR] Upstream-Timeout
</code>

Zwei Beobachtungen an dieser echten Ausgabe: Der Zeitstempel sind **rohe Unix-Sekunden**, kein formatiertes Datum — für lesbare Zeiten die Zeile selbst mit ''std.datetime'' bauen. Und die ''log_info_kv''-Zeile trägt **keinen** Zeitstempel, weil sie am Präfix-Aufbau von ''log_emit'' vorbei direkt schreibt.

==== Callback zum Weiterleiten ====

<code lyx>
import std.log;

var _fehler: int64 := 0;

fn zaehleUndSpiegle(msg: pchar): void {
    _fehler := _fehler + 1;
    PrintLn("  [audit] ", msg);
}

fn main(): int64 {
    PrintLn("Handler registriert? ", IntToStr(has_log_callback() as int64));
    register_log_callback(zaehleUndSpiegle as int64);
    PrintLn("Handler registriert? ", IntToStr(has_log_callback() as int64));

    log_warn("Plattenplatz unter 10 %");
    log_error("Schreibvorgang fehlgeschlagen");

    unregister_log_callback();
    log_warn("nach unregister — kein audit mehr");

    PrintLn("vom Handler gesehen: ", IntToStr(_fehler));
    return 0;
}
</code>

Ausgabe:

<code>
Handler registriert? 0
Handler registriert? 1
[WARN] Plattenplatz unter 10 %
  [audit] Plattenplatz unter 10 %
[ERROR] Schreibvorgang fehlgeschlagen
  [audit] Schreibvorgang fehlgeschlagen
[WARN] nach unregister — kein audit mehr
vom Handler gesehen: 2
</code>

Der Handler wird als Funktionszeiger übergeben (''as int64'') und muss die Signatur ''fn(pchar): void'' haben. Er bekommt die **nackte Nachricht** ohne Level-Präfix — das Level ist im Handler also nicht mehr erkennbar.

----

===== Fallstricke =====

Alle Punkte hier sind mit ''lyxc 1.0.17K'' nachgestellt; jeder hat ein offenes Issue.

==== 1. Kurzfunktionen ignorieren den Level-Filter ====

<code lyx>
import std.log;

fn main(): int64 {
    set_log_level(LOG_LEVEL_ERROR);

    log_info("log_info: erscheint trotz Level ERROR");
    log_debug("log_debug: erscheint ebenfalls");

    log_emit(LOG_LEVEL_INFO,  "log_emit INFO: korrekt unterdrueckt");
    log_emit(LOG_LEVEL_ERROR, "log_emit ERROR: erscheint");
    return 0;
}
</code>

<code>
[INFO] log_info: erscheint trotz Level ERROR
[DEBUG] log_debug: erscheint ebenfalls
[ERROR] log_emit ERROR: erscheint
</code>

Ursache: ''log_debug'' & Co. rufen direkt ''PrintLn'' statt ''log_emit''. Damit greift weder der Filter noch der Datei-Sink noch der Zeitstempel. Ein Dienst, der ''log_set_file'' aufruft und dann ''log_info'' benutzt, schreibt seine Logs weiter nach stdout — die Datei bleibt leer.

==== 2. ''log_set_color'' bleibt wirkungslos ====

''log_set_color(true)'' erzeugt kein einziges ANSI-Byte. Grund ist der Escape in ''_log_color_code'': die Farbcodes sind als ''"\033[36m"'' geschrieben, aber Lyx kennt **keine oktalen Escapes**. ''\0'' wird als NUL gelesen, der String hat damit Länge 0:

<code lyx>
fn main(): int64 {
    PrintLn("StrLen(\\033[36m) = ", IntToStr(StrLen("\033[36m")));
    PrintLn("StrLen(\\x1b[36m) = ", IntToStr(StrLen("\x1b[36m")));
    return 0;
}
</code>

<code>
StrLen(\033[36m) = 0
StrLen(\x1b[36m) = 5
</code>

Im eigenen Code deshalb ''\x1b'' verwenden, nie ''\033''.

==== 3. ''log_info_kv'' maskiert nichts ====

Anführungszeichen im Wert zerstören das JSON:

<code lyx>
log_info_kv("cfg", "pfad", "C:\"tmp\"x");
</code>

<code>
{"level":"info","event":"cfg","pfad":"C:"tmp"x"}
</code>

Das ist kein gültiges JSON mehr. Vor der Übergabe selbst maskieren (Backslash, Anführungszeichen, Steuerzeichen) oder ''std.json'' verwenden. ''log_info_kv'' ignoriert außerdem den Level-Filter und schreibt auch bei Level FATAL.

==== 4. Sektionen und App-Banner tragen keine Information ====

''log_section_enter("migration")'' und ''log_section_exit("migration")'' erzeugen **dieselbe** Zeile ''[INFO] migration'' — im Log ist Anfang und Ende nicht zu unterscheiden. ''log_app_start(name)'' ignoriert den übergebenen Namen und druckt ein festes Banner. Wer Abschnitte auswerten will, formuliert die Zeile selbst:

<code lyx>
log_emit(LOG_LEVEL_INFO, "-> migration");
log_emit(LOG_LEVEL_INFO, "<- migration");
</code>

==== 5. Die ''log_*f''-Wrapper lecken Speicher ====

''log_debugf''/''log_infof''/''log_warnf''/''log_errorf'' allokieren pro Aufruf einen 22-Byte-Zahlenpuffer und einen Kombinationspuffer, geben aber beides nie frei. In einer Schleife mit vielen Log-Zeilen wächst der Heap monoton. Bis zum Fix in Dauerschleifen ''log_emit'' mit selbst gebauter Nachricht verwenden:

<code lyx>
log_emit(LOG_LEVEL_INFO, StrConcat("aktive Verbindungen: ", IntToStr(n)));
</code>

----

===== Empfehlung =====

  * Ausgabe grundsätzlich über ''log_emit'' — nur dieser Weg respektiert Level und Ziel.
  * Level einmal beim Programmstart setzen, danach nicht mehr ändern.
  * Datei-Sink früh setzen, damit keine Zeilen vorher nach stdout entkommen.
  * Farben derzeit nicht einplanen (Fallstrick 2).
  * Für maschinell auswertbare Logs eigene JSON-Zeilen mit ''std.json'' bauen statt ''log_info_kv''.

----

===== Siehe auch =====

  * [[lyx_-_programmiersprache:units:datetime|std.datetime]] — lesbare Zeitstempel statt Unix-Sekunden
  * [[lyx_-_programmiersprache:units:json|std.json]] — korrekt maskierte strukturierte Ausgabe
  * [[lyx_-_programmiersprache:units:io|std.io]] — direkte Dateiausgabe
  * [[lyx_-_programmiersprache:units:os|std.os]] — ''open''/''write''/''close'', ''unix_time''