Skip to content

05. AREG Logging System

Aregtech edited this page May 29, 2023 · 18 revisions

Table of Contents

  1. General Information
  2. Compile-Time Log Enabling
  3. Log Activation and Deactivation
  4. Scopes and Logs
  5. Logging Configuration
  6. Logging Syntax

General Information

The AREG communication engine (or AREG Framework) comes with an advanced logging module that can be seamlessly integrated into any application. This logging module possesses several notable features, including:

  1. Compile-time log enabling and disabling.
  2. Runtime log enabling and disabling for all or specific log scopes.
  3. Runtime log enabling and disabling by priority for all or specific log scopes.

This document aims to provide a comprehensive, step-by-step guide for compiling and configuring the AREG logging module.


Compile-Time Log Enabling

Applications built using the AREG Framework have the ability to enable or disable logs at compile-time. This feature is particularly useful for developers who want to monitor the application's behavior in Debug mode while minimizing resource usage and achieving ultra-low latency in Release builds. By utilizing compile-time switches, developers can compile the applications with or without logs.

By default, applications are compiled with logs and enabled logging. To enable or disable logging during compilation, follow these steps:

  1. Using the cmake tool: toggle the compile option AREG_LOGS to ON or OFF. The default is ON.
  2. Using the make tool: set the compile option AREG_LOGS to 1 or 0. The default is 1.
  3. Using MSBuild (or MSVC): set the compile option AREG_LOGS to 1 or 0. By default, it is not set, and logging is enabled.

Here are examples of compiling the AREG SDK with different logging configurations:

  • Compiling AREG SDK with cmake and disabled logging:

    cmake -B build -DAREG_LOGS:BOOL=OFF
    cmake --build ./build -j 8
  • Compiling AREG SDK with make and enabled logging:

    make AREG_LOGS=1 -j 8
  • Compiling AREG SDK with MSBuild and disabled logging:

    MSBuild.exe /p:AdditionalDefines="AREG_LOGS=0"

💡 If the sources are compiled without logs, any calls to activate or deactivate the logs will be ignored. It's important to note that even if no messages are logged, all queries to check whether the logs are enabled will return true instead of false.


Log Activation and Deactivation

When an application is compiled with logs enabled (option AREG_LOGS=1), the logging module needs to be set up to initialize and start the logging engine. Once the logging engine is started, the application can begin to log the messages. Otherwise, the system will discard log messages. There are several methods available to configure and start logging.

Activate via Application class

The most common approach to configuring, starting, or stopping the logging module is by calling the static methods of the Application class.

Activating Logging:

To activate the logging module using the Application class, invoke the static method initApplication():

static void initApplication(  bool startTracing             /* starts logging module                                    */
                            , bool startServicing           /* starts service manager                                   */
                            , bool startRouting             /* starts multi-cast router client                          */
                            , bool startTimer               /* starts timer manager                                     */
                            , bool startWatchdog            /* starts watchdog manager                                  */
                            , const char * fileTraceConfig  /* relative or absolute path of logging configuration file  */
                            , const char * fileRouterConfig /* relative or absolute path of multi-cast router file      */ );

Developers can specify whether logging is enabled or disabled, as well as provide the relative or absolute path to the configuration file. By default, applications start with logging enabled (startTracing parameter) and utilize the default configuration path (./config/log.init for fileTraceConfig parameter).

Another method to activate logs using the Application class is by calling the static method startTracer():

static bool startTracer(const char* configFile = nullptr, bool force = false);
  • The configFile parameter indicates the relative or absolute path to the log configuration file. If nullptr is passed, the default path (./config/log.init) is used.
  • The force parameter determines whether logging should be forcibly started if the configuration file is not found or if there is a failure in configuring the logging. When set to true, if logging fails to configure, the application activates the logging module with default settings. By default, logging is not forced to start if there is a failure in configuring the logging.

Developers also have the option to configure logging separately by calling the tracerConfig() static method. They can specify the relative or absolute path to the configuration file or utilize the default path. In this case, to start logging, developers need to invoke startTracer(), where the passed parameters are ignored if logging is already configured.

Deactivate Logging:

To deactivate the logging module using the Application class, invoke the static method stopTracer(). This method stops the logging module, and any log messages generated by the application will be ignored.

Logging can also be stopped by calling Application::releaseApplication() static method . This method stops all services and modules, including logging, and releases associated resources.

Here's an example demonstrating the configuration, starting, and stopping of logging using default parameters:

#include "areg/appbase/Application.hpp"

int main(void)
{
    Application::initApplication();      // Initialize with default parameters
    // Your code is here...
    Application::releaseApplication();   // Stop all services and release resources
    return 0;
}

In the above example, logging is activated during the initialization phase using initApplication(), and later stopped by calling releaseApplication() to ensure proper cleanup and resource deallocation.

Activate via Macros

The file GETrace.h offers a collection of macros that simplify the activation and deactivation of the logging module. It's essential to understand that these macros are designed to handle the activation of the log module only when the sources are compiled with logs enabled (option AREG_LOGS=1). Consequently, developers can utilize these macros within their source code, knowing that the corresponding wrapped methods will be invoked only if the sources are compiled with logs.

