Application logging in Cloud Foundry


 

Contents:

  1. How should the application write logs ?

  2. How to view logs ?

  3. What does a Log entry consist of ?

a. LogType APP

b. LogType API

c. LogType RTR

d. LogType STG

e. LogType CELL

f. LogType SSH

g. LogType LGR


4. How to persist logs longer ?

 

The first thing that comes to a developers mind after deploying an application successfully in cloud foundry is, the logs the application is going to produce. Logs are important to understand whether the application is behaving as expected and whether an error condition occurred. Logs come handy to verify and investigate. That is the reason developers would like to know how application logs can be viewed and what they need to understand the logs.

In this blog post today I am going to explain this.


Loggregator is a Cloud Foundry component which is responsible for logging. It makes the stream of log outputs available for the application we deploy in Cloud Foundry and also for other cloud foundry system components. Details on the Loggregator can be found here (loggregator) in the Cloud Foundry documentation.


The Loggregator keeps the logs for a short period of time, logs are not persisted permanently. There is a certain limit in the Loggregator buffer which is assigned by default to each application. When the limit is exhausted the older logs are removed from the buffer to accommodate the newer logs.


The Loggregator in Cloud Foundry does not guarantee to capture all the logs produced in connection to the application because the platform uses best-effort strategy to gather and store the logs.


How should the application write logs ?


The applications should write logs always to either stdout or stderr and the applications should flush the stdout or stderr buffer before sending the log message to the Loggregator.


How to view logs ?


To view the log tails your application is producing to stderr or stdout the following command can be

cf logs <application-name>

This command streams the application logs into your terminal whenever new logs are produced by the application. This is generally known as log tailing.


To view the recent logs that the application produced which are still in the Loggregator bugger, add the --recent option to the command

cf logs <application-name> --recent

The application logs can be dumped into a file or can be filtered using the unix pipe command along with the cf logs command. It is advised to convert a stack trace into a single log entry, otherwise for each like in the stack trace a new log entry with a timestamp will appear in the Loggregator logs.


What does a Log entry consist of ?


Each log entry has a specific format. A log entry consists of the Timestamp, a LogType, a Channel and a Message. The timestamp shows when the logs were produced. Value for channel can be either OUT (when logs are written on stdout) or ERR(when logs are written on stderr). The Message contains the actual log message. depending on the LogType the content and format of the message changes. Let's look into what LogTypes are there.


LogType APP

When applications write the logs in stdout or stderr these logs are shown using this log type. For example

2021-10-29T14:59:54.11+0200 [APP/0]      OUT Hello

or

2021-10-29T14:59:54.11+0200 [APP/PROC/WEB/0] OUT Hello

The part APP/0 and APP/PROC/WEB/0 depends on how the cloud foundry is setup. Here 0 means it is the 0th instance of the application.


The below example shows an error message from the 2nd instance of the application

2021-10-29T15:04:58.76+0200 [APP/PROC/WEB/2] ERR Error occurred

LogType API

Users make API calls to request changes in app state. Cloud Controller, the Cloud Foundry component responsible for the API, logs the actions that Cloud Controller takes in response. There are API calls requested to perform lifecycle maintenance tasks. These APIs also internally gets triggered when we use CF CLI commands like

cf push, CF restart etc. The APIs calls are handled by the Cloud Controller (one of the central components in Cloud Foundry). The Cloud Controller then performs the instruction. The Cloud Controller logs the action that has been taken by itself as a response of the API calls.


For example, here the below two logs shows that the Cloud Controller Stopped and Started an application with guid 8bd23977-c971-4faf-bcea-b3ff3db69ae5, which can result if we can issue a cf restart command.

2021-10-29T15:18:27.88+0200 [API/35] OUT Updated app with guid 8bd23977-c971-4faf-bcea-b3ff3db69ae5 ({"state"=>"STOPPED"})
2021-10-29T15:18:29.87+0200 [API/40] OUT Updated app with guid 8bd23977-c971-4faf-bcea-b3ff3db69ae5 ({"state"=>"STARTED"})

