Skip to content

Commit

Permalink
feat: Add experimental metrics logging middleware (#461)
Browse files Browse the repository at this point in the history
Add abstract middleware that captures metrics for each grpc request.

Add metrics middleware implementation that writes the metrics to a
CSV.

Add metrics middleware implementation that logs the metrics.
  • Loading branch information
nand4011 authored Jul 31, 2023
1 parent 39346c6 commit 693ff93
Show file tree
Hide file tree
Showing 3 changed files with 268 additions and 0 deletions.
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
using System;
using System.Threading.Tasks;
using Microsoft.Extensions.Logging;
using System.IO;
using System.Text;

namespace Momento.Sdk.Config.Middleware
{
/// <summary>
/// This middleware enables per-request client-side metrics. Metrics for each
/// request will be written to a CSV file. This file can be analyzed or shared
/// with Momento to diagnose performance issues.
///
/// The metrics format is currently considered experimental. In a future release,
/// once the format is considered stable, this class will be renamed to remove
/// the Experimental prefix.
///
/// WARNING: enabling this middleware may have minor performance implications,
/// so enable with caution.
///
/// WARNING: depending on your request volume, the CSV file size may grow quickly.
/// Neither sampling nor file compression / rotation are included at this time
/// (though they may be added in the future).
/// </summary>
public class ExperimentalMetricsCsvMiddleware : ExperimentalMetricsMiddleware, IDisposable
{
private readonly StreamWriter _writer;
private readonly object _lock = new object();

/// <summary>
/// Constructor for the ExperimentalMetricsCsvMiddleware class.
/// If the file at the specified path exists, the StreamWriter will append to it.
/// If the file does not exist, the StreamWriter will create it.
/// </summary>
/// <param name="filePath">The path to the file where the middleware will write metrics data.</param>
/// <param name="loggerFactory">Used for logging in case of errors.</param>
public ExperimentalMetricsCsvMiddleware(string filePath, ILoggerFactory loggerFactory)
: base(loggerFactory)
{
_writer = new StreamWriter(filePath, true, Encoding.UTF8);
}

/// <summary>
/// Writes metrics for a request out to a CSV.
/// </summary>
public override Task EmitMetrics(ExperimentalRequestMetrics metrics)
{
var csvLine = $"{metrics.NumActiveRequestsAtStart}, {metrics.NumActiveRequestsAtFinish}, " +
$"{metrics.RequestType}, {metrics.Status}, {metrics.StartTime}, {metrics.EndTime}," +
$"{metrics.Duration}, {metrics.RequestSize}, {metrics.ResponseSize}";

lock (_lock)
{
_writer.WriteLine(csvLine);
_writer.Flush();
}

return Task.CompletedTask;
}

/// <summary>
/// Closes the CSV file writer.
/// </summary>
public void Dispose()
{
_writer.Close();
}
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
using System.Threading.Tasks;
using Microsoft.Extensions.Logging;

namespace Momento.Sdk.Config.Middleware
{
/// <summary>
/// This middleware enables per-request client-side metrics. Metrics for each
/// request will be written to logs. The log data can be analyzed or shared
/// with Momento to diagnose performance issues.
///
/// The metrics format is currently considered experimental. In a future release,
/// once the format is considered stable, this class will be renamed to remove
/// the Experimental prefix.
///
/// WARNING: enabling this middleware may have minor performance implications,
/// so enable with caution.
///
/// WARNING: depending on your request volume, this middleware will produce a high
/// volume of log output. If you are writing logs directly to local disk, be aware
/// of disk usage and make sure you have log rotation / compression enabled via a
/// tool such as `logrotate`.
/// </summary>
public class ExperimentalMetricsLoggingMiddleware : ExperimentalMetricsMiddleware
{
private readonly ILogger _logger;

/// <summary>
/// Constructor for the ExperimentalMetricsLoggingMiddleware class.
/// </summary>
/// <param name="loggerFactory">Used for logging the metrics and any errors that occur.</param>
public ExperimentalMetricsLoggingMiddleware(ILoggerFactory loggerFactory) : base(loggerFactory)
{
_logger = loggerFactory.CreateLogger<ExperimentalMetricsLoggingMiddleware>();
}

/// <summary>
/// Logs metrics for a Momento request.
/// </summary>
public override Task EmitMetrics(ExperimentalRequestMetrics metrics)
{
var json = "{" +
$"\"numActiveRequestsAtStart\": {metrics.NumActiveRequestsAtStart}, " +
$"\"numActiveRequestsAtFinish\": {metrics.NumActiveRequestsAtFinish}, " +
$"\"requestType\": \"{metrics.RequestType}\", " +
$"\"status\": \"{metrics.Status}\", " +
$"\"startTime\": \"{metrics.StartTime}\", " +
$"\"endTime\": \"{metrics.EndTime}\", " +
$"\"duration\": \"{metrics.Duration}\", " +
$"\"requestSize\": {metrics.RequestSize}, " +
$"\"responseSize\": {metrics.ResponseSize}" +
"}";

_logger.LogInformation(json);

return Task.CompletedTask;
}
}
}
140 changes: 140 additions & 0 deletions src/Momento.Sdk/Config/Middleware/ExperimentalMetricsMiddleware.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,140 @@
using System;
using System.Threading;
using System.Threading.Tasks;
using Grpc.Core;
using Microsoft.Extensions.Logging;

namespace Momento.Sdk.Config.Middleware
{

/// <summary>
/// A struct that records metrics about a Momento request. These metrics include the number of requests active
/// at the start and finish of the request, the type of the request, the status code of the response,
/// timing information about the request (start, end, and duration times in milliseconds),
/// and the size of the request and response bodies in bytes.
///
/// Metrics may be added to this struct in the future if they are useful.
/// </summary>
public record struct ExperimentalRequestMetrics(
// The number of requests active at the start of the request.
int NumActiveRequestsAtStart,
// The number of requests active at the finish of the request (including the request itself).
int NumActiveRequestsAtFinish,
// The generated grpc object type of the request.
string RequestType,
// The grpc status code of the response.
StatusCode Status,
// The time the request started (millis since epoch).
long StartTime,
// The time the request completed (millis since epoch).
long EndTime,
// The duration of the request (in millis).
long Duration,
// The size of the request body in bytes.
int RequestSize,
// The size of the response body in bytes.
int ResponseSize
);

/// <summary>
/// This middleware enables per-request client-side metrics. This is an abstract
/// class that does not route the metrics to a specific destination; concrete subclasses
/// may store the metrics as they see fit.
///
/// The metrics format is currently considered experimental. In a future release,
/// once the format is considered stable, this class will be renamed to remove
/// the Experimental prefix.
///
/// WARNING: enabling this middleware may have minor performance implications,
/// so enable with caution.
/// </summary>
public abstract class ExperimentalMetricsMiddleware : IMiddleware
{
private int activeRequestCount = 0;
private readonly ILogger _logger;

/// <summary>
/// Constructor for the ExperimentalMetricsMiddleware class.
/// </summary>
/// <param name="loggerFactory">Used for logging in case of errors.</param>
protected ExperimentalMetricsMiddleware(ILoggerFactory loggerFactory)
{
_logger = loggerFactory.CreateLogger<ExperimentalMetricsMiddleware>();
}

/// <summary>
/// Increments and returns the active request count in a thread-safe way.
/// </summary>
public void IncrementActiveRequestCount()
{
Interlocked.Increment(ref activeRequestCount);
}

/// <summary>
/// Decrements and returns the active request count in a thread-safe way.
/// </summary>
public void DecrementActiveRequestCount()
{
Interlocked.Decrement(ref activeRequestCount);
}

/// <summary>
/// Output metrics for a Momento request to a destination decided by the implementing class.
/// </summary>
public abstract Task EmitMetrics(ExperimentalRequestMetrics metrics);

/// <inheritdoc/>
public async Task<MiddlewareResponseState<TResponse>> WrapRequest<TRequest, TResponse>(
TRequest request,
CallOptions callOptions,
Func<TRequest, CallOptions, Task<MiddlewareResponseState<TResponse>>> continuation
) where TRequest : class where TResponse : class
{
if (!(request is Google.Protobuf.IMessage requestMessage))
{
_logger.LogError("Expected request to be type Google.Protobuf.IMessage. Found {}", request.GetType());
return await continuation(request, callOptions);
}
var requestSize = requestMessage.CalculateSize();

var startActiveRequestCount = activeRequestCount;
IncrementActiveRequestCount();

var startTime = DateTimeOffset.UtcNow.ToUnixTimeMilliseconds();

var nextState = await continuation(request, callOptions);

var endActiveRequestCount = activeRequestCount;
var endTime = DateTimeOffset.UtcNow.ToUnixTimeMilliseconds();

if (!(nextState.ResponseAsync.Result is Google.Protobuf.IMessage response))
{
_logger.LogError("Expected response to be type Google.Protobuf.IMessage. Found {}", nextState.ResponseAsync.Result.GetType());
DecrementActiveRequestCount();
return nextState;
}
var responseSize = response.CalculateSize();

var status = nextState.GetStatus();

var metrics = new ExperimentalRequestMetrics(
startActiveRequestCount,
endActiveRequestCount,
request.GetType().Name,
status.StatusCode,
startTime,
endTime,
endTime - startTime,
requestSize,
responseSize
);

await EmitMetrics(metrics);

DecrementActiveRequestCount();

return nextState;
}

}
}

0 comments on commit 693ff93

Please sign in to comment.