This approach provides flexibility, allowing developers to include the macros in their codebase without worrying about potential issues if logs are disabled during compilation.

Activate Logging:

To activate and start logging, developers can utilize either the TRACER_START_LOGGING(configFile) or TRACER_CONFIGURE_AND_START(configFile) macros. The configFile parameter allows for specifying the relative or absolute path to the log configuration file.

Alternatively, if developers wish to force the activation of logging, they can simply call the TRACER_FORCE_LOGGING() macro without any parameters. In this scenario, if logging has not been activated yet, it will start with default parameters, disregarding the configuration file.

Deactivate Logging:

To deactivate logging, developers can use the TRACER_STOP_LOGGING() macro without any parameters. This macro effectively stops the logging module and releases any associated resources.

Here's an example that demonstrates the configuration, starting, and stopping of logging using the provided macros:

#include "areg/trace/GETrace.h"

int main(void)
{
    TRACER_CONFIGURE_AND_START("./config/log.init");    // Initialize logging with default parameters
    // Your code is here...
    TRACER_STOP_LOGGING();                              // Stop logging; no file path is needed.
    return 0;
}

In the above example, logging is configured and started using the TRACER_CONFIGURE_AND_START() macro, specifying the relative path to the configuration file. Subsequently, logging is stopped using the TRACER_STOP_LOGGING() macro to ensure proper cleanup. It's important to note that if the sources are compiled without logs enabled (AREG_LOGS=0), these two calls will not invoke any methods related to logging.

Other Ways to Activate Logging

While there are alternative methods available in TraceManager.hpp to enable logging, it is strongly advised against using this class. The class declaration is located in the private sub-folder, which contains classes intended for internal use. Hence, it is highly recommended not to utilize this class for logging purposes.

For optimal usage and compatibility, it is recommended to use the previously mentioned methods provided by the Application class or the macros available in GETrace.h when configuring and activating logging in your applications. These methods and macros are designed to ensure proper integration and functionality with the AREG Framework logging module.


Scopes and Logs

The AREG Framework offers a robust logging mechanism that allows selective logging based on log names and message priority. This is accomplished through the use of logging scopes (or trace scopes) within the framework's logging module. Logging scopes are objects initialized during application startup, providing the ability to activate or deactivate specific logs and filter them by names and message priority. Each message log belongs to a scope, which should have a unique name. It is recommended to follow a naming convention similar to header file directives commonly used by C/C++ developers.

To demonstrate the declaration and usage of logging scopes and messages, let's consider an example involving a class named MyClass, located in the folder source/my/classes/, which includes two methods: foo() and bar(). In order to log messages within the source code, we need to declare scopes with unique names and utilize them as shown in the following example:

#include "source/my/classes/MyClass.hpp"
#include "areg/trace/GETrace.h"

// Declare scopes for methods foo() and bar()
DEF_TRACE_SCOPE(source_my_classes_MyClass_foo);
DEF_TRACE_SCOPE(source_my_classes_MyClass_bar);

// Use the scope of foo() and start logging messages
void MyClass::foo()
{
    // This trace scope must be declared before logging a message
    TRACE_SCOPE(source_my_classes_MyClass_foo);
    
    // The following are three messages with three different priorities, where DEBUG has the lowest priority
    TRACE_DBG("This message has DEBUG priority and is the lowest priority");
    TRACE_INFO("This message has INFO priority");
    TRACE_WARN("This message has WARNING priority");
}

// Use the scope of bar() and start logging messages
void MyClass::bar()
{
    // This trace scope must be declared before logging a message
    TRACE_SCOPE(source_my_classes_MyClass_bar);
    
    // The following are two messages with two different priorities, where FATAL has the highest priority
    TRACE_ERR("This message has ERROR priority");
    TRACE_FATAL("This message has FATAL priority");
}

💡 The utilization of macros offers a notable advantage in scenarios where developers compile applications without logs. In such cases, the foo() and bar() functions will be effectively empty, and no scope object will be instantiated. This allows for efficient handling of situations where logging is not required, resulting in streamlined and optimized code execution.

Once the scopes are instantiated and activated, the logging module can log all messages, only messages up to a specific priority, or no messages at all. Additionally, scopes can be used to log messages that allow users to track and measure method call times and execution durations. The log messages excerpt from the 04_trace example is provided below:

2023-05-22 13:05:28,080: [ 0x00000000000021EC  04_trace.main_HelloThread_onThreadRuns: Enter --> ]
2023-05-22 13:05:28,607: [ 0x00000000000021EC  WARNING >>> ] The thread [ HelloThread ] runs, going to output messages ...
2023-05-22 13:05:28,607: [ 0x00000000000021EC  INFO >>> ] !!!Hello World!!!
2023-05-22 13:05:28,607: [ 0x00000000000021EC  DEBUG >>> ] !!!Hello Tracing!!!
2023-05-22 13:05:29,134: [ 0x00000000000021EC  04_trace.main_HelloThread_onThreadRuns: Exit <-- ]

