Tipps von einem professionellen Programmierer (Teil III): Protokollierung. Anbindung an das Seq-Log-Sammel- und Analysesystem

Inhaltsverzeichnis

• Einführung
• Seq: System zum Sammeln und Analysieren von Protokollen
• Logger-Klasse
• Testen der Logger-Klasse
• MetaTrader 5-Protokolle in Seq importieren
• Schlussfolgerung

Einführung

Logging oder das Protokollieren ist die Ausgabe von Meldungen zur Analyse des Betriebs von Anwendungen. Die MQL5-Funktionen Print und PrintFormat speichern die ausgegebenen Meldungen im Expertenjournal. Das Expertenjournal ist eine Textdatei im Unicode-Format. Jeden Tag wird eine neue Datei MQL5/Logs/yyyymmdd.log erstellt, um eine Überlastung der Logs zu vermeiden.

Alle Skripte und Expert Advisors auf allen offenen Charts "schreiben das Log" in eine Datei. Einige Teile des Protokolls verbleiben im Festplatten-Cache. Mit anderen Worten: Wenn Sie die Protokolldatei im Explorer öffnen, sehen Sie nicht die neuesten Informationen, da sie sich im Cache befinden. Um das Terminal zu zwingen, den Cache in einer Datei zu speichern, sollten Sie entweder das Terminal schließen oder das Kontextmenü der Registerkarte Experten verwenden und dort den Eintrag Öffnen auswählen. Dadurch wird das Verzeichnis mit den Protokolldateien geöffnet.

Es ist nicht einfach, diese Protokolle zu analysieren, insbesondere im Terminal. Aber eine solche Analyse ist sehr wichtig. Im ersten Teil der Tipps habe ich eine der Möglichkeiten gezeigt, die Suche, Auswahl und Anzeige von Informationen in den Terminalprotokollen zu vereinfachen. In diesem Artikel zeige ich Ihnen, wie Sie:

• die Log-Ausgabe zu vereinheitlichen (Klasse Logger)
• Logs mit dem Seq-Log-Sammel- und Analysesystem verbinden
• Nachrichten (Ereignisse) online in Seq anzeigen
• reguläre MetaTrader 5-Logs in Seq importieren (Python-Paket)

Seq: System zum Sammeln und Analysieren von Protokollen

Seq ist ein Server zum Durchsuchen und Analysieren von Anwendungsprotokollen in reeller Zeit. Seine gut gestaltete Nutzeroberfläche, die Ereignisspeicherung im JSON-Format und die SQL-Abfragesprache machen ihn zu einer effektiven Plattform für die Identifizierung und Diagnose von Problemen in komplexen Anwendungen und Microservices.

Um Nachrichten an Seq zu senden, müssen Sie dies tun:

1. installieren von Seq auf Ihrem Computer.
   Nach der Installation ist die Seq UI verfügbar unter:
   http://localhost:5341/#/events
2. Fügen Sie die folgende Zeile in die Datei c:/windows/system32/drivers/etc/hosts ein:
   127.0.0.1 seqlocal.net
   um die URL zu den Einstellungen des MetaTrader 5 Terminals hinzufügen zu können
3. Deaktivieren der Verwendung der Zeitzone in Seq, um die Nachrichtenzeit "wie sie ist" anzuzeigen
   - gehen Sie zu UI Seq
   - Gehen Sie zu Admin/Einstellungen/Einstellungen
   - Aktivieren Sie "Show timestamps in Coordinated Universal Time (UTC)" (Zeitstempel in koordinierter Weltzeit (UTC) anzeigen).
4. Fügen Sie die folgende Adresse zu MT5/Tools/Options/Expert Advisors hinzu
   http://seqlocal.net
   damit die WebRequest-Funktion diese URL verwenden kann

Logger-Klasse

Die Idee ist so einfach wie dies: Um einheitliche und strukturierte Informationen zu erhalten, sollten diese in der gleichen Art und Weise gebildet und dargestellt werden. Für diesen Zweck werden wir die Logger-Klasse verwenden, die vollständig autonom ist. D.h., sie hat keine zusätzlichen Abhängigkeiten wie #include-Dateien. Die Klasse kann also "out of the box" verwendet werden.

