Open Telemetry support in IdentityServer v7

OpenTelemetry is a collection of tools, APIs, and SDKs for generating and collecting telemetry data (metrics, logs, and traces). This is very useful for analyzing software performance and behavior, especially in highly distributed systems.

We started our journey with Traces in Duende IdentityServer v6.1. .NET 8 has full support for Open Telemetry and so does Duende IdentityServer v7. IdentityServer emits traces, metrics and logs.

Metrics

Metrics are high level statistic counters. They provide an aggregated overview and can be used to set monitoring rules. For monitoring at a glance and usage on a high level dashboard, IdentityServer provides four high level metrics. There are also more detailed metrics that can be used to monitor specific flows.

Traces

Traces are used to generate distributed dependency graphs. They are useful to see how different parts of the system interact with each other and for performance monitoring.

Logs

The logging system in Asp.Net automatically integrates with Open Telemetry. A monitoring system that supports metrics, traces and logs can display the logs in the context of traces. This provides a way to quickly move from the overall view in the traces into the detailed information found in the logs.

Setup

Open Telemetry is now the default monitoring solution for .NET. IdentityServer works with that model and the IdentityServer metrics can be configured alongside metrics from other parts of the system and infrastructure.

In a real deployment the application performance monitoring tool of your choice would pick up and display the metrics and traces. To see the results in a development environment without extra tools it’s possible to get the metrics in text format on an endpoint and the traces written to the console. To create a /metrics endpoint we can use the Prometheus exporter. To get the traces to the console there is a built in console exporter.

Add the Open Telemetry configuration to your service setup.

var openTelemetry = builder.Services.AddOpenTelemetry();

openTelemetry.ConfigureResource(r => r
    .AddService(builder.Environment.ApplicationName));

openTelemetry.WithMetrics(m => m
    .AddMeter(Telemetry.ServiceName)
    .AddMeter(Pages.Telemetry.ServiceName)
    .AddPrometheusExporter());

openTelemetry.WithTracing(t => t
    .AddSource(IdentityServerConstants.Tracing.Basic)
    .AddSource(IdentityServerConstants.Tracing.Cache)
    .AddSource(IdentityServerConstants.Tracing.Services)
    .AddSource(IdentityServerConstants.Tracing.Stores)
    .AddSource(IdentityServerConstants.Tracing.Validation)
    .AddAspNetCoreInstrumentation()
    .AddConsoleExporter());

Add the Prometheus exporter to the pipeline

// Map /metrics that displays Otel data in human readable form.
app.UseOpenTelemetryPrometheusScrapingEndpoint();

This setup will write the tracing information to the console

[19:06:23 Information] Duende.IdentityServer.Services.KeyManagement.KeyManager
Active signing key found with kid 331A43945BC046873E2FC31CD0C1EF4B for alg RS256. Expires in 89.23:53:18.9837518. Retires in 103.23:53:18.9837518

Activity.TraceId:            659aa4241cddc636355cccdcd4d3d979
Activity.SpanId:             45186a707b1bfe0c
Activity.TraceFlags:         Recorded
Activity.ParentSpanId:       573c530b882abc6b
Activity.ActivitySourceName: Duende.IdentityServer.Services
Activity.DisplayName:        KeyManager.GetCurrentKeys
Activity.Kind:               Internal
Activity.StartTime:          2024-01-24T18:06:23.4896277Z
Activity.Duration:           00:00:00.0014259
Resource associated with Activity:
    service.name: Host.Main
    service.instance.id: 68a67ff4-cf2b-4410-8195-c7e75cd8869c
    telemetry.sdk.name: opentelemetry
    telemetry.sdk.language: dotnet
    telemetry.sdk.version: 1.6.0

Activity.TraceId:            659aa4241cddc636355cccdcd4d3d979
Activity.SpanId:             573c530b882abc6b
Activity.TraceFlags:         Recorded
Activity.ParentSpanId:       e5fad046a7cbe854
Activity.ActivitySourceName: Duende.IdentityServer.Services
Activity.DisplayName:        DefaultKeyMaterialService.GetAllSigningCredentials
Activity.Kind:               Internal
Activity.StartTime:          2024-01-24T18:06:23.4896164Z
Activity.Duration:           00:00:00.0049134
Resource associated with Activity:
    service.name: Host.Main
    service.instance.id: 68a67ff4-cf2b-4410-8195-c7e75cd8869c
    telemetry.sdk.name: opentelemetry
    telemetry.sdk.language: dotnet
    telemetry.sdk.version: 1.6.0

We can see that the inner activity/span KeyManager.GetcurrentKeys is reported as complete first, with a ParentSpanId of 573c530b882abc6b. Next the parent DefaultKeyMaterialService.GetAllSigningCredentials with SpanId 573c530b882abc6b is reported as completed.

The Prometheus metrics format on the /metrics endpoint is human readable

# TYPE user_login_total counter
user_login_total{client="",idp="local"} 1 1706119316543
user_login_total{client="mvc.code",idp="local"} 1 1706119316543

# TYPE user_login_failure_total counter
user_login_failure_total{client="mvc.code",error="invalid credentials",idp="local"} 1 1706119316543

# TYPE user_logout_total counter
user_logout_total{idp="local"} 1 1706119316543

# TYPE active_requests gauge
active_requests{endpoint="Duende.IdentityServer.Endpoints.DiscoveryEndpoint",path="/.well-known/openid-configuration"} 0 1706119316543
active_requests{endpoint="Duende.IdentityServer.Endpoints.DiscoveryKeyEndpoint",path="/.well-known/openid-configuration/jwks"} 0 1706119316543
active_requests{endpoint="Duende.IdentityServer.Endpoints.AuthorizeEndpoint",path="/connect/authorize"} 0 1706119316543
active_requests{endpoint="Duende.IdentityServer.Endpoints.AuthorizeCallbackEndpoint",path="/connect/authorize/callback"} 0 1706119316543
active_requests{endpoint="Duende.IdentityServer.Endpoints.TokenEndpoint",path="/connect/token"} 0 1706119316543
active_requests{endpoint="Duende.IdentityServer.Endpoints.UserInfoEndpoint",path="/connect/userinfo"} 0 1706119316543

# TYPE success_total counter
success_total{client="mvc.code"} 29 1706119316543

# TYPE client_validation_total counter
client_validation_total{client="mvc.code"} 16 1706119316543

# TYPE clientsecret_validation_total counter
clientsecret_validation_total{auth_method="SharedSecret",client="mvc.code"} 6 1706119316543

# TYPE token_issued_total counter
token_issued_total{authorize_request_type="Authorize",client="mvc.code",grant_type="authorization_code"} 1 1706119316543
token_issued_total{authorize_request_type="",client="mvc.code",grant_type="authorization_code"} 1 1706119316543
token_issued_total{authorize_request_type="",client="mvc.code",grant_type="refresh_token"} 5 1706119316543

# EOF

Using Prometheus we can display the information as graphs.