BDE 4.39.x Production Release
Loading...
Searching...
No Matches
ball_asyncfileobserver

Detailed Description

Provide an asynchronous observer that logs to a file and stdout.

Outline

Purpose

Provide an asynchronous observer that logs to a file and stdout.

Classes

See also
ball_record, ball_context, ball_observer, ball_fileobserver

Description

This component provides a concrete implementation of the ball::Observer protocol, ball::AsyncFileObserver, for asynchronously publishing log records to stdout and, optionally, to a user-specified file. A ball::AsyncFileObserver (informally, "async file observer") object processes the log records received through its publish method by pushing the supplied ball::Record object onto a queue and (typically) returning immediately (see {Log Record Queue}). Each enqueued record is ultimately published when an independent publication thread removes the log record from the queue and writes it to the configured log file and stdout. The following inheritance hierarchy diagram shows the classes involved and their methods:

,-----------------------.
`-----------------------'
| ctor
| disableFileLogging
| disablePublishInLocalTime
| disableSizeRotation
| disableStdoutLoggingPrefix
| disableTimeIntervalRotation
| enableFileLogging
| enableStdoutLoggingPrefix
| enablePublishInLocalTime
| forceRotation
| rotateOnSize
| rotateOnTimeInterval
| setFileLogFormat
| setLogFormat
| setLogFormats
| setOnFileRotationCallback
| setStdoutLogFormat
| setStdoutThreshold
| shutdownPublicationThread
| startPublicationThread
| stopPublicationThread
| suppressUniqueFileNameOnRotation
| getFileLogFormat
| getLogFormat
| getStdoutLogFormat
| isFileLoggingEnabled
| isPublicationThreadRunning
| isPublishInLocalTimeEnabled
| isStdoutLoggingPrefixEnabled
| isSuppressUniqueFileNameOnRotation
| recordQueueLength
| rotationLifetime
| rotationSize
| stdoutThreshold
V
,--------------.
( ball::Observer )
`--------------'
dtor
publish
releaseRecords
Definition ball_asyncfileobserver.h:686

The format of published log records is user-configurable for both logging to stdout and logging to a file (see {Log Record Formatting} below). Although logging to a file is initially disabled following construction, the most common use-case for ball::AsyncFileObserver is to also log to a file, enabled by calling the enableFileLogging method. In addition, an async file observer may be configured to perform automatic log file rotation (see {Log File Rotation} below).

Async File Observer Configuration Synopsis

ball::AsyncFileObserver offers several constructor arguments and manipulators that may be used to configure various aspects of an async file observer object. These are summarized in the following tables along with the accessors that can be used to query the current state of the configuration. Further details are provided in the following sections and the function-level documentation.

+-----------------------+---------------------------------+
| Aspect | Constructor Arguments |
+=======================+=================================+
| Log Record Timestamps | publishInLocalTime |
+-----------------------+---------------------------------+
| 'stdout' Logging | stdoutThreshold |
+-----------------------+---------------------------------+
| Log Record Queue | maxRecordQueueSize |
| | dropRecordsOnFullQueueThreshold |
+-----------------------+---------------------------------+
+-------------+------------------------------------+
| Aspect | Related Methods |
+=============+====================================+
| Log Record | setLogFormat |
| Formatting | enableStdoutLoggingPrefix |
| | disableStdoutLoggingPrefix |
| | getLogFormat |
| | isStdoutLoggingPrefixEnabled |
+-------------+------------------------------------+
| Log Record | enablePublishInLocalTime |
| Timestamps | disablePublishInLocalTime |
| | isPublishInLocalTimeEnabled |
+-------------+----------------------------------- +
| File | enableFileLogging |
| Logging | disableFileLogging |
| | isFileLoggingEnabled |
+-------------+----------------------------------- +
| 'stdout' | setStdoutThreshold |
| Logging | enableStdoutLoggingPrefix |
| | disableStdoutLoggingPrefix |
| | stdoutThreshold |
| | isStdoutLoggingPrefixEnabled |
+-------------+------------------------------------+
| Log File | rotateOnSize |
| Rotation | rotateOnTimeInterval |
| | disableSizeRotation |
| | disableTimeIntervalRotation |
| | setOnFileRotationCallback |
| | suppressUniqueFileNameOnRotation |
| | rotationSize |
| | rotationLifetime |
| | isSuppressUniqueFileNameOnRotation |
+-------------+------------------------------------+
| Publication | startPublicationThread |
| Thread | stopPublicationThread |
| Management | shutdownPublicationThread |
| | isPublicationThreadRunning |
+-------------+------------------------------------+

