# Logging on Multi Model Server

In this document we will go through logging mechanism in Multi Model Server. We will also go over how to modify the behavior of logging in model-server. Logging in Multi Model Server also covers
metrics, as metrics are logged into a file. To further understand how to customize metrics or define custom logging layouts, refer to the [metrics document](metrics.md)

# Pre-requisites
Before getting into this tutorials, you must familiarize yourself with log4j2 configuration. Refer to this online [document](https://logging.apache.org/log4j/2.x/manual/configuration.html) on how to configure the log4j2 parameters. Similarly, familiarize yourself with the default [log4j2.xml](../frontend/server/src/main/resources/log4j2.xml) used by Multi Model Server.

# Types of logs
Multi Model Server currently provides three types of logs.
1. Access Logs.
1. Model Server Logs.

## Access Logs:
These logs collect the access pattern to Multi Model Server. The configuration pertaining to access logs are as follows,
```xml
        <RollingFile
                name="access_log"
                fileName="${env:LOG_LOCATION:-logs}/access_log.log"
                filePattern="${env:LOG_LOCATION:-logs}/access_log.%d{dd-MMM}.log.gz">
            <PatternLayout pattern="%d{ISO8601} - %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="100 MB"/>
                <TimeBasedTriggeringPolicy/>
            </Policies>
            <DefaultRolloverStrategy max="5"/>
        </RollingFile>
```

As defined in the properties file, the access logs are collected in {LOG_LOCATION}/access_log.log file. When we load the model server
with a model and run inference against the server, the following logs are collected into the access_log.log
```text
2018-10-15 13:56:18,976 [INFO ] BackendWorker-9000 ACCESS_LOG - /127.0.0.1:64003 "POST /predictions/resnet-18 HTTP/1.1" 200 118
```
The above log tells us that a successful `POST` call to `/predictions/resnet-18` was made by remote host `127.0.0.1:64003` it took `118`ms to complete this request.

These logs are useful to determine the current performance of the model-server as well as understand the requests received by model-server.

## Model Server Logs
These logs collect all the logs from Model Server and from the backend workers (the custom model code).
The default configuration pertaining to mms logs are as follows:
```xml
        <RollingFile
                name="mms_log"
                fileName="${env:LOG_LOCATION:-logs}/mms_log.log"
                filePattern="${env:LOG_LOCATION:-logs}/mms_log.%d{dd-MMM}.log.gz">
            <PatternLayout pattern="%d{ISO8601} [%-5p] %t %c - %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="100 MB"/>
                <TimeBasedTriggeringPolicy/>
            </Policies>
            <DefaultRolloverStrategy max="5"/>
        </RollingFile>
```

This configuration by default dumps all the logs above `DEBUG` level. 

### Generating and logging custom logs
As a user of Multi Model Server(MMS), you might want to log custom logs into the log files. This could be for debug purposes or
to log any errors. To accomplish this, simply print the required logs to `stdout/stderr`. MMS will capture the logs generated by the 
backend workers and log it into the log file. Some examples of logs are as follows

1. Messages printed to stderr 
```text
2018-10-14 16:46:51,656 [WARN ] W-9000-stderr com.amazonaws.ml.mms.wlm.WorkerLifeCycle - [16:46:51] src/nnvm/legacy_json_util.cc:209: Loading symbol saved by previous version v0.8.0. Attempting to upgrad\
e...
2018-10-14 16:46:51,657 [WARN ] W-9000-stderr com.amazonaws.ml.mms.wlm.WorkerLifeCycle - [16:46:51] src/nnvm/legacy_json_util.cc:217: Symbol successfully upgraded!
```
 
1. Messages printed to stdout 
```text
2018-10-14 16:59:59,926 [INFO ] W-9000-stdout com.amazonaws.ml.mms.wlm.WorkerLifeCycle - preprocess time: 3.60
2018-10-14 16:59:59,926 [INFO ] W-9000-stdout com.amazonaws.ml.mms.wlm.WorkerLifeCycle - inference time: 117.31
2018-10-14 16:59:59,926 [INFO ] W-9000-stdout com.amazonaws.ml.mms.wlm.WorkerLifeCycle - postprocess time: 8.52
```

# Modifying the behavior of the logs
In order to modify the default behavior of the logging, you could define `log4j2.xml` file. There are two ways of starting
model server with custom logs

### Provide with config.properties
 Once you define custom `log4j2.xml`, add this to the `config.properties` file as follows

```properties
vmargs=-Dlog4j.configurationFile=file:///path/to/custom/log4j2.xml
```
Then start the model server as follows
```bash
$ multi-model-server --start --mms-config /path/to/config.properties
```
### Provide with CLI 
Alternatively, you could start the model server with the following command as well

```bash
$ multi-model-server --start --log-config /path/to/custom/log4j2.xml
```

# Enable asynchronous logging
If your model is super lightweight and seeking for high throughput, you can consider enable asynchronous logging.
Note that log output maybe delayed and latest log might be lost if MMS is terminated unexpectedly.
asynchronous logging is disabled by default.
To enable asynchronous logging, add following property in `config.properties`:
 
```properties
async_logging=true
```
