Tutorial - Management of log traces
This tutorial explains how logging process is managed in PID. The logging is the process of generating textual messages from the execution path of a program. It allows to print traces that may be usefull for developers for instance to debug their program or more generally to understand the behavior of an application.
Logs are most of time poorly managed within software. They are most of time just printing traces to file or terminal streams, eventually activated using specific preprocessor directives at compile time. Sometimes they rely on a bit more sophisticated approach, like in ROS, where the messages are labelled and can be filtered according to their severity. All those approaches reaveal to be unsatisfactory for many reasons:
- Most of time, it is not decidable at compile time whether logs needs to be activated or not. For instance if you consider a library that is able to generate logs, it is not decidable whether this logs will be usefull until a program actually use this library. A solution would be to generate both version of each library, one with logs and one without but this solution increases compilation time and furthermore it forbids to dynamically activate or deactivate logs.
- The output generated from log messages must be configurable in such a way that we can get only a subset of generated messages in a selective way (those we consider as relevant for a given run of the program).
- Most of logging systems, when used intensively in projects made of a large amount of components (libraries) tends to generate huge log outputs which finally makes them really difficult to read and manipulate by developpers. Instead we want to be able to target specific components or packages or groups of packages (framework in PID) responsible of the log traces generation.
To overcome these problems, PID is provided with a mechanism to easily manage log traces generation and manipulation. Let’s see how it works with the package my-first-package
defined in previous tutorials ! To get overall explanation about how to use the logging system you can consult pid-log
package documentation.
Step 1: Declare dependency to pid-log
To use logging system you need to use the pid-log
package, so you just need to add pid-log
as a dependency of my-first-package
:
... #same as previously
PID_Dependency(boost)
PID_Dependency(pid-rpath VERSION 2.0)
PID_Dependency(pid-log VERSION 3.0)
build_PID_Package()
1.1 Modify hello-shared
library
Now we want the library hello-shared
to generate log traces. To do this we need to modify a bit its description:
PID_Component(hello-shared SHARED DIRECTORY hello
INTERNAL DEFINITIONS DO_NOT_PRINT_HELLO
LOGGABLE)
The LOGGABLE
argument tells PID that this component must be identifiable during log trace generation: log messages coming from this component can be identified as being part of this component behavior. As a general advice any library using pid-log
API should be LOGGABLE
.
NB: There is no need to specify the dependency between hello-shared
and pid-log
library because hello-shared
is declared as LOGGABLE
.
Now let’s modify the library code to make it generate log traces:
Edit the file named hello.cpp
in the src/hello
folder and paste the following code:
#include <hello.h>
#include <iostream>
#include <pid/log/my-first-package_hello-shared.h> // HERE IMPORTANT LINE
using namespace std;
#ifdef DO_NOT_PRINT_HELLO
void print_Hello(const std::string& user_input){
//use the logger proxy to generate messages
pid_log<<pid::info << "Not Hello : " << user_input<<pid::endl<<pid::flush;
if(user_input == "false"){
pid_log<<pid::error << "PROBLEM with user input" <<pid::flush;
}
}
#else
void print_Hello(const std::string& user_input){
cout<<"Hello: "<<user_input<<endl;
}
#endif
The file pid/log/my-first-package_hello-shared.h
has been automatically generated because hello-shared
as been declared as LOGGABLE
. It must be included (directly or undirectly) into each source or header file using pid-log
API. This file should look like:
#pragma once
#ifdef LOG_my_first_package_hello_shared
#include <pid/log.h>
#undef PID_LOG_FRAMEWORK_NAME
#undef PID_LOG_PACKAGE_NAME
#undef PID_LOG_COMPONENT_NAME
#define PID_LOG_FRAMEWORK_NAME ""
#define PID_LOG_PACKAGE_NAME "my-first-package"
#define PID_LOG_COMPONENT_NAME "hello-shared"
#endif
As you may see it simply includes the pid-log
API and set preprocessor variables used to identify the calling unit (component) that generates log messages.
pid_log
object is what we call a proxy. It is used to generate logs for an identified component (in current example, same proxy is so used anytime hello-shared
generates log messages). pid_log
proxy object can be used as any C++ stream, using stream insertion operator (<<
). Please have a look to pid-log
package documentation to get in depth explanation of proxies API.
1.2 Modify hello-app
application
Now that the library is generating logs we want to manage them in the final application hello-app
. Let’s suppose that we want a specific subset of messages generated by all libraries in use, for instance all error messages: to do so hello-app
needs to use pid-log
API and so must depend on it. Simply change the description of hello-app
with this one:
PID_Component_Dependency(COMPONENT hello-app
DEPEND hello-shared pid-log/pid-log)
As you may have noticed hello-app
is not declared as loggable (but it could have been without consequences). This is simply because hello-app
does not generate traces by itself, only libraries it uses are doing so. Since it does not generate traces it does not need to be identified by the logging system.
Anyway hello-app
is responsible of configuring the logging process. Edit the file hello_main.cpp
in apps/hello
folder and paste the following code:
#include <hello.h>
#include <iostream>
#include <pid/log.h>
using namespace std;
int main(int argc, char* argv[]){
if(argc == 1){
cout<<"Only one argument ... error !! Please input a string as argument of the program"<<endl;
return 1;
}
PID_EXE(argv[0]);//not mandatory
pid::logger().configure("pid_log/only_errors_logs.yaml");//IMPORTANT LINE
print_Hello(argv[1]);
return 0;
}
hello-app
can configure and control the logger using the pid::logger()
function (or equivalent PID_LOGGER
macro). The configure()
function is used to configure the logger from a specific configuration file. Here the configuration file is one provided by default by the pid-log
package. Otherwise you simply have to:
- define a new configuration file in your package resources and
- to reference this configuration file (or one of its containing folder) as a runtime resource of the component (see previous tutorial).
1.3 Build the package
cd <my-first-package>
pid build
1.4 Run the app and see the result
cd <my-first-package>/build
./release/apps/hello-app "not_false"
You should see in standard output only error messages (those with severity error
or critical
). Since the program argument is not the string “false” no error has been generated so nothing has finally been printed. Indeed all messages with severity info
have been rejected by the filter.
Now if you do:
cd <my-first-package>/build
./release/apps/hello-app "false"
An error message should appear in the terminal.
Step 2: Providing a new configuration file
Now let’s suppose you only want to get log message coming from any component in the package my-first-package
. And you want to print these message into a specific file to keep them available after the run. You need to write a specific configuration file for your application to do so.
2.1 Provide a configuration file for the logger
First thing to do is to write the configuration file. Create the folders share/resources/my-first-package_logs
and share/resources/my-first-package_log_configs
. Then create the file share/resources/my-first-package_log_configs/only_my-first-package_messages.yaml
and paste the following code:
activate: true
accept:
packages: my-first-package
sinks:
- outputs:
- STD
- FILE: +my-first-package_logs/my_logs.txt
format: [severity]
activate
specifies that logging is enabled.accept
rule of the global filter only allows for messages coming frommy-first-package
.- the unique
sink
will print severity meta information in all generated outputs (standard output and the filemy-first-package_logs/my_logs.txt
. format
define the format of the header of the logged messages. This format is used for all outputs of the sink. Here header will simply contains the severity level.
The FILE
output defines the path to the generated file containing logs. Its is specified as a PID_PATH
expression. The +
denotes that the file will be created if not existing, instead of generating an exception while not found.
2.1 Modify the app
Now we just have to modify a bit the app to make it work as expected:
- in
hello_main.cpp
:
#include <hello.h>
#include <iostream>
#include <pid/log.h>
using namespace std;
int main(int argc, char* argv[]){
if(argc == 1){
cout<<"Only one argument ... error !! Please input a string as argument of the program"<<endl;
return 1;
}
PID_EXE(argv[0]);//not mandatory
pid::logger().configure("my-first-package_log_configs/only_my-first-package_messages.yaml");//MODIFIED LINE
print_Hello(argv[1]);
return 0;
}
We simply changed the path to the configuration file to use (a maybe better approach would have been to allow to give the path to this configuration file as a program argument, in order to allow configuration of the log trace at program launch time).
- change
CMakeLists.txt
ofapps
this way:
PID_Component_Dependency(COMPONENT hello-app
DEPEND hello-shared pid-log/pid-log
RUNTIME_RESOURCES my-first-package_log_configs my-first-package_logs)
We simply added the folders created in package resource folder as runtime resource of the application, this way the app can find them at runtime.
2.3 Build and run the package
- build:
cd <my-first-package>
pid build
- run:
./build/release/apps/hello-app "not_false"
- Now have a look into file
my-first-package_logs/my_logs.txt
from package resource folder:
You should see all messages generated from libraries previously defined with a mark specifying severity of the message.
Remark
Instead of using configuration files, you can directly configure the looger using pid-log
API. Please refer to pid-log
API documentation to see examples.
Step 3: Fine grain control of logging process
pid-log
provide a complete API to control the overall behavior of the logging system. This control is achieved using pid::logger()
function (or PID_LOGGER
macro).
Let’s modify a bit hello_main.cpp
:
#include <hello.h>
#include <iostream>
#include <pid/log.h>
using namespace std;
int main(int argc, char* argv[]){
PID_EXE(argv[0]);//not mandatory
pid::logger().disable();
print_Hello("that is not false");//should print nothing
print_Hello("false");//should print nothing
pid::logger().configure("my-first-package_log_configs/only_my-first-package_messages.yaml");
print_Hello("that is true");//should print something
print_Hello("false");//should print something
pid::logger().disable();
print_Hello("that is not false");//should print nothing
print_Hello("false");//should print nothing
pid::logger().enable();
print_Hello("that is true");//should print something
print_Hello("false");//should print something
pid::logger().configure("pid_log/only_debug_traces.yaml");
print_Hello("that is not false");//should print nothing
print_Hello("false");//should print nothing
pid::logger().reset();
return 0;
}
Simply rebuild and run the app:
cd <my-first-package>
pid build
./build/release/apps/hello-app
Most useful functions to control the logger are enable()
, disable()
and configure()
.
disable()
simply tells the logger to reject any message. The two lines following the first call todisable()
should so generate no log trace in standard output.enable()
is the reverse operation ofdisable()
: it reactivates log traces generation with the current configuration. Notice that logging system is configured and enabled by default with a specific configuration, that is why call toenable()
is not required.configure()
reset the logger with an entirely new configuration. After call toconfigure()
system is automatically enabled (as ifenable()
was explicilty called just after).reset()
is usefull to clear the current configuration before writting configuration of the logger with the C++ API instead of configuration file. The logging system is automatically disabled if still enabled when call to reset is performed.