[Instrumentation.SqlClient] Implements database metric db.client.operation.duration (open-telemetry#2309)

Author: matt-hensley

src/OpenTelemetry.Instrumentation.SqlClient/.publicApi/PublicAPI.Unshipped.txt

@@ -11,7 +11,9 @@ OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions.Rec
 OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions.SetDbStatementForText.get -> bool
 OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions.SetDbStatementForText.set -> void
 OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions.SqlClientTraceInstrumentationOptions() -> void
+OpenTelemetry.Metrics.SqlClientMeterProviderBuilderExtensions
 OpenTelemetry.Trace.TracerProviderBuilderExtensions
+static OpenTelemetry.Metrics.SqlClientMeterProviderBuilderExtensions.AddSqlClientInstrumentation(this OpenTelemetry.Metrics.MeterProviderBuilder! builder) -> OpenTelemetry.Metrics.MeterProviderBuilder!
 static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddSqlClientInstrumentation(this OpenTelemetry.Trace.TracerProviderBuilder! builder) -> OpenTelemetry.Trace.TracerProviderBuilder!
 static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddSqlClientInstrumentation(this OpenTelemetry.Trace.TracerProviderBuilder! builder, string? name, System.Action<OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions!>? configureSqlClientTraceInstrumentationOptions) -> OpenTelemetry.Trace.TracerProviderBuilder!
 static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddSqlClientInstrumentation(this OpenTelemetry.Trace.TracerProviderBuilder! builder, System.Action<OpenTelemetry.Instrumentation.SqlClient.SqlClientTraceInstrumentationOptions!>! configureSqlClientTraceInstrumentationOptions) -> OpenTelemetry.Trace.TracerProviderBuilder!

src/OpenTelemetry.Instrumentation.SqlClient/Implementation/SqlActivitySourceHelper.cs

@@ -2,6 +2,7 @@
 // SPDX-License-Identifier: Apache-2.0
 
 using System.Diagnostics;
+using System.Diagnostics.Metrics;
 using System.Reflection;
 using OpenTelemetry.Internal;
 using OpenTelemetry.Trace;
@@ -21,6 +22,14 @@ internal sealed class SqlActivitySourceHelper
     public static readonly string ActivitySourceName = AssemblyName.Name!;
     public static readonly ActivitySource ActivitySource = new(ActivitySourceName, Assembly.GetPackageVersion());
 
+    public static readonly string MeterName = AssemblyName.Name!;
+    public static readonly Meter Meter = new(MeterName, Assembly.GetPackageVersion());
+
+    public static readonly Histogram<double> DbClientOperationDuration = Meter.CreateHistogram<double>(
+        "db.client.operation.duration",
+        "s",
+        "Duration of database client operations.");
+
     public static TagList GetTagListFromConnectionInfo(string? dataSource, string? databaseName, SqlClientTraceInstrumentationOptions options, out string activityName)
     {
         activityName = MicrosoftSqlServerDatabaseSystemName;

src/OpenTelemetry.Instrumentation.SqlClient/Implementation/SqlClientDiagnosticListener.cs

@@ -26,6 +26,18 @@ internal sealed class SqlClientDiagnosticListener : ListenerHandler
     public const string SqlDataWriteCommandError = "System.Data.SqlClient.WriteCommandError";
     public const string SqlMicrosoftWriteCommandError = "Microsoft.Data.SqlClient.WriteCommandError";
 
+    private static readonly string[] SharedTagNames =
+    [
+        SemanticConventions.AttributeDbSystem,
+        SemanticConventions.AttributeDbCollectionName,
+        SemanticConventions.AttributeDbNamespace,
+        SemanticConventions.AttributeDbResponseStatusCode,
+        SemanticConventions.AttributeDbOperationName,
+        SemanticConventions.AttributeErrorType,
+        SemanticConventions.AttributeServerPort,
+        SemanticConventions.AttributeServerAddress,
+    ];
+
     private readonly PropertyFetcher<object> commandFetcher = new("Command");
     private readonly PropertyFetcher<object> connectionFetcher = new("Connection");
     private readonly PropertyFetcher<string> dataSourceFetcher = new("DataSource");
@@ -34,6 +46,7 @@ internal sealed class SqlClientDiagnosticListener : ListenerHandler
     private readonly PropertyFetcher<object> commandTextFetcher = new("CommandText");
     private readonly PropertyFetcher<Exception> exceptionFetcher = new("Exception");
     private readonly PropertyFetcher<int> exceptionNumberFetcher = new("Number");
+    private readonly AsyncLocal<long> beginTimestamp = new();
 
     public SqlClientDiagnosticListener(string sourceName)
         : base(sourceName)
@@ -44,7 +57,7 @@ public SqlClientDiagnosticListener(string sourceName)
 
     public override void OnEventWritten(string name, object? payload)
     {
-        if (SqlClientInstrumentation.TracingHandles == 0)
+        if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles == 0)
         {
             return;
         }
@@ -77,6 +90,7 @@ public override void OnEventWritten(string name, object? payload)
                     if (activity == null)
                     {
                         // There is no listener or it decided not to sample the current request.
+                        this.beginTimestamp.Value = Stopwatch.GetTimestamp();
                         return;
                     }
 
@@ -162,15 +176,18 @@ public override void OnEventWritten(string name, object? payload)
                     if (activity == null)
                     {
                         SqlClientInstrumentationEventSource.Log.NullActivity(name);
+                        this.RecordDuration(null, payload);
                         return;
                     }
 
                     if (activity.Source != SqlActivitySourceHelper.ActivitySource)
                     {
+                        this.RecordDuration(null, payload);
                         return;
                     }
 
                     activity.Stop();
+                    this.RecordDuration(activity, payload);
                 }
 
                 break;
@@ -180,11 +197,13 @@ public override void OnEventWritten(string name, object? payload)
                     if (activity == null)
                     {
                         SqlClientInstrumentationEventSource.Log.NullActivity(name);
+                        this.RecordDuration(null, payload);
                         return;
                     }
 
                     if (activity.Source != SqlActivitySourceHelper.ActivitySource)
                     {
+                        this.RecordDuration(null, payload);
                         return;
                     }
 
@@ -217,6 +236,7 @@ public override void OnEventWritten(string name, object? payload)
                     finally
                     {
                         activity.Stop();
+                        this.RecordDuration(activity, payload, hasError: true);
                     }
                 }
 
@@ -225,5 +245,84 @@ public override void OnEventWritten(string name, object? payload)
                 break;
         }
     }
+
+    private void RecordDuration(Activity? activity, object? payload, bool hasError = false)
+    {
+        if (SqlClientInstrumentation.MetricHandles == 0)
+        {
+            return;
+        }
+
+        TagList tags = default(TagList);
+
+        if (activity != null && activity.IsAllDataRequested)
+        {
+            foreach (var name in SharedTagNames)
+            {
+                var value = activity.GetTagItem(name);
+                if (value != null)
+                {
+                    tags.Add(name, value);
+                }
+            }
+        }
+        else if (payload != null)
+        {
+            if (this.commandFetcher.TryFetch(payload, out var command) && command != null &&
+                this.connectionFetcher.TryFetch(command, out var connection))
+            {
+                this.databaseFetcher.TryFetch(connection, out var databaseName);
+                this.dataSourceFetcher.TryFetch(connection, out var dataSource);
+
+                var connectionTags = SqlActivitySourceHelper.GetTagListFromConnectionInfo(
+                    dataSource,
+                    databaseName,
+                    SqlClientInstrumentation.TracingOptions,
+                    out _);
+
+                foreach (var tag in connectionTags)
+                {
+                    tags.Add(tag.Key, tag.Value);
+                }
+
+                if (this.commandTypeFetcher.TryFetch(command, out var commandType) &&
+                    commandType == CommandType.StoredProcedure)
+                {
+                    if (this.commandTextFetcher.TryFetch(command, out var commandText))
+                    {
+                        tags.Add(SemanticConventions.AttributeDbOperationName, "EXECUTE");
+                        tags.Add(SemanticConventions.AttributeDbCollectionName, commandText);
+                    }
+                }
+            }
+
+            if (hasError)
+            {
+                if (this.exceptionFetcher.TryFetch(payload, out var exception) && exception != null)
+                {
+                    tags.Add(SemanticConventions.AttributeErrorType, exception.GetType().FullName);
+
+                    if (this.exceptionNumberFetcher.TryFetch(exception, out var exceptionNumber))
+                    {
+                        tags.Add(SemanticConventions.AttributeDbResponseStatusCode, exceptionNumber.ToString(CultureInfo.InvariantCulture));
+                    }
+                }
+            }
+        }
+
+        var duration = activity?.Duration.TotalSeconds ?? this.CalculateDurationFromTimestamp();
+        SqlActivitySourceHelper.DbClientOperationDuration.Record(duration, tags);
+    }
+
+    private double CalculateDurationFromTimestamp()
+    {
+        var timestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
+        var begin = this.beginTimestamp.Value;
+        var end = Stopwatch.GetTimestamp();
+        var delta = end - begin;
+        var ticks = (long)(timestampToTicks * delta);
+        var duration = new TimeSpan(ticks);
+        return duration.TotalSeconds;
+    }
 }
 #endif

src/OpenTelemetry.Instrumentation.SqlClient/SqlClientInstrumentation.cs

@@ -22,6 +22,7 @@ internal sealed class SqlClientInstrumentation : IDisposable
 #if NET
     internal const string SqlClientTrimmingUnsupportedMessage = "Trimming is not yet supported with SqlClient instrumentation.";
 #endif
+    internal static int MetricHandles;
     internal static int TracingHandles;
 #if NETFRAMEWORK
     private readonly SqlEventSourceListener sqlEventSourceListener;
@@ -61,6 +62,8 @@ private SqlClientInstrumentation()
 
     public static SqlClientTraceInstrumentationOptions TracingOptions { get; set; } = new SqlClientTraceInstrumentationOptions();
 
+    public static IDisposable AddMetricHandle() => new MetricHandle();
+
     public static IDisposable AddTracingHandle() => new TracingHandle();
 
     /// <inheritdoc/>
@@ -73,6 +76,28 @@ public void Dispose()
 #endif
     }
 
+#if NET
+    [RequiresUnreferencedCode(SqlClientTrimmingUnsupportedMessage)]
+#endif
+    private sealed class MetricHandle : IDisposable
+    {
+        private bool disposed;
+
+        public MetricHandle()
+        {
+            Interlocked.Increment(ref MetricHandles);
+        }
+
+        public void Dispose()
+        {
+            if (!this.disposed)
+            {
+                Interlocked.Decrement(ref MetricHandles);
+                this.disposed = true;
+            }
+        }
+    }
+
 #if NET
     [RequiresUnreferencedCode(SqlClientTrimmingUnsupportedMessage)]
 #endif

src/OpenTelemetry.Instrumentation.SqlClient/SqlClientMeterProviderBuilderExtensions.cs

@@ -0,0 +1,39 @@
+// Copyright The OpenTelemetry Authors
+// SPDX-License-Identifier: Apache-2.0
+
+#if NET
+using System.Diagnostics.CodeAnalysis;
+#endif
+using OpenTelemetry.Instrumentation.SqlClient;
+using OpenTelemetry.Instrumentation.SqlClient.Implementation;
+using OpenTelemetry.Internal;
+
+namespace OpenTelemetry.Metrics;
+
+/// <summary>
+/// Extension methods to simplify registering of dependency instrumentation.
+/// </summary>
+public static class SqlClientMeterProviderBuilderExtensions
+{
+    /// <summary>
+    /// Enables SqlClient instrumentation.
+    /// </summary>
+    /// <param name="builder"><see cref="MeterProviderBuilder"/> being configured.</param>
+    /// <returns>The instance of <see cref="MeterProviderBuilder"/> to chain the calls.</returns>
+#if NET
+    [RequiresUnreferencedCode(SqlClientInstrumentation.SqlClientTrimmingUnsupportedMessage)]
+#endif
+    public static MeterProviderBuilder AddSqlClientInstrumentation(this MeterProviderBuilder builder)
+    {
+        Guard.ThrowIfNull(builder);
+
+        builder.AddInstrumentation(sp =>
+        {
+            return SqlClientInstrumentation.AddMetricHandle();
+        });
+
+        builder.AddMeter(SqlActivitySourceHelper.MeterName);
+
+        return builder;
+    }
+}