In general, a ball::AsyncFileObserver object can be dynamically configured throughout its lifetime (in particular, before or after being registered with a logger manager). Note that for ball::AsyncFileObserver, configuration changes that affect how records are logged (e.g., enablePublishInLocalTime and disablePublishInLocalTime) impact both those records received by the publish method subsequent to making the configuration change as well as those records that are already on the queue.

Log Record Queue

The log record queue of an async file observer has a configurable, but fixed, maximum size, where the default is 8192. The maxRecordQueueSize constructor argument may be used to specify an alternative maximum size for the record queue that can be either larger or smaller than the default.

By default, an async file observer is configured for the publish method to drop all records that it receives while the queue is full. This behavior can be modified by supplying a Severity::Level for the constructor argument dropRecordsOnFullQueueThreshold whereby only those records whose severity is less severe than that threshold are dropped. Each record whose severity is at least as severe as dropRecordsOnFullQueueThreshold will cause the publish method to block until the queue has spare capacity to accommodate the record (presumably freed up by the publication thread having consumed a record from the queue). For example, if this threshold is set to e_WARN on construction, e_INFO, e_DEBUG, and e_TRACE records are dropped by publish when the queue is full whereas e_WARN, e_ERROR, and e_FATAL records will cause publish to block while waiting for room in the queue. Note that while publish will never block with the default threshold setting, clients should consider the trade-offs between dropping potentially critical log messages versus possibly blocking in publish on such messages.

An async file observer maintains a count of the records that are dropped, periodically publishing a warning (i.e., an internally generated log record with severity e_WARN) that reports the number of dropped records. The record count is reset to 0 after each such warning is published, so each dropped record is counted only once.

Log Record Formatting

By default, the output format of published log records (whether to stdout or a user-specified file) is:

DATE_TIME PID:THREAD-ID SEVERITY FILE:LINE CATEGORY MESSAGE USER-FIELDS

where DATE and TIME are of the form DDMonYYYY and HH:MM:SS.mmm, respectively (Mon being the 3-letter abbreviation for the month). For example, assuming that no user-defined fields are present, a log record will have the following appearance when the default format is in effect:

18MAY2005_18:58:12.076 7959:1 WARN ball_asyncfileobserver.t.cpp:404 TEST hi

The default format for records published to stdout (only) can be shortened by calling disableStdoutLoggingPrefix. This method has the effect of reducing the above example message to the following when output to stdout:

WARN ball_asyncfileobserver.t.cpp:404 TEST hi

For additional flexibility, the setFileLogFormat and setStdoutLogFormat methods can be called to independently configure the format of published records to a file and to stdout, respectively. The format specifications can be either scheme-tagged (recommended) or legacy printf-style format strings that results in a RecordStringFormatter being used.

Scheme-Based Format Specifications (Recommended)

The recommended way to specify log record formats is using URI-like scheme-tagged format configuration strings. A scheme-tagged format string begins with a scheme identifier followed by :// and then a scheme-specific format specification:

<scheme>://<format-specification>

The scheme determines which formatter will be used and the syntax of the format specification. The following schemes are currently supported: text, json, qjson. See Scheme-Based Formatters for more details of the supported schemes and their accompanying format specification syntaxes.

For example, to log records to a file in JSON format with printf-style format specification, and to stdout using text format with ISO 8601 timestamps:

asyncFileObserver.setFileLogFormat("qjson://%d %p:%t %s %f:%l %c %m");
asyncFileObserver.setStdoutLogFormat("text://\n%I %p:%t %s %f:%l %c %m\n");

