Spring Cloud: Request correlation

Sometimes developing might seem like reinventing the wheel and this post partially might look so, since it does not invents nothing new, just provides an implementation for the common problem – request correlation.

It’s truism to say that in microservice environment the HTTP (apart from any other data that is being exchanged like messages) requests might be propagated and processed by multiple individual services. It becomes not trivial task to trace those and you need additional information to be able to track them. Yet simple and proven method is to pass the unique identifier with each individual request. There are various approaches and no unified header exists for this approach. Across web you will be able find solutions that use X-Request-Id, X-Trace-Id or X-Correlation-Id. Those values are always bound to the upstream request through HTTP headers and in most cases also internally by each process to the currently processed thread.

Exactly the same approach we have been using in our project, through simple implementation:

https://github.com/jmnarloch/request-correlation-spring-cloud-starter

That integrates seamlessly with Spring Cloud and gives you fallowing:

  • Generation of request correlation id for any inbound request to the system through one of the edge gateway services.
  • Propagation on the requests identifier internally.

What it does exactly?

The extension adds a servlet filter that process any incoming request and populates it with unique identifier. Next you will need means to propagate those with any outgoing request. The extension approaches this issue with out of the box support for fallowing use cases:

  • RestTemplate – an interceptor is being registered to any RestTemplate bean
  • Feign clients – similary proper request intercepor exists for Feign
  • Zuul proxy routes – those will also propagate the request identifier

It configures proper request interceptors for the above or uses tweaks to the request itself to be able to transparently propagate this information.

Our applications:

  • Logging request id as MDC field.
  • Request tracing (though not as complex as Zipkin’s)
  • Vnd.errors logref population
  • Spring Boot Actuator auditing

Let’s make a workable example:

Let’s say that you want to aggregate all of your logs into central storage and used that later for analysis. We can use for this purpose Logstash with ElasticSearch and Kibana dashboard for visualization.

It turns out that there is a very simple way to configure Logstash within Spring Boot through logback logstash encoder. We had end up with adding a logstash.xml file in one of our utility modules that afterwards is being imported by the application modules. This looks as fallows:

<?xml version="1.0" encoding="UTF-8"?>

<included>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>

    <property name="FILE_LOGSTASH" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}/}spring.log}.json"/>
    <appender name="LOGSTASH" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
        <file>${FILE_LOGSTASH}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <fileNamePattern>${FILE_LOGSTASH}.%i</fileNamePattern>
        </rollingPolicy>
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>10MB</MaxFileSize>
        </triggeringPolicy>
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <includeCallerInfo>true</includeCallerInfo>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="LOGSTASH"/>
    </root>
</included>

As you may notice the file itself imports the Spring Boot logback configuration so you can say that it extends it by adding additional appender.

Later on any application module can use this predefined configuration by imporinting the above file in it’s logback.xml configuaration.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <include resource="com/commons/logging/logback/logstash.xml"/>
</configuration>

Next we need to configure logstash to read the JSON encoded log file that LogstashEncoder will produce. To do that let’s setup central logstash deamon node and on every application node let’s use simple logstash forwarder – that is lighter and consumes less resources.

Logstash forwarder configuration may look like fallows:

{
    "network": {
        "servers": [
            "logstash.local:5043"
        ],
        "ssl certificate": "/etc/pki/tls/certs/logstash-forwarder/logstash-forwarder.crt",
        "ssl key": "/etc/pki/tls/private/logstash-forwarder/logstash-forwarder.key",
        "ssl ca": "/etc/pki/tls/certs/logstash-forwarder/logstash-forwarder.crt",
        "timeout": 15
    },
    "files": [
        {
            "paths": [
                "${ENV_SERVICE_LOG}/*.log.json"
            ],
            "fields": {
                "type": "${ENV_SERVICE_NAME}"
            }
        }
    ]
}

Finally we need our logstash configuration that will listen to logstash forwarder connections and process the input to finally persist them in ElasticSearch:

input {
    lumberjack {
        port => 5043

        ssl_certificate => "/etc/pki/tls/certs/logstash-forwarder/logstash-forwarder.crt"
        ssl_key => "/etc/pki/tls/private/logstash-forwarder/logstash-forwarder.key"
    }
}
filter {
    json {
        source => "message"
    }
}
output {
    elasticsearch { host => "elasticsearch.local" }
}

What we have gained by that?
At this point logs from entire system are being stored in central server where they are indexed and analyzed by ElasticSearch. We can perform queries against them and use Kibana visualization features to display in form of chart to see for instance how they fluctuate over time.

If this is does not yet convince you, let’s see how we can handle errors now. If you configure your error handler to return Vnd.error and populate it’s logref with the request correlation id, the client might receive fallowing error in form of JSON response:

{“logref”:”c1bd6562-b28e-497e-9b49-1b4a4a106fe0″,”message”:”status 401 content:\n{\”error\”:\”unauthorized\”,\”error_description\”:\”Full authentication is required to access this resource\”}”,”links”:[]}

We can use logref value to perform the search in Kibana and find all the logs corresponding to the request that were performed across any service with for instance ERROR log level.

kibana_correlation_id

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s