Skip to content

Overview

altenhof edited this page Mar 24, 2016 · 6 revisions

Java Logging Support for Cloud Foundry

This is a collection of support libraries for Java applications running on Cloud Foundry that serve two main purposes: It provides (a) means to emit structured application log messages and (b) instrument parts of your application stack to collect request metrics.

When we say structured, we actually mean in JSON format. In that sense, it's shares ideas with logstash-logback-encoder (and a first internal version was actually based on it), but takes a simpler approach as we want to ensure that these structured messages adhere to standardized formats. With such standardized formats in place, it becomes much easier to ingest, process and search such messages in log analysis stacks like, e.g., ELK.

A Short Overview of the Log Formats

While the full specification of the log formats can be found in the beats folder, we start off with a short overview of what messages would look like when using these support libraries.

Application Logs

If you run the sample application locally and access it's default page you'll see a log line printed to the console similar to this:

{ "written_at":"2016-03-24T09:22:14.085Z","written_ts":25268028630425,"component_type":"application","component_id":"-","space_name":"-","component_name":"-","component_instance":"0","organization_id":"-","correlation_id":"83b522f3-bdd6-49cd-82c6-b269bf17658c","organization_name":"-","space_id":"-","request_id":"-","container_id":"-","type":"log","logger":"com.sap.hcp.cf.sample.PickGreeting","thread":"http-bio-8080-exec-3","level":"INFO","categories":[],"msg":"Picked greeting : Bonjour!" }

This line actually stems from the following log statement in the code

		LOGGER.info("Picked greeting : {}", greeting);

The fields that should be familiar to you are logger, thread, level, and msg and directly correspond to pattern fields known from log4j2 or logback. There is, of course, also a "date" included in that message, but we've decided to call that field written_at. Next to it is a field written_ts which represents the "timestamp" when the message was written (using System.nanoTime()).

The field categories may contain additional category keys that can be later used to filter log messages by specific categories. How this field can be filled is covered in more detail in the section Writing Application Logs.

The remaining fields provide context information that is either derived from information provided by the Cloud Foundry runtime environment or via request instrumentation and is kept in mapped diagnostic contexts.

Request Metrics

In the console output of the sample application, you will also find a log line like this:

{ "written_at":"2016-03-24T09:22:14.102Z","written_ts":25268044216240,"component_type":"application","component_id":"-","space_name":"-","component_name":"-","component_instance":"0","organization_id":"-","correlation_id":"83b522f3-bdd6-49cd-82c6-b269bf17658c","organization_name":"-","space_id":"-","request_id":"-","container_id":"-","type":"request","request":"/logging-sample-app/","referer":"-","response_sent_at":"2016-03-24T09:22:14.089Z","response_status":200,"method":"GET","response_size_b":4039,"request_size_b":-1,"remote_port":"54559","layer":"[SERVLET]","remote_host":"0:0:0:0:0:0:0:1","x_forwarded_for":"-","remote_user":"-","protocol":"HTTP/1.1","remote_ip":"0:0:0:0:0:0:0:1","response_content_type":"text/html;charset=UTF-8","request_received_at":"2016-03-24T09:22:13.925Z","response_time_ms":163.783938,"direction":"IN"}

As you can see, it's shares all the context fields with application log messages. The log pattern fields though have been replaced by a set of request metric fields, like, e.g., response_status, response_time_ms, and response_size_b.

Correlation IDs

You may also notice that both log messages contain a field correlation_id which allows you to correlate an incoming request to application log messages that have been emitted during the cause of processing that request.

Note that an application log will only reported a meaningful correlation ID if that has been injected into the context information via proper instrumentation.

The available instrumentation libraries will be covered in the section Request Instrumentation.

Clone this wiki locally