Cloud Foundry logo in white on a blue background
blog single gear
Engineering

Rethink Application Logging with RabbitMQ

Application logging is essential to monitoring applications and diagnosing problems, but in a cloud universe where file systems may be ephemeral and application instances are provisioned dynamically keeping track of your application logs can be a challenge. Fortunately with Cloud Foundry you can get fast, multi-instance, cloud-proof application logging in just a few steps with RabbitMQ In this blog post I’ll show you how to configure a Spring application so that it logs messages via AMQP. But first, what are the benefits? The primary motivations are that it’s fast and it doesn’t rely on the local file system of your application (which can disappear in a cloud environment). It’s also very easy to set up multiple applications to log to the same message broker, allowing you to aggregate log messages. Finally, you have the power to route and process those messages, for example allowing you to index them for search and store them in a blob store. So how do you go about logging messages via the broker? If you’re happy to use Spring, you’re already ahead of the game. One of the best kept secrets of the Spring AMQP project is an AMQP Log4j appender that allows you log messages to any AMQP broker. All you have to do is configure it.

Application changes

As an example, I’m going to use the Spring travel application. The same principles apply to any Java, servlet-based web application. In order to send log messages to a non-standard location, you have to attach the appropriate appender to a logger. Typically, you attach it to the root logger. The easiest way to do this is to add the appender to your Log4j configuration file, be it a properties file or XML. The Spring travel application uses XML configuration, so adding the AMQP appender is a simple case of inserting the appender definition into log4j.xml:

[code 1="xml" language=""]
<?xml version="1.0" encoding="UTF-8"?>
  <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
  ...
 <appender name="amqp" class="org.springframework.amqp.rabbit.log4j.AmqpAppender">
    <param name="ExchangeName" value="amq.topic" />
    <param name="ExchangeType" value="topic" />
    <param name="RoutingKeyPattern" value="logs.spring-travel" />
    <param name="ApplicationId" value="spring-travel" />
  </appender>
  ...
 </log4j:configuration>
[/code]

and then adding the appender to whichever loggers you want. In the case of the root logger:

[code 1="xml" language=""]
<root>
  <priority value="info" />
  <appender-ref ref="console" />
  <appender-ref ref="amqp"/>
</root>
[/code]

These simple changes will result in the Spring Travel application logging messages to a RabbitMQ broker – as long as it’s running on the default port and with the standard ‘guest’ account. You can configure the connection settings for the broker in log4j.xml if you know the broker host and port information in advance, but Cloud Foundry assigns these values dynamically. Fortunately it is easy to configure your Cloud Foundry application to use those dynamically assigned values. Since the connection settings for the various Cloud Foundry services are injected into an application at runtime (via an environment variable), we have to programmatically configure Log4j at runtime as well. This is a simple case of adding a ServletContextListener that checks whether the application is running inside Cloud Foundry and if so, updates the connection settings of the “amqp” appender. The full code is in the application sample, but the basic process involves initializing the logging from log4j.xml, getting the appender by name, closing it (so that any existing AMQP connections are dropped) and then updating the connection settings. Of course, we need to make sure the listener actually runs! So, drop the listener definition into the applications web descriptor:

[code 1="xml" language=""]
<listener>
  <listener-class>org.springframework.samples.travel.web.Log4jConfigListener</listener-class>
</listener>
[/code]

The last piece of the puzzle is to make sure that AmqpAppender is on the application’s classpath, which means you need to add the spring-rabbit library as a dependency:

[code 1="xml" language=""]
<dependency>
  <groupId>org.springframework.amqp</groupId>
  <artifactId>spring-rabbit</artifactId>
  <version>1.0.0.RELEASE</version>
</dependency>
[/code]

And because we’re using the CloudEnvironment class to extract the RabbitMQ connection settings from Cloud Foundry, we also need the cloudfoundry-runtime JAR, although that’s already part of the Spring Travel sample project:

[code 1="xml" language=""]
<dependency>
  <groupId>org.cloudfoundry</groupId>
  <artifactId>cloudfoundry-runtime</artifactId>
  <version>0.8.1</version>
</dependency>
[/code]

Everything is now in place, so we’re ready to deploy the application to Cloud Foundry. All that’s unique to this deployment is that you have to bind a RabbitMQ service called “rabbitmq-logs” to the application. This is because that’s the name of the service the code in Log4jConfigListener looks for. If you want to try this app yourself, just clone the repository and use the latest vmc to deploy it:

$ git clone https://github.com/pledbrook/spring-travel.git
$ cd spring-travel/server
$ mvn package
$ vmc push --path target
Would you like to deploy from the current directory? [Yn]:
Application Name: spring-travel
Detected a Java SpringSource Spring Application, is this correct? [Yn]:
Application Deployed URL [spring-travel.cloudfoundry.com]: koala-travel
Memory reservation (128M, 256M, 512M, 1G, 2G) [512M]:
How many instances? [1]:
Bind existing services to 'spring-travel'? [yN]:
Create services to bind to 'spring-travel'? [yN]: y
1: mongodb
2: mysql
3: postgresql
4: rabbitmq
5: redis
What kind of service?: 2
Specify the name of the service [mysql-6117e]: travel-rdbms
Create another? [yN]: y
1: mongodb
2: mysql
3: postgresql
4: rabbitmq
5: redis
What kind of service?: 4
Specify the name of the service [rabbitmq-abd55]: rabbitmq-logs
Create another? [yN]:
Would you like to save this configuration? [yN]: y
Manifest written to manifest.yml.
Creating Application: OK
Creating Service [travel-rdbms]: OK
Binding Service [travel-rdbms]: OK
Binding Service [rabbitmq-logs]: OK
Uploading Application:
  Checking for available resources: OK
  Processing resources: OK
  Packing application: OK
  Uploading (41K): OK
