# 20. Logging

AMPS supports logging to many different targets including the console, syslog, and files. Every error message within AMPS is uniquely identified and can be filtered out or explicitly included in the logger output. This chapter of the AMPS User Guide describes the AMPS logger configuration and the unique settings for each logging target.

## Configuration

Logging within AMPS is enabled by adding a Logging section to the configuration. For example, the following would log all messages with an ‘info’ level or higher to the console:

    <AMPSConfig>
        ...
        <Logging>

            <!-- The Logging section defines a single Target, which is used to log all messages
            to the stdout output. -->
            <Target>
                <Protocol>stdout</Protocol>

                <!-- States that only messages with a log level of info or greater will be output to
                the screen. -->
                <Level>info</Level>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

## Log Messages

An AMPS log message is composed of the following:

- Timestamp (eg: 2010-04-28T21:52:03.4766640-07:00)
- AMPS thread identifier
- Log Level (eg: info)
- Error identifier (eg: 15-0008)
- Log message

An example of a log line (it will appear on a single line within the log):

    2011-11-23T14:49:38.3442510-08:00 [1] info: 00-0015 AMPS initialization completed (0 seconds).

Each log message has a unique identifier of the form `TT-NNNN` where `TT` is the component within AMPS which is reporting the message and `NNNN` is the number that uniquely identifies that message within the module. Each logging target allows the direct exclusion and/or inclusion of error messages by identifier. For example, a log file which would include all messages from module `00` except for `00-0001` and `00-0004` would use the following configuration:

    <Logging>
        <Target>
            <Protocol>stdout</Protocol>
            <IncludeErrors>00-0002</IncludeErrors>
            <ExcludeErrors>00-0001,00-0004,12-1.*</ExcludeErrors>
        </Target>
    </Logging>

In the above `Logging` configuration example, all log messages which are at or above the default log level of `info` will be emitted to the logging target of `stdout`. The configuration explicitly wants to see configuration messages where the error identifier matches `00-0002`. Additionally, the messages which match `00-0001`, `00-0004` will be excluded, along with any messages which match the regular expression of `12-1.*`.

## Log Levels

AMPS has nine log levels of escalating severity. When configuring a logging target to capture messages for a specific log level, all log levels at or above that level are sent to the logging target. For example, if a logging target is configured to capture at the “error” level, then all messages at the “error”, “critical”, and “emergency” levels will be captured because “critical” and “emergency” are of a higher level. The following table contains a list of all the log levels within AMPS.

Level | Description
--- | ---
developer | Information on the internal state of AMPS, typically used by the AMPS developers. Messages logged at this level do not indicate issues, but instead report the detailed state of the AMPS process.
trace | All inbound/outbound data. Development and test instances are recommended to log at this level
debug | Obsolete. The AMPS server no longer logs messages at this level. Plugin modules that attempt to log messages at this level will log messages at info level instead. Instances that log at this level are recommended to use info level or trace level logging instead
stats | Statistics messages.
info | General information messages. Production applications are recommended to log at this level or more verbose
warning | Problems that AMPS tries to correct that are often harmless.
error | Events in which processing had to be aborted. Events at this level often indicate that a client will receive incomplete or incorrect results (for example, a subscription could not be entered because an unknown option was provided).
critical | Events impacting major components of AMPS that if left uncorrected may cause a fatal event or message loss.
emergency | A fatal event. AMPS will typically exit after logging an emergency-level event.
none | No logging, even in the case of a critical or fatal event.

Table 20.1: Log Levels

Each logging target allows the specification of a `Level` attribute that will log all messages at the specified log level or with higher severity. The default `Level` is `none`, which would log nothing. Optionally, each target also allows the selection of specific log levels with the `Levels` attribute. Within `Levels`, a comma separated list of levels will be additionally included.

For example, having a log of only `trace` messages may be useful for later playback, but since `trace` is at the lowest level in the severity hierarchy it would normally include all log messages. To only enable `trace` level, specify `trace` in the `Levels` setting as below:

    <AMPSConfig>
        ...
        <Logging>
            <Target>
                <Protocol>gzip</Protocol>
                <FileName>traces.log.gz</FileName>
                <Levels>trace</Levels>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

Logging only `trace` and `info` messages to a file is demonstrated below:

    <AMPSConfig>
        ...
        <Logging>
        <Target>
                <Protocol>file</Protocol>
                <FileName>traces-info.log</FileName>
                <Levels>trace,info</Levels>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

Logging `trace` and `info` messages in addition to levels of `error` and above (`error`, `critical` and `emergency`) is demonstrated below:

    <Target>
        <Protocol>file</Protocol>
        <FileName>traces-error-info.log</FileName>
        <Level>error</Level>
        <Levels>trace,info</Levels>
    </Target>

