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:

  1. define a new configuration file in your package resources and
  2. 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 from my-first-package.
  • the unique sink will print severity meta information in all generated outputs (standard output and the file my-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 of apps 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 to disable() should so generate no log trace in standard output.
  • enable() is the reverse operation of disable(): 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 to enable() is not required.
  • configure() reset the logger with an entirely new configuration. After call to configure() system is automatically enabled (as if enable() 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.