Open sandboxFocusImprove this doc

Call telemetry example, step 3: Recording metrics

Spans describe individual calls. To monitor the number of calls and their duration over time, an application also records metrics. The .NET API for metrics is System.Diagnostics.Metrics. A Meter creates instruments, such as a Counter<T> and a Histogram<T>, and OpenTelemetry exports their measurements to a monitoring back-end.

In this step, the interceptors of the previous step also record two metrics for each call to PaymentClient:

  • payments.client.calls, a counter of the calls.
  • payments.client.duration, a histogram of the duration of the calls, in milliseconds.

Both metrics are tagged with the called method and the calling type. The calling code does not change in the source code:

Source Code
1using Metalama.Samples.CallTelemetry.Payments;
2
3namespace Metalama.Samples.CallTelemetry3;
4
5public class CheckoutService
6{
7    private readonly PaymentClient _payments = new();
8
9    public async Task<string> CheckoutAsync(
10        string cardNumber,
11        decimal amount,
12        CancellationToken cancellationToken = default )
13    {
14        var fee = this._payments.GetFee( amount );
15        var authorizationId = await this._payments.AuthorizeAsync( cardNumber, amount + fee, cancellationToken );
16        await this._payments.CaptureAsync( authorizationId, cancellationToken );
17
18        return authorizationId;
19    }
20}
21
Transformed Code
1using Metalama.Samples.CallTelemetry.Payments;
2
3namespace Metalama.Samples.CallTelemetry3;
4
5public class CheckoutService
6{
7    private readonly PaymentClient _payments = new();
8
9    public async Task<string> CheckoutAsync(
10        string cardNumber,
11        decimal amount,
12        CancellationToken cancellationToken = default )
13    {
14        var fee = PaymentsTelemetry.PaymentClient_GetFee_Interceptor( this._payments,amount:amount ,operation:"CheckoutService.CheckoutAsync",callingType:"CheckoutService");
15        var authorizationId = await PaymentsTelemetry.PaymentClient_AuthorizeAsync_Interceptor( this._payments,cardNumber:cardNumber,amount:amount + fee,cancellationToken:cancellationToken ,operation:"CheckoutService.CheckoutAsync",callingType:"CheckoutService");
16        await PaymentsTelemetry.PaymentClient_CaptureAsync_Interceptor( this._payments,authorizationId:authorizationId,cancellationToken:cancellationToken ,operation:"CheckoutService.CheckoutAsync",callingType:"CheckoutService");
17
18        return authorizationId;
19    }
20}
21

The program writes each measurement to the console. The durations change from one run to another.

[metric] payments.client.calls 1 {method=PaymentClient.GetFee, caller.type=PriceList}
[metric] payments.client.duration 8.7 ms {method=PaymentClient.GetFee, caller.type=PriceList}
Price with fee: 103.20
[metric] payments.client.calls 1 {method=PaymentClient.GetFee, caller.type=CheckoutService}
[metric] payments.client.duration 0 ms {method=PaymentClient.GetFee, caller.type=CheckoutService}
[metric] payments.client.calls 1 {method=PaymentClient.AuthorizeAsync, caller.type=CheckoutService}
[metric] payments.client.duration 50 ms {method=PaymentClient.AuthorizeAsync, caller.type=CheckoutService}
[metric] payments.client.calls 1 {method=PaymentClient.CaptureAsync, caller.type=CheckoutService}
[metric] payments.client.duration 9.8 ms {method=PaymentClient.CaptureAsync, caller.type=CheckoutService}
Authorization: AUTH-1111-103.20
[metric] payments.client.calls 1 {method=PaymentClient.GetFee, caller.type=CheckoutService}
[metric] payments.client.duration 0 ms {method=PaymentClient.GetFee, caller.type=CheckoutService}
[metric] payments.client.calls 1 {method=PaymentClient.AuthorizeAsync, caller.type=CheckoutService}
[metric] payments.client.duration 21 ms {method=PaymentClient.AuthorizeAsync, caller.type=CheckoutService}
Checkout failed: The card was declined.

A real application does not use a MeterListener. Instead, it configures OpenTelemetry to export the metrics of the Metalama.Samples.CallTelemetry.Payments meter, for instance with AddMeter( "Metalama.Samples.CallTelemetry.Payments" ).

Implementation

The PaymentsTelemetry class now also holds the Meter and its instruments:

1using System.Diagnostics;
2using System.Diagnostics.Metrics;
3
4namespace Metalama.Samples.CallTelemetry3;
5
6// Holds the ActivitySource and the metrics of the calls to the payment SDK. The fabric generates the interceptors
7// in this class.
8internal static class PaymentsTelemetry
9{
10    public const string Name = "Metalama.Samples.CallTelemetry.Payments";
11
12    public static readonly ActivitySource ActivitySource = new( Name );
13
14    private static readonly Meter _meter = new( Name );
15
16    public static readonly Counter<long> Calls = _meter.CreateCounter<long>( "payments.client.calls" );
17
18    public static readonly Histogram<double> Duration =
19        _meter.CreateHistogram<double>( "payments.client.duration", unit: "ms" );
20}
21

The fabric is the same as in the previous step, with two changes:

1using Metalama.Extensions.Interceptors;
2using Metalama.Framework.Aspects;
3using Metalama.Framework.Code;
4using Metalama.Framework.Fabrics;
5using Metalama.Samples.CallTelemetry.Payments;
6using System.Diagnostics;
7
8namespace Metalama.Samples.CallTelemetry3;
9
10// Creates a trace span around each call to the payment SDK, and records the number and the duration of the calls.
11internal class TelemetryFabric : ProjectFabric
12{
13    public override void AmendProject( IProjectAmender amender )
14        => amender.InterceptMethods(
15            calls => calls
16                .Type( typeof(PaymentClient) )
17                .AllMethods()
18                .RedirectToSynthesizedMethod( nameof(this.Monitor) )
19                .PlaceInType( typeof(PaymentsTelemetry) )
20                .Configure(
21                    method =>
22                    {
23                        // Each call site passes the name of the calling operation and of the calling type, so that
24                        // the call sites of a method share the same interceptor.
25                        var caller = method.Context.Caller.Member;
26
27                        var operation = method.Method.AddParameter( "operation", typeof(string) );
28                        method.SetArgument( operation, (TypedConstant) $"{caller.DeclaringType.Name}.{caller.Name}" );
29
30                        var callingType = method.Method.AddParameter( "callingType", typeof(string) );
31                        method.SetArgument( callingType, (TypedConstant) caller.DeclaringType.Name );
32                    } ) );
33
34    [Template]
35    public dynamic? Monitor( string operation, string callingType )
36    {
37        var interceptedMethod = meta.Interception.Method.InterceptedMethod;
38        var methodName = $"{interceptedMethod.DeclaringType.Name}.{interceptedMethod.Name}";
39
40        // The span covers the call. For an async method, meta.Proceed() awaits the call.
41        using Activity? activity = meta.ThisType.ActivitySource.StartActivity( methodName );
42
43        activity?.SetTag( "code.caller", operation );
44
45        var startTimestamp = Stopwatch.GetTimestamp();
46
47        try
48        {
49            return meta.Proceed();
50        }
51        catch ( Exception e )
52        {
53            activity?.SetStatus( ActivityStatusCode.Error, e.Message );
54
55            throw;
56        }
57        finally
58        {
59            // The metrics are tagged with the calling type, not with the calling operation, to keep the number of
60            // distinct tag values small.
61            var tags = new TagList { { "method", methodName }, { "caller.type", callingType } };
62
63            meta.ThisType.Calls.Add( 1, tags );
64            meta.ThisType.Duration.Record( Stopwatch.GetElapsedTime( startTimestamp ).TotalMilliseconds, tags );
65        }
66    }
67}
68
  • Configure adds a second parameter, callingType, whose value is the name of the calling type.
  • The Monitor template measures the duration of the call with Stopwatch.GetTimestamp. It records the metrics in a finally block, so that the failed calls are also counted. For async methods, meta.Proceed() awaits the call, so the duration covers the whole asynchronous operation.

The name of the called method is known at compile time, so the template writes it as a constant. The name of the calling type is a run-time parameter, so the call sites of a method still share the same interceptor.

The metrics are tagged with the calling type, and the span is tagged with the calling operation. The monitoring back-end creates a separate time series for each distinct combination of tag values. A tag with fewer distinct values, such as the calling type, keeps the number of time series small.