Note that both text:// and qjson:// schemes support printf-style % specifications in their format strings, though with different output structures (plain text vs. JSON).

Legacy Format Specifications

For backward compatibility, format specifications that do not begin with a scheme tag are treated as legacy printf-style format strings. Such specifications are implicitly treated as if they had a text:// prefix and use ball::RecordStringFormatter. For example, the following two calls are equivalent:

asyncFileObserver.setFileLogFormat("%d %p:%t %s %f:%l %c %m %a\n");
asyncFileObserver.setFileLogFormat("text://%d %p:%t %s %f:%l %c %m %a\n");

These %-prefixed conversion specifications are defined in ball_recordstringformatter .

Legacy API: setLogFormat

The setLogFormat method sets both file and stdout formats at once. Using setFileLogFormat and setStdoutLogFormat is preferred to set formats independently for file and stdout output:

// Legacy:
asyncFileObserver.setLogFormat(fileFormat, stdoutFormat);
// Preferred:
asyncFileObserver.setFileLogFormat(fileFormat);
asyncFileObserver.setStdoutLogFormat(stdoutFormat);

Interaction with enableStdoutLoggingPrefix & disableStdoutLoggingPrefix

When a format is set using setLogFormat, calling disableStdoutLoggingPrefix will change the stdout format to the default short format (i.e., "\n%s %f:%l %c %m %u\n"), regardless of whether the original format was specified as a printf-style format string or a scheme-based formatter. If enableStdoutLoggingPrefix is subsequently called, the format specified in the most recent call to setLogFormat will be reinstated, preserving the original formatter type (string-based or scheme-based).

Log Record Timestamps

By default, the timestamp attributes of published records are written in UTC time (unless true is supplied for the optional publishInLocalTime constructor flag). To write timestamps in local time instead, call the enablePublishInLocalTime method. Note that the local time offset is calculated using the UTC timestamp of each record. To revert to UTC time, call the disablePublishInLocalTime method. Whether UTC time or local time is in effect can be queried via isPublishInLocalTimeEnabled.

Note that log record timestamps that are output (to either stdout or to a file) reflect the times at which the records were received by the publish method of the async file observer (and pushed onto the queue). That is, the length of time that a record resides on the queue does not impact the record's timestamp when it is eventually output by the publication thread.

Local Time Offset Calculations

The calculation of the local time offset adds some overhead to the publication of each log record. If this overhead is an issue, it can be mitigated by installing a high-performance local-time offset callback for bdlt::CurrentTime in main. See bsls_systemtime for the details of installing such a callback and see baltzo_localtimeoffsetutil for an example facility. Note that such callbacks can improve performance for all users of bdlt::CurrentTime, not just the ball logger.

Log Filename Patterns

The enableFileLogging method supports the use of %-escape sequences to specify log filenames. The recognized sequences are as follows:

%Y - current year (4 digits with leading zeros)
%M - current month (2 digits with leading zeros)
%D - current day (2 digits with leading zeros)
%h - current hour (2 digits with leading zeros)
%m - current minute (2 digits with leading zeros)
%s - current second (2 digits with leading zeros)
%T - current datetime, equivalent to "%Y%M%D_%h%m%s"
%p - process ID

The date and time elements of the derived filename are based on the time when the log file is created. Furthermore, these elements are based on either UTC time or local time depending on the value returned by isPublishInLocalTimeEnabled. (See {Log Record Timestamps} for the similarity with the treatment of record timestamps.)

For example, a log filename pattern of "task.log.%Y%M%D_%h%m%s" will yield the filename task.log.20110501_123000 if the file is created on 01-May-2011 at 12:30:00 local time (assuming enablePublishInLocalTime was called).

Log File Rotation

A ball::AsyncFileObserver may be configured to perform automatic rotation of log files based on simple file rotation conditions (or rules).

File Rotation Conditions

Rotation rules may be established based on the size of the log file (i.e., a "rotation-on-size" rule), and a periodic time interval (i.e., a "rotation-on-time-interval" rule). These rules are independently enabled by the rotateOnSize and rotateOnTimeInterval methods, respectively. If both rules are in effect, log file rotation is performed whenever either rule applies.

