devonfw guide

Logging

We recommend to use SLF4J as API for logging, that has become a de facto standard in Java as it has a much better design than java.util.logging offered by the JDK. There are serveral implementations for SLF4J. For Spring applications our recommended implementation is Logback. Quarkus uses JBoss Logging which provides a JBoss Log Manager implementation for SLF4J. For more information on logging in Quarkus, see the Quarkus logging guide.

Logging Dependencies

To use Logback in your Spring application, you need to include the following dependencies:

<!-- SLF4J as logging API -->
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-api</artifactId>
</dependency>
<!-- Logback as logging implementation  -->
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
</dependency>
<!-- JSON logging for cloud-native log monitoring -->
<dependency>
  <groupId>net.logstash.logback</groupId>
  <artifactId>logstash-logback-encoder</artifactId>
</dependency>

In devon4j these dependencies are provided by the devon4j-logging module.

In Quarkus, SLF4J and the slf4j-jboss-logmanager are directly included in the Quarkus core runtime and can be used out of the box.

Logger Access

The general pattern for accessing loggers from your code is a static logger instance per class using the following pattern:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MyClass {
  private static final Logger LOG = LoggerFactory.getLogger(MyClass.class);
  ...
}

For detailed documentation how to use the logger API check the SLF4j manual.

Note	In case you are using devonfw-ide and Eclipse you can just type `LOG` and hit `[ctrl][space]` to insert the code pattern including the imports into your class.

Lombok

In case you are using Lombok, you can simply use the @Slf4j annotation in your class. This causes Lombok to generate the logger instance for you.

Log-Levels

We use a common understanding of the log-levels as illustrated by the following table. This helps for better maintenance and operation of the systems.

Table 44. Log-levels
Log-level	Description	Impact	Active Environments
FATAL	Only used for fatal errors that prevent the application to work at all (e.g. startup fails or shutdown/restart required)	Operator has to react immediately	all
ERROR	An abnormal error indicating that the processing failed due to technical problems.	Operator should check for known issue and otherwise inform development	all
WARNING	A situation where something worked not as expected. E.g. a business exception or user validation failure occurred.	No direct reaction required. Used for problem analysis.	all
INFO	Important information such as context, duration, success/failure of request or process	No direct reaction required. Used for analysis.	all
DEBUG	Development information that provides additional context for debugging problems.	No direct reaction required. Used for analysis.	development and testing
TRACE	Like DEBUG but exhaustive information and for code that is run very frequently. Will typically cause large log-files.	No direct reaction required. Used for problem analysis.	none (turned off by default)

Exceptions (with their stack trace) should only be logged on FATAL or ERROR level. For business exceptions typically a WARNING including the message of the exception is sufficient.

Configuration of Logback

The configuration of logback happens via the logback.xml file that you should place into src/main/resources of your app. For details consult the logback configuration manual.

Note	Logback also allows to overrule the configuration with a `logback-test.xml` file that you may put into `src/test/resources` or into a test-dependency.

Configuration in Quarkus

The are several options you can set in the application.properties file to configure the behaviour of the logger in Quarkus. For a detailed overview, see the corresponding part of the Quarkus guide.

JSON-logging

For easy integration with log-monitoring, we recommend that your app logs to standard out in JSON following JSON Lines.

In Spring applications, this can be achieved via logstash-logback-encoder (see dependencies). In Quarkus, it can be easily achieved using the quarkus-logging-json extension (see here for more details).

This will produce log-lines with the following format (example formatted for readability):

{
  "timestamp":"2000-12-31T23:59:59.999+00:00",
  "@version":"1",
  "message":"Processing 4 order(s) for shipment",
  "logger_name":"com.myapp.order.logic.UcManageOrder",
  "thread_name":"http-nio-8081-exec-6",
  "level":"INFO",
  "level_value":20000,
  "appname":"myapp",
}

Adding custom values to JSON log with Logstash

The JSON encoder even supports logging custom properties for your log-monitoring. The trick is to use the class net.logstash.logback.argument.StructuredArguments for adding the arguments to you log message, e.g.

import static net.logstash.logback.argument.StructuredArguments.v;

...
    LOG.info("Request with {} and {} took {} ms.", v("url", url), v("status", statusCode), v("duration", millis));
...

This will produce the a JSON log-line with the following properties:

...
  "message":"Request with url=https://api/service/v1/ordermanagement/order and status=200 took duration=251 ms",
  "url":"https://api/service/v1/ordermanagement/order",
  "status":"200",
  "duration":"251",
...

As you can quickly see besides the human readable message you also have the structured properties url, status and duration that can be extremly valuable to configure dashboards in your log-monitoring that visualize success/failure ratio as well as performance of your requests.

Classic log-files

Note	In devon4j, we strongly recommend using JSON logging instead of classic log files. The following section refers only to devon4j Spring applications that use Logback.

Even though we do not recommend anymore to write classical log-files to the local disc, here you can still find our approach for it.

Maven-Integration

In the pom.xml of your application add this dependency:

<dependency>
  <groupId>com.devonfw.java</groupId>
  <artifactId>devon4j-logging</artifactId>
</dependency>

The above dependency already adds transitive dependencies to SLF4J and logback. Also it comes with configration snipplets that can be included from your logback.xml file (see configuration).

The logback.xml to write regular log-files can look as following:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds">
  <property resource="com/devonfw/logging/logback/application-logging.properties" />
  <property name="appname" value="MyApp"/>
  <property name="logPath" value="../logs"/>
  <include resource="com/devonfw/logging/logback/appenders-file-all.xml" />
  <include resource="com/devonfw/logging/logback/appender-console.xml" />

  <root level="DEBUG">
    <appender-ref ref="ERROR_APPENDER"/>
    <appender-ref ref="INFO_APPENDER"/>
    <appender-ref ref="DEBUG_APPENDER"/>
    <appender-ref ref="CONSOLE_APPENDER"/>
  </root>

  <logger name="org.springframework" level="INFO"/>
</configuration>

The provided logback.xml is configured to use variables defined on the config/application.properties file. On our example, the log files path point to ../logs/ in order to log to tomcat log directory when starting tomcat on the bin folder. Change it according to your custom needs.

Listing 13. config/application.properties

log.dir=../logs/

Log Files

The classical approach uses the following log files:

Error Log: Includes log entries to detect errors.
Info Log: Used to analyze system status and to detect bottlenecks.
Debug Log: Detailed information for error detection.

The log file name pattern is as follows:

«LOGTYPE»_log_«HOST»_«APPLICATION»_«TIMESTAMP».log

Table 45. Segments of Logfilename
Element	Value	Description
«LOGTYPE»	info, error, debug	Type of log file
«HOST»	e.g. mywebserver01	Name of server, where logs are generated
«APPLICATION»	e.g. myapp	Name of application, which causes logs
«TIMESTAMP»	YYYY-MM-DD_HH00	date of log file

Example: error_log_mywebserver01_myapp_2013-09-16_0900.log

Error log from mywebserver01 at application myapp at 16th September 2013 9pm.

Output format

We use the following output format for all log entries to ensure that searching and filtering of log entries work consistent for all logfiles:

[D: «timestamp»] [P: «priority»] [C: «NDC»][T: «thread»][L: «logger»]-[M: «message»]

D: Date (Timestamp in ISO8601 format e.g. 2013-09-05 16:40:36,464)
P: Priority (the log level)
C: Correlation ID (ID to identify users across multiple systems, needed when application is distributed)
T: Thread (Name of thread)
L: Logger name (use class name)
M: Message (log message)

Example:

[D: 2013-09-05 16:40:36,464] [P: DEBUG] [C: 12345] [T: main] [L: my.package.MyClass]-[M: My message...]

Note	When using devon4j-logging, this format is used by default. To achieve this format in Quarkus, set `quarkus.log.console.format=[D: %d] [P: %p] [C: %X] [T: %t] [L: %c] [M: %m]%n` in your properties.

Correlation ID

In order to correlate separate HTTP requests to services belonging to the same user / session, we provide a servlet filter called DiagnosticContextFilter. This filter takes a provided correlation ID from the HTTP header X-Correlation-Id. If none was found, it will generate a new correlation id as UUID. This correlation ID is added as MDC to the logger. Therefore, it will then be included to any log message of the current request (thread). Further concepts such as service invocations will pass this correlation ID to subsequent calls in the application landscape. Hence you can find all log messages related to an initial request simply via the correlation ID even in highly distributed systems.

Security

In order to prevent log forging attacks you can simply use the suggested JSON logging format. Otherwise you can use com.devonfw.module.logging.common.impl.SingleLinePatternLayout as demonstrated here in order to prevent such attacks.