January 20, 2023

Categorised in: ,

Increase observability for your application using AWS X-Ray

AWS X-Ray is a distributed tracing framework for observability that provides a view over how your requests travel through the application and infrastructure.
You can enable it for AWS Lambda but for other workloads you also need to install an agent. Your application also needs to integrate with the AWS X-Ray SDK.

With AWS X-Ray you can see for instance the response time and latencies in the request flow and identify bottlenecks. It aims to provide an end-to-end view of the request flow as a single unit.

The tracing is based on sampling so X-Ray is not suited for audit purposes and long time storage isn’t supported either.

How does it work?

AWS will add a unique X-Ray ID on all incoming requests and then make sure that ID is propagated when your application is using other applications and AWS services. Services that that supports X-Ray are e.g. API Gateway, AWS Lambda, AWS SQS, AWS SNS and AWS S3 meaning that when your application is using the AWS SDK clients for AWS SQS the X-Ray ID will be propagated on the SQS message. For outgoing HTTP calls to other microservices then you need to use the X-Ray SDK. The Java version of the SDK has it own HttpClientBuilder that produces an X-Ray instrumented Apache Http client.

Small demo with an AWS Lambda function behind an API Gateway

The setup in this small demo, is an AWS lambda function (cloud-native) that implements a REST API with basic CRUD operations. The lambda function is deployed behind the API Gateway. (With API Gateway and AWS Lambda you can write serverless applications on AWS.) The lambda function is in fact a REST endpoint written in Micronaut which is a framework for microservices and serverless applications. The DB is AWS RDS MySQL but it can be any DB.

The lambda function needs to be deployed with “advanced tracing” enabled.
AWS will then add HTTP headers with a unique X-Ray ID and a request ID and downstream the X-Ray SDK make sure the X-Ray ID is passed along in any calls to other AWS services that your application is using.

If the lambda is written in Java and your are using some of the lambda event to HTTP request proxies for SpringBoot or Micronaut then you can log the X-Ray ID in the application log also since AWS adds it to the MDC (Mapped Diagnostic Context) for SLF4J/Logback:

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
      <pattern>[%date{yyyy-MM-dd'T'HH:mm:ss.SSSX, UTC}] [${HOSTNAME}] [%thread] %-5level %logger{36} - AWS-XRAY-TRACE-ID=%mdc{AWS-XRAY-TRACE-ID:-N/A} - AWSRequestId=%mdc{AWSRequestId:-N/A} - %msg%n
      </pattern>
    </encoder>
  </appender>

In order to trace the calls to the DB you need to wrap your data source with an X-Ray tracing capable data source proxy.
First depend on the X-Ray SDK in build.gradle:

implementation 'com.amazonaws:aws-xray-recorder-sdk-sql:2.13.0'

Then you need to create the datasource instance and wrap it. Below is how it is done in Micronaut and Hikari connection pool:

import javax.sql.DataSource;
import com.amazonaws.xray.sql.TracingDataSource;
import io.micronaut.configuration.jdbc.hikari.DatasourceConfiguration;
import io.micronaut.configuration.jdbc.hikari.DatasourceFactory;
import io.micronaut.context.ApplicationContext;
import io.micronaut.context.annotation.*;

@Factory
@Replaces(factory = DatasourceFactory.class)
public class XrayDataSourceFactory extends DatasourceFactory {
  public XrayDataSourceFactory(ApplicationContext applicationContext) {
    super(applicationContext);
  }
  @Override
  @Context
  @EachBean(DatasourceConfiguration.class)
  public DataSource dataSource(DatasourceConfiguration datasourceConfiguration) {
    return new TracingDataSource(super.dataSource(datasourceConfiguration));
  }
}

Analyse X-Ray in CloudWatch logs UI

To examine the request flow for the lambda navigate to CloudWatch and select X-Ray traces from the left menu.
You will get an overview over the activities using the “Service map” tab. Remember to pick a time frame.

You can then drill down per request or view the average. Below is a view of an invocation of the REST endpoint that interacts with the DB.

So for instance we can see that the small REST endpoint spent 23ms to do its thing but the overall invocation took 38ms from the API Gateway point of view.

X-Ray in Application log

In CloudWatch you can also check the application’s/lambda functions’s log and view the X-Ray ID. E.g:

START RequestId: 1bca61ca-3a68-490b-9a5b-17ffe90b90f5 Version: $LATEST
[2023-01-19T14:22:54.517Z] [169.254.18.205] [main] DEBUG com.example.book.BookController - AWS-XRAY-TRACE-ID=1-6384c438-0fedb3f04adfce125a0efc80 - AWSRequestId=1bca61ca-3a68-490b-9a5b-17ffe90b90f5 - in add method
END RequestId: 1bca61ca-3a68-490b-9a5b-17ffe90b90f5
REPORT RequestId: 1bca61ca-3a68-490b-9a5b-17ffe90b90f5	Duration: 519.54 ms	Billed Duration: 520 ms	Memory Size: 1024 MB	Max Memory Used: 253 MB	Init Duration: 5606.27 ms	
XRAY TraceId: 1-6384c438-0fedb3f04adfce125a0efc80	SegmentId: 43b04fed75278d89	Sampled: true

(The above log statement isn’t from the same request as the screenshots. This request was the first call to the lambda so the time reported here includes startup time for the Micronaut application etc. The first call is staggering 5.6 seconds for the s.c. “cold start”. But after that AWS will keep the lambda function warm for the next requests. But more about this in another post.)

Conclusion

AWS X-Ray is a good option to get an overview of where your application spends its time. It is really easy to start using it.
The cost is about $5.00 per 1 million traces recorded so definitely affordable.

We at House of Clouds can help you to get the most out of your cloud service provider. See our offerings about cost optimisation, security, migration, architecture and DevOps for more details.

Written by Lucas Persson