## Logging to a File

To log to a file, declare a logging target with a protocol value of `file`. Beyond the standard `Level`, `Levels`, `IncludeErrors`, and `ExcludeErrors` settings available on every logging target, file targets also permit the selection of a `FileName` mask and `RotationThreshold`.

### Selecting a Filename

The `FileName` attribute is a mask which is used to construct a directory and file name location for the log file. AMPS will resolve the file name mask using the symbols in the table below. For example, if a file name is masked as:

    %Y-%m-%dT%H:%M:%S.log

AMPS would create a log file in the current working directory with a timestamp of the form: `2012-02-23T12:59:59.log`.

If a `RotationThreshold` is specified in the configuration of the same log file, the next log file created will be named based on the current system time, not on the time that the previous log file was generated. Using the previous log file as an example, if the first rotation was to occur 10 minutes after the creation of the log file, then that file would be named `2012-02-23T13:09:59.log`.

Log files which need a monotonically increasing counter when log rotation is enabled can use the `%n` mask to provide this functionality. If a file is masked as:

    localhost-amps-%n.log

Then the first instance of that file would be created in the current working directory with a name of `localhost-amps-00000.log`. After the first log rotation, a log file would be created in the same directory named `localhost-amps-00001.log`.

Log file rotation is discussed in greater detail in the Log File Rotation section.

Mask | Definition
--- | ---
`%Y` | Year
`%m` | Month
`%d` | Day
`%H` | Hour
`%M` | Minute
`%S` | Second
`%n` | Iterator which starts at `00000` when AMPS is first started and increments each time a `RotationThreshold` size is reached on the log file.

Table 20.2: Log Filename Masks

### Log File Rotation

Log files can be “rotated” by specifying a valid threshold in the `RotationThreshold` attribute. Values for this attribute have units of bytes unless another unit is specified as a suffix to the number. The valid unit suffixes are:

Unit Suffix | Base Unit | Examples
--- | --- | ---
no suffix | bytes | “1000000” is 1 million bytes
k or K | thousands of bytes | “50k” is 50 thousand bytes
m or M | millions of bytes | “10M” is 10 million bytes
g or G | billions of bytes | “2G” is 2 billion bytes
t or T | trillions of bytes | “0.5T” is 500 billion bytes

Table 20.3: Log File Rotation Units

Tip

When using log rotation, if the next filename is the same as an existing file, the file will be truncated before logging continues. For example, if “amps.log” is used as the `FileName` mask and a `RotationThreshold` is specified, then the second rotation of the file will overwrite the first rotation. If it is desirable to keep all logging history, then it is recommended that either a timestamp or the `%n` rotation count be used within the `FileName` mask when enabling log rotation.

### Examples

The following logging target definition would place a log file with a name constructed from the timestamp and current log rotation number in the `./logs` subdirectory. The first log would have a name similar to `./logs/20121223125959-00000.log` and would store up to 2GB before creating the next log file named `./logs/201212240232-00001.log`.

    <AMPSConfig>
        ...
        <Logging>
            <Target>
                <Protocol>file</Protocol>
                <Level>info</Level>
                <FileName>./logs/%Y%m%d%H%M%S-%n.log</FileName>
                <RotationThreshold>2G</RotationThreshold>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

This next example will create a single log named `amps.log` which will be appended to during each logging event. If `amps.log` contains data when AMPS starts, that data will be preserved and new log messages will be appended to the file.

    <AMPSConfig>
        ...
        <Logging>
            <Target>
            <Protocol>file</Protocol>
            <Level>info</Level>
            <FileName>amps.log</FileName>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

## Logging to a Compressed File

AMPS supports logging to compressed files as well. This is useful when trying to maintain a smaller logging footprint. Compressed file logging targets are the same as regular file targets except for the following:

- The `Protocol` value is `gzip` instead of `file`
- The log file is written with gzip compression
- The `RotationThreshold` is metered off of the uncompressed log messages
- Makes a trade off between a small increase in CPU utilization for a potentially large savings in logging footprint

### Example

The following logging target definition would place a log file with a name constructed from the timestamp and current log rotation number in the `./logs` subdirectory. The first log would have a name similar to `./logs/20121223125959-0.log.gz` and would store up to 2GB of uncompressed log messages before creating the next log file named `./logs/201212240232-1.log.gz`.

    <AMPSConfig>
        ...
        <Logging>
            <Target>
                <Protocol>gzip</Protocol>
                <Level>info</Level>
                <FileName>./logs/%Y%m%d%H%M%S-%n.log.gz</FileName>
                <RotationThreshold>2G</RotationThreshold>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

