MSSQL span durations inaccurate when sourced from SqlClientDiagnosticListener

Kibana version: 7.17.3

Elasticsearch version: 7.17.3

APM Server version: 7.17.3

APM Agent language and version: dotnet 1.14.1 + 1.17.0

Browser version: N/A

Original install method (e.g. download page, yum, deb, from source, etc.) and version: nuget

Fresh install or upgraded from other version? N/A

Is there anything special in your setup? No

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant): MSSQL span durations appear inaccurate when sourced from SqlClientDiagnosticListener. Multiple queries across the same transaction appear to use aggregated sql server statistics in the diagnostic events, and APM treats the ExecutionTime statistic from each event as the duration for the individual span. For example if I have a 5 queries taking 100ms each, the span durations are 100 + 200 + 300 + 400 + 500 for a total of 1500ms when only 500ms have passed.

This can be observed by adding our own profiler across the database connection and creating our own span with a stopwatch to look at the duration. Early in the transaction the span duration of sql queries is correct, but then drifts and becomes inaccurate. At the end we see an update query which we have recorded on the stopwatch taking 4ms, and SqlClientDiagnosticListener has recorded it taking 102ms.

Note this doesn't affect the EFCore diagnostics listener, as EFCore libraries are timing each query with a stopwatch internally and do not use the statistics from the sql client. Should we be doing the same in SqlClientDiagnosticListener?

Steps to reproduce:

  1. Open a SQL connection
  2. Run multiple SQL commands across multiple query / execute calls
  3. Observe APM trace data

Errors in browser console (if relevant):

Provide logs and/or server output (if relevant):

Thanks for reporting @andrew012345

super useful!

I opened a GitHub issue for this: SqlClientDiagnosticListener - change how we measure duration · Issue #1869 · elastic/apm-agent-dotnet · GitHub.

We'll handle it directly in the .NET agent GitHub repo.

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.