In this log, main_HelloThread_onThreadRuns represents the name of the scope, while the logs Enter --> and Exit <-- along with the corresponding timestamps 13:05:28,080 and 13:05:29,134 indicate the method onThreadRuns of the HelloThread class being called and exited. All messages in the log have the ID 0x00000000000021EC, which corresponds to the ID of the scope that logged the messages. This is particularly useful when dealing with multithreading applications, where message logs are mixed in the file. By filtering messages based on their IDs, developers can easily track and analyze the logs.

💡 Currently, the AREG SDK log viewer is still in development. Once completed, it will be included as part of the SDK.
💡 Almost all the examples, starting from 04_trace, utilize logging. For further guidance on using logs, refer to these examples.


Logging Configuration

The AREG Framework provides a feature to configure logging settings using a log configuration file during the initialization of applications. This logging file allows developers to specify the names of log files, the active scopes, and their message priorities. Developers also have the option to customize the logging format within the file.

By default, the AREG Framework utilizes the log.init file, which can be found in the ./config folder after the compilation process. This file serves as the configuration file, containing vital data and offering an explanation of the format used. In this section, we will provide key information regarding the log configuration. The configuration file follows a straightforward syntax, consisting of key and value pairs. The key comprises a mandatory section and property, along with optional module and position elements. The syntax takes the form of section.property[.module][.position] = value.

💡 For a more comprehensive understanding of the configuration syntax, please refer to the Persistence Syntax section in the AREG SDK Wiki. It provides detailed information and further guidance on configuring the initialization file.

The logging configuration consists of several important sections: log, scope, and connection. The connection section is reserved for future use when implementing the logging service to collect logs from multiple processes concurrently. Currently, only the log and scope sections are utilized and play a significant role.

The log sections in the configuration is responsible for setting up the logging module. It contains properties, which are information such as enabling/disabling logging, specifying log file names, message formats, and more. These objects can refer to the global initialization for all processes or specific processes. For instance, setting log.enable.myapp = false disables the logging for the myapp process. If no process name is specified (log.enable = false), this setting will be applied to all processes. The following example demonstrates the setup of the logging module:

log.version = 1.0.0
log.enable  = true
log.file    = ./logs/%appname%_%time%.log

In this example, logging is enabled for all processes, and each process will log messages to a file named ./logs/%appname%_%time%.log, where the %appname% and %time% are placeholders representing the process name and timestamp respectively, normalized and set by the logging module of the AREG Framework. All logs are written to the logs subdirectory relative to the working directory.

Developers also have the ability to activate or deactivate specific scopes or groups of scopes for individual or all processes. They can also choose to log function enter and exit traces with timestamps or filter log priorities. The following example illustrates the configuration of logging scopes and message filtering by priorities:

scope.myapp.sources_my_classes_MyClass_*  = DEBUG | SCOPE ;
scope.myapp.source_other_classes_*        = ERROR ;
scope.source_other_classes_AnObject_foo   = INFO | SCOPE ;
scope.otherproc.*                         = NOTSET ;

In this example:

  • All scopes matching the mask sources_my_classes_MyClass_* will log all messages, including scope traces (enter and exit).
  • Scopes matching the mask source_other_classes_* will log only messages with priority levels ERROR and FATAL, while ignoring all other messages, including scope traces. An exception to this is the scope source_other_classes_AnObject_foo defined in the next line of the configuration.
  • The source_other_classes_AnObject_foo scope logs all messages except those with DEBUG priority. It also logs the scope (enter and exit).
  • All messages should be logged for the otherproc process.

Currently, to apply the configuration changes, developers or testers must restart the application. However, the logging feature of the AREG Framework allows dynamic modification and application of configuration settings without the need for a restart. A configuration tool to modify and apply these settings is planned for release alongside the log viewer tool.

The configuration and log filtering capabilities provided by the AREG Framework assist developers in managing the volume of logs, allowing them to focus on specific scopes. Furthermore, companies can collect and filter critical logs from their software products.


Logging Syntax

The AREG Framework utilizes a logging system that follows the formatting syntax introduced in the C-language printf() function. This choice serves several purposes:

  1. If logging is disabled during compile-time, no operation is executed, resulting in no impact on performance.
  2. The logging message buffer maintains a fixed size of 512 bytes and does not change dynamically.
  3. The formatted message is passed as a single message object, making it simpler and faster to write a single-line message in a multithreading environment without the need for synchronization objects.

Furthermore, this syntax is advantageous when the development of the logging service is complete and messages need to be collected from multiple applications. The consistent formatting syntax ensures that logs from various sources can be seamlessly combined as a single and compact message.

The following example demonstrates the usage of the format specifiers to create a formatted message log:

TRACE_DBG("The operation completed with %s, and the error code is %u", isSuccess ? "success" : "failure", errorCode);

By incorporating placeholders and corresponding arguments, such as %s and %u, the log message can be constructed dynamically, enabling the inclusion of variables, such as isSuccess and errorCode, in the log output.