## Logging to the Console

The console logging target instructs AMPS to log certain messages to the console. Both the standard output and standard error streams are supported. To select standard out use a `Protocol` setting of `stdout`. Likewise, for standard error use a `Protocol` of `stderr`.

### Example

Below is an example of a console logger that logs all messages at the `info` or `warning` level to standard out and all messages at the `error` level or higher to standard error (which includes `error`, `critical` and `emergency` levels).

    <AMPSConfig>
        ...
        <Logging>
            <Target>
                <Protocol>stdout</Protocol>
                <Levels>info,warning</Levels>
            </Target>
            <Target>
                <Protocol>stderr</Protocol>
                <Level>error</Level>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

## Logging to Syslog

AMPS can also log messages to the host’s syslog mechanism. To use the syslog logging target, use a `Protocol` of `syslog` in the logging target definition.

The host’s syslog mechanism allows a logger to specify an identifier on the message. This identifier is set through the `Ident` property and defaults to the AMPS instance name (see AMPS Configuration Reference Guide for configuration of the AMPS instance name.)

The syslog logging target can be further configured by setting the `Options` parameter to a comma-delimited list of syslog flags. The recognized syslog flags are:

Level | Description
--- | ---
`LOG_CONS` | Write directly to system console if there is an error while sending to system logger.
`LOG_NDELAY` | Open the connection immediately (normally, the connection is opened when the first message is logged).
`LOG_NOWAIT` | No effect on Linux platforms.
`LOG_ODELAY` | The converse of LOG_NDELAY; opening of the connection is delayed until `syslog()` is called. (This is the default, and need not be specified.)
`LOG_PERROR` | Print to standard error as well.
`LOG_PID` | Include PID with each message.

Table 20.4: Logging Options Available for SYSLOG Configuration

Tip

AMPS already includes the process identifier (PID) with every message it logs, however, it is a good practice to set the `LOG_PID` flag so that downstream syslog analysis tools will find the PID where they expect it.

The `Facility` parameter can be used to set the syslog “facility”. Valid options are: `LOG_USER` (the default), `LOG_LOCAL0`, `LOG_LOCAL1`, `LOG_LOCAL2`, `LOG_LOCAL3`, `LOG_LOCAL4`, `LOG_LOCAL5`, `LOG_LOCAL6`, or `LOG_LOCAL7`.

Finally, AMPS and the syslog do not have a perfect mapping between their respective log severity levels. AMPS uses the following table to convert the AMPS log level into one appropriate for the syslog:

AMPS Severity | Syslog Severity
--- | ---
none | LOG_DEBUG
developer | LOG_DEBUG
trace | LOG_DEBUG
debug | LOG_DEBUG
stats | LOG_INFO
info | LOG_INFO
warning | LOG_WARNING
error | LOG_ERR
critical | LOG_CRIT
emergency | LOG_EMERG

Table 20.5: Comparison of AMPS Log Severity to Syslog Severity

### Example

Below is an example of a syslog logging target that logs all messages at the `critical` severity level or higher and additionally the log messages matching `30-0000` to the syslog.

    <AMPSConfig>
        ...
        <Logging>
            <Target>
                <Protocol>syslog</Protocol>
                <Level>critical</Level>
                <IncludeErrors>30-0000</IncludeErrors>
                <Ident>\amps dma</Ident>
                <Options>LOG_CONS,LOG_NDELAY,LOG_PID</Options>
                <Facility>LOG_USER</Facility>
            </Target>
        </Logging>
        ...
    </AMPSConfig>

## Error Categories

In the AMPS log messages, the error identifier consists of an error category, followed by a hyphen, followed by an error identifier (eg. TT-NNNN). The error categories cover the different modules and features of AMPS, and can be helpful in diagnostics and troubleshooting by providing some context about where a message is being logged from. A list of the error categories found in AMPS are listed in the table below.

AMPS Code | Component
--- | ---
00 | AMPS Startup
01 | General
02 | Message Processing
03 | Expiration
04 | Publish Engine
05 | Statistics
06 | Metadata
07 | Client
08 | Regex
09 | ID Generator
0A | Diff Merge
0B | Out of Focus Processing
0C | View
0D | Message Data Cache
0E | Conflated Topic
0F | Message Processor Manager
11 | Connectivity
12 | Trace In - for inbound messages
13 | Datasource
14 | Subscription Manager
15 | SOW
16 | Query
17 | Trace Out - for outbound messages
18 | Parser
19 | Administration Console
1A | Evaluation Engine
1B | SQLite
1C | Meta Data Manager
1D | Transaction Log Monitor
1E | Replication Bootstrap Initialization
1F | Client Session
20 | Global Heartbeat
21 | Transaction Replay
22 | TX Completion
23 | Bookmark Subscription
24 | Thread Monitor
25 | Authorization
26 | SOW Cache
28 | Memory Cache
29 | Plug-in Modules (including AMPS features implemented as modules)
2A | Message Pipeline
2B | Module Manager
2C | File Management
2D | NUMA Module
2F | SOW Update Broadcaster
30 | AMPS Internal Utilities
31 | AMPS Queues
70 | AMPS Networking
FF | Shutdown

