Skip to content

Commit 9ea2d08

Browse files
matt-hensleyalanwest
matt-hensley
and
alanwest
authored
[Instrumentation.SqlClient] Implements database metric db.client.operation.duration (part 2/netfx) (#2311)
Co-authored-by: Alan West <[email protected]>
1 parent afe4342 commit 9ea2d08

File tree

5 files changed

+237
-90
lines changed

5 files changed

+237
-90
lines changed

‎src/OpenTelemetry.Instrumentation.SqlClient/CHANGELOG.md‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,16 @@
5353

5454
* **Breaking change**: The `SetDbStatementForStoredProcedure` option has been removed.
5555
([#TBD](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/TBD))
56+
* Add support for metric `db.client.operation.duration`
57+
from [new database semantic conventions](https://github.com/open-telemetry/semantic-conventions/blob/v1.28.0/docs/database/database-metrics.md#metric-dbclientoperationduration)
58+
on .NET 8+.
59+
([#2309](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2309))
60+
* Add support for metric `db.client.operation.duration`
61+
from [new database semantic conventions](https://github.com/open-telemetry/semantic-conventions/blob/v1.28.0/docs/database/database-metrics.md#metric-dbclientoperationduration)
62+
on .NET Framework.
63+
([#2311](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2311))
64+
* Only the following attributes are available when a trace is not captured:
65+
`db.system`, `db.response.status_code`, and `error.type`
5666

5767
* Updated OpenTelemetry core component version(s) to `1.10.0`.
5868
([#2317](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/2317))

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

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,18 @@ internal sealed class SqlActivitySourceHelper
3030
"s",
3131
"Duration of database client operations.");
3232

33+
internal static readonly string[] SharedTagNames =
34+
[
35+
SemanticConventions.AttributeDbSystem,
36+
SemanticConventions.AttributeDbCollectionName,
37+
SemanticConventions.AttributeDbNamespace,
38+
SemanticConventions.AttributeDbResponseStatusCode,
39+
SemanticConventions.AttributeDbOperationName,
40+
SemanticConventions.AttributeErrorType,
41+
SemanticConventions.AttributeServerPort,
42+
SemanticConventions.AttributeServerAddress,
43+
];
44+
3345
public static TagList GetTagListFromConnectionInfo(string? dataSource, string? databaseName, SqlClientTraceInstrumentationOptions options, out string activityName)
3446
{
3547
activityName = MicrosoftSqlServerDatabaseSystemName;
@@ -97,4 +109,14 @@ public static TagList GetTagListFromConnectionInfo(string? dataSource, string? d
97109

98110
return tags;
99111
}
112+
113+
internal static double CalculateDurationFromTimestamp(long begin, long? end = null)
114+
{
115+
end = end ?? Stopwatch.GetTimestamp();
116+
var timestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
117+
var delta = end - begin;
118+
var ticks = (long)(timestampToTicks * delta);
119+
var duration = new TimeSpan(ticks);
120+
return duration.TotalSeconds;
121+
}
100122
}

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

Lines changed: 3 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -26,18 +26,6 @@ internal sealed class SqlClientDiagnosticListener : ListenerHandler
2626
public const string SqlDataWriteCommandError = "System.Data.SqlClient.WriteCommandError";
2727
public const string SqlMicrosoftWriteCommandError = "Microsoft.Data.SqlClient.WriteCommandError";
2828

29-
private static readonly string[] SharedTagNames =
30-
[
31-
SemanticConventions.AttributeDbSystem,
32-
SemanticConventions.AttributeDbCollectionName,
33-
SemanticConventions.AttributeDbNamespace,
34-
SemanticConventions.AttributeDbResponseStatusCode,
35-
SemanticConventions.AttributeDbOperationName,
36-
SemanticConventions.AttributeErrorType,
37-
SemanticConventions.AttributeServerPort,
38-
SemanticConventions.AttributeServerAddress,
39-
];
40-
4129
private readonly PropertyFetcher<object> commandFetcher = new("Command");
4230
private readonly PropertyFetcher<object> connectionFetcher = new("Connection");
4331
private readonly PropertyFetcher<string> dataSourceFetcher = new("DataSource");
@@ -257,7 +245,7 @@ private void RecordDuration(Activity? activity, object? payload, bool hasError =
257245

258246
if (activity != null && activity.IsAllDataRequested)
259247
{
260-
foreach (var name in SharedTagNames)
248+
foreach (var name in SqlActivitySourceHelper.SharedTagNames)
261249
{
262250
var value = activity.GetTagItem(name);
263251
if (value != null)
@@ -310,19 +298,9 @@ private void RecordDuration(Activity? activity, object? payload, bool hasError =
310298
}
311299
}
312300

313-
var duration = activity?.Duration.TotalSeconds ?? this.CalculateDurationFromTimestamp();
301+
var duration = activity?.Duration.TotalSeconds
302+
?? SqlActivitySourceHelper.CalculateDurationFromTimestamp(this.beginTimestamp.Value);
314303
SqlActivitySourceHelper.DbClientOperationDuration.Record(duration, tags);
315304
}
316-
317-
private double CalculateDurationFromTimestamp()
318-
{
319-
var timestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
320-
var begin = this.beginTimestamp.Value;
321-
var end = Stopwatch.GetTimestamp();
322-
var delta = end - begin;
323-
var ticks = (long)(timestampToTicks * delta);
324-
var duration = new TimeSpan(ticks);
325-
return duration.TotalSeconds;
326-
}
327305
}
328306
#endif

‎src/OpenTelemetry.Instrumentation.SqlClient/Implementation/SqlEventSourceListener.netfx.cs‎

Lines changed: 79 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,7 @@ internal sealed class SqlEventSourceListener : EventListener
2929
internal const int BeginExecuteEventId = 1;
3030
internal const int EndExecuteEventId = 2;
3131

32+
private readonly AsyncLocal<long> beginTimestamp = new();
3233
private EventSource? adoNetEventSource;
3334
private EventSource? mdsEventSource;
3435

@@ -82,6 +83,29 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData)
8283
}
8384
}
8485

86+
private static (bool HasError, string? ErrorNumber, string? ExceptionType) ExtractErrorFromEvent(EventWrittenEventArgs eventData)
87+
{
88+
var compositeState = (int)eventData.Payload[1];
89+
90+
if ((compositeState & 0b001) != 0b001)
91+
{
92+
if ((compositeState & 0b010) == 0b010)
93+
{
94+
var errorNumber = $"{eventData.Payload[2]}";
95+
var exceptionType = eventData.EventSource.Name == MdsEventSourceName
96+
? "Microsoft.Data.SqlClient.SqlException"
97+
: "System.Data.SqlClient.SqlException";
98+
return (true, errorNumber, exceptionType);
99+
}
100+
else
101+
{
102+
return (true, null, null);
103+
}
104+
}
105+
106+
return (false, null, null);
107+
}
108+
85109
private void OnBeginExecute(EventWrittenEventArgs eventData)
86110
{
87111
/*
@@ -100,7 +124,7 @@ private void OnBeginExecute(EventWrittenEventArgs eventData)
100124
(https://github.com/dotnet/SqlClient/blob/f4568ce68da21db3fe88c0e72e1287368aaa1dc8/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs#L6641)
101125
*/
102126

103-
if (SqlClientInstrumentation.TracingHandles == 0)
127+
if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles == 0)
104128
{
105129
return;
106130
}
@@ -125,6 +149,7 @@ private void OnBeginExecute(EventWrittenEventArgs eventData)
125149
if (activity == null)
126150
{
127151
// There is no listener or it decided not to sample the current request.
152+
this.beginTimestamp.Value = Stopwatch.GetTimestamp();
128153
return;
129154
}
130155

@@ -155,7 +180,7 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
155180
[2] -> SqlExceptionNumber
156181
*/
157182

158-
if (SqlClientInstrumentation.TracingHandles == 0)
183+
if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles == 0)
159184
{
160185
return;
161186
}
@@ -166,6 +191,12 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
166191
return;
167192
}
168193

194+
if (SqlClientInstrumentation.TracingHandles == 0 && SqlClientInstrumentation.MetricHandles != 0)
195+
{
196+
this.RecordDuration(null, eventData);
197+
return;
198+
}
199+
169200
var activity = Activity.Current;
170201
if (activity?.Source != SqlActivitySourceHelper.ActivitySource)
171202
{
@@ -176,18 +207,14 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
176207
{
177208
if (activity.IsAllDataRequested)
178209
{
179-
var compositeState = (int)eventData.Payload[1];
180-
if ((compositeState & 0b001) != 0b001)
210+
var (hasError, errorNumber, exceptionType) = ExtractErrorFromEvent(eventData);
211+
212+
if (hasError)
181213
{
182-
if ((compositeState & 0b010) == 0b010)
214+
if (errorNumber != null && exceptionType != null)
183215
{
184-
var errorNumber = $"{eventData.Payload[2]}";
185216
activity.SetStatus(ActivityStatusCode.Error, errorNumber);
186217
activity.SetTag(SemanticConventions.AttributeDbResponseStatusCode, errorNumber);
187-
188-
var exceptionType = eventData.EventSource.Name == MdsEventSourceName
189-
? "Microsoft.Data.SqlClient.SqlException"
190-
: "System.Data.SqlClient.SqlException";
191218
activity.SetTag(SemanticConventions.AttributeErrorType, exceptionType);
192219
}
193220
else
@@ -200,7 +227,49 @@ private void OnEndExecute(EventWrittenEventArgs eventData)
200227
finally
201228
{
202229
activity.Stop();
230+
this.RecordDuration(activity, eventData);
231+
}
232+
}
233+
234+
private void RecordDuration(Activity? activity, EventWrittenEventArgs eventData)
235+
{
236+
if (SqlClientInstrumentation.MetricHandles == 0)
237+
{
238+
return;
239+
}
240+
241+
var tags = default(TagList);
242+
243+
if (activity != null && activity.IsAllDataRequested)
244+
{
245+
foreach (var name in SqlActivitySourceHelper.SharedTagNames)
246+
{
247+
var value = activity.GetTagItem(name);
248+
if (value != null)
249+
{
250+
tags.Add(name, value);
251+
}
252+
}
253+
}
254+
else
255+
{
256+
tags.Add(SemanticConventions.AttributeDbSystem, SqlActivitySourceHelper.MicrosoftSqlServerDatabaseSystemName);
257+
258+
var (hasError, errorNumber, exceptionType) = ExtractErrorFromEvent(eventData);
259+
260+
if (hasError)
261+
{
262+
if (errorNumber != null && exceptionType != null)
263+
{
264+
tags.Add(SemanticConventions.AttributeDbResponseStatusCode, errorNumber);
265+
tags.Add(SemanticConventions.AttributeErrorType, exceptionType);
266+
}
267+
}
203268
}
269+
270+
var duration = activity?.Duration.TotalSeconds
271+
?? SqlActivitySourceHelper.CalculateDurationFromTimestamp(this.beginTimestamp.Value);
272+
SqlActivitySourceHelper.DbClientOperationDuration.Record(duration, tags);
204273
}
205274
}
206275
#endif

0 commit comments

Comments
 (0)