Push Status: OK
Staging Application 'spring-travel': OK
Starting Application 'spring-travel': OK

Don’t forget to change the application URL if you’re deploying to cloudfoundry.com, otherwise you may be told that it’s already in use and the deployment will fail. Once you have successfully deployed the application and it starts up, those log messages will be flying! Hmmm…but where will they be flying to?

Who ate all the messages?

RabbitMQ will shift those log messages at a tremendous rate and retain them up to a point, but those messages need to be routed somewhere if you want to view them easily or search the logs in a week’s time. We obviously need to pick up those messages and put them into a data store for easy retrieval. For this blog post, I’m going to create a simple Grails application that consumes the messages and stores them in a MongoDB instance. I could use a relational database, but ACID and referential integrity aren’t important in this scenario. There are two parts to this application: a message consumer that stores the log messages in the database and a UI for viewing the messages. For the first part, I just declare dependencies on the RabbitMQ and MongoDB plugins (removing the Hibernate plugin) and create a handler service that consumes the messages and stores them into MongoDB:

package org.example
import org.springframework.amqp.core.Message
class MessageStoreService {
  static transactional = false
  static rabbitSubscribe = [ name: "amq.topic", routingKey: "logs.#", messageConverterBean: ""]
  void handleMessage(Message msg) {
    def props = msg.messageProperties
    def logMessage = new LogMessage( message: new String(msg.body, props.contentEncoding ?: "UTF-8"), appName: props.receivedRoutingKey - "logs.", category: props.headers.categoryName, level: props.headers.level).save(flush: true)
  }
}

The handleMessage() method is invoked each time a message is received from the amq.topic exchange whose routing key matches “logs.#”. It just extracts the relevant information from the AMQP message and stores that in a LogMessage instance, which maps to a MongoDB record:

package org.example
class LogMessage {
  String appName String message String category String level static constraints = { category nullable: true level nullable: true }
}

Note that the application name is pulled from the routing key of the message. Finally, the application has a scaffolded controller for LogMessage so that users can view the log messages:

package org.example
class LogMessageController { static scaffold = true }

The above are the only extra classes you need on top of a fresh Grails application. You will also need to add some RabbitMQ configuration to grails-app/conf/Config.groovy:

rabbitmq {
  connectionfactory {
    username = 'guest'
    password = 'guest'
    hostname = 'localhost'
    consumers = 5
  }
  queues = {
    exchange name: "amq.topic",
    type: topic,
    durable: true,
    autoDelete: false
  }
}

The key entry is the declaration of the ‘amq.topic’ exchange. The full source is of this application is available on GitHub and can be deployed directly to any Cloud Foundry account. All you need to do is create and bind a MongoDB service to the application and bind “rabbitmq-logs” (or whatever RabbitMQ service you’re using for logging). You will also need to download and install Grails 2 to try this application.

$ git clone https://github.com/pledbrook/cf-log-app.git
$ cd cf-log-app
$ grails compile
$ grails
grails> cf-create-service rabbitmq rabbitmq-logs
Service 'rabbitmq-logs' provisioned.
grails> cf-create-service mongodb mongo-logs
Service 'mongo-logs' provisioned.
grails> prod cf-push --appname=cf-log-apps --services=rabbitmq-logs,mongo-logs
Building war file
| Done creating WAR target/cf-temp-1332242548101.war
>
Application Deployed URL: 'cf-log-apps.cloudfoundry.com'?

Creating application cf-log-apps at cf-log-apps.cloudfoundry.com with 512MB and services [rabbitmq-logs, mongo-logs]:
2012-03-20 11:22:40,498 [main] WARN  client.RestTemplate  - GET request for "http://api.cloudfoundry.com/apps/cf-log-apps" resulted in 404 (Not Found); invoking error handler
 OK
Uploading Application:
  Checking for available resources:
 OK
  Processing resources:
 OK
  Packing application:
 OK
  Uploading (6K):
 OK

Trying to start Application: 'cf-log-apps'......
Application 'cf-log-apps' started at http://cf-log-apps.cloudfoundry.com

As before, don’t forget to change the application name if you follow the above instructions. You can also see the application live on cloudfoundry.com with some log messages from the grailstwitter sample application.

Power logging

This is of course a very basic application but it does demonstrate how easy it is to aggregrate the logs from multiple applications into a single location. It would also be fairly easy to add a separate application that archives logs to a blob service, all the while ensuring low latency inside the applications that are performing the logging. This is the power of logging via a message broker. Why stop at Java? In a polyglot environment, logging via AMQP will allow you to aggregate logs from all sorts of frameworks, such as Node.js and Ruby on Rails. As long as the consumer can handle any differences between message formats, you’re good to go.

– Peter Ledbrook Cloud Foundry Developer Relations