Table 20.6: AMPS Error Categories

## Using `amps-grep` to Find Information in Logs

The AMPS logs contain a record of events in the instance. Log messages are intended to be read as a part of that sequence of events. While an individual message is useful for showing that a particular event happened, the other messages in the log will show what sequence of events lead up to that event and what the results of that event were.

At the same time, an active AMPS instance with dozens or hundreds of active clients generates a high volume of events, which can make it difficult to locate and correlate the events that are relevant to a specific problem. To help with this, the AMPS distribution contains the `amps-grep` tool to make it easy to find information in the logs.

This section presents some of the most useful techniques for locating information in the logs using `amps-grep`.

### Finding Information for a Specific Client

When troubleshooting problems with a specific client (or connection), it’s often helpful to be able to see the full sequence of events for that client. For example, if AMPS is returning an invalid options message to a client, finding the command that the client is sending to AMPS and the detailed messages that AMPS logs in response, can be very helpful in understanding the details of the error.

To find information about a specific client, use the following general pattern:

    $ amps-grep client_name log_files > out.txt

The `amps-grep` command extracts every event that contains the client name from the log files, and then the Linux shell writes those events to the `out.txt` file. Because the `amps-grep` tool is aware of the structure of multi-line AMPS event records, it captures the full event message, not just the individual lines that contain the name of the client.

For example, if the client has a client name of `queue-processor-compute-host-39`, and the logs are stored in files with the suffix `.log`, the command to extract the events with that client name would be along the lines of:

    $ amps-grep 'queue-processor-compute-host-39' *.log > out.txt

This command will write every event message that contains a reference to the client `queue-processor-compute-host-39` to the `out.txt` file.

### Finding Information for a Specific Thread

Another situation where `amps-grep` can be useful is when it is important to get information about a specific thread in AMPS.

For example, in a situation where AMPS has produced a minidump, it is typically more useful to see the activity on the thread that produced the dump, than it is to see the activity of other threads near the time that the minidump was produced.

To track the sequence of events for a thread that produces a minidump, the first step is to find the AMPS identifier for the thread. This is the identifier used in the event log messages, which is different from the operating system assigned identifier for the thread. Then use that identifier to extract messages from the log.

For example, given a minidump message like the following:

    2020-04-25T07:27:59.1355850-07:00 [6] critical: 01-0022 AMPS has
    detected that it may not be running correctly and wrote a minidump to:
    /tmp/1516e4d1-8bca-b14b-17853753-45dba87b.dmp

AMPS has assigned thread ID `6` to this thread. For convenience in searching, AMPS always puts the thread ID in brackets at the beginning of the message (since `6`, by itself, is so common in the logs as to not be useful).

Extracting every message recorded by thread ID `6` in the log can be done with a command like the following:

    $ amps-grep ' [6] ' *.log > out.txt

With this command line, `amps-grep` locates all messages for that thread ID, and the Linux shell writes the results to the `out.txt` file.

### Tips for Using `amps-grep`

When using `amps-grep`, there are a few things to be aware of:

1. Unlike regular `grep`, by default `amps-grep` uses exact matching rather than regular expression matching. To use a regular expression, provide the `-E` option to `amps-grep`.

2. If you are searching multiple files and piping the output of one `amps-grep` command to another `amps-grep` command, use the `-h` flag to the first `amps-grep` to suppress the file name on matching lines. If you do not provide `-h`, the presence of the file name can interfere with `amps-grep` correctly identifying the start and end of each AMPS log message.

3. If you want to find more than one search term, you can use the `-e` flag to specify multiple search terms, for example:

       $ amps-grep -e 'error' -e 'warning' *.log

   Although it is possible to use a regular expression for a search like this, it is not necessary to do so.

4. The `amps-grep` utility provides a usage message with more details on the available options and usage.

## Looking Up Errors with ampserr

In the `$AMPSDIR/bin` directory is the `ampserr` utility. Running this utility is useful for getting detailed information and messages about specific AMPS errors observed in the log files.

The AMPS Utilities Guide contains more information on using the `ampserr` utility and other debugging tools.