Rotated File Naming

When a log file is rotated, a new filename is generated using the pattern supplied to enableFileLogging. If the file having the new name does not exist, the current log file is closed, and the logging continues to the new file.

If the file having the new name already exits, then the behavior of the file rotation is further controlled by the flag set with suppressUniqueFileNameOnRotation:

The two tables below illustrate the names of old and new log files when a file rotation occurs. We assume that the log file is rotated on 2011-May-21 at 12:29:59 local time and that the last rotation occurred at 12:30:00 on the previous day. We further assume that enablePublishInLocalTime was called, so that all date and time elements are rendered in local time.

The first table shows the name change (if any) of the (old) log file being rotated when the flag controlled by suppressUniqueFileNameOnRotation is set to false:

Disabled: 'suppressUniqueFileNameOnRotation'
For brevity:
<TS1> = 20210520_123000
<TS2> = 20210521_122959 (aka next day, about the same time)
+----------------+-----------------+----------------+----------------------
| Pattern | Filename Before | Filename After | Rotated Filename
| | Rotation | Rotation |
+----------------+-----------------+----------------+----------------------
| "a.log" | a.log | a.log | a.log.<TS1>
| "a.log.%T" | a.log.<TS1> | a.log.<TS2> | a.log.<TS1>
| "a.log.%Y%M" | a.log.202105 | a.log.202105 | a.log.202105.<TS1>
| "a.log.%Y%M%D" | a.log.20210520 | a.log.20110521 | a.log.20210520
+----------------+-----------------+----------------+----------------------

Note that upon rotation a timestamp was appended to the name of the rotated file when the log pattern does not contain %-escape sequences indicating a time period ("a.log"), or the rotation period (in our case, one day) is less than the time period encoded in the pattern (in case of "a.log.%Y%M" the period is one month).

The next table shows the rotated name when the flag controlled by suppressUniqueFileNameOnRotation is set to true, and (possibly new) name of the (new) log file following rotation:

Enabled: 'suppressUniqueFileNameOnRotation'
+----------------+-----------------+----------------+----------------------
| Pattern | Filename Before | Filename After | Rotated Filename
| | Rotation | Rotation |
+----------------+-----------------+----------------+----------------------
| "a.log" | a.log | a.log | none
| "a.log.%T" | a.log.<TS1> | a.log.<TS2> | a.log.<TS1>
| "a.log.%Y%M" | a.log.202105 | a.log.202105 | none
| "a.log.%Y%M%D" | a.log.20210520 | a.log.20110521 | a.log.20210520
+----------------+-----------------+----------------+----------------------

Note that the original filename is reused when the log pattern does not contain %-escape sequences indicating a time period ("a.log"), or the rotation period (in our case, one day) is less than the time period encoded in the pattern (in case of "a.log.%Y%M" the period is one month).

Also note, that in any cases, when the log pattern includes "%T", or encodes a time period that coincides the rotation period (in case of "a.log.%Y%M%D" the period is one day), then a unique name on each rotation is produced with the (local) time at which file rotation occurred embedded in the filename.

Thread Safety

All public methods of ball::AsyncFileObserver are thread-safe, and can be called concurrently by multiple threads.

Usage

This section illustrates intended use of this component.

Example 1: Publication Through the Logger Manager

This example demonstrates using a ball::AsyncFileObserver within the ball logging system.

First, we initialize the ball logging subsystem with the default configuration:

ball::LoggerManagerScopedGuard guard(configuration);
Definition ball_loggermanagerconfiguration.h:283
Definition ball_loggermanager.h:2162
Definition ball_loggermanager.h:1293
static LoggerManager & singleton()
Definition ball_loggermanager.h:2389

Note that the application is now prepared to log messages using the ball logging subsystem, but until the application registers an observer, all log records will be discarded.

Then, we create a shared pointer to a ball::AsyncFileObserver object, observerPtr, having default attributes. Note that a default-constructed async file observer has a maximum (fixed) size of 8192 for its log record queue and will drop incoming log records when that queue is full. (See {Log Record Queue} for further information.)