LogType RTR

Routing of the HTTP(S) requests to applications from the outside world or from another application is done by the GoRouter. the RTR logs are the request routing logs produced by the GoRouter. GoRouter is part of the platform which is invisible to the application developers using the platform as PaaS.


An example of the RTR log is, it also includes the zipkin headers. I have truncated a few headers due to security reasons.

2021-10-29T15:04:54.77+0200 [RTR/29] OUT www.exampleapp.com - [2021-10-29T13:04:54.646499588Z] "GET /services HTTP/1.1" 200 0 33 "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36" "-" "10.0.137.5:61077" x_forwarded_for:"-" x_forwarded_proto:"https" response_time:0.129264 gorouter_time:0.000072 app_id:"feb234e6-a126-4880-a57c-a569c11f751d" app_index:"2" instance_id:"96443393-dd66-4c9d-7e49-faf4" x_correlationid:"-"  x_cf_app_instance:"-"

There are attributes that can be set by the Admin of the platform like x_forwarded_proto, response_time etc which can have value or can be empty.

The request is coming from www.exampleapp.com to the endpoint /services of the current application. It's a GET request with HTTP/1.1 protocol. The return code was 200.


LogType STG

STG logs are emitted by the Diego Cell or the Droplet Execution Agent. Both are cloud foundry components. These logs are generated when an app is staged or restarted. CELL messages begin after STG messages end.


For example:

2021-10-29T15:04:54.77+0300 [STG/0]      OUT Staging...

LogType CELL

When a Diego cell starts and stops an app running in it, it emits the CELL type logs. This also can occur because of CF CLI command and the action the Cloud Controller needs to take.


Examples of CELL logs:

2021-10-29T15:18:27.87+0200 [CELL/0] OUT Cell 0e6cb57a-c1e6-4fd0-aa33-d205c703a6a9 stopping instance 76dc3e88-8dd8-4328-422f-e1fc
2021-10-29T15:18:29.94+0200 [CELL/0] OUT Cell 60ab1f1e-3f1f-4781-9931-d427d27bba7d creating container for instance 0c4d8fbc-cb47-48d5-685e-915d
2021-10-29T15:18:30.99+0200 [CELL/0] OUT Cell 60ab1f1e-3f1f-4781-9931-d427d27bba7d successfully created container for instance 0c4d8fbc-cb47-48d5-685e-915d
2021-10-29T15:18:31.10+0200 [CELL/0] OUT Downloading droplet...
2021-10-29T15:18:33.25+0200 [CELL/SSHD/0] OUT Exit status 0

LogType SSH

An application running in Cloud Foundry can be accessed via SSH. For example, we can issue the cf ssh <application_name> command to SSH to the server where the application is running. The SSH logs are written by the Diego Cell.


Examples of SSH type logs are below. The first log appears when we are logged in using the ssh command. The second log appears when we exit from the SSH session.

2021-10-29T15:41:45.62+0200 [SSH/0] OUT Successful remote access by 10.0.200.6:38992
2021-10-29T15:42:45.15+0200 [SSH/0] OUT Remote access ended for 10.0.200.6:38992

LogType LGR

LGR logs are emitted by the Loggregator to inform problems in the logging process.


For more details you can also go through the Cloud Foundry documentation


How to persist logs longer ?


The application developers need to drain the application logs into some third party logging management service if they want to persist the logs for a longer time period. This though needs to be done quickly before the buffer limit is reached, otherwise the logs will be overwritten with newer logs.


There could be reusable services in cloud foundry marketplace which can be used to frain logs. If a reusable service is not available for log drain then services outside Cloud Foundry can be used as well.


When we are using a reusable service then we need to create an instance of a reusable service and bind that to the application.


For details see this Cloud Foundry documentation.

1 view0 comments

Recent Posts

See All