Consejos de un programador profesional (Parte III): Registro Conexión al sistema de recopilación y análisis de logs Seq

Contenido

• Introducción
• Seq — sistema de recopilación y análisis de logs
• La clase Logger
• Probando la clase Logger
• Importación de logs de MetaTrader 5 a Seq
• Conclusión

Introducción

El registro es la muestra de mensajes para analizar el funcionamiento de las aplicaciones. Las funciones MQL5 Print y PrintFormat guardan la muestra de sus mensajes en el diario de expertos. El diario de expertos es un archivo de texto Unicode. Para no sobrecargar los logs, todos los días se crea un nuevo archivo MQL5/Logs/yyyymmdd.log.

Todos los scripts y asesores expertos en todos los gráficos abiertos "escriben el log" en un archivo. En este caso, parte del log permanece en la memoria caché del disco. En otras palabras, si abrimos el archivo de log desde el explorador, no veremos la información más reciente en él, ya que se encuentra en la caché. Para obligar al terminal a vaciar (guardar) la caché en un archivo, deberemos, o bien apagar y cerrar el terminal, o bien seleccionar el punto "Abrir" a través del menú contextual de la pestaña Experto. Se abrirá un directorio con los archivos de los logs.

Analizar dichos logs, especialmente en el terminal, no resulta fácil, pero es algo necesario. En la primera parte de los consejos, mostramos una forma de facilitar la búsqueda, la selección y la visualización de la información en los logs del terminal. En este artículo, mostraremos cómo:

• unificar la muestra de los logs (clase Logger)
• incluir logs en el sistema de recopilación y análisis de logs Seq
• ver mensajes (eventos) en el modo online (en Seq)
• importar logs normales de MT5 a Seq (paquete de Python)

Seq — sistema de recopilación y análisis de logs

Seq es un servidor para buscar y analizar logs de aplicaciones en tiempo real. Su interfaz de usuario bien diseñada, el almacenamiento de eventos JSON y el lenguaje de consulta SQL lo convierten en una plataforma eficaz para detectar y diagnosticar problemas en aplicaciones y microservicios complejos.

Para enviar mensajes a Seq, deberemos:

1. Instalar Seq en nuestra computadora.
   Una vez instalada, la interfaz de usuario (UI) de Seq estará disponible en
   http://localhost:5341/#/events
2. Añadir al archivo c:/windows/system32/drivers/etc/hosts la línea
   127.0.0.1 seqlocal.net
   para poder añadir una URL a la configuración del Terminal MetaTrader 5
3. Evitar que Seq use timezone para mostrar las horas de los mensajes "tal cual"   
   - ir a UI Seq
   - ir a admin/Preferences/Preferences   
   - activar el punto Show timestamps in Coordinated Universal Time (UTC)
4. Añadir a MT5/Tools/Options/Expert Advisors 
   http://seqlocal.net
   para permitir que la función WebRequest use la URL dada

Para monitorear los mensajes (eventos) en el modo online, deberemos habilitar el modo online a través de UI Seq (clicando en el botón Tail).

La clase Logger

Expresaremos en voz alta un pensamiento banal: para obtener información unificada (estructurada), será necesario formarla y mostrarla de la misma manera. Para ello se ha diseñado la clase Logger, esta es completamente autónoma, es decir, carece de dependencias adicionales en forma de conexiones #include. Como se suele decir, lista para usar.

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

El nivel del mensaje ofrece una idea aproximada de la importancia (seriedad) y la urgencia del mensaje. Para que en el diario del experto se puedan leer bien los niveles (resaltados y alineados), los hemos designado como prefijos de tres letras: DBG, INF, WRN, ERR, FTL. 

• DEBUG ha sido diseñado para el programador y en muchos sistemas de registro no se enviará a la consola, sino que se guardará en un archivo. Los mensajes DEBUG se muestran con más frecuencia que otros y suelen contener nombres de funciones con sus parámetros y/o los resultados de su llamada.
• INFO es un tipo de mensaje para el usuario. Se muestra con menos frecuencia que los mensajes DEBUG y contiene información sobre el funcionamiento de la aplicación. Por ejemplo, puede mostrar acciones del usuario (clic en un elemento del menú), resultados de transacciones, etcétera; es decir, todo lo que un usuario normal puede entender.
• WARNING indica que debemos prestar atención a esta información. Por ejemplo: apertura o cierre de una transacción, activación de una orden pendiente, etc. 
• ERROR indica un error (no uno crítico) después del cual la aplicación continúa funcionando. Por ejemplo, un precio no válido o un nivel stop en una orden, que ha provocado el rechazo de la misma (que esta no se ejecute).
• FATAL indica un error crítico, después del cual no se garantiza el funcionamiento posterior de la aplicación (si continúa) en el modo normal. Necesitaremos detener la aplicación urgentemente y corregir dicho error.

Para mayor legibilidad, y también para reducir el código, la muestra de mensajes se realiza usando las siguientes macrosustituciones (macros)

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

Por consiguiente, cada mensaje muestra el nombre del archivo (módulo), el nombre de la función y el mensaje en sí. Para formar un mensaje, se recomienda usar la función PrintFormat. En este caso, deberemos separar cada valor con la subcadena "/". Esta técnica hace que todos los mensajes sean unificados (estructurados).

Ejemplo de operadores

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

Mostrando los datos de los operadores en el diario del experto

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

Una peculiaridad de la muestra de mensajes en el terminal MT5 es que la columna Time indica la hora local (TimeLocal), mientras que la información se refiere a la hora del servidor (TimeCurrent). Por lo tanto, si queremos destacar la hora, deberemos indicar esta en el propio mensaje. Como se hace en el segundo mensaje: 13:00 - hora local, 12:00 - hora del servidor (hora real de apertura de la barra).

