Skip to content

Fix missing http.status_code tag on ASP.NET Core spans with errors#2458

Merged
andrewlock merged 2 commits into
masterfrom
andrew/fix-aspnetcore-errors
Feb 18, 2022
Merged

Fix missing http.status_code tag on ASP.NET Core spans with errors#2458
andrewlock merged 2 commits into
masterfrom
andrew/fix-aspnetcore-errors

Conversation

@andrewlock

@andrewlock andrewlock commented Feb 17, 2022

Copy link
Copy Markdown
Member

Summary of changes

  • Ensure that we always set the http.status_code flag on ASP.NET Core spans
  • Small sample helper for setting an exception on the active span using reflection.

Reason for change

If the customer marks the root aspnetcore request Span as an error (e.g. using Tracer.ActiveScope.Span.SetException(ex)), currently we don't record the HTTP status code on response end. As a 200 response is assumed in these cases, we have error spans with the wrong status code.

This is especially likely to occur when the customer is not using DD_TRACE_ROUTE_TEMPLATE_RESOURCE_NAMES_ENABLED (i.e. the default in v1.x), as in these cases we only create a single aspnetcore span. When the feature flag is enabled (the default in v2.x), calling Tracer.ActiveScope.Span.SetException(ex) sets the error on the inner span, and so we record the final status code correctly.

As part of the fix, spotted #2460

Implementation details

If an exception occurs in the pipeline and isn't handled, the OnHostingUnhandledException handler will record an appropriate status code. It needs to do some inferring of the final status code, as Kestrel may change the result after the pipeline has finished. Previously, we were using the presence of an error on the span to control whether to set the HTTP status code, to avoid overwriting with the wrong value.

Instead, we now check to see if the status code has been set at all. If it hasn't, we set it. This fixes the bug, without requiring any significant changes.

Test coverage

Added an additional endpoint for testing this situation. Created snapshots for the expected results, confirmed they were missing the status code, then made the fix and confirmed it resolved.

Other details

Fixes APMS-6804

@DataDog/apm-dotnet

…status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.
@andrewlock andrewlock added type:bug area:automatic-instrumentation Automatic instrumentation managed C# code (Datadog.Trace.ClrProfiler.Managed) labels Feb 17, 2022
@andrewlock
andrewlock requested a review from a team as a code owner February 17, 2022 13:55
@andrewlock
andrewlock force-pushed the andrew/fix-aspnetcore-errors branch from 770908f to e22e610 Compare February 17, 2022 14:10
@andrewlock

Copy link
Copy Markdown
Member Author

Code Coverage Report 📊

✔️ Merging #2458 into master will not change line coverage
✔️ Merging #2458 into master will not change branch coverage
⛔ Merging #2458 into master will will increase complexity by 66

master #2458 Change
Lines 11540 / 15880 11623 / 15971
Lines % 73% 73% 0% ✔️
Branches 6198 / 9276 6255 / 9336
Branches % 67% 67% 0% ✔️
Complexity 10480 10546 66

View the full report for further details:

Datadog.Trace Breakdown ✔️

master #2458 Change
Lines % 73% 73% 0% ✔️
Branches % 67% 67% 0% ✔️
Complexity 10480 10546 66

The following classes have significant coverage changes.

File Line coverage change Branch coverage change Complexity change
Datadog.Trace.ClrProfiler.AutoInstrumentation.MongoDb.MongoDbIntegration -7% 0% ✔️ 0 ✔️

The following classes were added in #2458:

File Line coverage Branch coverage Complexity
Datadog.Trace.Tagging.TraceTagCollection 94% 92% 58

View the full reports for further details:

@andrewlock

Copy link
Copy Markdown
Member Author

Benchmarks Report 🐌

Benchmarks for #2458 compared to master:

  • All benchmarks have the same speed
  • All benchmarks have the same allocations