// Message levels
#define LEV_DEBUG "DBG"   // debugging (for service use)
#define LEV_INFO "INF"    // information (to track the functions)
#define LEV_WARNING "WRN" // warning (attention)
#define LEV_ERROR "ERR"   // a non-critical error (check the log, work can be continued)
#define LEV_FATAL "FTL"   // fatal error (work cannot be continued)

Die Meldungslevel gibt eine ungefähre Vorstellung von der Schwere und Dringlichkeit der Nachricht. Damit die Stufen im Expertenjournal gut lesbar sind und hervorgehoben und ausgerichtet werden, verwende ich 3-Buchstaben-Präfixe für sie: DBG, INF, WRN, ERR, FTL. 

• DEBUG ist für den Programmierer gedacht und wird bei vielen Logging-Systemen nicht auf der Konsole ausgegeben, sondern in einer Datei gespeichert. DEBUG-Meldungen werden häufiger als andere angezeigt und enthalten meist die Namen von Funktionen mit Parametern und/oder deren Aufrufergebnisse.
• INFO ist für den Nutzer bestimmt. Diese Meldungen erscheinen seltener als DEBUG-Meldungen. Sie enthalten Informationen über den Betrieb der Anwendung. Das können zum Beispiel Nutzeraktionen sein, wie das Anklicken eines Menüpunktes, Transaktionsergebnisse usw., also alles, was ein Nutzer verstehen kann.
• WARNUNG zeigt an, dass diese Informationen beachtet werden sollten. Zum Beispiel: Position eröffnet oder geschlossen, schwebende Order ausgelöst, usw. 
• FEHLER bedeutet, dass ein unkritischer Fehler aufgetreten ist, nach dem die Anwendung weiter funktioniert. Zum Beispiel ein ungültiger Preis oder ein ungültiges Stop-Level in einer Order, aufgrund dessen die Order abgelehnt oder nicht ausgeführt wurde.
• FATAL bedeutet, dass ein kritischer Fehler aufgetreten ist, nach dem ein weiterer Betrieb der Anwendung im normalen Modus nicht mehr gewährleistet ist. Die Anwendung muss dringend angehalten werden, um den Fehler zu beheben.

Aus Gründen der Lesbarkeit und der Code-Reduzierung werden die Meldungen durch die folgenden Makro-Substitutionen ausgegeben:

// Message output macros
#define LOG_SENDER gLog.SetSender(__FILE__, __FUNCTION__)
#define LOG_INFO(message) LOG_SENDER; gLog.Info(message)
#define LOG_DEBUG(message) LOG_SENDER; gLog.Debug(message)
#define LOG_WARNING(message) LOG_SENDER; gLog.Warning(message)
#define LOG_ERROR(message) LOG_SENDER; gLog.Error(message)
#define LOG_FATAL(message) LOG_SENDER; gLog.Fatal(message)

So zeigt jede Nachricht den Namen der Datei oder des Moduls, den Namen der Funktion und die Nachricht selbst an. Um eine Nachricht zu erstellen, empfehle ich die Funktion PrintFormat zu verwenden. Es ist wünschenswert, jeden Wert mit dem Teilstring " / " zu trennen. Diese Technik macht alle Nachrichten einheitlich und strukturiert.

Beispiel für Operatoren:

LOG_INFO(m_result);
LOG_INFO(StringFormat("%s / %s / %s", StringSubstr(EnumToString(m_type), 3), 
    TimeToString(m_time0Bar), m_result));

Ausgabe der Operationsdaten in das Expertenprotokoll

Time                     Source              Message
---------------------------------------------------------------------------------------------------------------------
2022.02.16 13:00:06.079  Cayman (GBPUSD,H1)  INF: AnalyserRollback::Run Rollback, H1, 12:00, R1, D1, RO, order 275667165
2022.02.16 13:00:06.080  Cayman (GBPUSD,H1)  INF: Analyser::SaveParameters Rollback / 2022.02.16 12:00 / Rollback, H1, 12:00, R1, D1, RO, order 275667165

Die Besonderheit der in MetaTrader 5 gedruckten Nachrichten besteht darin, dass in der Spalte TimeLocal die Zeit angegeben wird, während die eigentliche Information zur Serverzeit TimeCurrent gehört. Wenn es also notwendig ist, die Zeit zu betonen, sollte die Zeit in der Nachricht selbst angegeben werden. Dies wird in der zweiten Nachricht gezeigt, in der 13:00 Uhr die Ortszeit und 12:00 Uhr die Serverzeit ist (reale Öffnungszeit der Bar).