La clase Logger tiene la siguiente estructura

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

Todo es conciso, legible, sin excesos. Tenga en cuenta la declaración de la instancia de registrador gLog. Las variables declaradas como externas con el mismo tipo e identificador pueden existir en diferentes archivos fuente del mismo proyecto. Las variables externas se pueden inicializar, pero solo una vez, es decir, después de crear un registrador en cualquier archivo de proyecto, la variable gLog indicará el mismo objeto.

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

El constructor del registrador toma dos parámetros:

• appName - nombre de la aplicación para Seq. El sistema Seq puede adoptar logs de varias aplicaciones en línea. appName se utiliza para filtrar los mensajes.
• urlSeq - URL del servicio Seq. Puede ser un sitio local con escucha de un puerto específico (http://localhost:5341/#/events).

El parámetro urlSeq es opcional. Si no lo indicamos, los mensajes solo se enviarán al diario del asesor experto. Si definimos urlSeq, los mensajes se enviarán adicionalmente a través de WebRequest al servicio Seq.

// -----------------------------------------------------------------------------
// 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", "");
}

La función SetSender toma dos parámetros obligatorios y establece el remitente del mensaje. La extensión de archivo ".mq5" se elimina del nombre del módulo. Si el operador de registro (LOG_LEVEL) se usa en un método de clase, el nombre de la clase se añadirá al nombre de la función, por ejemplo, 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);
}

El tipo de fecha y hora para Seq debe estar en el formato ISO8601 (YYYY-MM-DDThh:mm:ss[.SSS]). El tipo de fecha y hora en MQL5 se calcula hasta un segundo. La fecha y hora en Seq se representan en milisegundos. Por lo tanto, la cantidad de milisegundos que han transcurrido desde que se inició el sistema (GetTickCount64) se añade artificialmente (intencionalmente) a la fecha y hora indicadas. Esta técnica nos permitirá comparar la hora de los mensajes entre sí.

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

El periodo en Seq se transmite en forma simbólica. La representación simbólica de cualquier periodo tiene el prefijo "PERIOD_". Por lo tanto, al convertir un periodo en una línea, el prefijo simplemente se corta. Por ejemplo, PERIOD_H1 se convierte en "H1".

La función SendToSeq se usa para enviar un mensaje (registro de un evento) al sistema Seq

// -----------------------------------------------------------------------------
// 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);

    // pass messgae 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));
    }
}

Inicialmente, las líneas nuevas y las pestañas se reemplazan con espacios. A continuación, se forma una entrada JSON con los parámetros del mensaje en forma de pares "clave": "valor". Los parámetros con el prefijo @ son obligatorios (de servicio), el resto son definidos por el usuario. Los nombres y su número son determinados por el programador. Los parámetros y sus valores se pueden usar en solicitudes SQL.

Preste atención a la fecha y la hora del mensaje  @t = TimeCurrent(). Se registra la hora del servidor, no la hora local (TimeLocal()), como en el terminal. A continuación, se forma el cuerpo de la solicitud, que luego se transmite al servicio Seq a través de WebRequest.

// -----------------------------------------------------------------------------
// 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();
}

La función toma dos parámetros obligatorios: el nivel (urgencia) del mensaje y la línea del mensaje en sí. El mensaje se muestra en el log (diario del experto). En este caso, después del nivel se coloca un carácter de dos puntos. Esto se ha hecho específicamente para Notepad++, para resaltar líneas (WRN: - negro sobre amarillo, ERR: - amarillo sobre rojo).

Probando la clase Logger

El script TestLogger.mq5 se usa para poner a prueba la clase. Las macros de registro se usan en varias funciones. 

#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 memery
    delete testObj;
    delete gLog;
}

Visualización de mensajes en el diario de expertos.  Los mensajes muestran claramente los niveles y los remitentes (propietarios) de los mensajes.

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

Visualización de mensajes en el editor Notepad++

Visualización de mensajes en Seq

Importación de logs de MetaTrader 5 a Seq

Para importar los logs a Seq, hemos creado el paquete seq2log en Python. No lo vamos a describir en este artículo. El paquete contiene un archivo README.md. En él se comenta el código completo con todo detalle. El paquete seq2log importa logs arbitrarios del diario de expertos MQL5/Logs/yyyymmdd.log. A los mensajes sin nivel de importancia se les asigna el nivel INF:

¿Dónde se puede usar seq2log? Por ejemplo, si usted es un desarrollador (trabajador independiente) y le pide a su cliente que envíe un log del experto. Es posible realizar el análisis en un editor de texto, pero en el servicio Seq le resultará más cómodo hacerlo usando solicitudes SQL. Las consultas que se usan con mayor frecuencia o se elaboran con astucia se pueden almacenar en Seq y ejecutarse en un solo clic en el nombre de la solicitud.

    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

Conclusión

Este artículo describe la clase Logger y cómo usarla para:

• registrar mensajes estructurados con niveles de importancia
• registrar mensajes (eventos) en el sistema de recopilación y análisis de logs Seq

En el artículo se adjuntan los códigos fuente de la clase Logger y su prueba. Asimismo, se adjunta el código fuente del paquete log2seq escrito en Python para importar los logs de MT5 existentes al servicio Seq.

El servicio Seq nos permite analizar los logs a nivel profesional con excelentes capacidades de muestreo y visualización de datos. Además, el código fuente de la clase Logger nos permite añadir datos a los mensajes de los logs, especialmente diseñados para la visualización en forma de gráficos en Seq. Tal vez esto anime al lector a reconsiderar la composición de la información de depuración en los logs de su aplicación. Pruébelo y póngalo en práctica. ¡Buena suerte!