Retrieving Request Metrics from the AWS SDK for .NET

In an earlier post, we discussed how you can turn on AWS SDK for .NET logging and how to log the SDK request metrics in JSON. In this post, we will discuss how you can use log4net or System.Diagnostics logging to gain access to the real RequestMetrics objects and work with raw metrics.

This approach may be useful as part of your testing to keep track of service calls made by the SDK or to log metrics data using your own loggers without the added overhead of trying to parse logs and reconstruct the metrics information.

To demonstrate, let’s implement a custom appender (MetricsAppender) for log4net that will extract and display metrics data to the console.

public class MetricsAppender : AppenderSkeleton
{
    // override AppenderSkeleton.Append to intercept all messages
    protected override void Append(LoggingEvent loggingEvent)
    {
        // extract the message data
        var logMessage = loggingEvent.MessageObject as ILogMessage;
        if (logMessage != null)
        {
            // find IRequestMetrics in logMessage.Args, if it is present
            var metrics = logMessage.Args == null ? null :
                logMessage.Args.Where(a => a is IRequestMetrics).FirstOrDefault() as IRequestMetrics;
            if (metrics != null)
            {
                // write MethodName and ClientExecuteTime to console
                Console.WriteLine("{0} took {1}ms to complete",
                    metrics.Properties[Metric.MethodName].First(),
                    metrics.Timings[Metric.ClientExecuteTime].First().ElapsedTime.TotalMilliseconds);
            }
        }
    }
}

Here is a simple example of the use of MetricsAppender with the SDK:

// create and configure metrics appender
var appender = new MetricsAppender();
BasicConfigurator.Configure(appender);

// configure the SDK to use log4net for metrics logging
AWSConfigs.LoggingConfig.LogMetrics = true;
AWSConfigs.LoggingConfig.LogTo = LoggingOptions.Log4Net;

// make service call and log the resultant metrics
using (var ddb = new AmazonDynamoDBClient())
{
    ddb.ListTables();
}

After you run this code, a message like this will be written to the console:

ListTablesRequest took 415.5368ms to complete

So what’s going on here? During logging, the AWS SDK for .NET passes an ILogMessage object to the loggers. ILogMessage holds the information required to execute String.Format to create a string that can be logged. String.Format isn’t called until the logger needs to convert the data to text (for example, in a logger that writes output to a file), but it can also be used to work with logged objects in memory. MetricsAppender simply analyzes all of the logged ILogMessage instances and looks for an ILogMessage that contains the IRequestMetrics object. It then extracts the required data from that object and writes this data to the console.

For this post we chose to use log4net because it has the handy AppenderSkeleton, which allowed us to only override one method to create a fully functional appender. This is not present in System.Diagnostics, though it is very easy to implement one. In fact, you can grab the TestTraceListener from this GitHub discussion and use it. As you can see, the inner code for both MetricsAppender and TestTraceListener is virtually identical.

Conclusion

We hope this look at logging in the AWS SDK for .NET will help you take full advantage of metrics data in your own application. If you have questions or feedback about the SDK, feel free to post them to our GitHub repo. In fact, this very post is the result of a user question about SDK metrics logging.