Die Klasse Logger hat die folgende Struktur:

class Logger {
private:
    string  m_module;  // module or file name
    string  m_sender;  // function name
    string  m_level;   // message level
    string  m_message; // message text
    string  m_urlSeq;  // url of the Seq message service
    string  m_appName; // application name for Seq
    // private methods
    void Log(string level, string message);
    string TimeToStr(datetime value);
    string PeriodToStr(ENUM_TIMEFRAMES value);
    string Quote(string value);
    string Level();
    void SendToSeq();
public:
    Logger(string appName, string urlSeq);
    void SetSender(string module, string sender);
    void Debug(string message) { Log(LEV_DEBUG, message); };
    void Info(string message) { Log(LEV_INFO, message); };
    void Warning(string message) { Log(LEV_WARNING, message); };
    void Error(string message) { Log(LEV_ERROR, message); };
    void Fatal(string message) { Log(LEV_FATAL, message); };
};

extern Logger *gLog; // logger instance

Alles ist prägnant, lesbar und enthält keine unnötigen Details. Achten Sie auf die Deklaration der gLog-Logger-Instanz. Als "extern" deklarierte Variablen mit demselben Typ und Bezeichner können in verschiedenen Quelldateien desselben Projekts vorhanden sein. Externe Variablen können nur einmal initialisiert werden. Nach der Erstellung eines Loggers in einer beliebigen Projektdatei zeigt die gLog-Variable also auf dasselbe Objekt.

// -----------------------------------------------------------------------------
// Constructor
// -----------------------------------------------------------------------------
Logger::Logger(string appName, string urlSeq = "") {
    m_appName = appName;
    m_urlSeq = urlSeq;
}

Der Logger-Konstruktor erhält zwei Parameter:

• appName - Anwendungsname für Seq. Das Seq-System kann im Online-Modus Protokolle von verschiedenen Anwendungen empfangen. appName wird zum Filtern von Meldungen verwendet.
• urlSeq - URL des Seq-Dienstes. Es kann ein lokaler Standort sein, der auf einem bestimmten Port lauscht (http://localhost:5341/#/events).

Der Parameter urlSeq ist optional. Wenn er nicht angegeben wird, werden die Meldungen nur in das Expertenprotokoll ausgegeben. Wenn urlSeq definiert ist, werden die Ereignisse zusätzlich per WebRequest an den Seq-Dienst gesendet.

// -----------------------------------------------------------------------------
// Set the message sender          
// -----------------------------------------------------------------------------
void Logger::SetSender(string module, string sender) { 
    m_module = module; // module or file name
    m_sender = sender; // function name
    StringReplace(m_module, ".mq5", "");
}

Die Funktion SetSender erhält zwei erforderliche Parameter und legt den Absender der Nachricht fest. Die Dateierweiterung ".mq5" wird aus dem Modulnamen entfernt. Wenn der Protokollierungsoperator LOG_LEVEL in einer Klassenmethode verwendet wird, wird der Klassenname an den Funktionsnamen angehängt, zum Beispiel TestClass::TestFunc.

// -----------------------------------------------------------------------------
// Convert time to the ISO8601 format for Seq
// -----------------------------------------------------------------------------
string Logger::TimeToStr(datetime value) {
    MqlDateTime mdt;
    TimeToStruct(value, mdt);
    ulong msec = GetTickCount64() % 1000; // for comparison
    return StringFormat("%4i-%02i-%02iT%02i:%02i:%02i.%03iZ", 
        mdt.year, mdt.mon, mdt.day, mdt.hour, mdt.min, mdt.sec, msec);
}

Der Zeittyp für Seq muss im ISO8601-Format sein (JJJJ-MM-DTThh:mm:ss[.SSS]). Der Datetime-Typ in MQL5 wird bis auf eine Sekunde genau berechnet. Die Zeit in Seq wird bis zu einer Millisekunde dargestellt. Daher wird die Anzahl der Millisekunden, die seit dem Systemstart (GetTickCount64) verstrichen sind, zwangsweise zur angegebenen Zeit addiert. Mit dieser Methode können Sie die Zeit von Nachrichten relativ zueinander vergleichen.

// -----------------------------------------------------------------------------
// Convert period to string
// -----------------------------------------------------------------------------
string Logger::PeriodToStr(ENUM_TIMEFRAMES value) {
    return StringSubstr(EnumToString(value), 7);
}

Die Periode (Zeitrahmen) wird in symbolischer Form an Seq übergeben. Der symbolischen Darstellung jeder Periode ist "PERIOD_" vorangestellt. Daher wird bei der Umwandlung einer Periode in eine Zeichenkette das Präfix einfach abgeschnitten. Zum Beispiel wird PERIOD_H1 in "H1" umgewandelt.

Die Funktion SendToSeq wird verwendet, um eine Nachricht (zur Registrierung eines Ereignisses) an Seq zu senden

// -----------------------------------------------------------------------------
// Send message to Seq via http
// -----------------------------------------------------------------------------
void Logger::SendToSeq() {

    // replace illegal characters
    StringReplace(m_message, "\n", " ");
    StringReplace(m_message, "\t", " ");
    
    // prepare a string in the CLEF (Compact Logging Event Format) format
    string speriod = PeriodToStr(_Period);
    string extended_message = StringFormat("%s, %s / %s / %s / %s",
        _Symbol, speriod, m_module, m_sender, m_message);
    string clef = "{" +
        "\"@t\":" + Quote(TimeToStr(TimeCurrent())) + // event time
        ",\"AppName\":" + Quote(m_appName) +          // application name (Cayman)
        ",\"Symbol\":" + Quote(_Symbol) +             // symbol (EURUSD)
        ",\"Period\":" + Quote(speriod) +             // period (H4)
        ",\"Module\":" + Quote(m_module) +            // module name (__FILE__)
        ",\"Sender\":" + Quote(m_sender) +            // sender name (__FUNCTION__)
        ",\"Level\":" + Quote(m_level) +              // level abbreviation (INF)
        ",\"@l\":" + Quote(Level()) +                 // level details (Information)
        ",\"Message\":" + Quote(m_message) +          // message without additional info
        ",\"@m\":" + Quote(extended_message) +        // message with additional info
    "}";

    // prepare data for POST request
    char data[]; // HTTP message body data array
    char result[]; // Web service response data array
    string answer; // Web service response headers
    string headers = "Content-Type: application/vnd.serilog.clef\r\n";
    ArrayResize(data, StringToCharArray(clef, data, 0, WHOLE_ARRAY, CP_UTF8) - 1);

    // send message to Seq via http
    ResetLastError();
    int rcode = WebRequest("POST", m_urlSeq, headers, 3000, data, result, answer);
    if (rcode > 201) {
        PrintFormat("%s / rcode=%i / url=%s / answer=%s / %s", __FUNCTION__, 
            rcode, m_urlSeq, answer, CharArrayToString(result));
    }
}

Zunächst werden Zeilenumbrüche und Tabulatoren durch Leerzeichen ersetzt. Dann wird ein JSON-Datensatz mit Nachrichtenparametern als "key": "Wert"-Paare gebildet. Parameter mit dem Präfix @ sind obligatorisch (Dienst), der Rest ist nutzerdefiniert. Die Namen und ihre Anzahl werden vom Programmierer festgelegt. Parameter und ihre Werte können in SQL-Abfragen verwendet werden.

Achten Sie auf die Meldung time @t = TimeCurrent(). Sie legt die Serverzeit fest, aber nicht die lokale (TimeLocal()), im Gegensatz zum Terminal. Als Nächstes wird der Request Body gebildet und dann per WebRequest an den Seq-Dienst gesendet.

// -----------------------------------------------------------------------------
// Write a message to log
// -----------------------------------------------------------------------------
void Logger::Log(string level, string message) {
    
    m_level = level;
    m_message = message;
    
    // output a message to the expert log (Toolbox/Experts)
    PrintFormat("%s: %s %s", m_level, m_sender, m_message);
    
    // if a URL is defined, then send a message to Seq via http
    if (m_urlSeq != "") SendToSeq();
}

Die Funktion hat zwei erforderliche Parameter: den Schweregrad der Meldung und die Zeichenfolge der Meldung. Die Meldung wird in das Expertenjournal gedruckt. Auf den Level folgt ein Doppelpunkt. Dies wurde speziell für Notepad++ gemacht, um Zeilen hervorzuheben (WRN: - schwarz auf gelb, ERR: - gelb auf rot).

Testen der Logger-Klasse

Das Skript TestLogger.mq5 wird zum Testen der Klasse verwendet. Die Logger-Makros werden in verschiedenen Funktionen verwendet. 

#include <Cayman/Logger.mqh>

class TestClass {
    int m_id;
public:
    TestClass(int id) { 
        m_id = id;
        LOG_DEBUG(StringFormat("create object with id = %i", id));
    };
};

void TestFunc() {
    LOG_INFO("info message from inner function");
}

void OnStart() {

    string urlSeq = "http://seqlocal.net:5341/api/events/raw?clef";
    gLog = new Logger("TestLogger", urlSeq);
    
    LOG_DEBUG("debug message");
    LOG_INFO("info message");
    LOG_WARNING("warning message");
    LOG_ERROR("error message");
    LOG_FATAL("fatal message");
    
    // call function
    TestFunc();
    
    // create object
    TestClass *testObj = new TestClass(101);

    // free memory
    delete testObj;
    delete gLog;
}

Anzeigen von Nachrichten im Expertenprotokoll. Die Nachrichten zeigen deutlich Levels und Absender (Besitzer) der Nachricht.

2022.02.16 20:17:21.048 TestLogger (USDJPY,H1)  DBG: OnStart debug message
2022.02.16 20:17:21.291 TestLogger (USDJPY,H1)  INF: OnStart info message
2022.02.16 20:17:21.299 TestLogger (USDJPY,H1)  WRN: OnStart warning message
2022.02.16 20:17:21.303 TestLogger (USDJPY,H1)  ERR: OnStart error message
2022.02.16 20:17:21.323 TestLogger (USDJPY,H1)  FTL: OnStart fatal message
2022.02.16 20:17:21.328 TestLogger (USDJPY,H1)  INF: TestFunc info message from inner function
2022.02.16 20:17:21.332 TestLogger (USDJPY,H1)  DBG: TestClass::TestClass create object with id = 101

Anzeigen von Nachrichten im Editor Notepad++

Anzeigen von Nachrichten in Seq

MetaTrader 5-Protokolle in Seq importieren

Um Protokolle in Seq zu importieren, habe ich das Paket seq2log in Python erstellt. Ich werde es in diesem Artikel nicht beschreiben. Das Paket enthält die Datei README.md. Der Code enthält ausführliche Kommentare. Das seq2log-Paket importiert beliebige Protokolle aus dem Expertenjournal MQL5/Logs/yyyymmdd.log. Meldungen ohne Wichtigkeitslevel werden mit dem Level INF versehen:

Wo kann seq2log eingesetzt werden? Wenn Sie zum Beispiel ein freiberuflicher Entwickler sind, können Sie Ihren Kunden bitten, ein Expertenprotokoll zu senden. Es ist möglich, Protokolle in einem Texteditor zu analysieren, aber in Seq ist es bequemer durch die Verwendung von SQL-Abfragen. Die am häufigsten verwendeten oder komplexen Abfragen können in Seq gespeichert und mit einem einzigen Klick auf den Abfragenamen ausgeführt werden.

    Run: py log2seq appName pathLog
    where log2seq - package name
        appName - application name to identify events in Seq
        pathLog - MetaTrader 5 log path
    Example: py log2seq Cayman d:/Project/MQL5/Logs/20211028.log

Schlussfolgerung

Dieser Artikel beschreibt die Klasse Logger und wie man sie verwendet, um

• strukturierte Nachrichten mit Severity Levels zu protokollieren,
• Meldungen (Ereignisse) im Seq-Log-Sammel- und Analysesystem zu registrieren.

Die Quellcodes der Logger-Klasse und ihres Tests sind beigefügt. Zusätzlich enthält der Anhang den Python-Quellcode des log2seq-Pakets, das zum Importieren bestehender MetaTrader 5-Logs in Seq verwendet wird.

Der Seq-Dienst ermöglicht die Analyse von Logs auf einem professionellen Level. Er bietet umfangreiche Möglichkeiten der Datenerfassung und -visualisierung. Darüber hinaus ermöglicht der Quellcode der Logger-Klasse das Hinzufügen von Daten zu den Log-Meldungen, die speziell für die Visualisierung vorgesehen sind - zum Zeichnen von Diagrammen in Seq. Dies kann Sie dazu anregen, die Debug-Informationen in Ihren Anwendungsprotokollen zu überprüfen. Versuchen Sie, es in der Praxis anzuwenden. Viel Glück!