Logging
This page documents the real implementation of ROAD's logging and the ideas behind. A manual how-to use and work with log files is an extra topic.
Topics
ROAD Logging General
Every ROAD process running on a ROAD host writes event information into a log file, which mostly has a limited lifetime as it's intended for troubleshooting and analysis purposes only.
ROAD maintains two directories keeping the log files: One for the ROAD Service and one for the ROAD Workers. Usually both are sub-folders of a common log folder (by default ProgramData\ROAD\Logging).
ROAD provides a special plugin for the LogExpert tool, which allows to analysis a complete set of log files with ROAD's format.
File Creation and Rotation
A new log file is created each time a ROAD process is being started. When a log file extends a specific size (default is about 10 MB), it is closed and extended with a new file, where the rotation counter is incremented.
For the Service this occurs quite infrequent (the Service is restartet only for maintenance reasons).
The Worker is started and ended for each single job, so there's a bigger amount of log files for Workers. If workers are started in advance (usual configuration to increase speed of job creation), the file creation time may be distinctly before the actual job run time.
File Cleanup and Archiving
To avoid flooding with log files, older ones are automatically deleted or shifted to an archive folder. This purging is configurable; it allows different criteria like by age or number of files and where to archive them (or alternatively delete them).
See paragraph "Purging Oldest Log Files" below.
File Naming
ROAD's log file names follow the pattern "RoadService_yyyy-hh-mm_c.log" or "RoadWorker_(p)_yyyy-hh-mm_c.log", with yyyy=year, hh=hour, mm=minute, c=rotation counter, p=process id.
Header
ROAD's log files are introduced with a header showing general information like this:
*****************************************************
** Logging session starting
** Executable: C:\Program Files\ROAD\RoadService.exe 0.1.143.0, process id 4156
** Time zone: UTC-2:00 W. Europe Daylight Time
** Log severity at least: I
*****************************************************
Footer
Finished Process' Footer
A closed log file always has a footer at its end. If there is no footer, the process is still running.
When a process is terminating, it adds a footer like this:
*****************************************************
Logging finishes in this program session.
Header and Footer with Exceeded Rotation Size
If a log file is being closed due to its size (exceeding the configured rotation size), the log file ends with:
*****************************************************
Logging session is being continued in a new file => ...
Then a new log file is created having the same name, except the rotation counter, which is incremented. The new log file's header looks like this:
*****************************************************
... => Logging session continues (complementing former log file)
** Executable: C:\Program Files\RoadWorker.exe 0.1.143.0, process id 14760
** Time zone: UTC-2:00 W. Europe Daylight Time
** Log severity at least: I
*****************************************************
Log Entries
Each log event is documented with one entry, which is a text line with a specific format, ending with a line break (\n). Entries start with their time stamp. They appear in chronological sequence.
Format
Each entry contains these fields, which are separated by tabs (\t). Each entry starts at the beginning of a text line. Entries with a message extending more than one line are indented, so all lines starting with an indention (two space characters) are the continuation of the former entry's message.
Above all entries a head line is written containing all field titles.
| Head line | Field | Description |
|---|---|---|
| Date | Date (YYYY-MM-DD) | Date when entry was created |
| Time | Time (HH:mm:ss.sss) | Time when entry was created. Post-comma digits contain the milliseconds. (Used time zone is described in log file header.) |
| Thrd | Thread ID | Numeric id of Windows thread having written this entry |
| File | Creation's code: Source file | Internal information about the entry's origin |
| Line | Creation's code: Source file line | Internal information about the entry's origin |
| Function | Creation's code: Name of function | Internal information about the entry's origin |
| Priority | Priority | Priority of entry (see below) |
| Severity | Severity | Severity of entry (see below) |
| Module | Module (name of EXE/DLL/OCX) | Originating executable module's file name |
| Message | Log message | The message. If extending several lines, the next lines are indented. |
Priority and Severity
Each log entry has a priority and a severity. Both can be used for reducing the amount of log entries and the size of log files by filtering more or less obvious or important entries. For this a minimal severity can be configured.
Priority is a numerical value which could be used to filter log output but has no semantic meaning. In future a threshold could become configurable, which only lets messages pass whose priority is above this threshold. 
Yet the priority is always zero and not used.
Severity is a value with one of these values (ordered from less to more severe ones):
| Abbreviation | Meaning | Description |
|---|---|---|
| D | debug | Program-internal information mostly not needed |
| I | info | Information |
| S | success | Something was processed successfully Not yet used. Will we maintain this  |
| W | warning | Warning due to a reason |
| E | error | An error occurred |
| V | severe | Something severe occurred Not yet used. Will we maintain this |
| F | fatal | Something fatal occurred. Mostly this event causes a process to terminate irregularly. |
Purging Oldest Log Files
To avoid flooding with log files, older ones are automatically deleted or shifted to an archive folder.
Features
- The functionality includes
- purging files based on their "last write" time stamp
- purging files based on the number of log files
- purging by deleting files
- purging by moving files
- The purge action is executed immediately after the service starts, and then on regular intervals.
- Purging always proceeds from the oldest file to younger files.
- The operation is applied to service and worker log files, and service and worker files have separate sets of configuration values.
- Files with names that do not conform to the name pattern for log files do not take part in the purging; they are simply ignored and do not even count against the number of files in the log directory. For example, a file whose name indicates a date like 2018-02-29 will be ignored because this is not a valid date.
Combined Effect of "Purge by Days" and "Purge by Number"
- ServiceLogFilesPurgeByDays = 2 means: Purge service log files that were last modified before the day before yesterday.
- ServiceLogFilesPurgeByNumber = 100 means: If the number of service log files exceeds 100, then purge the oldest files so that only 100 remain.
- Setting ServiceLogFilesPurgeByDays = 2, and, at the same time, ServiceLogFilesPurgeByNumber = 100, means: Purge files that were last modified before the day before yesterday, but only so many that 100 survive.
- To have only one of them both criteria apply, set the other to 0.
- Set both parameters to 0 to completely disable purging.
Configuration
The logging configuration for Service and Workers both is placed in the Service's RoadService.exe.config file.
| Parameter | Default | Description |
|---|---|---|
| LogFilesPurgeInterval | 43200 (= 12 hours) | Time interval (in seconds) when the ROAD Service cares for purging old log files. Set to 0 to purge just once at service startup or leave empty to disable purging. |
| ServiceLogFilesArchivePath WorkerLogFilesArchivePath | <empty> | Directory in file system to shift old log files to when purged. Leave this setting empty to get purged log files deleted. |
| ServiceLogFilesPurgeByDays WorkerLogFilesPurgeByDays | 7 | Purge log files older than this amount of days (0 or more) Files that were created that many or fewer days ago will not be purged. For testing purposes, you use values like 120s, i.e., a number immediately followed by s, to denote seconds instead of days. |
| ServiceLogFilesPurgeByNumber WorkerLogFilesPurgeByNumber | 100 | Purge the oldest log files exceeding this amount (0 or more). Purging will leave at least that many files of the respective category (service or worker) in the directory. |
| ServiceLoggingPath WorkerLoggingPath | C:\ProgramData\ROAD\Logging\Service C:\ProgramData\ROAD\Logging\Worker | Directories to store log files in |
| ServiceLogMinimalSeverity WorkerLogMinimalSeverity | I = Info | Minimal severity to filter log entries |
| ServiceLogRotationSize WorkerLogRotationSize | 10000000 | File size to close a growing log size and continue in a new one with incremented counter in filename. This number is an approximate value. |