9. Logging
Document ID: |
|
Revision: |
2.4 |
Last modification: |
January 17, 2025 |
Status: |
Released |
Repository: |
|
File: |
log.rst |
Project: |
ELT CII |
Owner: |
Marcus Schilling |
Revision |
Date |
Changed/ reviewed |
Section(s) |
Modification |
|---|---|---|---|---|
0.1 |
25.02.2020 |
rfernandez |
All |
Document creation. |
1.0 |
06.05.2020 |
rfernandez/ bterpinc |
All |
Updated all sections and added tracing. Final review. |
1.1 |
11.09.2020 |
dkumar |
9.2.3 9.2.2.2 9.2.3 |
Tracing changes. New heading 9.2.3. |
1.2 |
28.09.2020 |
rfernandez |
All |
Updates after LAT topical review |
1.3 |
28.09.2020 |
dkumar |
9.2.4 9.2.3 |
OLDB Context propagation . Mal pub/sub examples. |
1.4 |
29.09.2020 |
rfernandez |
4.8 5 |
Rearranged TOC structure. Moved String formatting and CLI tool sections |
1.5 |
15.10.2020 |
rfernandez |
2, 8.1 6.1.1 8.2.1.1, 8.2.1.2 |
Added “separation ” between logging and tracing. Added description of Filebeat multiline options. New chapters added. |
1.6 |
01.12.2020 |
rfernandez |
4 |
Fixed inconsisten cies in C++ example executables names |
1.7 |
27.01.2021 |
rfernandez |
2, 4, 6 , 7.1 |
Replaced usages of INTROOT with CIISRV_ROOT |
1.8 |
14.03.2022 |
mschilli |
5, 6, 7 |
logSend(5) now part of Tools(now 6) Added ciiLogViewer |
1.9 |
02.02.2023 |
mschilli |
All |
corrected logsink: /var/log/elt and $CII_LOGS |
1.10 |
27.04.2023 |
mschilli |
2 |
new section “Includes and Imports” |
2.0 |
20.06.2023 |
mschilli |
2,3,4,6 |
ELK-stack replaced by rsyslog |
2.1 |
28.02.2024 |
mschilli |
4, 6 |
Configure C++ logging from Python Regex-based view filter |
2.2 |
18.03.2024 |
mschilli |
0 |
Public doc |
2.3 |
12.11.2024 |
mzurowsk |
All |
Changed elt.cii into cii. Removed JAVA |
2.4 |
17.01.2025 |
mschilli |
All |
ciiLogSend, opslogging, gui-queries are AND’ed |
Confidentiality
This document is classified as Public.
Scope
This document is a manual for the Logging system of the ELT Core Integration Infrastructure software.
Audience
This document is aimed at Users and Maintainers of the ELT Core Integration Infrastructure software.
Glossary of Terms
API |
Application Programming Interface |
|---|---|
CII |
Core Integration Infrastructure |
MAL |
Middleware Abstraction Layer |
OLDB |
Online Database |
EA |
Engineering Archive |
CLI |
Command Line Interface |
GUI |
Graphical User Interface |
JSON |
JavaScript object notation |
XML |
Extensible Markup Language |
YAML |
YAML Ain’t Markup Language |
TTL |
Time-To-Live |
References
ESO, Core Integration Infrastructure Requirements Specification, ESO-192922 Version 7
Cosylab, ELT CII Log Transfer Document, CSL-DOC-20-181435, Version X.X
Cosylab, ELT CII Error handling Manual Document, CSL-DOC-20-181435, Version X.X
Python logging, https://docs.python.org/3/library/logging.html
Log4j2 Async Logging, https://logging.apache.org/log4j/2.x/manual/async.html
Checker Framework, https://checkerframework.org/
Log4cplus logging macros, https://log4cplus.sourceforge.io/docs/html/loggingmacros_8h_source.html
OpenTracing API docs, https://opentelemetry.io/docs/
Jaeger Tracing docs, https://www.jaegertracing.io/docs/1.17/
Jaeger Client Libraries, https://www.jaegertracing.io/docs/1.17/client-libraries/
Jaeger Trace Adjusters, https://pkg.go.dev/github.com/jaegertracing/jaeger/model/adjuster
9.1. Overview
This document is a user manual for usage of CII Logging and tracing systems. It explains how to use the Logging Client API through ELT CII common library and GUI Applications to interact with it. It also explains how to use the different services that comprise the distributed logging CII system.
All examples in this manual are also presented in git repository https://gitlab.eso.org/cii/info/cii-demo under logging-examples.
9.2. Introduction
CII Log provides the logging and tracing services of the Control System. Logging pertains to all aspects of CII services. Its purpose is to provide basic and detailed information of the different services and systems in the CII in order to have a better understanding of the behaviour of the distributed system, and in particular to troubleshoot the system in case of problems. Figure 2‑1 shows how the CII Log Service interacts with other elements of the ELT Core Integration Infrastructure. Logging is considered a basic service and doesn’t use any other CII service.
Figure 2‑1 Log interaction
CII Log system components can be divided into four subcomponents according to their responsibilities:
Client API (Log API)
Transmission
Persistence
Visualization
Figure 2‑2 Data flow between log producers (Host n) and central log sink (Collector).
Host 1,2,...
============
[ Log Config: ]
[ handler=syslog ]
[ formatter=cii ]
/
/
/ (Persistence) (Visualization)
/ + => /var/log/elt/elt.log => CII Log Viewer
/ |
App => Log API => rsyslog ==> +
|
| (Transmission)
+ - - - - - - +
|
Collector |
========= | (Persistence) (Visualization)
=> rsyslog -> /var/log/elt/elt.log => CII Log Viewer
Figure 2‑2 Standard workflow of CII Log system
The CII Log Client API enables users to produce log messages from their applications using Logger objects (see 2.2). These messages are produced as strings and follow a predefined format defined in the CII Logging library (see 2.3). The API leverages on existing logging frameworks and extends them in order to provide all CII functionalities. The logging frameworks it leverages on are:
Log4cplus (C++) [5]
Python logging (Python) [6]
As of CII v4, rsyslog is used as transmission and management service. A client-side rsyslog daemon is responsible for pushing CII logs from a single host (see 2.1) to a remote rsyslog daemon on another host ( so-called log collector). This log message is transported using rsyslog’s own format, wrapping the CII-specific fields that carry way more information than a rsyslog log would have by itself.
The serialized message is not parsed by the transporting rsyslog, instead
it is written verbatim to file, both on the sending host and on the
collecting host. On each host, a single file is used to aggreate all
log messages: /var/log/elt/elt.log. The file is automatically rolled
over based on time. See the administration section for details.
In CII v4, there is no log harvester that would read the file and inject its content into a database. This functionality will be re-established once an updated version of the Engineering Archive is available.
A Qt GUI and a Qt widget are available as visualization tools for querying and browsing CII logs.
Tracing is separated from logging, as it serves a different purpose. Tracing is explained in detail in section 8.
9.2.1. Logsink directory
Applications have the freedom to write logs to any place they configure in their log configurations (for examples see below: “Basic usage example with custom configuration”).
To participate in the central log transport, applications need to use rsyslog as a handler/appender in combination with the standard CII log layout format. Note that the CII brief or simple format will not work.
Logs emitted this way will be written to the log sink (/var/log/elt).
The Log Viewer (see below) by defaults operates on /var/log/elt, but can also be instructed to find logs in a different location.
9.2.2. Loggers and Appenders
The architecture of the three used logging frameworks is relatively similar. The main elements of this architecture are the loggers, the appenders, and the layouts.
While the loggers are the elements responsible for exposing
the API to create log events, appenders are responsible for writing
those events to the appropriate outputs, whether it is stdout, a file, a
database, a socket, or any other.
Loggers are organized in a named hierarchical structure in a parent-child relationship fashion. Each logger has a name with dot-separated components, which indicates the position of the logger in the hierarchy. An example hierarchy is shown in Figure 2‑4.
There must always be a root logger with an empty name.
Appenders are attached to loggers. Each logger can have one or more appenders attached, and the same appender can be attached to multiple loggers.
Figure 2‑5 Loggers and Appenders example
Another possible scenario is having multiple child loggers with no appenders attached, having the appenders attached only to the root/parent logger. This can be useful to handle logs from different classes or packages through the child loggers but leveraging the output of those log messages to the parent/root logger and its appenders.
9.2.3. Log Layouts
Log layouts are components of the logging libraries responsible for serializing a log event into the format that will be output by the appenders, usually a string.
CII Logging library provides two different layouts that produce plain strings according to the CII Log format:
CiiLayout
CiiSimpleLayout
The CiiLayout is intended both for human and machine consumption, and it must be used for logs written to the central log transport (see 2.1). It contains the fields described in Appendix B, in the same order as shown there.
The CiiSimpleLayout is a simplified version and is intended for human consumption. It is composed of the date and time of the log event, the log type, a log ID, the message and all the optional fields described in Appendix B.
Additional details and usage instructions can be found in section 4.4.
Example log messages using both the CiiLayout and the CiiSimpleLayout are included in section 4.5 as well as examples how to use it in configurations are included in section 4.3.
Appendix B describes the fields of which a CII log is composed. All optional fields can be added to the log message using the CII Log Client API. See section 4.7 for further details.
TraceID and SpanID are used to log information about the current tracing context (see section 8).
ErrorTypeName, ErrorDateTime, ErrorMessage, and ErrorTrace are used to log a formatted CiiException.
9.2.4. Postmortem buffer
CII Log Client API offers a logs postmortem buffer facility. It enables users to obtain on demand logging information that otherwise would have been lost due to filtering by the active logging configuration.
The postmortem buffers stores produced log events for all logging levels, regardless of the filtering configurations of the loggers and appenders.
This buffer is time-bound. Events are evicted after a defined time is elapsed. The time-to-live (TTL) for the buffered log events can be configured by the user.
The flushing of this buffer is triggered on demand through the CII Log Client API. When this happens, the buffered events are flushed to the appropriate destinations.
By default, this buffer is disabled. Configuration and usage instructions can be found in section 4.8.
9.2.5. Log Levels
Every log mesage can be assigned a certain log level. Since CII v4.3 log levels are unified in both C++ and Python.
TRACE |
C++: logger.log(log4cplus::TRACE_LOG_LEVEL, “message”); |
Python: logger.trace(“message”) |
|
DEBUG |
C++: logger.log(log4cplus::DEBUG_LOG_LEVEL, “message”); |
Python: logger.debug(“message”) |
|
INFO |
C++: logger.log(log4cplus::INFO_LOG_LEVEL, “message”); |
Python: logger.info(“message”) |
|
WARN |
C++: logger.log(log4cplus::WARN_LOG_LEVEL, “message”); |
Python: logger.warning(“message”) |
|
ERROR |
C++: logger.log(log4cplus::ERROR_LOG_LEVEL, “message”); |
Python: logger.error(“message”) |
|
Python: logger.exception(“message”, exception) |
|
FATAL |
C++: logger.log(log4cplus::FATAL_LOG_LEVEL, “message”); |
Python: logger.fatal(“message”) |
|
Python: logger.critical(“message”) |
9.3. Prerequisites
This section describes the prerequisites for using the CII Logging libraries and applications. Note that the preparation of the environment (i.e. installation of required modules, configuration, running of services) is not in the scope of this document. Consult your administrator and the Log TRD document for information on how to establish the environment for usage of CII Logging libraries and applications.
9.3.1. Includes and imports
For basic usage of the Logging library, the user needs the CiiLogManager class. This class contains the API for interacting with the underlying Logging framework using the CII Log extensions, whether it’s Log4cplus (C++), or Python logging.
It provides methods for configuring the logging system, getting a Logger object, or flushing the postmortem buffer. Detailed API per language is provided in Appendix A. Additional details can be found in section 4.1.
In addition, the language-specific Logger and Level classes shall be imported. Level class is not necessary if convenience log methods for the different levels are used, such as debug(“message”) instead of log(Level.DEBUG, “message”).
C++ also needs to include ciiException class, since the ciiLogManager configuration methods can throw an exception in case of an error during configuration initialization.
For more advanced use, it is necessary include the CiiLogMessageBuilder class. The CiiLogAudience enum must be imported as well if Audience field value is provided. Also, the appropriate CiiException class must be imported.
These includes, in addition to linked libraries, are shown in the example code in logging-examples module.
9.3.2. C++
To use the logging API from C++, the following directives are needed:
wscript (project)
cnf.check_wdep(wdep_name='client-api.elt-common.cpp.log', uselib_store='cii-logging')
# Transitive Dependencies:
cnf.check_cfg(package='log4cplus', uselib_store='log4cplus', args='--cflags --libs')
wscript (module)
use=[...,
'cii-logging'
# Transitive Dependencies:
'log4cplus'
source
#include <log4cplus/loggingmacros.h>
#include <ciiLogManager.hpp>
#include <ciiLogMessageBuilder.hpp>
#include <ciiLogConfigurator.hpp>
#include <ciiLogAudience.hpp>
#include <ciiException.hpp>
9.3.3. Python
To use the logging API from Python, the following directives are needed:
wscript (project)
(nothing to be done, just require 'cxx python cii')
wscript (module)
(nothing to be done)
source
import logging
from elt.log import CiiLogManager
from elt.log import CiiLogMessageBuilder
from elt.log import CiiLogAudience
9.4. Logging Library Usage
This section describes the CII Logging Client API, and explains through examples how to configure and use the CII Logging API library in an application.
The CII Log Client API is split between two classes. The CiiLogManager and the CiiLogMessageBuilder.
Because of the fact that Cii Log Client API leverages on different libraries for C++ (Log4cplus) and Python (Python logging), and the constraints this imposes due to the different implementations and APIs, the CII Log client API methods signatures vary across languages and some methods are only available for certain languages.
A complete description of the CII Log Client API for C++ and Python can be found in Appendix A.
9.4.1. CiiLogManager
This is the main class of the CII Log Client API. It provides static methods for configuring and initializing the application’s logging, retrieving, creation of logger objects used to log messages, or flushing of the post-mortem appender.
The loggers retrieved using the CiiLogManager are used according to the APIs of the specific logging frameworks for each language [4][5][6].
9.4.2. CiiLogMessageBuilder
The CiiLogMessageBuilder is aimed at helping users to create correctly formatted log messages with extended information, such as:
Audience
Tracing context
CII Error messages
User-defined log ID
See section 4.7 for usage details and examples.
9.4.3. Logging Configuration
Each of the three logging libraries CII Log Client API provides different ways of configuration. The following sections explain how logging is configured for C++ and Python.
If logging is initialized without providing any custom configuration, a default configuration will be used. This configuration will have:
A root logger configured to an ERROR level with one appender attached.
An stdout appender using a CiiSimpleLayout layout.
Thus, if using default configuration, logs will be output to console only.
The configuration is set through the CII Log Manager. The python version of the Log Manager additionally allows to also configure the C++ logging, to give python applications control over the logging of underlying C++ libraries. To do this, the developers passes both a python Logging configuration as well as C++ logging config to the Python Log Manager.
Examples of default configuration files for Log4cplus, and Python are shown in sections 4.3.1, 4.3.2, and 4.3.2.
It is relevant to notice the default path for any file creation or search is the compilation folder generated when the ‘waf build’ command is called. So any developer string containing a specific path file should be relative to the project build directory.
9.4.3.1. C++
In addition to the default configuration, the CII Log Client API provides support for custom configuration of the Log4cplus logging framework. Two configuration options are available:
Properties object
Properties file
The CiiLogManager class offers methods that can take either an object or a file containing Log4cplus configuration options. It also provides a method without arguments that uses the default CII configuration. Listing 4‑2a shows an example properties configuration equivalent to the default one.
Listing 4‑2a Example C++ default configuration
log4cplus.appender.ConsoleAppender=log4cplus::ConsoleAppender
log4cplus.appender.ConsoleAppender.layout= elt::log::layout::CiiSimpleLayout
log4cplus.rootLogger=ERROR, ConsoleAppender
The next example shows how to enable distributed logging, with log transmission to a central log collector host.
Listing 4‑2b Example C++ configuration with log transmission
log4cplus.appender.ConsoleAppender=log4cplus::ConsoleAppender
log4cplus.appender.ConsoleAppender.layout= elt::log::layout::CiiSimpleLayout
log4cplus.appender.SyslogAppender=log4cplus::SysLogAppender
log4cplus.appender.SyslogAppender.layout=elt::log::layout::CiiLayout
log4cplus.rootLogger=ERROR, ConsoleAppender, SyslogAppender
The next example shows how to log to a local file at a custom path writable by the user.
Listing 4‑2c Example C++ configuration with log file
log4cplus.appender.ConsoleAppender=log4cplus::ConsoleAppender
log4cplus.appender.ConsoleAppender.layout= elt::log::layout::CiiSimpleLayout
log4cplus.appender.LogfileAppender=log4cplus::RollingFileAppender
log4cplus.appender.LogfileAppender.File=/tmp/custom-log-file.log
log4cplus.appender.LogfileAppender.MaxFileSize=16MB
log4cplus.appender.LogfileAppender.MaxBackupIndex=5
log4cplus.appender.LogfileAppender.layout=elt::log::layout::CiiLayout
log4cplus.rootLogger=ERROR, ConsoleAppender, LogfileAppender
Listing 4‑2d Example C++ configuration with properties object
elt::log::CiiLogManager::Configure({
{"log4cplus.appender.ConsoleAppender", "log4cplus::ConsoleAppender"},
{"log4cplus.appender.ConsoleAppender.layout", "elt::log::layout::CiiLayout"},
{"log4cplus.rootLogger", "ERROR, ConsoleAppender"},
{"log4cplus.logger.myapp.mypkg.mylogger", "INFO, ConsoleAppender"}
});
Detailed CiiLogManager API can be found in Appendix A.
9.4.3.2. Python
Four configuration modes are supported:
Default CII Log configuration
Custom dictionary-based configuration
Custom file configuration
Configuration of the LOG4CPLUS logger used by underlying C++ libraries
If a file configuration is used, the file should contain the equivalent to a dictionary based configuration.
In Listing 4‑3a an example of a configuration equivalent to the default configuration can be seen.
Listing 4‑3a Python default configuration
'version': 1,
'cii_log_buffer': {
'enabled': False,
'ttl_ms': 60000
},
'handlers': {
'cii-console': {
'class': 'logging.StreamHandler',
'formatter': 'cii-brief',
'stream': 'ext://sys.stdout'
}
},
'formatters': {
'cii-brief': {
'format': 'CII_SIMPLE_LOG_PATTERN',
'datefmt': 'CII_LOG_PATTERN_DATE'
}
},
'root': {
'level': 'ERROR',
'handlers': ['cii-console']
}
The next example shows how to enable distributed logging, with log transmission to a central log collector host.
Listing 4‑3b Example Python configuration with log transmission
'version': 1,
'handlers': {
'cii-syslog': {
'class': 'logging.handlers.SysLogHandler',
'formatter': 'cii',
'address': '/dev/log'
}
},
'formatters': {
'cii': {
'format': 'CII_LOG_PATTERN',
'datefmt': 'CII_LOG_PATTERN_DATE'
}
},
'root': {
'level': 'INFO',
'handlers': ['cii-syslog']
}
The next example shows how to log to a local file at a custom path writable by the user.
Listing 4‑3c Example Python configuration with log file
'version': 1,
'handlers': {
'logfile': {
'class': 'logging.handlers.RotatingFileHandler',
'backupCount": 5,
'filename': '/tmp/custom-log-file.log',
'formatter': 'cii',
'maxBytes': 10485760
}
},
'formatters': {
'cii': {
'format': 'CII_LOG_PATTERN',
'datefmt': 'CII_LOG_PATTERN_DATE'
}
},
'root': {
'level': 'DEBUG',
'handlers': ['logfile']
}
The next example shows how a python application can forward logs to C++ logging, allowing a joint log of the Python application and its underlying (via Python bindings) C++ libraries.
Listing 4‑3d Example Python configuration with joint C++ logging
'version': 1,
'handlers': {
'forward-handler': {
'class': 'elt.log.CiiLogHandler',
'cii_logger_name': 'name_of_cpp_logger'
}
},
'root': {
'level': 'INFO',
'handlers': ['forward-handler']
}
Detailed API can be found in Appendix A.
9.4.4. Log Layouts
Two CII Log Layouts are provided:
CiiLayout
CiiSimpleLayout
These layouts are described in section 2.3.
Examples on how to use the CII Log Layouts can be found in the configurations shown in section 4.3.
9.4.4.1. C++
The CII Log Layouts are provided as Log4cplus plugins, implemented by the classes CiiLayout and CiiSimpleLayout. Usage example can be found in Listing 4‑2.
9.4.4.2. Python
To use the CII Log Layouts, the cii and cii-brief formatters can be used to enable the CiiLogLayout and the CiiSimpleLayout respectively. The definition of those formatters is injected in the configuration by the CiiLogManager configuration methods. Usage example can be found in Listing 4‑3.
9.4.5. Basic usage example with default configuration
The following examples show a basic usage workflow of the CII Logging API to produce log messages of different levels using a default CII configuration, as described in 4.3.
9.4.5.1. C++
This example can be found in the cii-demo repository: cpp/logging-app
Listing 4‑5 C++ basic example
/**
* @copyright (c) Copyright ESO 2019 All Rights Reserved
* ESO (eso.org) is an Intergovernmental Organisation, and therefore special legal conditions apply.
* @ingroup logging-examples-cpp
*/
#include <iostream>
#include <ciiException.hpp>
#include <ciiLogManager.hpp>
int main(int ac, char *av[]) {
try {
/* Automatically initialize the logging framework and get the root logger.
* No configuration is provided so a default configuration is used. The default
* configuration has one appender that outputs to stdout using CiiSimpleLogLayout.
* Only log events of levels ERROR and FATAL will be output to the appender.
*/
log4cplus::Logger root_logger = ::elt::log::CiiLogManager::GetLogger();
std::vector<log4cplus::SharedAppenderPtr> appenders = root_logger.getAllAppenders();
for (const auto& appender : appenders) {
std::cout << "Appender:" << appender->getName() << '\n';
}
/* Send INFO level message to root logger
* This log will be discarded since the minimum log level for the root logger is ERROR
*/
root_logger.log(log4cplus::INFO_LOG_LEVEL, "First root logger message");
/* Send ERROR level message to root logger
* This log will be passed to the appender for processing, since the minimum
* log level for the root logger is ERROR
*/
root_logger.log(log4cplus::ERROR_LOG_LEVEL, "Second root logger message");
/* Get a logger with name 'elt.log.test'. There's no logger configured with that name,
* therefore it will be created inheriting the configuration of its nearest ancestor
* in the loggers named hierarchy. In this case, since there is only root logger
* configured, the configuration of the root logger will be used.
*/
log4cplus::Logger logger = ::elt::log::CiiLogManager::GetLogger("elt.log.test");
/* Send INFO level message to elt.log.test logger
* This log will be discarded since the minimum log level is ERROR
*/
root_logger.log(log4cplus::INFO_LOG_LEVEL, "First elt.log.test logger message");
/* Send ERROR level message to elt.log.test logger
* This log will be passed to the appender for processing, since the minimum
* log level is ERROR
*/
root_logger.log(log4cplus::ERROR_LOG_LEVEL, "Second elt.log.test logger message");
return 0;
} catch (const ::elt::error::CiiException& ex) {
std::cerr << "CiiException occured while executing sample code. What: "
<< ex.what() << '\n';
}
return -1;
}
This would produce the following output on stdout:
Appender:ConsoleAppender
2024-06-27T12:59:57.361+0000, ERROR, root/140680786894720, Second root logger message
2024-06-27T12:59:57.361+0000, ERROR, root/140680786894720, Second elt.log.test logger message
9.4.5.2. Python
This example can be found in the cii-demo repository: python/logging-app
Listing 4‑6 Python basic example
#!/usr/bin/env python3
# coding=utf-8
"""
@copyright (c) Copyright ESO 2019 All Rights Reserved
ESO (eso.org) is an Intergovernmental Organisation, and therefore special legal conditions apply.
@ingroup logging-examples-python
Python logging example app
"""
# pylint: disable=C0103
import sys
from elt.log import CiiLogManager
def main():
"""
Main application code
@return status code, int
"""
result = 0
try:
# Automatically initialize the logging framework and get the root logger.
# No configuration is provided so a default configuration is used.
# This default configuration has one handler that outputs to stdout
# using elt.log.CiiLogConfigurator.CII_SIMPLE_LOG_PATTERN.
# Only log events of levels ERROR and FATAL will be output to the handler.
root_logger = CiiLogManager.get_logger()
# Send INFO level message to root logger
# This log will be discarded since the minimum log level for the root logger is ERROR
root_logger.info("First root logger message")
# Send ERROR level message to root logger
# This log will be passed to the handler for processing, since the minimum
# log level for the root logger is ERROR
root_logger.error("Second root logger message")
# Get a logger with name 'elt.log.test'. There's no logger configured with that name,
# therefore it will be created inheriting the configuration of its nearest ancestor
# in the loggers hirearchy. In this case, since there is only root logger configured,
# the configuration of the root logger will be used
logger = CiiLogManager.get_logger("elt.log.test")
# Send INFO level message to elt.log.test logger.
# This log will be discarded since the minimum log level is ERROR
logger.info("First elt.log.test logger message")
# Send ERROR level message to elt.log.test logger
# This log will be passed to the handler for processings, since the
# minimum log level is ERROR
logger.error("Second elt.log.test logger message")
# pylint: disable=W0703
except Exception as e:
print('Exception occured while executing sample code: %s', e)
result = 5
return result
if __name__ == '__main__':
sys.exit(main())
This would produce the following output on stdout:
2024-06-27T13:06:24.989+0000, ERROR, cii-logging-example-app-py/MainThread, Second root logger message
2024-06-27T13:06:24.989+0000, ERROR, cii-logging-example-app-py/MainThread, Second elt.log.test logger message
9.4.6. Basic usage example with custom configuration
This section shows how the use a custom configuration. In this case, we have a configuration with two different loggers, and each logger has a different appender, as described in Table 4‑1.
Table 4‑1 Example loggers and appenders
Logger name |
Logger level |
Appender type |
|---|---|---|
“” (root) |
WARN |
File |
“cii.log.test” |
TRACE |
Console |
This configuration can be useful if, for example, we want to send all logs of severity WARN or higher to the logsink directory, but we are trying to troubleshot a bug in package cii.log.test, therefore we want logs of severity as low as TRACE to be output as well for that specific package.
In certain cases, it is necessary or useful for a developer to be able to change the existing logging configuration at runtime. In the C++ and Python cases, the respective log4cplus and Python logging APIs are unaffected by the CII Log extensions of those frameworks, and appropriate documentation on runtime configuration of the frameworks is available in their respective APIs documentation [4][5][6]. More details on the limitations on the usage of the Log4 API are described in section 4.9.1.
The example code and configurations for each language and outputs produced by the examples from section 4.4 with these configurations are shown below. These examples can be also found in logging-examples module.
9.4.6.1. C++
This example can be found in the cii-demo repository: cpp/logging-customconfig-app
Listing 4‑9 C++ example app with custom configuration
int main(int ac, char *av[]) {
try {
/*
* Logging is initialized with custom configuration.
*
* This custom configuration has two loggers:
* - root: With a INFO level and a rolling file appender to /var/tmp directory
* - "elt.log.test": With a TRACE level, a console appender, and additivity enabled
*/
::elt::log::CiiLogManager::Configure("log4cplus-test.prop");
/* Get the root logger.*/
log4cplus::Logger root_logger = ::elt::log::CiiLogManager::GetLogger();
/* Send INFO level message to root logger
* This log will be output to the log file in logsink directory
*/
root_logger.log(log4cplus::INFO_LOG_LEVEL, "First root logger message");
/* Send TRACE level message to root logger. This log message will be discarded
* due to the root logger having a threshold level of INFO
*/
root_logger.log(log4cplus::TRACE_LOG_LEVEL, "Second root logger message");
/* Get a logger with name 'elt.log.test' */
log4cplus::Logger logger = ::elt::log::CiiLogManager::GetLogger("elt.log.test");
/*
* Send TRACE level message to elt.log.test logger
* This log will be outputed to console since the minimum log level is TRACE.
* It will be also passed to its parent logger (root) since additivity property of
* this logger is set to true. The root logger will accept it also, despite of
* its level being set to INFO. This is due to the fact that the logger level
* threshold is only checked at the logger where the message is created.
* If a threshold level would be set to on the appender attached to the root logger,
* that one would be applied.
*/
logger.log(log4cplus::TRACE_LOG_LEVEL, "First elt.log.test logger message");
/*
* Send ERROR level message to elt.log.test logger
* This log will be output to console since the minimum log level is TRACE.
* It will be also passed to its parent logger (root) since additivity property of
* this logger is set to true. The root logger will also pass it to the logsink
* file appender.
*/
logger.log(log4cplus::ERROR_LOG_LEVEL, "Second elt.log.test logger message");
return 0;
} catch (const ::elt::error::CiiException& ex) {
std::cerr << "CiiException occured while executing sample code. What: "
<< ex.what() << '\n';
}
return -1;
}
Listing 4‑10 Log4cplus custom configuration
log4cplus.rootLogger=INFO, ROLLINGFILE
log4cplus.logger.elt.log.test=TRACE, STDOUT
log4cplus.additivity.elt.log.test=TRUE
log4cplus.appender.STDOUT=log4cplus::ConsoleAppender
log4cplus.appender.STDOUT.layout=elt::log::layout::CiiSimpleLayout
log4cplus.appender.ROLLINGFILE=log4cplus::RollingFileAppender
log4cplus.appender.ROLLINGFILE.File=/var/tmp/custom-example.log
log4cplus.appender.ROLLINGFILE.MaxFileSize=16MB
log4cplus.appender.ROLLINGFILE.MaxBackupIndex=1
log4cplus.appender.ROLLINGFILE.layout=elt::log::layout::CiiLayout
This configuration would produce the following output on console:
2024-06-27T13:32:05.153+0000, TRACE, elt.log.test/140541073407872, First elt.log.test logger message
2024-06-27T13:32:05.153+0000, ERROR, elt.log.test/140541073407872, Second elt.log.test logger message
And the following output on the the custom-example.log file in the logsink directory:
Cref=../cpp/logging-customconfig-app/src/cii-logging-example-customconfig-app.cpp:87, Date=2024-06-27T13:32:05.153+0000, HostName=eltmal28.hq.eso.org, LogType=INFO, SourceID=140541073407872, LogID=root.main-87, Message=First root logger message
Cref=../cpp/logging-customconfig-app/src/cii-logging-example-customconfig-app.cpp:107, Date=2024-06-27T13:32:05.153+0000, HostName=eltmal28.hq.eso.org, LogType=TRACE, SourceID=140541073407872, LogID=elt.log.test.main-107, Message=First elt.log.test logger message
Cref=../cpp/logging-customconfig-app/src/cii-logging-example-customconfig-app.cpp:116, Date=2024-06-27T13:32:05.153+0000, HostName=eltmal28.hq.eso.org, LogType=ERROR, SourceID=140541073407872, LogID=elt.log.test.main-116, Message=Second elt.log.test logger message
9.4.6.2. Python
This example can be found in the cii-demo repository: python/logging-customconfig-app
Listing 4‑11 Python example app with custom configuration
def main():
"""
Main application code
@return status code, int
"""
result = 0
try:
# Logging is initialize with custom configuration
#
# This custom configuration has two loggers:
# - root: With a INFO level and rolling file handler to /var/tmp directory
# - "elt.log.test": With a TRACE level, a console appender and propagation enabled
CiiLogManager.configure(CONFIG_FILE_NAME)
# Get the root logger
root_logger = CiiLogManager.get_logger()
# Send INFO level message to root logger
# This log will be forwarded to the lof file in logsink directory
root_logger.info("First root logger message")
# Send TRACE level message to root logger.
# This log message will be discarded due to the
# root logger having ad threshold level of INFO
root_logger.trace("Second root logger message")
# Get a logger with name 'elt.log.test'
logger = CiiLogManager.get_logger("elt.log.test")
# Send a TRACE level message to elt.log.test logger
# This log will be forwarded to console since the minimum log level is TRACE.
# It will be also passed to its parent logger (root) since propagate property
# of this logger is set to True (by default). The root logger will also pass it
# to the logsing file handler. This is due ot a fact that the logger level
# threshold is only checked at the logger where the message is created.
logger.trace("First elt.log.test logger message")
# Send ERROR level message to elt.log.test logger
# This log will be displayed on console since the minimum log level is TRACE.
# It will be also passed to its parent logger (root) since propagate
# property of this logger is set to True (by default). The root logger
# will also pass it to the logsing file handler.
logger.error("Second elt.log.test logger message")
# pylint: disable=W0703
except Exception as e:
print('Exception occured while executing sample code: %s', e)
result = 5
return result
Listing 4‑12 Python logging custom configuration
{
"version": 1,
"handlers": {
"logsink": {
"class": "logging.handlers.RotatingFileHandler",
"backupCount": 5,
"filename": "/var/tmp/custom-example-py.log",
"formatter": "cii",
"maxBytes": 10485760
},
"console": {
"class": "logging.StreamHandler",
"formatter": "cii-brief",
"stream": "ext://sys.stdout"
}
},
"root": {
"handlers": [
"logsink"
],
"level": "INFO"
},
"formatters": {
"cii": {
"format": "CII_LOG_PATTERN",
"datefmt": "CII_LOG_PATTERN_DATE"
},
"cii-brief": {
"format": "CII_SIMPLE_LOG_PATTERN",
"datefmt": "CII_LOG_PATTERN_DATE"
}
},
"loggers": {
"elt.log.test": {
"handlers": [
"console"
],
"level": "TRACE"
}
}
}
This configuration would produce the following output on console:
2024-06-27T13:41:55.717+0000, TRACE, cii-logging-example-customconfig-app-py/MainThread, First elt.log.test logger message
2024-06-27T13:41:55.717+0000, ERROR, cii-logging-example-customconfig-app-py/MainThread, Second elt.log.test logger message
And the following output on the eelt-dev-output.log file in the logsink directory:
Cref=cii-logging-example-customconfig-app-py.main-92, Date=2024-06-27T13:41:55.717+0000, HostName=eltmal28, LogType=INFO, SourceID=cii-logging-example-customconfig-app-py/MainThread, LogID=root-92, Message=First root logger message
Cref=cii-logging-example-customconfig-app-py.main-108, Date=2024-06-27T13:41:55.717+0000, HostName=eltmal28, LogType=TRACE, SourceID=cii-logging-example-customconfig-app-py/MainThread, LogID=elt.log.test-108, Message=First elt.log.test logger message
Cref=cii-logging-example-customconfig-app-py.main-115, Date=2024-06-27T13:41:55.717+0000, HostName=eltmal28, LogType=ERROR, SourceID=cii-logging-example-customconfig-app-py/MainThread, LogID=elt.log.test-115, Message=Second elt.log.test logger message
Instead of saving the configuration to a file, and passing the filename like in the previous example,
it can also be passed as a string to CiiLogManager.configure (<file_content>) directly.
Here is an example that does this, after constructing the log configuration dynamically.
loglevel='INFO'
logfile='mylog'
log_config = {
'handlers': {
'cii-console': {
'class': 'logging.StreamHandler',
'formatter': 'cii-brief',
'stream': 'ext://sys.stdout',
'level': ''
}
},
'root': {
'level': '',
'handlers': ['cii-console']
}
}
log_config['handlers']['cii-console']['level'] = loglevel
log_config['root']['level'] = loglevel
if logfile:
log_config['handlers']['file-handler'] = {
'class': 'logging.handlers.RotatingFileHandler',
'backupCount': 10,
'filename': logfile,
'formatter': 'cii',
'maxBytes': 10*1024*1024,
'level': loglevel
}
log_config['root']['handlers'] = ['cii-console', 'file-handler']
CiiLogManager.configure(log_config)
9.4.7. Adding optional information to log messages
Some of the fields in a CII log message are optional and have to be explicitly added to a log event by the user.
9.4.7.1. Via LogManager
The following optional fields can be set directly through the CiiLogManager.
AppName: The name of the application (or one particular instance of it)
elt::log::CiiLogManager::SetApplicationName("MyApplication");
log4cplus::Logger logger = elt::log::CiiLogManager::GetLogger("MyAppLogger");
9.4.7.2. Via MessageBuilder
The following optional fields can be set through the CiiLogMessageBuilder, letting deveopers create a log message with additional information. Also see CII Log Client API (section X.4.2 of this document).
This optional information can be added to a log message:
Audience: The intended audience of the log message
UserLogID: A log ID provided by the user.
Formatted CiiException: A CII Exception [3] provided by the user that will be formatted into the fields:
ErrorMessage
ErrorTypeName
ErrorDateTime
ErrorTrace
Tracing info: The builder is responsible for extracting the following data from an existing active Tracing context:
TraceID
SpanID
Once the optional parameters are defined, the user can call the build() method on the builder to produce the formatted string with the selected optional fields.
The builder also provides convenience factory methods for the most common logging use cases: setting a log’s audience and logging a formatted CII Error.
Support for tracing information is currently not available for C++ and Python. It will be added in following releases.
Complete API can be found in Appendix A.
Sections 4.7.1, 4.7.2, 4.7.3 show usage examples for the CiiLogMessageBuilder on C++ and Python. All examples follow the same workflow.
First, the language-specific logging frameworks are initialized with the default CII configuration and a logger named myLogger is retrieved.
(How to enable tracing to be added in following versions)
Then, the following logs with optional information are produced:
A log with a message, a custom user ID, and an audience value.
A log with a message and a formatted CII exception using the builder pattern.
A log with a message and a formatted CII exception using the builder’s convenience method.
A log with a message and an audience value using the builder’s convenience method.
A log without message and a formatted CiiException. Since no message is passed, the CiiException error message will be used as log message field.
A log with current tracing context information. Note that these examples will not output any tracing information, since tracing is not enabled. These examples are meant to illustrate the usage of the CiiLogMessageBuilder.
9.4.7.3. C++
This example can be found in the cii-demo repository: logging-example-messagebuilder
Listing 4‑15 Adding optional info to logs (C++)
int main(int ac, char *av[]) {
try {
log4cplus::Logger logger = ::elt::log::CiiLogManager::GetLogger("myLogger");
//Build and log message with message value, user ID and DEVELOPER audience
logger.log(log4cplus::ERROR_LOG_LEVEL,
::elt::log::CiiLogMessageBuilder::Create().WithMessage("Message value")
.WithUserLogId("user_log_id")
.WithAudience(::elt::log::CiiLogAudience::DEVELOPER)
.Build());
try {
CII_THROW(::elt::error::CiiException, "TEST EXCEPTION");
} catch (const elt::error::CiiException& e) {
//Build and log message with formatted CiiException using builder
//pattern
logger.log(log4cplus::ERROR_LOG_LEVEL,
::elt::log::CiiLogMessageBuilder::Create()
.WithMessage("This is and exception")
.WithException(e)
.Build());
//Build and log message with formatted CiiException using the
//convenience method
logger.log(log4cplus::ERROR_LOG_LEVEL,
::elt::log::CiiLogMessageBuilder::CreateAndBuildWithException(
"This is an exception", e));
}
//Build and log message with DEVELOPER audience
logger.log(log4cplus::ERROR_LOG_LEVEL,
::elt::log::CiiLogMessageBuilder::CreateAndBuildWithAudience(
"Message for DEVELOPER audience",
::elt::log::CiiLogAudience::DEVELOPER));
//Build and log a message with tracing context information
logger.log(log4cplus::ERROR_LOG_LEVEL,
::elt::log::CiiLogMessageBuilder::Create(
"This is a log message with tracing info")
.WithTracingInfo(true).Build());
return 0;
} catch (const ::elt::error::CiiException& ex) {
std::cerr << "CiiException occured while executing sample code. What: "
<< ex.what() << '\n';
}
return -1;
}
The output of the code in Listing 4‑15 using the CiiSimpleLayout would be the following:
Listing 4‑16 Output CiiLogMessageBuilder usage example C++
2020-04-19T21:56:56.130+0200, ERROR, myLogger/140218499314368, Message value, Audience=DEVELOPER, UserLogID=user_log_id
2020-04-19T21:56:56.303, ERROR, myLogger/140218499314368, This is and exception, ErrorTypeName=elt::error::CiiException, ErrorDateTime=1587333416, ErrorMessage=TEST EXCEPTION, ErrorTrace= 0# elt::error::CiiException::CiiException(std::string const&) at ../elt-common/cpp/error/client/src/ciiException.cpp:29
1# main at ../cpp/logging-messagebuilder-app/src/logging-messagebuilder-app.cpp:25
2# __libc_start_main in /lib64/libc.so.6
3# 0x0000000000414039 in cii-logging-example-messagebuilder-app
2020-04-19T21:56:56.303+0200, ERROR, myLogger/140218499314368, This is an exception, ErrorTypeName=elt::error::CiiException, ErrorDateTime=1587333416, ErrorMessage=TEST EXCEPTION, ErrorTrace= 0# elt::error::CiiException::CiiException(std::string const&) at ../elt-common/cpp/error/client/src/ciiException.cpp:29
1# main at ../cpp/logging-messagebuilder-app/src/logging-messagebuilder-app.cpp:25
2# __libc_start_main in /lib64/libc.so.6
3# 0x0000000000414039 in cii-logging-example-messagebuilder-app
2020-04-19T21:56:56.303+0200, ERROR, myLogger/140218499314368, Message for DEVELOPER audience, Audience=DEVELOPER
2020-04-19 21:56:56.303, ERROR, myLogger/140218499314368, This is a log message with tracing info
9.4.7.4. Python
This example can be found in the cii-demo repository: cii-logging-example-messagebuilder-py
Listing 4‑17 Adding optional info to logs (Python)
def main():
"""
Main application code
@return status code, int
"""
result = 0
try:
logger = CiiLogManager.get_logger("myLogger")
# Build and log message with message value, user ID and DEVELOPER
# audience
logger.error(CiiLogMessageBuilder()
.with_message("Message value")
.with_user_log_id("user_log_id")
.with_audience(CiiLogAudience.DEVELOPER)
.build())
try:
raise CiiException("TEST EXCEPTION")
except CiiException as e:
# Build and log message with formatted exception using builder
# pattern
logger.error(CiiLogMessageBuilder.create()
.with_message("This is an exception")
.with_exception(e)
.build())
# Build and log message with formatted exception using convenience
# method
logger.error(CiiLogMessageBuilder
.create_and_build_with_exception("This is an excaption", e))
# Build and log message with DEVELOPER audience
logger.error(CiiLogMessageBuilder
.create_and_build_with_audience("Message for DEVELOPER audience", CiiLogAudience.DEVELOPER))
# Build and log a message with tracing context information
logger.error(CiiLogMessageBuilder
.create("This is a log message with tracing info")
.with_tracing_info(True)
.build())
# Build and log a message with keyword args
logger.error(CiiLogMessageBuilder
.create_and_build_with_args(message='This is a message',
user_log_id='USER_LOG_ID',
audience=CiiLogAudience.DEVELOPER))
except Exception as e:
print('Exception occured while executing sample code: %s', e)
result = 5
return result
if __name__ == '__main__':
sys.exit(main())
The output of the code in Listing 4‑17 using the CiiSimpleLayout would be the following:
Listing 4‑18 Output CiiLogMessageBuilder usage example Python
2020-04-19T21:56:56.130+0200, ERROR, cii-logging-example-messagebuilder-app-py/MainThread, Message value, Audience=DEVELOPER, UserLogID=user_log_id
2020-04-19T21:56:56.303+0200, ERROR, cii-logging-example-messagebuilder-app-py/MainThread, This is an exception, ErrorTypeName=cii.error.Exceptions.CiiException, ErrorDateTime=1588727172250, ErrorMessage=TEST EXCEPTION, ErrorTrace=Traceback (most recent call last):
File "/home/rfernandez/INTROOT/bin/cii-logging-example-messagebuilder-app-py", line 30, in main
raise CiiException("TEST EXCEPTION")
cii.error.Exceptions.CiiException: TEST EXCEPTION
2020-04-19T21:56:56.303+0200, cii-logging-example-messagebuilder-app-py/MainThread, This is an exception, ErrorTypeName=cii.error.Exceptions.CiiException, ErrorDateTime=1588727172250, ErrorMessage=TEST EXCEPTION, ErrorTrace=Traceback (most recent call last):
File "/home/rfernandez/INTROOT/bin/cii-logging-example-messagebuilder-app-py", line 30, in main
raise CiiException("TEST EXCEPTION")
cii.error.Exceptions.CiiException: TEST EXCEPTION
2020-04-19T21:56:56.303+0200, ERROR, cii-logging-example-messagebuilder-app-py/MainThread, Message for DEVELOPER audience, Audience=DEVELOPER
2020-04-19T21:56:56.303+0200, ERROR, cii-logging-example-messagebuilder-app-py/MainThread, This is a log message with tracing info
2020-04-19T21:56:56.303+0200, ERROR, cii-logging-example-messagebuilder-app-py/MainThread, This is a message, Audience=DEVELOPER, UserLogID=USER_LOG_ID
9.4.8. String formatting
Usage of formatted strings in the printf style is supported in both C++ and Python.
In C++ it is supported through the LOG4CPLUS_<LEVEL>_FMT macros [20], as shown in the following example:
LOG4CPLUS_WARN_FMT(root, "Number: %d", 100);
In Python it is also supported using the language’s regular string formatting constructs.
logger.error("Number: %d", 100)
logger.error("Number: %d" % 100)
9.4.8.1. Compile-time validation
Compile-time validation of the formatted strings is supported for C++.
In the C++ case, compile time validation is automatically done if the LOG4CPLUS_<LEVEL>_FMT macros [20] are used.
In Python this is not supported, since it is not compiled.
9.4.9. Using the Postmortem Buffer
This section describes the usage of the postmortem buffer. By default, this buffer is disabled and it is the responsibility of the user to enable it.
The postmortem buffer is configured through two environment variables:
CII_LOG_BUFFER_ON: If set to true, the postmortem buffer will enabled. If not set, or set to any other value, the postmortem buffer will be disabled.
CII_LOG_BUFFER_TTL_MS: Time-To-Live in milliseconds of the buffered log events.
Changes to these environment variables, once the logging has been initialized, will not have any effect on the current configuration. In order for it to be applied, logging must be shut down and initialized again.
Programatic and file-based configurations of the postmortem buffer will take precedence over these environment variables.
Due to the differences in implementations and APIs of the logging frameworks CII Log Client API leverages on, the implementation and usage of the postmortem buffer vary from language to language. Configuration and usage instructions are described for each of the three languages in the following subsections.
Note: Enabling the postmortem buffer can make significant performance impact. The impact depends on the number of produced logs. When it is, enabled, all the logging events (regardless of its level) will gather all the log context information (hostname, line number, file name, etc…). Gathering this information will take significant time, when a lot of logs are produced.
9.4.9.1. C++
In C++, the postmortem buffer can be configured using the environment variables mentioned earlier, as well as programmatically. The CiiLogConfigurator class provides methods to initialize a configuration with the postmortem buffer enabled, as well as a method to enable the postmortem buffer once the configuration has been already initialized.
When the postmortem buffered is flushed, log messages indicating the START and END of the flushed logs will be injected, as can be seen in Listing 4‑22, helping the user identify the logs that were buffered by the postmortem facility.
More details on how to configure the postmortem buffer can be found in Appendix A.2.
A usage example of the postmortem buffer in C++ is shown in Listing 4‑21. In this example, the postmortem buffer is enabled and a log TTL of 30 seconds is set. Then, logging is initialized with the default configuration. A series of log messages of different levels are produced, and finally, the postmortem buffer is flushed to all the configured appenders.
This example can be found in the cii-demo repository: logging-example-postmortem-buffer-app
Listing 4‑21 Example postmortem appender (C++)
int main(int ac, char *av[]) {
try {
//Enable postmortem appender and set the time-to-live of the log events in
//the buffer to 30s
std::string postmortem_enable_env = std::string(
::elt::log::CiiLogManager::POSTMORTEM_APPENDER_ENABLED_ENV_VAR) +
"=true";
putenv(const_cast<char*>(postmortem_enable_env.c_str()));
std::string postmortem_ttl_env = std::string(
::elt::log::CiiLogManager::POSTMORTEM_APPENDER_ENTRYTTL_MS_ENV_VAR) +
"=30000";
putenv(const_cast<char*>(postmortem_ttl_env.c_str()));
// Automatically initialize the logging framework with console and file
// appender and get the logger with the name
// elt.log.examples.PostmortemAppenderExample
log4cplus::Logger logger = ::elt::log::CiiLogManager::GetLogger(
"PostmortemAppenderExample");
// Create a log message of each level
// Only messages of levels ERROR and FATAL will be output to the console
// and file
logger.log(log4cplus::TRACE_LOG_LEVEL, "Trace message");
logger.log(log4cplus::DEBUG_LOG_LEVEL, "Debug message");
logger.log(log4cplus::INFO_LOG_LEVEL, "Info message");
logger.log(log4cplus::WARN_LOG_LEVEL, "Warn message");
logger.log(log4cplus::ERROR_LOG_LEVEL, "Error message");
logger.log(log4cplus::FATAL_LOG_LEVEL, "Fatal message");
std::this_thread::sleep_for(std::chrono::seconds(1));
// Flush the postmortem appender.
// Logs of levels TRACE, DEBUG, INFO, and WARN will be now output to the
// console and file
::elt::log::CiiLogManager::FlushPostmortemBuffer();
return 0;
} catch (const ::elt::error::CiiException& ex) {
std::cerr << "CiiException occured while executing sample code. What: "
<< ex.what() << '\n';
}
return -1;
}
This example produces the following output:
Listing 4‑22 Console output from postmortem example (C++)
2020-04-19T22:27:50.415+0100, ERROR, PostmortemAppenderExample/140577659003584, Error message
2020-04-19T22:27:50.415+0100, FATAL, PostmortemAppenderExample/140577659003584, Fatal message
2020-04-19T22:27:51.416+0100, TRACE, root/140577659003584, [START] DUMPING POSTMORTEM LOGS
2020-04-19T22:27:50.415+0100, TRACE, PostmortemAppenderExample/140577659003584, Trace message
2020-04-19T22:27:50.415+0100, DEBUG, PostmortemAppenderExample/140577659003584, Debug message
2020-04-19T22:27:50.415+0100, INFO, PostmortemAppenderExample/140577659003584, Info message
2020-04-19T22:27:50.415+0100, WARN, PostmortemAppenderExample/140577659003584, Warn message
2020-04-19T22:27:51.416+0100, TRACE, root/140577659003584, [END] DUMPING POSTMORTEM LOGS
9.4.9.2. Python
The postmortem buffer can be configured by one of the methods provided by the elt.log.CiiLogManager module. Note that once the buffered logger is configured into the system, it can not be disabled.
The standard Python Logging API is unaffected by the use of the postmortem buffer.
The example in Listing 4‑23 shows an example usage of the postmortem buffer in Python.
More details on how to configure the postmortem buffer can be found in Appendix A.3.
An usage example of the postmortem buffer in Python is shown in Listing 4‑23. In this example, the postmortem buffer is enabled and a log TTL of 30 seconds is set. Then, logging is initialized with the default configuration. A series of log messages of different level are produced, and finally the postmortem buffer is flushed to all the configured handlers.
This example can be found in the cii-demo repository: cii-logging-example-postmortem-buffer-app-py
Listing 4‑23 Example postmortem buffer (Python)
def main():
"""
Main application code
@return status code, int
"""
result = 0
try:
# Enable postmortem functionality and set time-to-live of the log events
# in the buffer to 30s
os.environ[CiiLogManager.POSTMORTEM_BUFFER_ON_ENV_VAR] = 'true'
os.environ[CiiLogManager.POSTMORTEM_BUFFER_TTL_MS_ENV_VAR] = '30000'
# Automatically initialize the logging framework with console and file
# handler and get the logger with name 'PostmortemBufferExample'
logger = CiiLogManager.get_logger("PostmortemBufferExample")
# Create a log message of each level
# Only messages of levels ERROR and FATAL will be outoput to the console
# and file
logger.trace("Trace message")
logger.debug("Debug message")
logger.info("Info message")
logger.warning("Warning message")
logger.error("Error message")
logger.fatal("Fatal message")
# Wait a little
time.sleep(1)
print('Flushing postmortem buffer')
# Flush postmortem buffer, trace, debug and info messages should be seen
# on stdout
CiiLogManager.flush_postmortem_buffer()
except Exception as e:
print('Exception occured while executing sample code: %s', e)
result = 5
return result
if __name__ == '__main__':
sys.exit(main())
In CII v4.3 and above this example produces the following output (in v4.2 CRITICAL was printed instead of FATAL and WARNING instead of WARN):
2020-05-06T11:45:02.407+0100, ERROR, cii-logging-example-postmortem-buffer-app-py/MainThread, Error message
2020-05-06T11:45:02.407+0100, FATAL, cii-logging-example-postmortem-buffer-app-py/MainThread, Fatal message
2020-05-06T11:45:02.407+0100, TRACE, cii-logging-example-postmortem-buffer-app-py/MainThread, Trace message
2020-05-06T11:45:02.407+0100, DEBUG, cii-logging-example-postmortem-buffer-app-py/MainThread, Debug message
2020-05-06T11:45:02.407+0100, INFO, cii-logging-example-postmortem-buffer-app-py/MainThread, Info message
2020-05-06T11:45:02.407+0100, WARN, cii-logging-example-postmortem-buffer-app-py/MainThread, Warning message
9.4.10. Ops-Logs
The so-called “ops-logs” feature was added with CII 4.5. It produces logs in a predefined format that can be more easily machine parsed.
Ops-Logs are typically used to record changes of a value over time. Due to this conceptual proximity, the ops logs API is implemented as a part of the CII Telemetry module,
using a log stream as the “database” backend
the “database” is write-only, i.e. querying, etc. is not supported
Note: The log viewer - see section “Log Viewer” - has a special mode dedicated for viewing ops-logs.
9.4.10.1. Ops-Logs Example C++
#include <ciiTelem.hpp>
//[...]
// 1. configure your cii-logging
// -----------------------------
//[... see section 'Logging Library Usage' ...]
// 2. acquire ops-logger (= telem-recorder with log-backend)
// ---------------------------------------------------------
using namespace cii::telem;
std::shared_ptr<TelemManager> tm = TelemManager::GetInstance();
// optional: choose logger and level
tm->backends.log.config["logger"] = "hlcc.eltpk"; // default: root-logger
tm->backends.log.config["level"] = "DEBUG"; // default: INFO
std::shared_ptr<TelemRecorder> rec1;
rec1 = tm->CreateTelemRecorder("rec1", tm->backends.log);
// optional: provide detail info
TsMetadata tsmeta {};
tsmeta.tsname = "/elt/cs/hlcc/eltpk/mon/state";
tsmeta.units = "";
tsmeta.comment = "PK State";
tsmeta.origin = "eltpk";
rec1->RecordMetadata (tsmeta);
// 3. log values
// -------------
rec1->RecordPoint (TsPoint("idle"));
rec1->RecordPoint (TsPoint("oper"));
// Resulting ops-logs, e.g. in /var/log/elt/elt.log
// -------------------------------------------------
// Cref=[...] > /elt/cs/hlcc/eltpk/mon/state = idle / PK State [eltpk], Audience=OPERATOR, UserLogID=/elt/cs/hlcc/eltpk/mon/state
// Cref=[...] > /elt/cs/hlcc/eltpk/mon/state = oper / PK State [eltpk], Audience=OPERATOR, UserLogID=/elt/cs/hlcc/eltpk/mon/state
9.4.10.2. Ops-Logs Example Python
import cii.telem as tel
#[...]
# 1. configure your cii-logging
# -----------------------------
#[... see section 'Logging Library Usage' ...]
# 2. acquire ops-logger (= telem-recorder with log-backend)
# ---------------------------------------------------------
tm = tel.TelemManager.get_instance()
# optional: choose logger and level
tm.backends.log.config["logger"] = "hlcc.eltpk" # default: root-logger
tm.backends.log.config["level"] = "DEBUG" # default: INFO
rec1 = tm.create_telem_recorder("rec1", tm.backends.log)
# optional: provide detail info
tsmeta = TsMetadata()
tsmeta.tsname = "/elt/cs/hlcc/eltpk/mon/state"
tsmeta.units = ""
tsmeta.comment = "PK State"
tsmeta.origin = "eltpk"
rec1.record_metadata (tsmeta)
# 3. log values
# -------------
rec1.record_point (tel.TsPoint("idle"))
rec1.record_point (tel.TsPoint("oper"))
# Resulting ops-logs, e.g. in /var/log/elt/elt.log
# ------------------------------------------------
# Cref=[...] > /elt/cs/hlcc/eltpk/mon/state = idle / PK State [eltpk], Audience=OPERATOR, UserLogID=/elt/cs/hlcc/eltpk/mon/state
# Cref=[...] > /elt/cs/hlcc/eltpk/mon/state = oper / PK State [eltpk], Audience=OPERATOR, UserLogID=/elt/cs/hlcc/eltpk/mon/state
9.5. Logging services administration
This section describes the services used by logging. These services should be managed and maintained by system administrators.
9.5.1. Logging services configuration
It must be noted that running the services is not needed for being able to use the Logging Client API. For details on how to use the CII Log Client API, see section 3.3.
- As of CII v4, the log transmission uses these services:
rsyslog
logrotate
9.5.1.1. Host Setup
During cii-postinstall, an adminstrator chooses a cii-role for the host.
In accordance, cii-postinstall configures the rsyslog of the host.
The roles have the following effects:
Role |
Effect |
|---|---|
own server |
writes to local file elt.log |
group client |
writes to local file elt.log, and pushes logs to a log-collector-host |
group server |
writes to local file elt.log, and accepts logs pushed from other hosts |
9.5.1.2. Start/Stop Services
The log services can be started using
sudo cii-services start log
and stopped using
sudo cii-services stop log
9.5.1.3. Configuration
The log file is rotated daily, and 21 days will be kept.
To modify the amount of retained logs, see
/etc/logrotate.d/elt-log (requires privileges)
9.5.2. Logging services monitoring
To check the status of the logging services, do
systemctl status --no-pager rsyslog logrotate
To see the service logs, do
journalctl -u rsyslog
journalctl -u logrotate
9.6. Logging User Tools
This section describes the different user interface tools that enable users to create, query, and browse CII Log events.
9.6.1. ciiLogSend
Notice: As of CII v4, the alias names logSend
and cii-services-log-cli have been removed.
This section describes how to use the ciiLogSendd command line tool. This tool allows a user to write a log entry to the local CII log service, which will add the log to the logsink directory on the local machine, and can also (depending on the CII role of the host) transmit the log entry to a centralized CII log collector via CII distributed log transport.
This tool takes the Message field value and accepts parameters for all the rest of the CII Log format fields as described in Appendix B. For the required fields, the “N/A” value is used if no value is provided, except for the LogType field, for which the INFO level will be used, and for the HostName field, for which the current hostname will be used. The Date field is populated with the current time. Table 5‑1 shows the mappings beteen the sendLog command flags and the CII Log fields.
Table 6‑1 ciiLogSend CLI tool flags mappings
Flag |
Field name |
|---|---|
-h, –help |
|
-lt, –logtype |
LogType |
-cr, –cref |
Cref |
-si, –sourceid |
SourceID |
-h, –hostname |
HostName |
-au, –audience |
Audience |
-uli, –userlogid |
UserLogID |
-ti, –traceid |
TraceID |
-spi, –spanid |
SpanID |
-en, –exceptionname |
ErrorTypeName |
-ed, –exceptiontimestamp |
ErrorDateTime |
-em, –errormessage |
ErrorMessage |
-et, –errortrace |
ErrorTrace |
-an, –appname |
App Name |
A basic usage example can be seen below:
$ ciiLogSend "This is a log message"
Which will create the following log:
Cref=N/A, Date=2020-03-27T19:44:57.872+0200, HostName=docker-eso-eelt, LogType=INFO, SourceID=N/A, LogID=N/A, Message=This is a log message
This is a more advanced example, where several of the log fields are passed as arguments:
$ ciiLogSend "This is a log message" -lt ERROR -cr example_code_reference -si \
example_source_id -li example_log_id -au DEVELOPER
Which will produce the following log:
Cref=example_code_reference, Date=2020-03-27T19:50:28.739+0200, HostName=docker-eso-eelt, LogType=ERROR, SourceID=example_source_id, LogID=example_log_id, Audience=DEVELOPER, Message=This is a log message
9.6.2. Log Viewer
This section describes usage of the ciiLogViewer application, which is a graphical viewer application for logs. It is a stand-alone version of the CII log viewer widget.
Table 6‑2 log viewer command line options
Flag |
Description |
|---|---|
-h, –help |
Shows help |
-f, –follow |
Display (tail) new local logs |
-c, –columns |
Set default table columns (editable) |
-q, –query |
Set default query expr (editable) |
-Q, –forced-query |
Set permanent query expr (non-editable) |
–ops |
Only show logs for audience operator |
–nops |
Suppress logs for audience operator |
In “follow” mode, it detects all newly created log messages on the local host, found in the local log sink directory, and displays them in an automatically refreshing table.
To run it:
ciiLogViewer [/path/to/logs]
To show the centralised logs:
ciiLogViewer /var/log/elt
Default for when “[/path/to/logs]” is omitted:
CII v4
$CII_LOGS(if set)
$INTROOT/logsink(if set)
Next Version:
/var/log/eltwill become the default in the next version.
9.6.2.1. Column Chooser
Right-click on the table header, then select the checkboxes to apply.
9.6.2.2. View Filtering
As of CII v4, the log viewer can filter over all columns, using regexp-based query expressions.
Syntax:
<COLUMN NAME 1> [NOT] <LIKE STATEMENT 1> <COLUMN NAME 2> [NOT] <LIKE STATEMENT 2> ...
# where the <LIKE STATEMENT N> is of the form:
LIKE (<REGULAR EXPRESSION FOR THE COLUMN>)
The NOT operator acts as negation, for example:
# display records where the host column does not contain "test" (case insensitive)
Host NOT LIKE(test)
The AND operator (change in CII 4.5) is implicit, for example:
Host LIKE(\.eso\.org) Log ID LIKE(^Default) Message NOT LIKE(^MyID$)
# means:
Host should contain ".eso.org
and: Log ID should start from "Default"
and: Message must not be exactly "MyID"
More examples:
Host LIKE(*.eso.org) - an invalid regular expression, no effect
Host LIKE(.eso.org) will match "?eso?org"
Host LIKE(\.eso\.org) will match anything that contains ".eso.org"
Host LIKE(^elt\.eso\.org$) will match "elt.eso.org" exactly
Host LIKE(eltciid20|eltciid25) will match either of the two hosts
Notes:
The relation between all column “filters” is AND (since CII 4.5)
The NOT and LIKE keywords must be upper-case
Column names are matched case-insensitive, e.g. Host, host, HOST
Columns names with white space need not be quoted, e.g. Log ID
Filters for non-existing columns are ignored, e.g. Host33 NOT LIKE(.*)
9.6.3. Log Viewer Widget (Qt)
This is a Qt widget, meant for integration into an ELT application, allowing to display and filter ELT log data. The widget is the basis for the Log Viewer application described in the previous section.
To set the “/path/to/logs”:
pass it as a constructor argument, or
set the “directory” Qt property. Note this can be done any time.
9.7. Tracing
This section describes the CII Tracing system, including application instrumentation examples as well as the different services used to manage and browse the tracing data produced by the CII distributed systems.
9.7.1. Introduction
Tracing purpose is to aid developers and engineers in the understanding of interactions between components in a distributed system.
It must be noted that logging and tracing are handled separately and there is no automatic connection between logs and traces. This logical connection must be created manually by the user.
It is supported in CII with the OpenTracing API [22], and Jaeger [23] is used as the OpenTracing implementation.
Figure 8‑1 CII Tracing architecture
The architecture of the tracing system is shown in the figure above.
It can be divided in:
Instrumented application using OpenTracing API and Jaeger Client libraries
Jaeger services
Elasticsearch persistence backend
The Jaeger services used are:
Jaeger Agent
Jaeger Collector
Jaeger Query
A standard workflow of the tracing system is also shown in Figure 8‑1.
Applications and services instrumented with the OpenTracing API produce tracing data, that is sent to a Jaeger Agent by the Jaeger Client library.
The Jaeger Agent collects tracing data from multiple applications and sends batches of data to the Jaeger Collector.
The Jaeger Collector is responsible for persisting the tracing data received from the Jaeger Agents to an Elasticsearch instance.
Finally, the Jaeger Query service provides access to the persisted tracing data, as well as the Jaeger UI, which can be used to browse the tracing data.
9.7.1.1. Traces and Spans
Distributed tracing relies on traces and spans. A trace is the complete processing of a request. The trace represents the whole execution path of a request as it moves through all of the services or components of a distributed system. All trace events generated by a request share a trace ID that tools use to organize, filter, and search for specific traces.
Each trace is comprised of several spans. A span is an activity or operation that takes place within individual services or components of the distributed system. Each span is another step in the total processing of the overall request. Spans are typically named and timed operations. Spans each carry a unique span ID, and can also carry a reference to their parent span, metadata, or other annotations.
A trace can be seen as a directed acyclic graph, where spans are the nodes and references between spans are the edges.
For example, the following figure illustrates a trace made up of 6 spans:
Figure 8‑2 Causal relationships between spans in a trace
While this representation allows us to visualize the relationships between the different spans in a trace, it can also be useful to visualize traces in a timeline:
Figure 8‑3 Temporal relationships between spans in a trace
Each trace is identified by a unique Trace ID. A traced transaction that spans across multiple hosts, processes, or threads shall have a tracing context propagated between them.
This trace context must contain the following information to be able to trace the call flow of a transaction between services:
Trace ID: Identifier for a specific operation spanning across one or more distributed systems. When this operation is initiated, a Trace ID is generated and passed to other services that are called as part of the operation.
A trace is composed of one or more spans in one or more distributed hosts. Each span describes a logical unit of work, and contains the following information:
Operation name: String describing the unit of work represented by the span, e.g. ConfigService::readConfig.
Span ID: Identifies the span. It must be unique within a trace.
Parent ID: Identifier that references the ID of the span that triggered the current span.
Start time: Timestamp indicating when a span was started.
End time: Timestamp indicating when a span was ended.
The flow of this tracing context information across different services through operation can be seen in Figure 8‑4.
Figure 8‑4 Tracing context information flow
In this case, Service 1 would create a tracing context with Trace ID = A, Span ID = 1, and Parent ID = NULL. Together with the call to Service 2, Trace ID and Span ID of the caller are passed. Then Service 2 will create a trace context with Parent ID equal to the Span ID from Service 1 and the Trace ID to the one passed by Service 1. This newly created context will be set as the current context for Service 2. The same procedure applies to the interaction between Service 2 and Service 3 and to subsequent calls to any other service.
9.7.2. Tracing Library Usage
The following sections describe basic tracing instrumentation usage examples.
Advanced usage and configuration of the OpenTracing API and Jaeger are out of the scope of this document. For further information, see [22] and [23].
9.7.2.1. Tracing request-reply communication
Every request-reply action is instrumented.
When a new request is being issued by the client a new span is created. The MAL middleware implementation must check for existence of an active span using GlobalTracer.get().scopeManager().activeSpan() method. If there is a span active a newly created span Parent Id is set to Span Id of the active span, otherwise Parent Id is to 0. Operation name of the span is set to <instance name>::<method name>, e.g. ConfigService::readConfig. Trace Id and Span Id of the span are propagated to the server side among other request data. Upon completion or cancelation of the request the Span.finish() method is called on the created span instance.
On the server side a new span is created when request is received. The span shares the same operation name and Trace Id. It is created as a child span of the request span, i.e. Span Id of the span is set to Parent Id the of the request span. Upon completion or cancelation of the reply the Span.finish() method is called on the created span instance. The server-side implementation of a CII request-reply interface can create a child span of the span that CII created using mal tracing utilities by calling elt::mal::util::tracing::startSpan, which will create a child span of an active span if an active span exits, otherwise a childless span will be created.
9.7.2.2. Tracing publish-subscribe communication
Publish-subscribe communication is not instrumented by default. It needs to be enabled per data entity in ICD, i.e. by setting structure attribute trace to ”true”. This will instruct ICD generator to declare agnostic data entity structure as traceable by extending Traceable interface. The interface provides access to Trace Id and Span Id.
interface Traceable {
int64_getTraceId();
uint64 getSpanId();
};
Figure 8‑5 Definition of Traceable interface in pseudo-IDL.
On publisher side the process is the same as on the client side of request-reply communication pattern with exception that the operation name equals “publish(<data entity name>)” and the span finishes as soon as it is published (enqueued).
On the subscriber side it is programmer’s responsibility to create a new span, mal mapping will not create any spans automatically. User needs to extract a tracing context (i.e. sample->getTrace()) and create a span using mal tracing utilities. This decision has been made mostly due to the fact that multiple data entities can be read at once. The Logging API will provide helper method to create and activate a new span from received data entity that implements Traceable, e.g. TracingUtils#createSpan(methodName, traceable).
9.7.2.3. Includes/Imports
9.7.2.3.1. C++
#include <ciiTrace.hpp>
9.7.2.3.2. Python
import elt.trace
9.7.2.4. Basic usage example
In these examples, tracing is initialized using the provided TracingUtils.initializeTracing() helper method, which can be used to initialize the tracing framework and register a global tracer for the current application.
Then a root span is created, and a second span with the root span as its parent.
Finally, after all spans are finished, the tracer is closed.
9.7.2.4.1. C++
This example can be found in the cii-demo repository: cii-tracing-example-app
Listing 8‑3 Tracing basic example (C++)
int main(int ac, char *av[]) {
try {
/* Initialize tracing framework and register global tracer.*/
::elt::trace::InitializeTracing("demo-service-name");
/* Obtain a tracer (registered in previous step) */
std::shared_ptr<opentracing::Tracer> tracer = opentracing::Tracer::Global();
if (!tracer) {
throw ::elt::error::CiiException("No tracer registered");
}
/* Start a parent span */
std::unique_ptr<opentracing::Span> parentSpan = tracer->StartSpan("method1");
/* Start a child span */
std::unique_ptr<opentracing::Span> span = opentracing::Tracer::Global()->StartSpan(
"method2", { opentracing::ChildOf(&parentSpan->context())});
std::this_thread::sleep_for(std::chrono::seconds(2));
/* close the child span */
span->Finish();
std::this_thread::sleep_for(std::chrono::seconds(3));
/* close the parentSpan */
parentSpan->Finish();
/* close global tracer */
tracer->Close();
return 0;
} catch (const ::elt::error::CiiException& ex) {
std::cerr << "CiiException occured while executing sample code. What: "
<< ex.what() << '\n';
}
return -1;
}
9.7.2.4.2. Python
In this example, the use of a span and the tracer as context manager is shown as well.
This example can be found in the cii-demo repository: cii-tracing-example-app-py
Listing 8‑4 Tracing basic example (Python)
def main():
"""
Main application code
@return status code, int
"""
result = 0
try:
# Initialize tracing framework and register global tracer
elt.trace.initialize_tracing('demo-service-name')
# Obtain a tracer (registered in previous step)
tracer = elt.trace.opentracing.Tracer.get_global()
if tracer is None:
raise RuntimeError('No tracer registered')
# Start a parent span
parent_span = tracer.start_span('method 1')
# Start a child span
span = tracer.start_span("method2",
[elt.trace.opentracing.child_of(parent_span.context())])
time.sleep(2)
# Close the child span
span.finish()
# Span as context manager
with tracer.start_span("method3",
[elt.trace.opentracing.child_of(parent_span.context())]):
time.sleep(1)
# span.finish() was called on context exit
time.sleep(1)
# Close the parent span
parent_span.finish()
# Use tracer as context manager that closes itself automatically
with tracer:
# make another span and use it as context manager
with tracer.start_span('another span'):
time.sleep(1)
# global tracer is closed a this point
# to explicitly close the tracer, use: tracer.close()
except Exception as e:
print('Exception occured while executing sample code: %s', e)
traceback.print_exc()
result = 5
return result
if __name__ == '__main__':
sys.exit(main())
9.7.2.5. Mal pub/sub and request/response tracing basic examples
Mal tracing examples are part of icd-demo project and are listed in Table 2.
Table 2: MAL tracing basic examples in icd-demo
Example type |
Example location |
|---|---|
Mal pub/sub c++ tracing example |
app/cpp/ps/publisher/src app/cpp/ps/subscriber/src |
Mal pub/sub python tracing example |
app/python/ps/publisher/src app/python/ps/subscriber/src |
Mal request/response c++ tracing example |
app/cpp/rr/client/src app/cpp/rr/server/src |
Mal request/response python tracing example |
app/python/rr/client/src app/python/rr/server/src |
Basic examples for mal pub/sub tracing (based on examples in icd-demo):
Listing 8‑5 Tracing mal pub/sub example (C++)
/**
* @brief Initialize tracing (implementation specific to the user
* environment, mal is using only opentracing API to obtain the tracer)
*
* In this example we are using jaeger implementation of opentracing
* standard.
*
* @param service_name opentracing service name
*
*/
void InitializeTracing(const std::string& service_name) {
const bool log_span = true;
const bool disabled = false;
const double always_sample = 1.0;
/* Configuration specific to jaeger (opentracing API implementation) */
jaegertracing::Config config = jaegertracing::Config(
disabled,
jaegertracing::samplers::Config(
CONST_SAMPLING_STRATEGY,
always_sample),
jaegertracing::reporters::Config(
jaegertracing::reporters::Config::kDefaultQueueSize,
jaegertracing::reporters::Config::defaultBufferFlushInterval(),
log_span,
::jaegertracing::reporters::Config::kDefaultLocalAgentHostPort));
std::shared_ptr<opentracing::Tracer> tracer = jaegertracing::Tracer::make(
service_name, config, jaegertracing::logging::consoleLogger());
/* Register jaeger tracer as global opentracing tracer,
MAL will call opentracing API to obtain this tracer*/
opentracing::Tracer::InitGlobal(
std::static_pointer_cast<opentracing::Tracer>(tracer));
}
InitializeTracing("Some service");
/* Create a subscriber and a publisher in usual way and start publishing */
::elt::mal::Uri uri("zpb.ps://127.0.0.1:12404/test");
std::unique_ptr<ps::Subscriber<elt::SampleDataEntity>> subscriber =
mal::CiiFactory::getInstance().getSubscriber<elt::SampleDataEntity>(
uri, m_standardQoS, m_malProperties);
std::unique_ptr<ps::Publisher<elt::SampleDataEntity>> publisher =
mal::CiiFactory::getInstance().getPublisher<elt::SampleDataEntity>(
uri, m_standardQoS, m_malProperties);
std::shared_ptr<elt::SampleDataEntity> dataEntity = publisher->createDataEntity();
dataEntity->setText("Initial");
dataEntity->setSampleId(0);
const std::size_t SAMPLE_COUNT = 3;
for (std::size_t i = 0; i < SAMPLE_COUNT; i++) {
std::stringstream ss;
ss << "Some text" << i;
dataEntity->setText(ss.str());
dataEntity->setSampleId(i);
/* Since the global tracer is set (InitializeTracing) and
elt::SampleDataEntity has struct attribute trace="true",
MAL will start a new span and finish it immediately and propagate the span
context using sample->setTrace()*/
publisher->publish(*dataEntity, std::chrono::milliseconds(100));
}
std::this_thread::sleep_for(std::chrono::milliseconds(100));
std::vector<std::shared_ptr<elt::SampleDataEntity>> samples = subscriber->read(0);
std::shared_ptr<elt::SampleDataEntity> sample = samples.at(0);
/* Obtain tracer using opentracing API */
std::shared_ptr<opentracing::Tracer> tracer = opentracing::Tracer::Global();
/* Obtain the span context from sample and create a child span */
std::stringstream contextStrm(sample->getTrace());
std::unique_ptr<::opentracing::SpanContext> spanContext = ::elt::mal::util::tracing::deserializeSpan(contextStrm);
{
std::unique_ptr<opentracing::Span> childSpan = opentracing::Tracer::Global()->StartSpan(
"tracerPublishSubscribeTest",
{opentracing::ChildOf(spanContext.get())});
}
9.7.2.6. Context Propagation
Tracing context is automatically propagated through MAL communication. Every request-reply action is instrumented. Upon completion or cancelation of the request, the Span.finish() method is called on the created span.
OLDB messaging automatically propagates the tracing context as well. If there is no active span at the time of call of OLDB API function, then no tracing context is transferred to the OLDB. Span.finish() method is called just before OLDB call completes but only if there was an active span. The OLDB client can obtain the span context from a data point value by calling a getTrace method which will return the context only if an active span exited at the time when write method was called. Otherwise, the context will be empty. It is then the responsibility of the client to create a child span from the context read from the data point value. For the OLDB subscriptions the user is also responsible for obtaining the span context from data point value received trough a subscription listener (NewValue call) and then creating new child spans.
In both cases, if there is an active span, the new span is created with the active span as a parent.
Any other type of tracing context propagation is the responsibility of the developer (see [22]).
9.7.3. Tracing Services
This section describes the services used by tracing. The services described below are used for collection, transmission, persistence, and querying of distributed CII traces data. They must be running and properly configured for the tracing system to work.
These services should be managed and maintained by system administrators. See the Log TRD document on how to set up the tracing services.
Documentation on configuration and deployment of these services can be found in [23].
9.7.3.1. Jaeger Agent
Network daemon that listens for spans sent over UDP, which it batches and sends to the collector.
9.7.3.2. Jaeger Collector
Receives traces from Jaeger Agents and runs them through a processing pipeline. It is responsible for persisting traces to the storage backend. It supports Elasticsearch as a storage backend.
9.7.3.3. Jaeger Query
This service retrieves traces from storage and hosts a UI to display them
9.7.4. Tracing GUI (Jaeger UI)
The Jaeger UI is a web application provided by the Jaeger Query service. It allows browsing the tracing data produced by the different CII services and applications.
By default, it’s available on port 16686.
To access it, open to the http://ciijaegerqueryhost:16686 on your browser, where ciijaegerqueryhost is the hostname of the Jaeger Query service. The Jaeger UI search page will be presented to the user, as shown in Figure 8‑6.
Figure 8‑6 Jaeger UI search view
On the left side of this view, the different filtering parameters for the traces search can be defined by the user. To perform the search, click the Find Traces button. When this button is clicked, a list of traces matching the search filtering options will be displayed on the right side of the screen, as shown in Figure 8‑7.
Figure 8‑7 Jaeger UI traces search result
It is possible to look for a specific trace using the Lookup by Trace ID input field on the top-left side of the screen. It is also possible to browse a trace directly with the URL https://ciijaegerqueryhost:16686/trace/<trace_id>.
When clicking on a trace on the search results list, or accessing it directly, the trace view will be presented to the user in a trace timeline view, as shown in Figure 8‑8. Clicking on each of the spans will display the information about that span.
Figure 8‑8 Jaeger UI trace view
The trace view offers the following trace visualization modes:
Trace Timeline: Displays the trace and its spans in a timeline visualization (Figure 8‑8).
Trace Graph: Displays the trace and its spans as a directed acyclic graph (Figure 8‑9).
Trace JSON: Displays the trace and its spans as a JSON object.
Trace JSON (Unadjusted): Displays the trace and its spans as a JSON object with raw data without any adjustments [25].
Figure 8‑9 Jaeger UI Trace Graph visualization
9.8. CII Log Client API
This are the listings for the CII Log API methods with short descriptions. APIs for C++ and Python are slightly different, therefore a listing for each of the three languages is provided.
9.8.1. C++
C++ CII Log Client API is provided by CiiLogManager, CiiLogMessageBuilder, CiiLogConfigurator, CiiLayout, and CiiSimpleLayout classes.
9.8.1.1. CiiLogManager
void elt::log::CiiLogManager::configure ( const std::map< std::string, std::string > & properties, cpp_logging=False ) |
|---|
Configure logging from properties. Parameters:
|
void elt::log::CiiLogManager::configure ( const std::string & logConfigFile, cpp_logging=False ) |
|---|
Configure logging from a file name. Parameters:
|
std::string elt::log::CiiLogManager::detailMessage( const std::string & message, const CiiLogAudience audience, const std::string userLogId = “” ) |
|---|
Utility method producing a detailed message with all method’s parameters included. Parameters:
|
log4cplus::Logger elt::log::CiiLogManager::getLogger ( const std::string loggerName ) |
|---|
Gets a logger instance. Parameters:
|
9.8.1.2. CiiLogMessageBuilder
Provides a way to construct a log message according to the CII log format
elt::log::CiiLogMessageBuilder::CiiLogMessageBuilder ( ) |
|---|
Default constructor. |
elt::log::CiiLogMessageBuilder::CiiLogMessageBuilder ( const std::string & message ) |
|---|
Constructor, taking message as argument Parameters:
|
std::string elt::log::CiiLogMessageBuilder::Build ( ) const |
|---|
Build formatted log message string from information within builder and return it. Returns:
|
static CiiLogMessageBuilder elt::log::CiiLogMessageBuilder::Create ( ) |
|---|
Static method to create CiiLogMessageBuilder Returns:
|
static CiiLogMessageBuilder elt::log::CiiLogMessageBuilder::Create ( const std::string & message ) |
|---|
Static method to create CiiLogMessageBuilder with message Parameters:
Returns:
|
static std::string elt::log::CiiLogMessageBuilder::CreateAndBuildWithAudience ( const std::string & message, CiiLogAudience audience ) |
|---|
Static method to create a formatted log message string with provided message and audience Parameters:
Returns:
|
static std::string elt::log::CiiLogMessageBuilder::CreateAndBuildWithException ( const std::string & message, const elt::error::CiiException & exception ) |
|---|
Static method to create a formatted log message string with provided message and CiiException Parameters:
Returns:
|
static std::string elt::log::CiiLogMessageBuilder::CreateAndBuildWithMessage ( const std::string & message ) |
|---|
Static method to create a formatted log message string with provided message Parameters:
Returns:
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithAudience ( CiiLogAudience audience ) |
|---|
Add audience to the builder and return reference to self (chaining support) Parameters
Returns
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithException ( const elt::error::CiiException & exception ) |
|---|
Add information about an elt::error::CiiException to the builder and return reference to self (chaining support). Parameters:
Returns:
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithException ( const std::exception & exception ) |
|---|
Add information about std::exception to the builder and return reference to self (chaining support) Parameters:
Returns:
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithMessage ( const std::string & message ) |
|---|
Add message to the builder and return reference to self (chaining support) Parameters:
Returns:
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithTracingInfo ( bool tracing_info ) |
|---|
Enable/disable tracing info flag and return reference to self (chaining support) Parameters:
Returns:
|
CiiLogMessageBuilder& elt::log::CiiLogMessageBuilder::WithUserLogId ( const std::string & user_log_id ) |
|---|
Add user log ID string to the builder and return reference to self (chaining support) Parameters:
Returns:
|
9.8.1.3. CiiLogConfigurator
Configures Log4cplus loggers and appenders from configuration file and injects each configured logger with one PostmortemAppender instance to keep all filtered events for some specified time for later usage.
Configure loggers with configuration from log4cplus.properties file and life time of 1 second with example:
//configure log4cplus from log4cplus.properties file and then set the
//life time of the stored events for 1 second
CiiLogConfigurator::doConfigure ( 1 , "log4cplus.properties" );
If configuration of Log4cplus is initialized without the postmortem buffer enabled, it is possible to enable it once the Log4cplus configuration has been initialized with the following method:
//set the life time of the stored events for 1 second
CiiLogConfigurator::inject( 1 );
To dump stored events which still have valid lifetimes call this method:
//dump all valid events to parent logger
CiiLogConfigurator::postmortemDump();
CiiLogConfigurator has an option to reset log4cplus configuration be fully reset when calling doConfigure:
CiiLogConfigurator::setResetOnConfigure( shouldReset );
static void elt::log::CiiLogConfigurator::doConfigure( uint32_t life_time, const log4cplus::tstring & config_filename, log4cplus::Hierarchy & h = log4cplus::Logger::getDefaultHierarchy(), unsigned flags = 0 ) |
|---|
This method eliminates the need to create a temporary PropertyConfigurator to configure log4cplus. It is equivalent to the following: PropertyConfigurator config("filename");
config.configure();
Parameters:
|
static void elt::log::CiiLogConfigurator::inject ( uint32_t life_time ) |
|---|
Inject PostMortemAppender into each configured logger instance without loading property file. Parameters:
|
static void elt::log::CiiLogConfigurator::postmortemDump ( ) |
|---|
Dump all valid events (events which have life time less than globally specified life time) to all the loggers that previously rejected them. |
static void elt::log::CiiLogConfigurator::setResetOnConfigure ( bool reset ) |
|---|
Decides whether the configuration should reset all already configured loggers when a new configuration is applied. Parameters:
|
static bool elt::log::CiiLogConfigurator::getResetOnConfigure ( ) |
|---|
Returns:
|
9.8.1.4. CiiLayout
Log layout for CII Log format.
elt::log::layout::CiiLayout::CiiLayout( const log4cplus::helpers::Properties & properties ) |
|---|
Construct CII layout with properties. Parameters:
|
9.8.1.5. CiiSimpleLayout
Simple log layout for CII Log format.
elt::log::layout::CiiSimpleLayout::CiiSimpleLayout( const log4cplus::helpers::Properties & properties ) |
|---|
Construct CII simple layout with properties. Parameters:
|
9.8.2. Python
Python CII Log Client API is provided by CiiLogManager, CiiLogConfigurator, and CiiLogMessageBuilder classes.
9.8.2.1. CiiLogManager
Provides methods to manage and configure logging, as well as methods to obtain logger objects.
log.CiiLogManager.configure(config = None) |
|---|
Perform logging configuration from provided dictionary/file just like logging.config.dictConfig() function with additional functionality:
Parameters:
Returns:
|
log.CiiLogManager.get_logger(name = None) |
|---|
CII logger factory method. Parameters:
Returns:
|
log.CiiLogManager.flush_postmortem_buffer() |
|---|
Flush buffered logs to the handlers that have previosly rejected thos log messages. Cyclic log buffer is reset. Returns:
|
log.CiiLogManager.is_postmortem_buffer_enabled() |
|---|
Query whether buffered logger is installed. Returns:
|
9.8.2.2. CiiLogConfigurator
log.CiiLogConfigurator.load_configuration(filename) |
|---|
Load log configuration from provided file. Log configuration must be saved in JSON format. Note that this is not supported with Python logging subsystem. Parsing of log configuration must produce a dictionary that is compatible with CiiLogManager.configure() method Parameters:
Returns:
|
log.CiiLogConfigurator.configure(config = None) |
|---|
Perform logging configuration from provided dictionary/file just like logging.config.dictConfig() function with additional functionality:
Parameters:
Returns:
|
log.CiiLogConfigurator.check_config( ) |
|---|
Check whether configure() method was already called. If that was not the case, it calls it to configure defaults. |
log.CiiLogConfigurator.save_configuration(config, filename) |
|---|
Save log configuration dictionary as json into provided filename. Parameters:
|
log.CiiLogConfigurator.get_formatter(simple = False) |
|---|
Create and return CII specific formatter Parameters:
Returns:
|
log.CiiLogConfigurator.flush_postmortem_buffer() |
|---|
Flush buffered logs to the handlers that have previosly rejected thos log messages. Cyclic log buffer is reset. Returns:
|
log.CiiLogConfigurator.flush_postmortem_buffer_to_string() |
|---|
Flush content of the cyclic log buffer to string. Cyclic log buffer is reset. Returns:
|
log.CiiLogConfigurator.reset_postmortem_buffer() |
|---|
Empty the log buffer if buffered logger is installed. Returns:
|
log.CiiLogConfigurator.get_effective_logsink_filename() |
|---|
Return full name of the filename for log sink (if one was created by calling get_logsink_filename). Returns:
|
log.CiiLogConfigurator.get_logsink_filename() |
|---|
Return full name of the filename for log sink. Returns:
|
log.CiiLogConfigurator.enable_postmortem_buffer(ttl_seconds = 60) |
|---|
Enable postmortem buffer by installing a buffered logger as a root logger. Parameters:
Returns:
|
log.CiiLogConfigurator.is_postmortem_buffer_enabled() |
|---|
Query whether buffered logger is installed. Returns:
|
9.8.2.3. CiiLogMessageBuilder
Provides a way to construct a log message according to the CII log format.
__init__(self, message=None) |
|---|
Constructor Parameters:
|
create(cls, message=None) |
|---|
Creates a formatted log message string with exception info. Parameters:
Returns:
|
create_and_build_with_exception(cls, message, exception) |
|---|
Creates a formatted log message string with exception info. Parameters:
Returns:
|
create_and_build_with_audience(cls, message, audience) |
|---|
Creates a formatted log message string with audience field. Parameters:
Returns:
|
create_and_build_with_args(cls, **kwargs) |
|---|
Create a formatted log message string from provided arguments. See with_args. The following arguments are supported:
Parameters:
Returns:
|
with_message(self, message) |
|---|
Sets the mesage field value. Parameters:
Returns:
|
with_user_log_id(self, user_log_id) |
|---|
Sets the user ID field value. Parameters:
Returns:
|
with_audience(self, audience) |
|---|
Sets the audience for the log message. Parameters:
Returns:
|
with_tracing_info(self, tracing_info=True) |
|---|
Sets the log message to include/exclude tracing info fields. Returns:
|
with_cii_exception(self, exception) |
|---|
Sets the exception to be formatted and included in the log message. Parameters:
Returns:
|
with_exception(self, exception) |
|---|
Sets the exception to be formatted and included in the log message. Alias for with_cii_exception. Parameters:
Returns:
|
with_args(self, message=None, audience=None, user_log_id=None, exception=None, with_tracing_info=None) |
|---|
Sets the fields from provided keyword arguments. The following arguments are supported:
Parameters:
Returns:
|
build(self) |
|---|
Construct the log message string according to the defined parameters. Returns:
|
9.9. CII Log Fields
All fields in a log message, aside from the date/time fields are treated as strings.
Table 8‑3 Log fields
Field |
ES field name |
Description |
Optional |
|---|---|---|---|
Cref |
cii.cref |
Source filename/line number. |
NO |
Date |
cii.date |
Date and time of log creation down to milliseconds in UTC timescale with the ‘T’ designator between date and time, eg: 2020-03-16T09:3 2:09.681+0100. It follows ISO 8601 standard. |
NO |
HostName |
cii.hostname |
Hostname of the computing node where the log was produced. |
NO |
LogType |
cii.logtype |
The type of log message (level). |
NO |
SourceID |
cii.sourceid |
Class name, thread name. |
NO |
LogID |
ci.logid |
ID of the log message source location. |
NO |
Message |
cii.message |
Text message of the log event. |
NO |
Audience |
cii.audience |
The intended recipient of the log. |
YES |
UserLogID |
cii.userlogid |
A user provided ID. |
YES |
TraceID |
cii.traceid |
ID of the trace for the current tracing context. |
YES |
SpanID |
cii.spanid |
ID of the span for the current tracing context. |
YES |
ErrorTypeName |
cii.error.typen ame |
Name of the CII Error |
YES |
ErrorDateTime |
cii.error.datet ime |
Unix timestamp of the error |
YES |
ErrorMessage |
cii.error.messa ge |
Message of the error |
YES |
ErrorTrace |
cii.error.trace |
Stack trace of the error |
YES |