The following thresholds were used for comparing the benchmark speeds:

  • Mann–Whitney U test with statistical test for significance of 5%
  • Only results indicating a difference greater than 10% and 0.3 ns are considered.

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net472 853μs 3.84μs 14.9μs 0 0 0 3.16 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 640μs 2.52μs 9.42μs 0 0 0 2.57 KB
#2458 WriteAndFlushEnrichedTraces net472 861μs 3.05μs 11.4μs 0 0 0 3.17 KB
#2458 WriteAndFlushEnrichedTraces netcoreapp3.1 654μs 2.45μs 9.48μs 0 0 0 2.57 KB
Benchmarks.Trace.AspNetCoreBenchmark - Unknown 🤷 Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
master SendRequest netcoreapp3.1 303μs 1.27μs 4.76μs 0.146 0 0 19.71 KB
#2458 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#2458 SendRequest netcoreapp3.1 297μs 1.36μs 6.64μs 0.152 0 0 19.71 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net472 1.66μs 6.03ns 23.4ns 0.0923 0.000839 0 586 B
master ExecuteNonQuery netcoreapp3.1 1.67μs 9.08ns 51.4ns 0.00884 0 0 624 B
#2458 ExecuteNonQuery net472 1.83μs 8.3ns 32.2ns 0.0929 0 0 586 B
#2458 ExecuteNonQuery netcoreapp3.1 1.5μs 5.47ns 20.5ns 0.00856 0 0 624 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net472 2.57μs 13.7ns 69.9ns 0.126 0 0 794 B
master CallElasticsearch netcoreapp3.1 1.77μs 5.16ns 19.3ns 0.0102 0 0 784 B
master CallElasticsearchAsync net472 2.7μs 7.19ns 24.9ns 0.147 0.00262 0.00131 931 B
master CallElasticsearchAsync netcoreapp3.1 1.73μs 6.98ns 26.1ns 0.0122 0 0 904 B
#2458 CallElasticsearch net472 2.82μs 14.9ns 84.5ns 0.126 0 0 794 B
#2458 CallElasticsearch netcoreapp3.1 1.77μs 6.51ns 25.2ns 0.0111 0 0 784 B
#2458 CallElasticsearchAsync net472 2.85μs 16.1ns 109ns 0.145 0 0 931 B
#2458 CallElasticsearchAsync netcoreapp3.1 1.8μs 6.62ns 24.8ns 0.0124 0 0 904 B
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net472 2.92μs 15.2ns 69.4ns 0.167 0.00145 0 1.05 KB
master ExecuteAsync netcoreapp3.1 2.03μs 9.76ns 40.2ns 0.0139 0 0 1.02 KB
#2458 ExecuteAsync net472 2.96μs 14.5ns 64.8ns 0.167 0.00146 0 1.05 KB
#2458 ExecuteAsync netcoreapp3.1 1.96μs 7.22ns 27ns 0.0145 0 0 1.02 KB
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net472 6.79μs 35.6ns 178ns 0.364 0 0 2.3 KB
master SendAsync netcoreapp3.1 4.85μs 13.4ns 50ns 0.0287 0 0 2.2 KB
#2458 SendAsync net472 6.91μs 30.7ns 119ns 0.364 0 0 2.3 KB
#2458 SendAsync netcoreapp3.1 5.5μs 93.8ns 938ns 0.0311 0 0 2.2 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 3.28μs 11.1ns 42.8ns 0.225 0 0 1.44 KB
master EnrichedLog netcoreapp3.1 3.02μs 7.19ns 25.9ns 0.021 0 0 1.52 KB
#2458 EnrichedLog net472 3.19μs 8.55ns 32ns 0.225 0 0 1.44 KB
#2458 EnrichedLog netcoreapp3.1 3.02μs 11.2ns 40.4ns 0.0208 0 0 1.52 KB
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 288μs 1.11μs 4.31μs 0.427 0.142 0 4.31 KB
master EnrichedLog netcoreapp3.1 226μs 865ns 3μs 0 0 0 4.19 KB
#2458 EnrichedLog net472 298μs 1.29μs 4.67μs 0.422 0.141 0 4.31 KB
#2458 EnrichedLog netcoreapp3.1 233μs 1.12μs 4.77μs 0 0 0 4.19 KB
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 7.41μs 42.4ns 306ns 0.502 0 0 3.21 KB
master EnrichedLog netcoreapp3.1 6.58μs 32.2ns 154ns 0.0491 0 0 3.58 KB
#2458 EnrichedLog net472 7.15μs 25.2ns 94.4ns 0.502 0 0 3.21 KB
#2458 EnrichedLog netcoreapp3.1 6.54μs 17.1ns 66.2ns 0.0504 0 0 3.58 KB
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net472 2.28μs 11.9ns 60.8ns 0.159 0 0 1 KB
master SendReceive netcoreapp3.1 1.98μs 3.84ns 14.4ns 0.0137 0 0 1 KB
#2458 SendReceive net472 2.36μs 10.2ns 39.7ns 0.158 0.00114 0 1 KB
#2458 SendReceive netcoreapp3.1 1.99μs 10.1ns 45ns 0.0138 0 0 1 KB
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 5.82μs 20.9ns 81ns 0.288 0 0 1.85 KB
master EnrichedLog netcoreapp3.1 4.92μs 14.6ns 56.6ns 0.0197 0 0 1.47 KB
#2458 EnrichedLog net472 5.98μs 24.6ns 92ns 0.29 0 0 1.85 KB
#2458 EnrichedLog netcoreapp3.1 5.14μs 10ns 34.7ns 0.0202 0 0 1.47 KB
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net472 916ns 4.33ns 17.3ns 0.0707 0 0 449 B
master StartFinishSpan netcoreapp3.1 887ns 2.7ns 10.5ns 0.00617 0 0 448 B
master StartFinishScope net472 1.04μs 4.04ns 15.1ns 0.0834 0 0 530 B
master StartFinishScope netcoreapp3.1 1.05μs 5.04ns 19.5ns 0.00779 0 0 568 B
#2458 StartFinishSpan net472 881ns 4.1ns 15.9ns 0.0706 0 0 449 B
#2458 StartFinishSpan netcoreapp3.1 866ns 4ns 14.4ns 0.00601 0 0 448 B
#2458 StartFinishScope net472 1.05μs 3.63ns 14ns 0.0829 0 0 530 B
#2458 StartFinishScope netcoreapp3.1 1.16μs 14.7ns 145ns 0.00756 0 0 568 B

