Skip to content

Writing Application Logs

WolfgangTheilmann edited this page Jun 7, 2016 · 17 revisions

The Basics

As outlined in the README.md, we do support applications that write logs using the slf4j API in combination with one of the API implementations logback or log4j2.

So you need to decide

  • which logging implementation you use,
  • set your Maven dependencies, and
  • adjust your logging configurations accordingly

As we're talking about application logs in this section, we're only using the core feature and link it with the specific implementation. Since the core feature is pulled as a dependency in these implementation, we only need to add the dependency to the implementation.

Using logback

Maven Dependencies

<!-- pulls cf-java-logging-support-core feature -->
<dependency>
   <groupId>com.sap.hcp.cf.logging</groupId>
   <artifactId>cf-java-logging-support-logback</artifactId>
   <version>${cf-logging-version}</version>
</dependency>
<!-- logback -->
<dependency>
   <groupId>ch.qos.logback</groupId>
   <artifactId>logback-classic</artifactId>
   <version>1.1.3</version>
</dependency>

Logging Configuration

Our logback implementation provides a dedicated logback encoder which you want to configure as your default in your logback.xml like this:

<configuration debug="false" scan="false">
   <appender name="STDOUT-JSON" class="ch.qos.logback.core.ConsoleAppender">
      <encoder class="com.sap.hcp.cf.logback.encoder.JsonEncoder"/>
   </appender>
   <root level="${LOG_ROOT_LEVEL:-WARN}">
      <appender-ref ref="STDOUT-JSON" />
   </root>
</configuration>

Using log4j2

Maven Dependencies

<!-- pulls cf-java-logging-support-core feature -->
<dependency>
   <groupId>com.sap.hcp.cf.logging</groupId>
   <artifactId>java-logging-support-log4j2</artifactId>
   <version>${cf-logging-version}</version>
</dependency>
<!-- log4j2 including the slj4j implementation-->
<dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-slf4j-impl</artifactId>
   <version>2.4.1</version>
</dependency>
<dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-core</artifactId>
   <version>2.4.1</version>
</dependency>

Logging Configuration

Our log4j2 implementation provides a dedicated layout which you want to configure as your default in your log4j2.xml like this:

<Configuration status="warn" strict="true" packages="com.sap.hcp.cf.log4j2.converter,com.sap.hcp.cf.log4j2.layout">
   <Appenders>
      <Console name="STDOUT-JSON" target="SYSTEM_OUT" follow="true">
         <JsonPatternLayout charset="utf-8"/>
      </Console>
   <Loggers>
      <Root level="${LOG_ROOT_LEVEL:-WARN}">
         <!-- Use 'STDOUT' instead for human-readable output -->
         <AppenderRef ref="STDOUT-JSON" />
      </Root>
   </Loggers>
</Configuration>     

Logging Exceptions

Whenever you need to report an exception, you most likely want to include (a part) of the stack trace in that message. To do so, you should simple use the standard pattern and pass the exception object as a parameter:

logger.error("some accompanying message", ex);

This will produce a formatted, single-line, log message which, instead of writing the stack trace as multiple lines, reports the stack trace within an additional array field stacktrace which will make the life of log parsers much easier.

Invoking [http://localhost:8080/log-sample-app/stacktrace] for the sample application will yield a (fairly long) log line like this:

  
{ "written_at":"2016-03-24T11:49:04.861Z","written_ts":31713016750207,"component_type":"application","component_id":"-","space_name":"-","component_name":"-","component_instance":"0","organization_id":"-","correlation_id":"abbabb88-aea4-42cb-a545-e645f2162736","organization_name":"-","space_id":"-","request_id":"-","container_id":"-","type":"log","logger":"com.iamjambay.cloudfoundry.stickysession.MainServlet","thread":"http-bio-8080-exec-8","level":"ERROR","categories":[],"msg":"Exception occured","stacktrace":["java.lang.NullPointerException","at com.iamjambay.cloudfoundry.stickysession.MainServlet.doGet(MainServlet.java:123)","at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)","at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)","at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)","at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)","at com.sap.hcp.cf.logging.servlet.filter.RequestLoggingFilter.doFilterRequest(RequestLoggingFilter.java:95)","at com.sap.hcp.cf.logging.servlet.filter.RequestLoggingFilter.doFilter(RequestLoggingFilter.java:54)","at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)","at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)","at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)","at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)","at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)","at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)","at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)","at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)","at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)","at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)","at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)","at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)","at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)","at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)","at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)","at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)","at java.lang.Thread.run(Thread.java:745)"] }

Logging Categories

We mentioned in the Overview that there is one additional field categories that will allow you to assign categories to individual log messages. You may, e.g., want to tag any log message that deals with database calls with a category db-call, such that later on, log analysis may use this information as an additional filter facet.

In order to fill that field, you create Marker via the MarkerFactory utility class:

Marker dbCall = MarkerFactory.getMarker("db-call");
String logMsg = createMsg(request);

LOGGER.info(dbCall, logMsg);

Note: You can use almost any string for creating a marker, except for those used internally, which are defined in Markers.java.

Custom Fields

While we provide quite a number of fields out of the box, there might be situations where you need additional fields. If that's the case, you should pass them as additional parameters of type CustomField to your log message:

import static com.sap.hcp.cf.logging.common.customfields.CustomField.customField;

// stuff omitted for brevity 

LOGGER.info("Logging with custom field {}", customField("customKey", customValue"));

Mapped Diagnostic Contexts (MDC)

You can, of course, add additional information to log messages by putting it into the MDC. These key/value pairs will show up as additional fields in the log message. In that sense, they are similar to custom fields, but will be emitted for all log messages as long as they are defined.

Note:As we're using this technique internally to propagate context information across the call stack, there are a number of predefined context fields that cannot be set or overridden using MDC. Please refer to LogContext.java for details.

Clone this wiki locally