bsl::make_shared<ball::AsyncFileObserver>();
Definition bslstl_sharedptr.h:1838

Next, we set the required logging format by calling the setFileLogFormat and setStdoutLogFormat methods. The statements below output timestamps in ISO 8601 format to a log file and in bdlt-style (default) format to stdout, where timestamps are output with millisecond precision in both cases:

observer->setFileLogFormat("%I %p:%t %s %f:%l %c %m\n");
observer->setStdoutLogFormat("%d %p:%t %s %f:%l %c %m\n");

Note that both of the above format specifications omit user fields ("%u") in the output. Also note that, unlike the default, this format does not emit a blank line between consecutive log messages.

Next, we start the publication thread by invoking startPublicationThread:

observer->startPublicationThread();

Then, we register the async file observer with the logger manager. Upon successful registration, the observer will start to receive log records via the publish method:

int rc = manager.registerObserver(observer, "asyncObserver");
assert(0 == rc);
int registerObserver(const bsl::shared_ptr< Observer > &observer, const bsl::string_view &observerName)
Definition ball_loggermanager.h:2585

Next, we set the log category and log a few records with different logging severity. By default, only the records with e_WARN, e_ERROR, or e_FATAL severity will be logged to stdout. Note that logging to a file is not enabled by default:

BALL_LOG_SET_CATEGORY("ball::AsyncFileObserverTest");
BALL_LOG_INFO << "Will not be published on 'stdout'.";
BALL_LOG_WARN << "This warning *will* be published on 'stdout'.";
#define BALL_LOG_SET_CATEGORY(CATEGORY)
Definition ball_log.h:1210
#define BALL_LOG_WARN
Definition ball_log.h:1466
#define BALL_LOG_INFO
Definition ball_log.h:1462

Then, we change the default severity for logging to stdout by calling the setStdoutThreshold method:

observerPtr->setStdoutThreshold(ball::Severity::e_INFO);
BALL_LOG_DEBUG << "This debug message is not published on 'stdout'.";
BALL_LOG_INFO << "This info will be published on 'stdout'.";
BALL_LOG_WARN << "This warning will be published on 'stdout'.";
#define BALL_LOG_DEBUG
Definition ball_log.h:1458
@ e_INFO
Definition ball_severity.h:177

Next, we disable logging to stdout and enable logging to a file:

observer->setStdoutThreshold(ball::Severity::e_OFF);
// Create and log records to a file named "/var/log/task/task.log".
observer->enableFileLogging("/var/log/task/task.log");
@ e_OFF
Definition ball_severity.h:173

Note that logs are now asynchronously written to the file.

Then, we specify rules for log file rotation based on the size and time interval:

// Rotate the file when its size becomes greater than or equal to 32
// megabytes.
observer->rotateOnSize(1024 * 32);
// Rotate the file every 24 hours.
observer->rotateOnTimeInterval(bdlt::DatetimeInterval(1));
Definition bdlt_datetimeinterval.h:201

Note that in this configuration the user may end up with multiple log files for a specific day (because of the rotation-on-size rule).

Next, we demonstrate how to correctly shut down the async file observer. We first stop the publication thread by explicitly calling the stopPublicationThread method. This method blocks until all the log records that were on the record queue on entry to stopPublicationThread have been published:

observer->stopPublicationThread();

Then, we disable the log rotation rules established earlier and also completely disable logging to a file:

observer->disableSizeRotation();
observer->disableTimeIntervalRotation();
observer->disableFileLogging();

Note that stopping the publication thread and disabling various features of the async file observer is not strictly necessary before object destruction. In particular, if a publication thread is still running when the destructor is invoked, all records on the record queue upon entry are published and then the publication thread is automatically stopped before destroying the async file observer. In any case, all resources managed by the async file observer will be released when the object is destroyed.

Finally, we can deregister our async file observer from the ball logging subsystem entirely (and destroy the observer later):

rc = manager.deregisterObserver("asyncObserver");
assert(0 == rc);
int deregisterObserver(const bsl::string_view &observerName)
Definition ball_loggermanager.h:2556