Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[ASM] Catch HttpException when reading the request body in .net461 #6459

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from
Draft

[ASM] Catch HttpException when reading the request body in .net461 #6459

wants to merge 2 commits into from

Conversation

NachoEchevarria
Copy link
Contributor

@NachoEchevarria NachoEchevarria commented Dec 18, 2024 •
edited
Loading

Summary of changes

In .net461, we are getting an uncatched exception in two customers. The exception is System.Web.HttpException ---> System.Runtime.InteropServices.COMException

The stacktrace is:

at System.Web.Hosting.IIS7WorkerRequest.RaiseCommunicationError(Int32 result, Boolean throwOnDisconnect)
at System.Web.Hosting.IIS7WorkerRequest.ReadEntityCoreSync(Byte[] buffer, Int32 offset, Int32 size)   
at System.Web.HttpRequest.GetEntireRawContent()   
at System.Web.HttpRequest.FillInFormCollection()   
at System.Web.HttpRequest.EnsureForm()   
at System.Web.HttpRequest.get_Form()   
at Datadog.Trace.Util.RequestDataHelper.GetForm(HttpRequest request)   
at Datadog.Trace.AppSec.Coordinator.SecurityCoordinator.GetBodyFromRequest()   
at Datadog.Trace.AspNet.TracingHttpModule.OnBeginRequest(Object sender, EventArgs eventArgs)

If we take a look at the code of the system.Web assembly, we can see that this error is originated in these methods:

private int ReadEntityCoreSync(byte[] buffer, int offset, int size) {
            bool fAsync = false;
            int bytesRead = 0;
            IntPtr ppAsyncReceiveBuffer;
            int result = 0;

            try {
                // Acquire blocking call
                IsInReadEntitySync = true;  

                result = IIS.MgdReadEntityBody(_context, buffer, offset, size, fAsync, out bytesRead,out ppAsyncReceiveBuffer);
            }
            finally {
                // Release the blocking call
                IsInReadEntitySync = false;
            }

            // DevDiv Bugs 177323: mimic classic mode and don't throw if the client disconnected
            if (result < 0) {
                RaiseCommunicationError(result, false /*throwOnDisconnect*/);
            }

            if (bytesRead > 0) {
                PerfCounters.IncrementCounterEx(AppPerfCounter.REQUEST_BYTES_IN, bytesRead);
            }

            return bytesRead;
        }

        private void RaiseCommunicationError(int result, bool throwOnDisconnect) {
            if (IIS.MgdIsClientConnected(_context)) {
                throw new HttpException(SR.GetString(SR.Server_Support_Function_Error, result.ToString("X8", CultureInfo.InvariantCulture)), Marshal.GetExceptionForHR(result));
            }
            else {
                //give different error if connection was closed
                IncrementRequestsDisconnected();
                if (throwOnDisconnect) {
                    throw new HttpException(SR.GetString(SR.Server_Support_Function_Error_Disconnect, result.ToString("X8", CultureInfo.InvariantCulture)), result);
                }
            }
        }

Basically, the method IIS.MgdReadEntityBody returns an error that is sent to the method RaiseCommunicationError.

Since the method RaiseCommunicationError does not launch exceptions when the connection is closed because throwOnDisconnect is false, it is not related to that.

The method belongs to the native library webengine4.dll

    [DllImport("webengine4.dll", CharSet = CharSet.Unicode)]
    internal static extern int MgdReadEntityBody(
      IntPtr pHandler,
      byte[] pBuffer,
      int dwOffset,
      int dwBytesToRead,
      bool fAsync,
      out int pBytesRead,
      out IntPtr ppAsyncReceiveBuffer);

Other people are experiencing it:
https://stackoverflow.com/questions/7825127/system-runtime-interopservices-comexception-incorrect-function-exception-from
https://stackoverflow.com/questions/30854972/response-isclientconnected-causes-exceptions
https://stackoverflow.com/questions/8299887/asp-net-4-0-web-app-throwing-incorrect-function-exception-from-hresult-0x800

Some people suggest that this error might be caused by network card configuration problems. In any case, this is an error that might occasionally happen when reading the body of a request and does not seem to be related to the tracer's activity. In order to avoid this exception to be thrown, we should change the scope of the caught exceptions in the request helper method to include the System.Web.HttpExceptions and not only the ValidationExceptions

Reason for change

Implementation details

Test coverage

Other details

@NachoEchevarria NachoEchevarria changed the title Catch HttpException [ASM] Catch HttpException when reading the request body in .net461 Dec 18, 2024
@github-actions github-actions bot added area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) area:asm labels Dec 18, 2024
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Dec 18, 2024 •
edited
Loading

Datadog Report

Branch report: nacho/RequestComExceptionReadingBody
Commit report: 16fdae4
Test service: dd-trace-dotnet

✅ 0 Failed, 455696 Passed, 2817 Skipped, 19h 31m 45.68s Total Time

@andrewlock
Copy link
Member

Execution-Time Benchmarks Report ⏱️

Execution-time results for samples comparing the following branches/commits:

Execution-time benchmarks measure the whole time it takes to execute a program. And are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are shown in red. The following thresholds were used for comparing the execution times:

  • Welch test with statistical test for significance of 5%
  • Only results indicating a difference greater than 5% and 5 ms are considered.

Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard.

Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph).

gantt
    title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (68ms)  : 65, 72
     .   : milestone, 68,
    master - mean (69ms)  : 65, 72
     .   : milestone, 69,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (977ms)  : 954, 1000
     .   : milestone, 977,
    master - mean (978ms)  : 958, 999
     .   : milestone, 978,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (107ms)  : 105, 109
     .   : milestone, 107,
    master - mean (107ms)  : 104, 110
     .   : milestone, 107,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (678ms)  : 668, 689
     .   : milestone, 678,
    master - mean (677ms)  : 659, 695
     .   : milestone, 677,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (91ms)  : 89, 93
     .   : milestone, 91,
    master - mean (91ms)  : 89, 93
     .   : milestone, 91,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (634ms)  : 618, 649
     .   : milestone, 634,
    master - mean (635ms)  : 617, 653
     .   : milestone, 635,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (193ms)  : 189, 197
     .   : milestone, 193,
    master - mean (194ms)  : 189, 198
     .   : milestone, 194,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (1,104ms)  : 1063, 1146
     .   : milestone, 1104,
    master - mean (1,099ms)  : 1069, 1128
     .   : milestone, 1099,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (277ms)  : 271, 283
     .   : milestone, 277,
    master - mean (278ms)  : 274, 282
     .   : milestone, 278,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (867ms)  : 842, 892
     .   : milestone, 867,
    master - mean (868ms)  : 844, 892
     .   : milestone, 868,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6459) - mean (266ms)  : 263, 270
     .   : milestone, 266,
    master - mean (267ms)  : 263, 270
     .   : milestone, 267,

    section CallTarget+Inlining+NGEN
    This PR (6459) - mean (851ms)  : 815, 887
     .   : milestone, 851,
    master - mean (849ms)  : 813, 885
     .   : milestone, 849,
Loading

@andrewlock
Copy link
Member

Throughput/Crank Report ⚡

Throughput results for AspNetCoreSimpleController comparing the following branches/commits:

Cases where throughput results for the PR are worse than latest master (5% drop or greater), results are shown in red.

Note that these results are based on a single point-in-time result for each branch. For full results, see one of the many, many dashboards!

gantt
    title Throughput Linux x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6459) (11.319M)   : 0, 11318548
    master (11.134M)   : 0, 11133746
    benchmarks/2.9.0 (11.033M)   : 0, 11032866

    section Automatic
    This PR (6459) (7.126M)   : 0, 7125751
    master (7.165M)   : 0, 7165366
    benchmarks/2.9.0 (7.786M)   : 0, 7785853

    section Trace stats
    master (7.362M)   : 0, 7362423

    section Manual
    master (11.175M)   : 0, 11175451

    section Manual + Automatic
    This PR (6459) (6.715M)   : 0, 6715419
    master (6.739M)   : 0, 6739123

    section DD_TRACE_ENABLED=0
    master (10.183M)   : 0, 10183238
Loading 
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6459) (9.412M)   : 0, 9411855
    master (9.513M)   : 0, 9513449
    benchmarks/2.9.0 (9.495M)   : 0, 9494821

    section Automatic
    This PR (6459) (6.438M)   : 0, 6437989
    master (6.294M)   : 0, 6294410

    section Trace stats
    master (6.661M)   : 0, 6661128

    section Manual
    master (9.508M)   : 0, 9507729

    section Manual + Automatic
    This PR (6459) (5.956M)   : 0, 5955625
    master (5.947M)   : 0, 5946752

    section DD_TRACE_ENABLED=0
    master (8.801M)   : 0, 8800856
Loading 
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6459) (9.667M)   : 0, 9666502
    master (9.562M)   : 0, 9561990
    benchmarks/2.9.0 (10.020M)   : 0, 10019592

    section Automatic
    This PR (6459) (5.982M)   : 0, 5982494
    master (6.221M)   : 0, 6220954
    benchmarks/2.9.0 (7.255M)   : 0, 7255257

    section Trace stats
    master (6.711M)   : 0, 6710560

    section Manual
    master (9.596M)   : 0, 9595699

    section Manual + Automatic
    This PR (6459) (5.450M)   : crit ,0, 5449583
    master (5.895M)   : 0, 5895238

    section DD_TRACE_ENABLED=0
    master (8.872M)   : 0, 8872498
Loading

@andrewlock
Copy link
Member

Benchmarks Report for tracer 🐌

Benchmarks for #6459 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.119
  • 1 benchmarks are slower, with geometric mean 1.119
  • 1 benchmarks have more 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.ActivityBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 7.95μs 43.4ns 264ns 0.016 0.00798 0 5.6 KB
master StartStopWithChild netcoreapp3.1 10μs 55.9ns 353ns 0.0197 0.00986 0 5.8 KB
master StartStopWithChild net472 16.6μs 62.7ns 243ns 1.05 0.335 0.0921 6.21 KB
#6459 StartStopWithChild net6.0 8.05μs 39.8ns 264ns 0.0117 0.00391 0 5.61 KB
#6459 StartStopWithChild netcoreapp3.1 10.2μs 55.2ns 317ns 0.0196 0.00978 0 5.8 KB
#6459 StartStopWithChild net472 16.6μs 45ns 174ns 1.05 0.322 0.0992 6.21 KB
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 493μs 589ns 2.28μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 667μs 461ns 1.78μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 852μs 722ns 2.79μs 0.425 0 0 3.3 KB
#6459 WriteAndFlushEnrichedTraces net6.0 504μs 461ns 1.72μs 0 0 0 2.7 KB
#6459 WriteAndFlushEnrichedTraces netcoreapp3.1 662μs 605ns 2.26μs 0 0 0 2.7 KB
#6459 WriteAndFlushEnrichedTraces net472 854μs 356ns 1.33μs 0.425 0 0 3.3 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net6.0 157μs 888ns 7.99μs 0.164 0 0 14.47 KB
master SendRequest netcoreapp3.1 172μs 1.08μs 10.6μs 0.165 0 0 17.27 KB
master SendRequest net472 0.00382ns 0.00149ns 0.00517ns 0 0 0 0 b
#6459 SendRequest net6.0 153μs 1.05μs 10.5μs 0.141 0 0 14.47 KB
#6459 SendRequest netcoreapp3.1 162μs 903ns 5.71μs 0.185 0 0 17.27 KB
#6459 SendRequest net472 0.00267ns 0.0014ns 0.00526ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #6459

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 41.62 KB 41.92 KB 308 B 0.74%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 563μs 3.13μs 22.4μs 0.553 0 0 41.52 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 683μs 3.88μs 27.2μs 0.327 0 0 41.62 KB
master WriteAndFlushEnrichedTraces net472 832μs 4.23μs 18.9μs 8.47 2.42 0.403 53.35 KB
#6459 WriteAndFlushEnrichedTraces net6.0 579μs 3.09μs 16.9μs 0.576 0 0 41.67 KB
#6459 WriteAndFlushEnrichedTraces netcoreapp3.1 662μs 2.55μs 9.89μs 0.329 0 0 41.92 KB
#6459 WriteAndFlushEnrichedTraces net472 848μs 4.35μs 19.5μs 8.33 2.5 0.417 53.31 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 net6.0 1.25μs 1.14ns 4.43ns 0.014 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.78μs 2.47ns 9.56ns 0.0136 0 0 1.02 KB
master ExecuteNonQuery net472 2.1μs 1.85ns 7.18ns 0.157 0.00105 0 987 B
#6459 ExecuteNonQuery net6.0 1.34μs 0.842ns 3.15ns 0.0142 0 0 1.02 KB
#6459 ExecuteNonQuery netcoreapp3.1 1.78μs 2.06ns 7.97ns 0.0143 0 0 1.02 KB
#6459 ExecuteNonQuery net472 2.05μs 2.6ns 10.1ns 0.156 0.00102 0 987 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 net6.0 1.28μs 0.63ns 2.36ns 0.0135 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.53μs 0.506ns 1.96ns 0.013 0 0 976 B
master CallElasticsearch net472 2.55μs 1.65ns 6.38ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.32μs 0.513ns 1.92ns 0.0132 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.64μs 1.68ns 6.49ns 0.0139 0 0 1.02 KB
master CallElasticsearchAsync net472 2.65μs 1.05ns 4.07ns 0.166 0 0 1.05 KB
#6459 CallElasticsearch net6.0 1.24μs 0.466ns 1.68ns 0.0136 0 0 976 B
#6459 CallElasticsearch netcoreapp3.1 1.57μs 1.69ns 6.31ns 0.0133 0 0 976 B
#6459 CallElasticsearch net472 2.53μs 2.37ns 8.88ns 0.158 0 0 995 B
#6459 CallElasticsearchAsync net6.0 1.35μs 4.19ns 16.2ns 0.0133 0 0 952 B
#6459 CallElasticsearchAsync netcoreapp3.1 1.66μs 0.778ns 2.91ns 0.014 0 0 1.02 KB
#6459 CallElasticsearchAsync net472 2.61μs 2.49ns 9.63ns 0.167 0 0 1.05 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.23μs 0.73ns 2.73ns 0.013 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.66μs 0.466ns 1.68ns 0.0131 0 0 952 B
master ExecuteAsync net472 1.75μs 0.632ns 2.45ns 0.145 0 0 915 B
#6459 ExecuteAsync net6.0 1.25μs 0.407ns 1.52ns 0.0132 0 0 952 B
#6459 ExecuteAsync netcoreapp3.1 1.64μs 0.64ns 2.48ns 0.0131 0 0 952 B
#6459 ExecuteAsync net472 1.84μs 0.432ns 1.62ns 0.145 0 0 915 B
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net6.0 4.44μs 1.5ns 5.6ns 0.0312 0 0 2.31 KB
master SendAsync netcoreapp3.1 5.35μs 3.14ns 12.2ns 0.0376 0 0 2.85 KB
master SendAsync net472 7.49μs 34.7ns 139ns 0.496 0 0 3.12 KB
#6459 SendAsync net6.0 4.47μs 1.18ns 4.41ns 0.0313 0 0 2.31 KB
#6459 SendAsync netcoreapp3.1 5.41μs 1.83ns 7.1ns 0.0389 0 0 2.85 KB
#6459 SendAsync net472 7.46μs 3.38ns 13.1ns 0.496 0 0 3.12 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 net6.0 1.54μs 0.589ns 2.28ns 0.0232 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.28μs 1.28ns 4.98ns 0.0216 0 0 1.64 KB
master EnrichedLog net472 2.79μs 1.42ns 5.3ns 0.25 0 0 1.57 KB
#6459 EnrichedLog net6.0 1.58μs 0.457ns 1.71ns 0.023 0 0 1.64 KB
#6459 EnrichedLog netcoreapp3.1 2.23μs 1.71ns 6.61ns 0.0213 0 0 1.64 KB
#6459 EnrichedLog net472 2.75μs 1.67ns 6.46ns 0.249 0 0 1.57 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 net6.0 117μs 80.2ns 300ns 0.0588 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 120μs 95.4ns 357ns 0.0599 0 0 4.28 KB
master EnrichedLog net472 150μs 110ns 410ns 0.678 0.226 0 4.46 KB
#6459 EnrichedLog net6.0 116μs 111ns 430ns 0.0577 0 0 4.28 KB
#6459 EnrichedLog netcoreapp3.1 121μs 266ns 1.03μs 0.0606 0 0 4.28 KB
#6459 EnrichedLog net472 153μs 190ns 735ns 0.686 0.229 0 4.46 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 net6.0 3.08μs 1.42ns 5.48ns 0.0309 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.35μs 1.43ns 5.52ns 0.0284 0 0 2.2 KB
master EnrichedLog net472 4.88μs 1.47ns 5.69ns 0.32 0 0 2.02 KB
#6459 EnrichedLog net6.0 3.03μs 1.02ns 3.67ns 0.0304 0 0 2.2 KB
#6459 EnrichedLog netcoreapp3.1 4.24μs 1.39ns 5.21ns 0.0298 0 0 2.2 KB
#6459 EnrichedLog net472 4.86μs 1.34ns 5.19ns 0.32 0 0 2.02 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 net6.0 1.47μs 0.608ns 2.35ns 0.0162 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.8μs 1.06ns 4.11ns 0.0152 0 0 1.14 KB
master SendReceive net472 2.09μs 0.692ns 2.59ns 0.183 0 0 1.16 KB
#6459 SendReceive net6.0 1.4μs 0.675ns 2.61ns 0.0161 0 0 1.14 KB
#6459 SendReceive netcoreapp3.1 1.8μs 0.624ns 2.16ns 0.0153 0 0 1.14 KB
#6459 SendReceive net472 2.15μs 1.33ns 5.13ns 0.183 0 0 1.16 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 net6.0 2.78μs 1.02ns 3.96ns 0.0222 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.99μs 1.76ns 6.6ns 0.0218 0 0 1.65 KB
master EnrichedLog net472 4.53μs 4.85ns 18.8ns 0.322 0 0 2.04 KB
#6459 EnrichedLog net6.0 2.69μs 1.04ns 3.91ns 0.0215 0 0 1.6 KB
#6459 EnrichedLog netcoreapp3.1 3.93μs 1.05ns 3.65ns 0.0216 0 0 1.65 KB
#6459 EnrichedLog net472 4.36μs 4.23ns 16.4ns 0.324 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #6459

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 1.119 405.12 453.24

Faster 🎉 in #6459

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 1.119 615.14 549.59

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 405ns 0.185ns 0.715ns 0.0081 0 0 576 B
master StartFinishSpan netcoreapp3.1 560ns 0.462ns 1.79ns 0.00781 0 0 576 B
master StartFinishSpan net472 663ns 0.516ns 2ns 0.0916 0 0 578 B
master StartFinishScope net6.0 615ns 0.458ns 1.78ns 0.00961 0 0 696 B
master StartFinishScope netcoreapp3.1 675ns 3.59ns 18.7ns 0.00943 0 0 696 B
master StartFinishScope net472 904ns 0.817ns 3.17ns 0.104 0 0 658 B
#6459 StartFinishSpan net6.0 453ns 0.271ns 0.94ns 0.008 0 0 576 B
#6459 StartFinishSpan netcoreapp3.1 559ns 0.408ns 1.53ns 0.0076 0 0 576 B
#6459 StartFinishSpan net472 663ns 0.255ns 0.953ns 0.0917 0 0 578 B
#6459 StartFinishScope net6.0 549ns 0.393ns 1.52ns 0.0097 0 0 696 B
#6459 StartFinishScope netcoreapp3.1 718ns 0.378ns 1.46ns 0.00941 0 0 696 B
#6459 StartFinishScope net472 901ns 0.859ns 3.33ns 0.104 0 0 658 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 636ns 0.502ns 1.94ns 0.00981 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 1.01μs 0.883ns 3.42ns 0.00962 0 0 696 B
master RunOnMethodBegin net472 1.15μs 0.614ns 2.38ns 0.104 0 0 658 B
#6459 RunOnMethodBegin net6.0 669ns 0.525ns 2.03ns 0.00975 0 0 696 B
#6459 RunOnMethodBegin netcoreapp3.1 913ns 0.395ns 1.53ns 0.00951 0 0 696 B
#6459 RunOnMethodBegin net472 1.15μs 1.03ns 3.99ns 0.104 0 0 658 B

andrewlock
andrewlock reviewed Dec 19, 2024
View reviewed changes
tracer/src/Datadog.Trace/Util/RequestDataHelper.cs
@@ -77,7 +77,7 @@ internal static QueryString GetQueryString(HttpRequest request)
{
return request.Form;
}
catch (HttpRequestValidationException)
catch (HttpException)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

At this point, I have to wonder why we're not just catching all exceptions here 🤔 What exceptions would we want to bubble up, if we're catching "valid" issues?

The one concern I have is that it's likely we'll trigger behaviour that only happens the first time a form (or any of the other request data tbh) is accessed.

For example, take this case. We call EnsureForm() and that "fills" the form, which triggers an exception. What happens if the customer calls request.Form later? Is EnsureForm called again and the exception thrown again? If so, that's great. But if not (because it's only called once), then we're potentially introducing hard-to-debug issues...

I think the behaviour is what really matters here. e.g. what happens if a customer calls request.Form again in this scenario? Is that something we can test (or just confirm from the code)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more. 

    internal HttpValueCollection EnsureForm()
    {
        if (_form == null)
        {
            _form = new HttpValueCollection();
            if (_wr != null)
            {
                FillInFormCollection();
            }

            _form.MakeReadOnly();
        }

        return _form;
    }

Good point. FillInFormCollection() can potentially throw an HttpException (confirmed by looking at the code) and the next time, _form would not be null anymore so, yes, we might encounter situations where we could be modifying the result obtained by the customers code.

This is something that will happen anyway. If we catch or not the exception will not change that. On the other hand, we really need to read the body of the request. I wonder if there is any possible way that we could read the body of the request without causing this potential behavior change.

About catching exceptions, I tried to be restrictive here, catching only the exceptions types that we have reviewed. If a new exception type is thrown, it would probably be worth to log it and check if we should just catch it or if we should do anything else.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@andrewlock andrewlock Awaiting requested review from andrewlock

At least 1 approving review is required to merge this pull request.

Assignees
No one assigned
Labels
area:asm area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations)
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@NachoEchevarria @andrewlock