Logging

Logging is an essential aspect of application development, and it plays a crucial role in monitoring and debugging applications. In Java, there are several logging libraries available. The OCS.io application uses Logback, which is one of the most popular and widely used logging libraries. Logback is an open-source, feature-rich logging library that provides support for various logging frameworks, including Log4j and SLF4J (which is used within OCS.io).

The OCS.io utilizes concept of MDC. MDC stands for Mapped Diagnostic Context, and it is a feature provided by various logging frameworks, including Logback, Log4j, and SLF4J. MDC allows you to store context-specific data, such as a user’s session ID, thread ID, or any other relevant metadata, and include this data in your log messages.

MDC is particularly useful in multi-threaded applications where multiple threads may be executing concurrently, and it may be challenging to track which log message came from which thread. By using MDC, you can add a unique identifier to each thread’s context, making it easy to identify which thread generated which log message.

In this chapter, we will explore how to set up logging in the OCS.io application deployment using the Logback library.

Add Logback dependency to your project

The first step to start using Logback is to add the Logback dependency to your project. You can do this by adding the following dependency to your pom.xml file if you are using Maven.

<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>${logbackVersion}</version>
</dependency>

If you are using Gradle, add the following dependency to your build.gradle file:

implementation 'ch.qos.logback:logback-classic:${logbackVersion}'

Create a Logback configuration file

The next step is to create a Logback configuration file. The Logback configuration file tells Logback how to log messages, where to log messages, and what to log. You can create a Logback configuration file in XML or Groovy format.

Here is an example of a standard OCS.io Logback configuration file in XML format:

<configuration>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="STDOUT-PBS" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - transactionId=%X{transactionId} - %msg%n</pattern>
        </encoder>
    </appender>


    <logger name="io.ocs.pbs" level="info" additivity="false">
        <appender-ref ref="STDOUT-PBS" />
    </logger>

    <root level="info">
        <appender-ref ref="STDOUT" />
    </root>

</configuration>

Above configurations will ensure that:

OCS.io modules will log to standard output using Logback library
log entries from OCS.io will be logged including MDC key-value pair "Business Transaction ID" (in log named as "transactionId" which will enable to correlate multiple log entries into one logical business transaction
log entries other than OCS.io will be logged without "Business Transaction ID"

for more detailed configuration refer to Logback documentation.

Read and process the log

The next step is to read and process produced log entries. It differs deployment by deployment how logs are processed.

Following lines are the typical log entries after CASM 'CreateCustomer' API has been called from an external system:

2023-04-01 00:00:00.000 [http-nio-8881-exec-2] INFO  i.o.f.common.api.AbstractBulkAPI - transactionId=769d977a-86fe-436d-94ce-847cb4546045 - Request 'CreateCustomer' received,"parameters":{"requestId": "769d977a-86fe-436d-94ce-847cb4546045", "transactionId": "769d977a-86fe-436d-94ce-847cb4546045", "externalId": "CUST-DEMO-03", "customName": "Demo Customer #3", "state": ACTIVE, "stateReason": "active", "customAttributes.key1": "value 1", "customAttributes.key2": "value 2"}
....
2023-04-01 00:00:00.000 [http-nio-8881-exec-2] INFO  i.o.f.common.api.AbstractBulkAPI - transactionId=769d977a-86fe-436d-94ce-847cb4546045 - Request 'CreateCustomer' finished,"parameters":{"requestId": "769d977a-86fe-436d-94ce-847cb4546045", "transactionId": "769d977a-86fe-436d-94ce-847cb4546045", "externalId": "CUST-DEMO-03", "customName": "Demo Customer #3", "state": ACTIVE, "stateReason": "active", "customAttributes.key1": "value 1", "customAttributes.key2": "value 2", "status": "OK", "duration": 301}

From the above example we can see that:

Each log entry from OCS.io contains MDC key-value pair "transactionId", in our example value transactionId=769d977a-86fe-436d-94ce-847cb4546045.
Message of the log consists of message itself and optionally additional parameters:
- in our example message is Request 'CreateCustomer' received or Request 'CreateCustomer' finished
- in our example optional parameters are present in format of json - "parameters": {"key1": "value1", "key2": "value2"}
In the Response log entry parameters "status" and "duration" are always added:
- "status" is a string value representing status of the operation, it is enumeration with values "OK" and "Error".
- "duration" is a long integer value representing duration of the operation in milliseconds.
In case "status" = "Error", additional parameters are added: "error.code", "error.message" and optionally "error.violations" containing list of all violations.

2023-04-01 00:00:00.000 [http-nio-8881-exec-6] INFO  i.o.f.common.api.AbstractGetAPI - transactionId=ba5f461f-ce03-4b2c-9d53-72399ca21fbf - Request 'ReadCustomer' finished,"parameters":{"transactionId": "ba5f461f-ce03-4b2c-9d53-72399ca21fbf", "customer.externalId": "CUST-DEMO-NOT-EXIST", "accounts": false, "offers": false, "status": "Error", "duration": 8, "error.code": "CMN-VALIDATION-FAILED", "error.message": "Validation of the Request failed. Check 'violations' for more details.", "error.violations": [{path='customer', code='validation.NotExists'}]}

Please refer to Logging section in Operations & Maintenance guide.