@andrewlock
andrewlock merged commit ae675e1 into master Feb 18, 2022
@andrewlock
andrewlock deleted the andrew/fix-aspnetcore-errors branch February 18, 2022 09:46
@github-actions github-actions Bot added this to the vNext milestone Feb 18, 2022
andrewlock added a commit that referenced this pull request Feb 21, 2022
…2458)

* Add tests for case where an exception is set on a span and a non-200 status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.

* Fix missing HTTP status code tag when span is manually marked as an error
andrewlock added a commit that referenced this pull request Feb 21, 2022
…2458)

* Add tests for case where an exception is set on a span and a non-200 status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.

* Fix missing HTTP status code tag when span is manually marked as an error
andrewlock added a commit that referenced this pull request Feb 21, 2022
…2458)

* Add tests for case where an exception is set on a span and a non-200 status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.

* Fix missing HTTP status code tag when span is manually marked as an error
andrewlock added a commit that referenced this pull request Feb 21, 2022
…2458)

* Add tests for case where an exception is set on a span and a non-200 status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.

* Fix missing HTTP status code tag when span is manually marked as an error
andrewlock added a commit that referenced this pull request Feb 21, 2022
* Fix missing `http.status_code` tag on ASP.NET Core spans with errors (#2458)

* Add tests for case where an exception is set on a span and a non-200 status code is set

Shows that the tests are failing for the "legacy" (feature-flag disabled) use case.

* Fix missing HTTP status code tag when span is manually marked as an error

* Support cleaning filenames in http-client + aspnet (#2471)

The HttpClient integration (and the ASP.NET/ASP.NET Core integration when the feature flag is disabled) all do "cleaning" of URLs to try and reduce the cardinality introduced by number/guid route parameters. This works by examining each "segment" in a URL, and using heuristics to see if we should replace it with `?`.

This works as expected for the following paths:
- `/some/value/123` => `/some/value/?`
- `/some/value/123/123-456 => `/some/value/?/?`
- `/some/value/123/example.png => `/some/value/?/example.png`

However, it treats the whole final segment as a single unit, which means filenames with extensions will never be obfuscated, e.g.

- `/some-filevalue/123.png`
- `/some-filevalue/123.456`
- `/some-filevalue/123.c`

That can lead to high cardinality, which in turn can cause problems for customers with too many endpoints in their account.

To work around it, we treat the filename as a separate segment from the file extension, and don't try and obfuscate the extension

* Always set response header tags in ASP.NET Core (#2480)

* Fix sample helpers and update snapshots

Thes changes were necessary because of the significant differences between master and release/1.x
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area:automatic-instrumentation Automatic instrumentation managed C# code (Datadog.Trace.ClrProfiler.Managed) type:bug

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants