[Instrumentation.SqlClient] Implements database metric db.client.operation.duration (part 2/netfx)

src/OpenTelemetry.Instrumentation.SqlClient/CHANGELOG.md

@@ -53,6 +53,16 @@
 
 * **Breaking change**: The `SetDbStatementForStoredProcedure` option has been removed.
   ([#TBD](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/TBD))
+* Add support for metric `db.client.operation.duration`
+  from [new database semantic conventions](https://github.com/open-telemetry/semantic-conventions/blob/v1.28.0/docs/database/database-metrics.md#metric-dbclientoperationduration)
+  on .NET 8+.
+  ([#2309](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2309))
+* Add support for metric `db.client.operation.duration`
+  from [new database semantic conventions](https://github.com/open-telemetry/semantic-conventions/blob/v1.28.0/docs/database/database-metrics.md#metric-dbclientoperationduration)
+  on .NET Framework.
+  ([#2311](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2311))
+  * Only the following attributes are available when a trace is not captured:
+  `db.system`, `db.response.status_code`, and `error.type`
 
 * Updated OpenTelemetry core component version(s) to `1.10.0`.
   ([#2317](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2317))

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

@@ -30,6 +30,18 @@ internal sealed class SqlActivitySourceHelper
         "s",
         "Duration of database client operations.");
 
+    internal static readonly string[] SharedTagNames =
+    [
+        SemanticConventions.AttributeDbSystem,
+        SemanticConventions.AttributeDbCollectionName,
+        SemanticConventions.AttributeDbNamespace,
+        SemanticConventions.AttributeDbResponseStatusCode,
+        SemanticConventions.AttributeDbOperationName,
+        SemanticConventions.AttributeErrorType,
+        SemanticConventions.AttributeServerPort,
+        SemanticConventions.AttributeServerAddress,
+    ];
+
     public static TagList GetTagListFromConnectionInfo(string? dataSource, string? databaseName, SqlClientTraceInstrumentationOptions options, out string activityName)
     {
         activityName = MicrosoftSqlServerDatabaseSystemName;
@@ -97,4 +109,14 @@ public static TagList GetTagListFromConnectionInfo(string? dataSource, string? d
 
         return tags;
     }
+
+    internal static double CalculateDurationFromTimestamp(long begin, long? end = null)
+    {
+        end = end ?? Stopwatch.GetTimestamp();
+        var timestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
+        var delta = end - begin;
+        var ticks = (long)(timestampToTicks * delta);
+        var duration = new TimeSpan(ticks);
+        return duration.TotalSeconds;
+    }
 }

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

@@ -26,18 +26,6 @@ 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");
@@ -257,7 +245,7 @@ private void RecordDuration(Activity? activity, object? payload, bool hasError =
 
         if (activity != null && activity.IsAllDataRequested)
         {
-            foreach (var name in SharedTagNames)
+            foreach (var name in SqlActivitySourceHelper.SharedTagNames)
             {
                 var value = activity.GetTagItem(name);
                 if (value != null)
@@ -310,19 +298,9 @@ private void RecordDuration(Activity? activity, object? payload, bool hasError =
             }
         }
 
-        var duration = activity?.Duration.TotalSeconds ?? this.CalculateDurationFromTimestamp();
+        var duration = activity?.Duration.TotalSeconds
+            ?? SqlActivitySourceHelper.CalculateDurationFromTimestamp(this.beginTimestamp.Value);
         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/Implementation/SqlEventSourceListener.netfx.cs

@@ -29,6 +29,7 @@ internal sealed class SqlEventSourceListener : EventListener
     internal const int BeginExecuteEventId = 1;
     internal const int EndExecuteEventId = 2;
 
+    private readonly AsyncLocal<long> beginTimestamp = new();
     private EventSource? adoNetEventSource;
     private EventSource? mdsEventSource;
 
@@ -82,6 +83,29 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData)
         }
     }
 
+    private static (bool HasError, string? ErrorNumber, string? ExceptionType) ExtractErrorFromEvent(EventWrittenEventArgs eventData)
+    {
+        var compositeState = (int)eventData.Payload[1];
+
+        if ((compositeState & 0b001) != 0b001)
+        {
+            if ((compositeState & 0b010) == 0b010)
+            {
+                var errorNumber = $"{eventData.Payload[2]}";
+                var exceptionType = eventData.EventSource.Name == MdsEventSourceName
+                    ? "Microsoft.Data.SqlClient.SqlException"
+                    : "System.Data.SqlClient.SqlException";
+                return (true, errorNumber, exceptionType);
+            }
+            else
+            {
+                return (true, null, null);
+            }
+        }
+
+        return (false, null, null);
+    }
+
     private void OnBeginExecute(EventWrittenEventArgs eventData)
     {
         /*
@@ -100,7 +124,7 @@ private void OnBeginExecute(EventWrittenEventArgs eventData)
                 (https://github.com/dotnet/SqlClient/blob/f4568ce68da21db3fe88c0e72e1287368aaa1dc8/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs#L6641)
          */
 
-        if (SqlClientInstrumentation.TracingHandles == 0)
+        if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles == 0)
         {
             return;
         }
@@ -125,6 +149,7 @@ private void OnBeginExecute(EventWrittenEventArgs eventData)
         if (activity == null)
         {
             // There is no listener or it decided not to sample the current request.
+            this.beginTimestamp.Value = Stopwatch.GetTimestamp();
             return;
         }
 
@@ -155,7 +180,7 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
             [2] -> SqlExceptionNumber
          */
 
-        if (SqlClientInstrumentation.TracingHandles == 0)
+        if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles == 0)
         {
             return;
         }
@@ -166,6 +191,12 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
             return;
         }
 
+        if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles != 0)
+        {
+            this.RecordDuration(null, eventData);
+            return;
+        }
+
         var activity = Activity.Current;
         if (activity?.Source != SqlActivitySourceHelper.ActivitySource)
         {
@@ -176,18 +207,14 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
         {
             if (activity.IsAllDataRequested)
             {
-                var compositeState = (int)eventData.Payload[1];
-                if ((compositeState & 0b001) != 0b001)
+                var (hasError, errorNumber, exceptionType) = ExtractErrorFromEvent(eventData);
+
+                if (hasError)
                 {
-                    if ((compositeState & 0b010) == 0b010)
+                    if (errorNumber != null && exceptionType != null)
                     {
-                        var errorNumber = $"{eventData.Payload[2]}";
                         activity.SetStatus(ActivityStatusCode.Error, errorNumber);
                         activity.SetTag(SemanticConventions.AttributeDbResponseStatusCode, errorNumber);
-
-                        var exceptionType = eventData.EventSource.Name == MdsEventSourceName
-                            ? "Microsoft.Data.SqlClient.SqlException"
-                            : "System.Data.SqlClient.SqlException";
                         activity.SetTag(SemanticConventions.AttributeErrorType, exceptionType);
                     }
                     else
@@ -200,7 +227,49 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
         finally
         {
             activity.Stop();
+            this.RecordDuration(activity, eventData);
+        }
+    }
+
+    private void RecordDuration(Activity? activity, EventWrittenEventArgs eventData)
+    {
+        if (SqlClientInstrumentation.MetricHandles == 0)
+        {
+            return;
+        }
+
+        var tags = default(TagList);
+
+        if (activity != null && activity.IsAllDataRequested)
+        {
+            foreach (var name in SqlActivitySourceHelper.SharedTagNames)
+            {
+                var value = activity.GetTagItem(name);
+                if (value != null)
+                {
+                    tags.Add(name, value);
+                }
+            }
+        }
+        else
+        {
+            tags.Add(SemanticConventions.AttributeDbSystem, SqlActivitySourceHelper.MicrosoftSqlServerDatabaseSystemName);
+
+            var (hasError, errorNumber, exceptionType) = ExtractErrorFromEvent(eventData);
+
+            if (hasError)
+            {
+                if (errorNumber != null && exceptionType != null)
+                {
+                    tags.Add(SemanticConventions.AttributeDbResponseStatusCode, errorNumber);
+                    tags.Add(SemanticConventions.AttributeErrorType, exceptionType);
+                }
+            }
         }
+
+        var duration = activity?.Duration.TotalSeconds
+            ?? SqlActivitySourceHelper.CalculateDurationFromTimestamp(this.beginTimestamp.Value);
+        SqlActivitySourceHelper.DbClientOperationDuration.Record(duration, tags);
     }
 }
 #endif