[CIVisibility] TestPlatform AssemblyResolver .ctor integration #5088

tonyredondo · 2024-01-19T11:13:56Z

Summary of changes

This PR tries to fix #5084 using a different approach.

Reason for change

The solution done in #5084 was just to ignore the issue, in this case we try to instrument the conflict .ctor method and make CI Visibility methods to wait until the .ctor is finished (in case of it has been called) to avoid the race condition.

Implementation details

We create a new instrumentation to the AssemblyResolver..ctor method that has the race condition, we create a TaskContinuationSource and resolve the task after the .ctor code has finished.

In the other side we make the async CIVisibility methods that were producing this issue to wait until the .ctor has finished in case is already running.

2024-01-19 13:03:36.467 +01:00 [INF] ITR: Update and uploading git tree metadata and getting skippable tests.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.472 +01:00 [DBG] Running command: git rev-parse HEAD  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.481 +01:00 [DBG] ITR: Getting settings...  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.481 +01:00 [DBG] ITR: Uploading Repository Changes...  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.482 +01:00 [DBG] Initializing security singleton instance.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.482 +01:00 [DBG] Running command: git log --format=%H -n 1000 --since="1 month ago"  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.487 +01:00 [INF] DATADOG TRACER CONFIGURATION - {"date":"2024-01-19T13:03:36.478259+01:00","os_name":"Windows","os_version":"Microsoft Windows NT 10.0.23615.0","version":"2.46.0.0","native_tracer_version":"2.41.0","platform":"x64","lang":".NET","lang_version":"7.0.15","env":"tony_test_006","enabled":true,"service":"dd-trace-dotnet","agent_url":"http://127.0.0.1:8126/","agent_transport":"Default","debug":true,"health_checks_enabled":false,"analytics_enabled":false,"sample_rate":null,"sampling_rules":null,"tags":[],"log_injection_enabled":false,"runtime_metrics_enabled":false,"disabled_integrations":["OpenTelemetry"],"routetemplate_resourcenames_enabled":true,"routetemplate_expansion_enabled":false,"querystring_reporting_enabled":true,"obfuscation_querystring_regex_timout":200.0,"obfuscation_querystring_size":5000,"partialflush_enabled":false,"partialflush_minspans":500,"runtime_id":"75dc363f-ff68-461d-af29-9a3e7e9ad88c","agent_reachable":true,"agent_error":"","appsec_enabled":false,"appsec_trace_rate_limit":100,"appsec_rules_file_path":"(default)","appsec_libddwaf_version":"(none)","iast_enabled":false,"iast_deduplication_enabled":true,"iast_weak_hash_algorithms":"HMACMD5,MD5,HMACSHA1,SHA1","iast_weak_cipher_algorithms":"DES,TRIPLEDES,RC2","direct_logs_submission_enabled_integrations":[],"direct_logs_submission_enabled":false,"direct_logs_submission_error":"","exporter_settings_warning":["No transport configuration found, using default values"],"dd_trace_methods":"","activity_listener_enabled":false,"profiler_enabled":false,"code_hotspots_enabled":false,"wcf_obfuscation_enabled":true,"data_streams_enabled":false,"span_sampling_rules":null,"stats_computation_enabled":false,"dbm_propagation_mode":"Disabled","header_tags":[],"service_mapping":[]}  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.487 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ServiceFabric.ServiceRemotingService, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.490 +01:00 [DBG] Initialization of non native parts finished.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.490 +01:00 [DBG] Sending CallTarget integration definitions to native library.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.503 +01:00 [INF] The profiler has been initialized with 365 definitions.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.504 +01:00 [DBG] Sending CallTarget derived integration definitions to native library.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.508 +01:00 [INF] The profiler has been initialized with 15 derived definitions.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.508 +01:00 [DBG] Sending CallTarget interface integration definitions to native library.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.509 +01:00 [INF] The profiler has been initialized with 2 interface definitions.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.509 +01:00 [DBG] Initializing TraceMethods instrumentation.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.510 +01:00 [INF] TraceMethods instrumentation enabled with Assembly=Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb, Type=Datadog.Trace.ClrProfiler.AutoInstrumentation.TraceAnnotations.TraceAnnotationsIntegration, and Configuration=.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.510 +01:00 [DBG] Skipping AppSec initialization because AppSec is disabled  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.510 +01:00 [DBG] Skipping Iast initialization because Iast is disabled  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.510 +01:00 [DBG] Legacy Initialization finished.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.510 +01:00 [DBG] Initialization finished.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.520 +01:00 [DBG] Process finished with exit code: 0.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.535 +01:00 [DBG] Process finished with exit code: 0.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

// ^
// |
// Process were executed before the TestPlatform.AssemblyResolver....

2024-01-19 13:03:36.535 +01:00 [DBG] ITR: Local commits = 69  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.536 +01:00 [DBG] ITR: Searching commits...  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.553 +01:00 [DBG] ITR: JSON RQ = {"data":[{"id":"1cb6a5c53811c99610cbbb109cad74a4c677a670","type":"commit"},{"id":"8fa8e768ac6afa257b6198f4c4525991ee138a3b","type":"commit"},{"id":"fdb124cee4d1c79ceba26ae929dc131eb88e6714","type":"commit"},{"id":"92ee5bb6858480f7857c35cdff34dfcb95409f5e","type":"commit"},{"id":"5c2300a9721995bbebd407954113a3597ef42a09","type":"commit"},{"id":"c946f6810ec62e5d2ac372bdf47ae4bf6f9b849b","type":"commit"},{"id":"0c3aae1e0f13ee8ca1587220003c596b86eba929","type":"commit"},{"id":"596ab544ab7f60be8e47839e488ec08ef205c5c3","type":"commit"},{"id":"12b52585d032e50f58ffb7f24254cb7847606656","type":"commit"},{"id":"a0379fe79094af1fe97eee63c0348eb1f69f7c60","type":"commit"},{"id":"47594e9536015b1f6d806a877be4e024612c7e6d","type":"commit"},{"id":"40a49fb63684c6ae38224ffc2d83e7f233da6e0f","type":"commit"},{"id":"6051f08cb40b9b33d5058695f88e07e190ebde05","type":"commit"},{"id":"7608f71ffe033dec06a6c8cc35d3abaa8339683c","type":"commit"},{"id":"064b9388612eae7eed9d9449dac14fe19a0b00c2","type":"commit"},{"id":"47fb923e31ba5ba5137372bb6fc7e6680517430a","type":"commit"},{"id":"1b18a7a09a18c6e693bf42d8b95634e2745f9cf9","type":"commit"},{"id":"4a142f04259fcac832eec87563eb6cafec4c3c33","type":"commit"},{"id":"94a5572cbc04a950418cebb1824b6666436e05ae","type":"commit"},{"id":"895034998f07614b1d150c05a8709ae1f8aedb4a","type":"commit"},{"id":"836ed2670935fafd05a901c2f29d6c17754115b8","type":"commit"},{"id":"c324490cd7126e0d01fceae972505d0dbb18d010","type":"commit"},{"id":"7db632023b57972d77895d0807095cb68e3a5315","type":"commit"},{"id":"3b94302c06cbe4150719f62f56265b226a0cff1f","type":"commit"},{"id":"996080abcf4f78fb0e5c12d177110711a9fb4e05","type":"commit"},{"id":"02a6860991d15dfec22bf3cddfecf8069f0e7fbd","type":"commit"},{"id":"9a82fdff18694361cd67c1450a762470f95cedaf","type":"commit"},{"id":"d5011bec87a3a518ceb2abc1c1e1c0592e67e95e","type":"commit"},{"id":"a9786932a0ce03155f13b49c9a67446694b75d86","type":"commit"},{"id":"8f69bccd64e1fc274457d79f312e72131ab83fe4","type":"commit"},{"id":"7e55d0816b944c2457a4ffe039104189b8f90c20","type":"commit"},{"id":"f323145171acd4281d7a535ef71d32f57e061290","type":"commit"},{"id":"731bee785d5e3a8091612b535ee00179f079ff06","type":"commit"},{"id":"d88e2556337331b3ca2eca7a0a94d37ac119e117","type":"commit"},{"id":"223293907dfbfd9f960ac0b84b9127ae7c9f2560","type":"commit"},{"id":"bd249681a0796ad8fff5b2ddd83a947a7d9c49a3","type":"commit"},{"id":"93d9aca9502d2d475b14871a90c0ac36c1f0c2d6","type":"commit"},{"id":"0e711b6278560bbff883d4a912e2434c56e2b3e4","type":"commit"},{"id":"02650cd64adff09e626973f26916a9423b1701f8","type":"commit"},{"id":"ebfdcb06c921a9f6f398feaa0b2323a36eaead7b","type":"commit"},{"id":"20ed715afca0bb0e1a3d4a4ac1224e1b85b02c1d","type":"commit"},{"id":"1434498d3cfbfaa980c3121c5189bc3148919a20","type":"commit"},{"id":"aaec3dd88e75f579c61267b126ad90db206aef30","type":"commit"},{"id":"1d30900c58ab5cf0689c55fc26e2b2a697f5385b","type":"commit"},{"id":"703cf2ffe978d884c8ecfbf1fb16fc5a80eb914f","type":"commit"},{"id":"3101597406a6b5e93bdea4c06291e4b1d721302e","type":"commit"},{"id":"853f2a8625b7f471d4d797bf0a425fb7c1c78e27","type":"commit"},{"id":"c947d39cf68ed372de9886f8f58db0ad6c6c8fd1","type":"commit"},{"id":"9971e9ee5269aab44955863324c911afaca71b51","type":"commit"},{"id":"aaa9a8bd7a6f0351766e94879455f2e88d9f1cdc","type":"commit"},{"id":"fac9ead8ab390d7d33bfe6931ab2f15fbd082f22","type":"commit"},{"id":"2da269dae5a4b0f74e87c7842a79e08c8abebbea","type":"commit"},{"id":"501a77e940445712d792fcd351367eedb00051f5","type":"commit"},{"id":"d36a7aa5c54284cf6fecb052519d4b8a475c7389","type":"commit"},{"id":"f6d09a3cb46fa24394eee889b4dfbdee0cf61002","type":"commit"},{"id":"8f0857db0e71da254da1416a7b13d847643923a4","type":"commit"},{"id":"3189bafd903d5262888d8ded5b399f729d3c420b","type":"commit"},{"id":"6726974ebe79371743238d4a8924ace7f1eff924","type":"commit"},{"id":"768ea8ac63f31246c841f137080de7383c9a31ee","type":"commit"},{"id":"4493d4d1136324bfb8b7859d0f501593d65b503d","type":"commit"},{"id":"a1726531d4b45c9f6b21077f403c22bd7fb4e964","type":"commit"},{"id":"b048619a003f8cb0c6ad73bb4235719c32a70a18","type":"commit"},{"id":"c0e34dc2df0d4bb24679d9a6bc1174590c4bef4b","type":"commit"},{"id":"8eba85562714d9a242a32ee052adbf92242a3b9f","type":"commit"},{"id":"dee3e1fa1a1777183381f4a9b1e50f4aa0863314","type":"commit"},{"id":"9d4214403de4527f0b89243a9e2d31673ca0c9ed","type":"commit"},{"id":"8718e69b49ea79d5f09a6309fa479d6baac059b3","type":"commit"},{"id":"d8ac6f920f436eec73c80c4c5f8c52d5e73330ec","type":"commit"},{"id":"2f8841de69a76783c68a06a2b70006cb08583893","type":"commit"}],"meta":{"repository_url":"git@github.com:DataDog/dd-trace-dotnet.git"}}  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.556 +01:00 [DBG] ITR: Searching commits from: https://api.datadoghq.com/api/v2/git/repository/search_commits  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.558 +01:00 [DBG] ITR: JSON RQ = {"data":{"id":"1cb6a5c53811c99610cbbb109cad74a4c677a670","type":"ci_app_test_service_libraries_settings","attributes":{"service":"dd-trace-dotnet","env":"tony_test_006","repository_url":"git@github.com:DataDog/dd-trace-dotnet.git","branch":"tony/testplatform-assemblyresolver-ctor-integration","sha":"1cb6a5c53811c99610cbbb109cad74a4c677a670","configurations":{"os.platform":"Windows","os.version":"Microsoft Windows NT 10.0.23615.0","os.architecture":"x64","runtime.name":".NET","runtime.version":"7.0.15","runtime.architecture":"x64"}}}}  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.560 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.IntegrationOptions`2[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[System.Net.Http.HttpClientHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.560 +01:00 [DBG] ITR: Getting settings from: https://api.datadoghq.com/api/v2/libraries/tests/services/setting  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.565 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.IntegrationMapper, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.565 +01:00 [DBG] Creating BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration' integration. [Target=System.Net.Http.HttpClientHandler]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.580 +01:00 [DBG] Created BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration' integration. [Target=System.Net.Http.HttpClientHandler]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.586 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.IntegrationOptions`2[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[System.Net.Http.SocketsHttpHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.586 +01:00 [DBG] Creating BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration' integration. [Target=System.Net.Http.SocketsHttpHandler]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.586 +01:00 [DBG] Created BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration' integration. [Target=System.Net.Http.SocketsHttpHandler]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.618 +01:00 [DBG] Creating EndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration' integration. [Target=System.Net.Http.SocketsHttpHandler, ReturnType=System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]]]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.618 +01:00 [DBG] 'OnMethodEnd' method was not found in integration type: 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration'.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.619 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.IntegrationOptions`2[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Testing.AssemblyResolverCtorIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver, Microsoft.VisualStudio.TestPlatform.Common, Version=15.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.619 +01:00 [DBG] Creating BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Testing.AssemblyResolverCtorIntegration' integration. [Target=Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.619 +01:00 [DBG] Created BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Testing.AssemblyResolverCtorIntegration' integration. [Target=Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:36.620 +01:00 [DBG] Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver.ctor started.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:36.621 +01:00 [DBG] Creating AsyncEndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration' integration. [Target=System.Net.Http.SocketsHttpHandler, ReturnType=System.Net.Http.HttpResponseMessage]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.621 +01:00 [DBG] Created AsyncEndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration' integration. [Target=System.Net.Http.SocketsHttpHandler, ReturnType=System.Net.Http.HttpResponseMessage]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.621 +01:00 [DBG] Creating EndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Testing.AssemblyResolverCtorIntegration' integration. [Target=Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.622 +01:00 [DBG] Created EndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Testing.AssemblyResolverCtorIntegration' integration. [Target=Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.622 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.Continuations.ContinuationGenerator`2[[System.Net.Http.SocketsHttpHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.622 +01:00 [DBG] == TaskContinuationGenerator<Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration, System.Net.Http.SocketsHttpHandler, System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Http.HttpResponseMessage> using Resolver: Datadog.Trace.ClrProfiler.CallTarget.Handlers.Continuations.TaskContinuationGenerator`4+SyncCallbackHandler[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.SocketsHttpHandler.SocketsHttpHandlerIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[System.Net.Http.SocketsHttpHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:36.622 +01:00 [DBG] Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver.ctor finished.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:36.625 +01:00 [DBG] Creating EndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration' integration. [Target=System.Net.Http.HttpClientHandler, ReturnType=System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]]]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.625 +01:00 [DBG] 'OnMethodEnd' method was not found in integration type: 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration'.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.625 +01:00 [DBG] Creating AsyncEndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration' integration. [Target=System.Net.Http.HttpClientHandler, ReturnType=System.Net.Http.HttpResponseMessage]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.625 +01:00 [DBG] Created AsyncEndMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration' integration. [Target=System.Net.Http.HttpClientHandler, ReturnType=System.Net.Http.HttpResponseMessage]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.625 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.Continuations.ContinuationGenerator`2[[System.Net.Http.HttpClientHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:36.625 +01:00 [DBG] == TaskContinuationGenerator<Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration, System.Net.Http.HttpClientHandler, System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Http.HttpResponseMessage> using Resolver: Datadog.Trace.ClrProfiler.CallTarget.Handlers.Continuations.TaskContinuationGenerator`4+SyncCallbackHandler[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Http.HttpClient.HttpClientHandler.HttpClientHandlerIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[System.Net.Http.HttpClientHandler, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Threading.Tasks.Task`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.146 +01:00 [DBG] ITR: JSON RS = {"data":{"id":"1cb6a5c53811c99610cbbb109cad74a4c677a670","type":"ci_app_tracers_test_service_settings","attributes":{"code_coverage":false,"flaky_test_retries_enabled":false,"itr_enabled":false,"require_git":false,"tests_skipping":false}}}  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

// ^
// |
// Instrumented Http requests executed while  TestPlatform.AssemblyResolver ctor is running

2024-01-19 13:03:37.163 +01:00 [DBG] Request was completed successfully.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.163 +01:00 [INF] ITR: Code Coverage has been changed to false by settings api.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.163 +01:00 [INF] ITR: Tests Skipping has been changed to false by settings api.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.163 +01:00 [INF] ITR: Tests code coverage is disabled.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.245 +01:00 [DBG] Telemetry sent successfully  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.246 +01:00 [DBG] Successfully sent telemetry  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.286 +01:00 [DBG] ITR: JSON RS = {"data":[{"id":"1cb6a5c53811c99610cbbb109cad74a4c677a670","type":"commit"},{"id":"8fa8e768ac6afa257b6198f4c4525991ee138a3b","type":"commit"},{"id":"fdb124cee4d1c79ceba26ae929dc131eb88e6714","type":"commit"},{"id":"92ee5bb6858480f7857c35cdff34dfcb95409f5e","type":"commit"},{"id":"5c2300a9721995bbebd407954113a3597ef42a09","type":"commit"},{"id":"c946f6810ec62e5d2ac372bdf47ae4bf6f9b849b","type":"commit"},{"id":"0c3aae1e0f13ee8ca1587220003c596b86eba929","type":"commit"},{"id":"596ab544ab7f60be8e47839e488ec08ef205c5c3","type":"commit"},{"id":"12b52585d032e50f58ffb7f24254cb7847606656","type":"commit"},{"id":"a0379fe79094af1fe97eee63c0348eb1f69f7c60","type":"commit"},{"id":"47594e9536015b1f6d806a877be4e024612c7e6d","type":"commit"},{"id":"40a49fb63684c6ae38224ffc2d83e7f233da6e0f","type":"commit"},{"id":"6051f08cb40b9b33d5058695f88e07e190ebde05","type":"commit"},{"id":"7608f71ffe033dec06a6c8cc35d3abaa8339683c","type":"commit"},{"id":"064b9388612eae7eed9d9449dac14fe19a0b00c2","type":"commit"},{"id":"47fb923e31ba5ba5137372bb6fc7e6680517430a","type":"commit"},{"id":"1b18a7a09a18c6e693bf42d8b95634e2745f9cf9","type":"commit"},{"id":"4a142f04259fcac832eec87563eb6cafec4c3c33","type":"commit"},{"id":"94a5572cbc04a950418cebb1824b6666436e05ae","type":"commit"},{"id":"895034998f07614b1d150c05a8709ae1f8aedb4a","type":"commit"},{"id":"836ed2670935fafd05a901c2f29d6c17754115b8","type":"commit"},{"id":"c324490cd7126e0d01fceae972505d0dbb18d010","type":"commit"},{"id":"7db632023b57972d77895d0807095cb68e3a5315","type":"commit"},{"id":"3b94302c06cbe4150719f62f56265b226a0cff1f","type":"commit"},{"id":"996080abcf4f78fb0e5c12d177110711a9fb4e05","type":"commit"},{"id":"02a6860991d15dfec22bf3cddfecf8069f0e7fbd","type":"commit"},{"id":"9a82fdff18694361cd67c1450a762470f95cedaf","type":"commit"},{"id":"d5011bec87a3a518ceb2abc1c1e1c0592e67e95e","type":"commit"},{"id":"a9786932a0ce03155f13b49c9a67446694b75d86","type":"commit"},{"id":"8f69bccd64e1fc274457d79f312e72131ab83fe4","type":"commit"},{"id":"7e55d0816b944c2457a4ffe039104189b8f90c20","type":"commit"},{"id":"f323145171acd4281d7a535ef71d32f57e061290","type":"commit"},{"id":"731bee785d5e3a8091612b535ee00179f079ff06","type":"commit"},{"id":"d88e2556337331b3ca2eca7a0a94d37ac119e117","type":"commit"},{"id":"223293907dfbfd9f960ac0b84b9127ae7c9f2560","type":"commit"},{"id":"bd249681a0796ad8fff5b2ddd83a947a7d9c49a3","type":"commit"},{"id":"93d9aca9502d2d475b14871a90c0ac36c1f0c2d6","type":"commit"},{"id":"0e711b6278560bbff883d4a912e2434c56e2b3e4","type":"commit"},{"id":"02650cd64adff09e626973f26916a9423b1701f8","type":"commit"},{"id":"ebfdcb06c921a9f6f398feaa0b2323a36eaead7b","type":"commit"},{"id":"20ed715afca0bb0e1a3d4a4ac1224e1b85b02c1d","type":"commit"},{"id":"1434498d3cfbfaa980c3121c5189bc3148919a20","type":"commit"},{"id":"aaec3dd88e75f579c61267b126ad90db206aef30","type":"commit"},{"id":"1d30900c58ab5cf0689c55fc26e2b2a697f5385b","type":"commit"},{"id":"703cf2ffe978d884c8ecfbf1fb16fc5a80eb914f","type":"commit"},{"id":"3101597406a6b5e93bdea4c06291e4b1d721302e","type":"commit"},{"id":"853f2a8625b7f471d4d797bf0a425fb7c1c78e27","type":"commit"},{"id":"c947d39cf68ed372de9886f8f58db0ad6c6c8fd1","type":"commit"},{"id":"9971e9ee5269aab44955863324c911afaca71b51","type":"commit"},{"id":"aaa9a8bd7a6f0351766e94879455f2e88d9f1cdc","type":"commit"},{"id":"fac9ead8ab390d7d33bfe6931ab2f15fbd082f22","type":"commit"},{"id":"2da269dae5a4b0f74e87c7842a79e08c8abebbea","type":"commit"},{"id":"501a77e940445712d792fcd351367eedb00051f5","type":"commit"},{"id":"d36a7aa5c54284cf6fecb052519d4b8a475c7389","type":"commit"},{"id":"f6d09a3cb46fa24394eee889b4dfbdee0cf61002","type":"commit"},{"id":"8f0857db0e71da254da1416a7b13d847643923a4","type":"commit"},{"id":"3189bafd903d5262888d8ded5b399f729d3c420b","type":"commit"},{"id":"6726974ebe79371743238d4a8924ace7f1eff924","type":"commit"},{"id":"768ea8ac63f31246c841f137080de7383c9a31ee","type":"commit"},{"id":"4493d4d1136324bfb8b7859d0f501593d65b503d","type":"commit"},{"id":"a1726531d4b45c9f6b21077f403c22bd7fb4e964","type":"commit"},{"id":"b048619a003f8cb0c6ad73bb4235719c32a70a18","type":"commit"},{"id":"c0e34dc2df0d4bb24679d9a6bc1174590c4bef4b","type":"commit"},{"id":"8eba85562714d9a242a32ee052adbf92242a3b9f","type":"commit"},{"id":"dee3e1fa1a1777183381f4a9b1e50f4aa0863314","type":"commit"}]}  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.291 +01:00 [DBG] Request was completed successfully.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:37.292 +01:00 [DBG] Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver.ctor already ran.  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

2024-01-19 13:03:37.292 +01:00 [DBG] Running command: git rev-parse --is-shallow-repository  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.293 +01:00 [DBG] Logger retrieved for: Datadog.Trace.ClrProfiler.CallTarget.Handlers.IntegrationOptions`2[[Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.ProcessStartIntegration, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb],[System.Diagnostics.Process, System.Diagnostics.Process, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.293 +01:00 [DBG] Creating BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.ProcessStartIntegration' integration. [Target=System.Diagnostics.Process]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.293 +01:00 [DBG] Created BeginMethod Dynamic Method for 'Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.ProcessStartIntegration' integration. [Target=System.Diagnostics.Process]  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.302 +01:00 [DBG] Logger retrieved for: Datadog.Trace.Activity.ActivityListener, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }
2024-01-19 13:03:37.303 +01:00 [DBG] Logger retrieved for: Datadog.Trace.Span, Datadog.Trace, Version=2.46.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb  { MachineName: ".", Process: "[46408 testhost]", AppDomain: "[1 testhost]", AssemblyLoadContext: "\"Default\" System.Runtime.Loader.DefaultAssemblyLoadContext #2", TracerVersion: "2.46.0.0" }

// ^
// |
// Instrumented Http requests executed after TestPlatform.AssemblyResolver ctor ran

Test coverage

This scenario is really hard to test due to the race condition, so no new test were added.

datadog-ddstaging · 2024-01-19T11:58:18Z

Datadog Report

Branch report: tony/testplatform-assemblyresolver-ctor-integration
Commit report: 8d99fb2
Test service: dd-trace-dotnet

❌ 1 Failed (0 Known Flaky), 307792 Passed, 1507 Skipped, 59m 59.69s Wall Time
⌛ 1 Performance Regression

❌ Failed Tests (1)

Profiler_liveheap - scenarios - Details

Expand for error

 Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
    at System.Diagnostics.Tracing.EventPipePayloadDecoder.DecodePayload(EventMetadata ByRef, System.ReadOnlySpan\`1<Byte>)
    at System.Diagnostics.Tracing.NativeRuntimeEventSource.ProcessEvent(UInt32, UInt32, System.DateTime, System.Guid, System.Guid, System.ReadOnlySpan\`1<Byte>)
    at System.Diagnostics.Tracing.EventPipeEventDispatcher.DispatchEventsToEventListeners()
    at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
    at System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread)
 
 ######## Starting at 01/19/2024 13:21:44
 
 Usage:
 ...

⌛ Performance Regressions vs Default Branch (1)

Profiler_contention - scenarios 2.4s (+60.7ms, +3%) - Details

andrewlock · 2024-01-19T12:12:50Z

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 (5088) - mean (72ms)  : 63, 81
     .   : milestone, 72,
    master - mean (70ms)  : 62, 79
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (957ms)  : 938, 975
     .   : milestone, 957,
    master - mean (955ms)  : 937, 973
     .   : milestone, 955,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5088) - mean (105ms)  : 101, 109
     .   : milestone, 105,
    master - mean (106ms)  : 103, 110
     .   : milestone, 106,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (713ms)  : 688, 739
     .   : milestone, 713,
    master - mean (698ms)  : 675, 721
     .   : milestone, 698,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5088) - mean (90ms)  : 87, 93
     .   : milestone, 90,
    master - mean (89ms)  : 85, 93
     .   : milestone, 89,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (652ms)  : 631, 674
     .   : milestone, 652,
    master - mean (653ms)  : 636, 670
     .   : milestone, 653,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5088) - mean (188ms)  : 186, 190
     .   : milestone, 188,
    master - mean (188ms)  : 185, 192
     .   : milestone, 188,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (1,068ms)  : 1044, 1091
     .   : milestone, 1068,
    master - mean (1,064ms)  : 1043, 1085
     .   : milestone, 1064,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5088) - mean (273ms)  : 269, 276
     .   : milestone, 273,
    master - mean (271ms)  : 266, 276
     .   : milestone, 271,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (1,051ms)  : 1025, 1078
     .   : milestone, 1051,
    master - mean (1,045ms)  : 1023, 1067
     .   : milestone, 1045,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5088) - mean (262ms)  : 258, 266
     .   : milestone, 262,
    master - mean (261ms)  : 257, 264
     .   : milestone, 261,

    section CallTarget+Inlining+NGEN
    This PR (5088) - mean (1,018ms)  : 995, 1042
     .   : milestone, 1018,
    master - mean (1,017ms)  : 997, 1037
     .   : milestone, 1017,

andrewlock · 2024-01-19T15:23:53Z

Benchmarks Report 🐌

Benchmarks for #5088 compared to master:

5 benchmarks are faster, with geometric mean 1.152
2 benchmarks are slower, with geometric mean 1.143
2 benchmarks have fewer allocations
2 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	8.88μs	49.3ns	304ns	0.0188	0.00938	0	7.49 KB
master	`StartStopWithChild`	netcoreapp3.1	10.9μs	58.7ns	316ns	0.0276	0.011	0	7.57 KB
master	`StartStopWithChild`	net472	17μs	73.4ns	284ns	1.34	0.341	0.119	7.95 KB
#5088	`StartStopWithChild`	net6.0	8.66μs	47.9ns	303ns	0.0171	0.00857	0	7.48 KB
#5088	`StartStopWithChild`	netcoreapp3.1	10.8μs	51ns	197ns	0.027	0.0108	0	7.58 KB
#5088	`StartStopWithChild`	net472	17.3μs	34.7ns	130ns	1.36	0.374	0.122	7.96 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	455μs	196ns	735ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	623μs	170ns	657ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	816μs	520ns	1.95μs	0.408	3.3 KB
#5088	`WriteAndFlushEnrichedTraces`	net6.0	458μs	225ns	873ns	0	2.7 KB
#5088	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	648μs	312ns	1.12μs	0	2.7 KB
#5088	`WriteAndFlushEnrichedTraces`	net472	795μs	351ns	1.36μs	0.396	3.3 KB

Benchmarks.Trace.Asm.AppSecBodyBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5088

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.Asm.AppSecBodyBenchmark.ObjectExtractorSimpleBody‑netcoreapp3.1	1.155	241.81	209.41

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`AllCycleSimpleBody`	net6.0	38.6μs	14.7ns	51ns	0.0193	0	1.77 KB
master	`AllCycleSimpleBody`	netcoreapp3.1	42.3μs	79.4ns	308ns	0.0208	0	1.74 KB
master	`AllCycleSimpleBody`	net472	44.7μs	71.4ns	258ns	0.288	0	1.81 KB
master	`AllCycleMoreComplexBody`	net6.0	198μs	110ns	427ns	0.0989	0	9.25 KB
master	`AllCycleMoreComplexBody`	netcoreapp3.1	211μs	125ns	483ns	0.106	0	9.14 KB
master	`AllCycleMoreComplexBody`	net472	224μs	77ns	288ns	1.45	0	9.32 KB
master	`ObjectExtractorSimpleBody`	net6.0	145ns	0.0748ns	0.259ns	0.00397	0	280 B
master	`ObjectExtractorSimpleBody`	netcoreapp3.1	242ns	0.132ns	0.513ns	0.00378	0	272 B
master	`ObjectExtractorSimpleBody`	net472	166ns	0.163ns	0.609ns	0.0446	0	281 B
master	`ObjectExtractorMoreComplexBody`	net6.0	2.94μs	2.4ns	8.99ns	0.0529	0	3.78 KB
master	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	3.98μs	1.28ns	4.61ns	0.0498	0	3.69 KB
master	`ObjectExtractorMoreComplexBody`	net472	3.81μs	4.32ns	16.2ns	0.602	0.00571	3.8 KB
#5088	`AllCycleSimpleBody`	net6.0	38.3μs	13.7ns	52.9ns	0.0191	0	1.77 KB
#5088	`AllCycleSimpleBody`	netcoreapp3.1	41.6μs	27.6ns	107ns	0.0208	0	1.74 KB
#5088	`AllCycleSimpleBody`	net472	44.4μs	20.2ns	78.1ns	0.288	0	1.81 KB
#5088	`AllCycleMoreComplexBody`	net6.0	203μs	130ns	503ns	0.101	0	9.25 KB
#5088	`AllCycleMoreComplexBody`	netcoreapp3.1	211μs	193ns	747ns	0.106	0	9.14 KB
#5088	`AllCycleMoreComplexBody`	net472	228μs	57.1ns	221ns	1.47	0	9.32 KB
#5088	`ObjectExtractorSimpleBody`	net6.0	143ns	0.149ns	0.578ns	0.00392	0	280 B
#5088	`ObjectExtractorSimpleBody`	netcoreapp3.1	211ns	0.711ns	2.75ns	0.00365	0	272 B
#5088	`ObjectExtractorSimpleBody`	net472	174ns	0.157ns	0.608ns	0.0446	0	281 B
#5088	`ObjectExtractorMoreComplexBody`	net6.0	3.04μs	2.53ns	9.46ns	0.0531	0	3.78 KB
#5088	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	4.02μs	1.57ns	5.89ns	0.0504	0	3.69 KB
#5088	`ObjectExtractorMoreComplexBody`	net472	3.84μs	3.66ns	14.2ns	0.602	0.00573	3.8 KB

Benchmarks.Trace.Asm.AppSecWafBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #5088

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWaf(args: NestedMap (10))‑net6.0	1.128	50,823.99	57,343.44

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`RunWaf(args=NestedMap (10))`	net6.0	50.8μs	21ns	78.4ns	0.226	0	16.06 KB
master	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	70.1μs	179ns	692ns	0.206	0	16.06 KB
master	`RunWaf(args=NestedMap (10))`	net472	98.2μs	495ns	2.16μs	2.55	0.1	16.14 KB
master	`RunWafTwice(args=NestedMap (10))`	net6.0	52.3μs	22.4ns	83.9ns	0.236	0	16.6 KB
master	`RunWafTwice(args=NestedMap (10))`	netcoreapp3.1	75μs	385ns	1.72μs	0.19	0	16.58 KB
master	`RunWafTwice(args=NestedMap (10))`	net472	104μs	49.8ns	193ns	2.62	0.105	16.69 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	119μs	57.4ns	222ns	0.326	0	22.41 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	129μs	673ns	3.3μs	0.255	0	22.36 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	163μs	112ns	432ns	3.54	0.157	22.7 KB
master	`RunWaf(args=NestedMap (100))`	net6.0	110μs	53.3ns	200ns	0.43	0	32.76 KB
master	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	135μs	66.9ns	232ns	0.443	0	33.33 KB
master	`RunWaf(args=NestedMap (100))`	net472	189μs	709ns	2.75μs	5.33	0.374	33.67 KB
master	`RunWafTwice(args=NestedMap (100))`	net6.0	103μs	555ns	3.09μs	0.449	0	33.3 KB
master	`RunWafTwice(args=NestedMap (100))`	netcoreapp3.1	142μs	478ns	1.85μs	0.424	0	33.86 KB
master	`RunWafTwice(args=NestedMap (100))`	net472	201μs	61.3ns	237ns	5.35	0.389	34.23 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	172μs	105ns	405ns	0.551	0	39.1 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	198μs	761ns	2.95μs	0.486	0	39.63 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	253μs	159ns	614ns	6.36	0.509	40.23 KB
master	`RunWaf(args=NestedMap (20))`	net6.0	99.6μs	43.3ns	189ns	0.43	0	32.18 KB
master	`RunWaf(args=NestedMap (20))`	netcoreapp3.1	134μs	753ns	4.82μs	0.441	0	32.3 KB
master	`RunWaf(args=NestedMap (20))`	net472	183μs	72.3ns	271ns	5.1	0.364	32.63 KB
master	`RunWafTwice(args=NestedMap (20))`	net6.0	103μs	453ns	1.75μs	0.469	0	32.72 KB
master	`RunWafTwice(args=NestedMap (20))`	netcoreapp3.1	139μs	749ns	4.3μs	0.427	0	32.82 KB
master	`RunWafTwice(args=NestedMap (20))`	net472	197μs	729ns	2.82μs	5.21	0.386	33.19 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	166μs	94.7ns	367ns	0.557	0	38.53 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	197μs	90ns	349ns	0.491	0	38.6 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	251μs	114ns	428ns	6.16	0.503	39.2 KB
#5088	`RunWaf(args=NestedMap (10))`	net6.0	57.3μs	90.2ns	337ns	0.229	0	16.06 KB
#5088	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	68.2μs	298ns	1.19μs	0.199	0	16.06 KB
#5088	`RunWaf(args=NestedMap (10))`	net472	100μs	62.2ns	241ns	2.53	0.0953	16.14 KB
#5088	`RunWafTwice(args=NestedMap (10))`	net6.0	52.8μs	38.1ns	137ns	0.236	0	16.6 KB
#5088	`RunWafTwice(args=NestedMap (10))`	netcoreapp3.1	74.8μs	420ns	2.91μs	0.208	0	16.58 KB
#5088	`RunWafTwice(args=NestedMap (10))`	net472	104μs	26.9ns	101ns	2.6	0.104	16.69 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	113μs	27.4ns	102ns	0.286	0	22.41 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	131μs	395ns	1.48μs	0.264	0	22.36 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	158μs	106ns	409ns	3.56	0.158	22.7 KB
#5088	`RunWaf(args=NestedMap (100))`	net6.0	100μs	48.6ns	175ns	0.451	0	32.76 KB
#5088	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	132μs	318ns	1.23μs	0.44	0	33.33 KB
#5088	`RunWaf(args=NestedMap (100))`	net472	191μs	87.9ns	340ns	5.3	0.365	33.67 KB
#5088	`RunWafTwice(args=NestedMap (100))`	net6.0	101μs	19.6ns	67.9ns	0.452	0	33.3 KB
#5088	`RunWafTwice(args=NestedMap (100))`	netcoreapp3.1	140μs	694ns	2.86μs	0.424	0	33.86 KB
#5088	`RunWafTwice(args=NestedMap (100))`	net472	196μs	90.8ns	340ns	5.41	0.386	34.23 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	166μs	799ns	3.2μs	0.556	0	39.1 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	192μs	58.5ns	203ns	0.48	0	39.63 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	260μs	138ns	535ns	6.31	0.505	40.23 KB
#5088	`RunWaf(args=NestedMap (20))`	net6.0	100μs	361ns	1.3μs	0.453	0	32.18 KB
#5088	`RunWaf(args=NestedMap (20))`	netcoreapp3.1	130μs	722ns	4.51μs	0.398	0	32.3 KB
#5088	`RunWaf(args=NestedMap (20))`	net472	184μs	204ns	789ns	5.14	0.367	32.63 KB
#5088	`RunWafTwice(args=NestedMap (20))`	net6.0	112μs	55.7ns	216ns	0.453	0	32.72 KB
#5088	`RunWafTwice(args=NestedMap (20))`	netcoreapp3.1	139μs	328ns	1.27μs	0.409	0	32.82 KB
#5088	`RunWafTwice(args=NestedMap (20))`	net472	192μs	137ns	531ns	5.26	0.383	33.19 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	163μs	811ns	3.44μs	0.501	0	38.53 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	198μs	684ns	2.65μs	0.486	0	38.6 KB
#5088	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	254μs	1.1μs	4.26μs	6.23	0.498	39.2 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	175μs	153ns	594ns	0.174	18.25 KB
master	`SendRequest`	netcoreapp3.1	195μs	302ns	1.17μs	0.196	20.41 KB
master	`SendRequest`	net472	0.000187ns	0.000166ns	0.000621ns	0	0 b
#5088	`SendRequest`	net6.0	172μs	95.1ns	356ns	0.257	18.25 KB
#5088	`SendRequest`	netcoreapp3.1	194μs	379ns	1.47μs	0.195	20.41 KB
#5088	`SendRequest`	net472	0.00056ns	0.000277ns	0.001ns	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Fewer allocations 🎉

Fewer allocations 🎉 in #5088

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1	41.85 KB	41.6 KB	-251 B	-0.60%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	543μs	2.33μs	9.04μs	0.558	0	0	41.45 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	641μs	516ns	2μs	0.321	0	0	41.85 KB
master	`WriteAndFlushEnrichedTraces`	net472	865μs	4.46μs	20.9μs	8.45	2.53	0.422	53.24 KB
#5088	`WriteAndFlushEnrichedTraces`	net6.0	554μs	1.29μs	4.99μs	0.546	0	0	41.55 KB
#5088	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	654μs	1.72μs	6.43μs	0.334	0	0	41.6 KB
#5088	`WriteAndFlushEnrichedTraces`	net472	819μs	3.8μs	14.2μs	8.06	2.42	0.403	53.27 KB

Benchmarks.Trace.DbCommandBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5088

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0	1.143	1,218.93	1,066.01

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.22μs	0.642ns	2.49ns	0.0109	768 B
master	`ExecuteNonQuery`	netcoreapp3.1	1.46μs	0.797ns	3.09ns	0.0104	768 B
master	`ExecuteNonQuery`	net472	1.81μs	1.42ns	5.1ns	0.116	730 B
#5088	`ExecuteNonQuery`	net6.0	1.07μs	0.339ns	1.18ns	0.0107	768 B
#5088	`ExecuteNonQuery`	netcoreapp3.1	1.46μs	2.5ns	9.7ns	0.0103	768 B
#5088	`ExecuteNonQuery`	net472	1.78μs	4.53ns	17.5ns	0.115	730 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.21μs	0.96ns	3.72ns	0.0133	936 B
master	`CallElasticsearch`	netcoreapp3.1	1.5μs	0.727ns	2.82ns	0.0121	936 B
master	`CallElasticsearch`	net472	2.61μs	1.72ns	6.68ns	0.151	955 B
master	`CallElasticsearchAsync`	net6.0	1.28μs	0.439ns	1.64ns	0.0125	912 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.56μs	0.658ns	2.46ns	0.0133	984 B
master	`CallElasticsearchAsync`	net472	2.6μs	1.04ns	4.05ns	0.16	1.01 KB
#5088	`CallElasticsearch`	net6.0	1.17μs	0.644ns	2.41ns	0.0133	936 B
#5088	`CallElasticsearch`	netcoreapp3.1	1.48μs	0.73ns	2.73ns	0.0121	936 B
#5088	`CallElasticsearch`	net472	2.56μs	0.763ns	2.95ns	0.151	955 B
#5088	`CallElasticsearchAsync`	net6.0	1.35μs	0.355ns	1.28ns	0.0128	912 B
#5088	`CallElasticsearchAsync`	netcoreapp3.1	1.67μs	0.303ns	1.13ns	0.0133	984 B
#5088	`CallElasticsearchAsync`	net472	2.64μs	1.04ns	4.04ns	0.16	1.01 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.29μs	0.89ns	3.45ns	0.0131	912 B
master	`ExecuteAsync`	netcoreapp3.1	1.67μs	1.56ns	6.03ns	0.0126	912 B
master	`ExecuteAsync`	net472	1.78μs	1.12ns	4.19ns	0.139	875 B
#5088	`ExecuteAsync`	net6.0	1.36μs	0.328ns	1.18ns	0.013	912 B
#5088	`ExecuteAsync`	netcoreapp3.1	1.63μs	0.573ns	2.14ns	0.0123	912 B
#5088	`ExecuteAsync`	net472	1.8μs	1.39ns	5.38ns	0.138	875 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	3.93μs	3.21ns	12.4ns	0.0293	2.1 KB
master	`SendAsync`	netcoreapp3.1	4.94μs	23.2ns	125ns	0.0341	2.63 KB
master	`SendAsync`	net472	7.8μs	8.05ns	31.2ns	0.524	3.31 KB
#5088	`SendAsync`	net6.0	4.22μs	2.35ns	8.47ns	0.0297	2.1 KB
#5088	`SendAsync`	netcoreapp3.1	4.97μs	1.81ns	7.03ns	0.0348	2.63 KB
#5088	`SendAsync`	net472	7.8μs	5.5ns	21.3ns	0.524	3.31 KB

Benchmarks.Trace.Iast.StringAspectsBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #5088

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net472	57.67 KB	62.51 KB	4.84 KB	8.39%
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net6.0	202.62 KB	214.3 KB	11.69 KB	5.77%

Fewer allocations 🎉 in #5088

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑netcoreapp3.1	212.78 KB	203.7 KB	-9.09 KB	-4.27%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Allocated
master	`StringConcatBenchmark`	net6.0	58.1μs	602ns	5.93μs	43.44 KB
master	`StringConcatBenchmark`	netcoreapp3.1	53.9μs	260ns	1.01μs	42.64 KB
master	`StringConcatBenchmark`	net472	38.1μs	91.8ns	344ns	57.67 KB
master	`StringConcatAspectBenchmark`	net6.0	272μs	4.72μs	43.6μs	202.62 KB
master	`StringConcatAspectBenchmark`	netcoreapp3.1	293μs	5.49μs	50.6μs	212.78 KB
master	`StringConcatAspectBenchmark`	net472	245μs	4.46μs	42.3μs	221.18 KB
#5088	`StringConcatBenchmark`	net6.0	52μs	186ns	1.28μs	43.44 KB
#5088	`StringConcatBenchmark`	netcoreapp3.1	53.3μs	129ns	754ns	42.64 KB
#5088	`StringConcatBenchmark`	net472	38μs	55.9ns	209ns	62.51 KB
#5088	`StringConcatAspectBenchmark`	net6.0	278μs	1.49μs	8.02μs	214.3 KB
#5088	`StringConcatAspectBenchmark`	netcoreapp3.1	298μs	3.06μs	27.4μs	203.7 KB
#5088	`StringConcatAspectBenchmark`	net472	244μs	3.47μs	33.1μs	221.18 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.44μs	0.961ns	3.47ns	0.0223	1.57 KB
master	`EnrichedLog`	netcoreapp3.1	2.28μs	1.73ns	6.47ns	0.0205	1.57 KB
master	`EnrichedLog`	net472	2.72μs	3.3ns	12.8ns	0.237	1.5 KB
#5088	`EnrichedLog`	net6.0	1.54μs	0.546ns	2.12ns	0.0217	1.57 KB
#5088	`EnrichedLog`	netcoreapp3.1	2.25μs	1.95ns	7.29ns	0.0213	1.57 KB
#5088	`EnrichedLog`	net472	2.58μs	2.29ns	8.56ns	0.238	1.5 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EnrichedLog`	net6.0	113μs	168ns	652ns	0	0	4.21 KB
master	`EnrichedLog`	netcoreapp3.1	118μs	113ns	438ns	0	0	4.21 KB
master	`EnrichedLog`	net472	149μs	42.4ns	153ns	0.669	0.223	4.39 KB
#5088	`EnrichedLog`	net6.0	113μs	97.7ns	366ns	0	0	4.21 KB
#5088	`EnrichedLog`	netcoreapp3.1	118μs	85ns	329ns	0.0587	0	4.21 KB
#5088	`EnrichedLog`	net472	149μs	46.2ns	167ns	0.667	0.222	4.39 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	3.07μs	2.17ns	8.42ns	0.0292	2.13 KB
master	`EnrichedLog`	netcoreapp3.1	4.3μs	2.37ns	8.22ns	0.0279	2.13 KB
master	`EnrichedLog`	net472	4.76μs	1.27ns	4.57ns	0.308	1.95 KB
#5088	`EnrichedLog`	net6.0	3.06μs	0.965ns	3.74ns	0.0296	2.13 KB
#5088	`EnrichedLog`	netcoreapp3.1	4.24μs	8.92ns	34.5ns	0.0273	2.13 KB
#5088	`EnrichedLog`	net472	4.75μs	1.94ns	7.53ns	0.308	1.95 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.35μs	1.69ns	6.55ns	0.0155	1.1 KB
master	`SendReceive`	netcoreapp3.1	1.74μs	1.3ns	4.88ns	0.0148	1.1 KB
master	`SendReceive`	net472	2.18μs	2.41ns	9.34ns	0.177	1.12 KB
#5088	`SendReceive`	net6.0	1.43μs	0.589ns	2.28ns	0.015	1.1 KB
#5088	`SendReceive`	netcoreapp3.1	1.78μs	0.689ns	2.67ns	0.0142	1.1 KB
#5088	`SendReceive`	net472	2.11μs	2.69ns	10.4ns	0.176	1.12 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.71μs	0.959ns	3.71ns	0.0216	1.53 KB
master	`EnrichedLog`	netcoreapp3.1	3.97μs	1.11ns	4.17ns	0.0198	1.58 KB
master	`EnrichedLog`	net472	4.32μs	1.13ns	4.22ns	0.311	1.97 KB
#5088	`EnrichedLog`	net6.0	2.78μs	0.894ns	3.46ns	0.0209	1.53 KB
#5088	`EnrichedLog`	netcoreapp3.1	3.96μs	2.24ns	8.07ns	0.0217	1.58 KB
#5088	`EnrichedLog`	net472	4.46μs	2.29ns	8.86ns	0.312	1.97 KB

Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5088

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472	1.123	788.40	702.07

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	513ns	0.127ns	0.476ns	0.00738	536 B
master	`StartFinishSpan`	netcoreapp3.1	739ns	0.887ns	3.32ns	0.00731	536 B
master	`StartFinishSpan`	net472	788ns	0.314ns	1.17ns	0.0853	538 B
master	`StartFinishScope`	net6.0	608ns	0.267ns	1.03ns	0.00914	656 B
master	`StartFinishScope`	netcoreapp3.1	811ns	0.31ns	1.2ns	0.00848	656 B
master	`StartFinishScope`	net472	936ns	1.05ns	4.09ns	0.0981	618 B
#5088	`StartFinishSpan`	net6.0	517ns	0.149ns	0.577ns	0.00755	536 B
#5088	`StartFinishSpan`	netcoreapp3.1	697ns	2.52ns	9.42ns	0.00726	536 B
#5088	`StartFinishSpan`	net472	702ns	0.169ns	0.631ns	0.0852	538 B
#5088	`StartFinishScope`	net6.0	606ns	0.189ns	0.708ns	0.00908	656 B
#5088	`StartFinishScope`	netcoreapp3.1	808ns	1.06ns	4.12ns	0.00865	656 B
#5088	`StartFinishScope`	net472	965ns	0.354ns	1.37ns	0.0981	618 B

Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #5088

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑netcoreapp3.1	1.158	858.63	993.93

Faster 🎉 in #5088

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net472	1.171	1,232.74	1,052.46
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0	1.166	747.69	641.21

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	748ns	0.473ns	1.83ns	0.00935	656 B
master	`RunOnMethodBegin`	netcoreapp3.1	863ns	2.12ns	8.2ns	0.00884	656 B
master	`RunOnMethodBegin`	net472	1.23μs	0.347ns	1.34ns	0.0978	618 B
#5088	`RunOnMethodBegin`	net6.0	641ns	0.366ns	1.42ns	0.00921	656 B
#5088	`RunOnMethodBegin`	netcoreapp3.1	994ns	0.376ns	1.46ns	0.00894	656 B
#5088	`RunOnMethodBegin`	net472	1.05μs	0.406ns	1.52ns	0.0977	618 B

andrewlock

LGTM with one question

andrewlock · 2024-01-19T16:43:17Z

...src/Datadog.Trace/ClrProfiler/AutoInstrumentation/Testing/AssemblyResolverCtorIntegration.cs

+    internal static CallTargetState OnMethodBegin<TTarget, TArg1>(TTarget instance, ref TArg1 directories)
+    {
+        Common.Log.Debug("Microsoft.VisualStudio.TestPlatform.Common.Utilities.AssemblyResolver.ctor started.");
+        _callHasBeenCompletedTaskCompletionSource = new TaskCompletionSource<bool>(TaskCreationOptions.RunContinuationsAsynchronously);


Is there any risk of new AssemblyResolver() being called more than once? 🤔

It's called twice but for different scenarios, one as of them for the IDE an scenario that is not covered by CI Visibility. So we are safe.

andrewlock · 2024-01-19T19:49:27Z

Throughput/Crank Report:zap:

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 (5088) (11.735M)   : 0, 11735022
    master (11.998M)   : 0, 11998376
    benchmarks/2.9.0 (11.682M)   : 0, 11681575

    section Automatic
    This PR (5088) (8.077M)   : 0, 8076719
    master (8.129M)   : 0, 8129379
    benchmarks/2.9.0 (8.446M)   : 0, 8445739

    section Trace stats
    This PR (5088) (8.325M)   : 0, 8325480
    master (8.529M)   : 0, 8529273

    section Manual
    This PR (5088) (10.093M)   : 0, 10093028
    master (10.271M)   : 0, 10271133

    section Manual + Automatic
    This PR (5088) (7.570M)   : 0, 7569960
    master (7.591M)   : 0, 7590530

    section Version Conflict
    This PR (5088) (6.827M)   : 0, 6826622
    master (6.907M)   : 0, 6906785

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5088) (9.649M)   : 0, 9649178
    master (9.594M)   : 0, 9593658
    benchmarks/2.9.0 (9.657M)   : 0, 9656830

    section Automatic
    This PR (5088) (6.768M)   : 0, 6768407
    master (6.574M)   : 0, 6573613

    section Trace stats
    This PR (5088) (6.918M)   : 0, 6917537
    master (6.962M)   : 0, 6961649

    section Manual
    This PR (5088) (8.329M)   : 0, 8328542
    master (8.281M)   : 0, 8281219

    section Manual + Automatic
    This PR (5088) (6.279M)   : 0, 6279092
    master (6.258M)   : 0, 6258314

    section Version Conflict
    This PR (5088) (5.766M)   : 0, 5766130
    master (5.552M)   : 0, 5551784

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5088) (10.439M)   : 0, 10439229
    master (10.243M)   : 0, 10242543
    benchmarks/2.9.0 (10.207M)   : 0, 10206890

    section Automatic
    This PR (5088) (7.057M)   : 0, 7056508
    master (7.076M)   : 0, 7076485
    benchmarks/2.9.0 (7.362M)   : 0, 7361712

    section Trace stats
    This PR (5088) (7.469M)   : 0, 7469033
    master (7.453M)   : 0, 7453286

    section Manual
    This PR (5088) (9.106M)   : 0, 9105904
    master (8.806M)   : 0, 8806398

    section Manual + Automatic
    This PR (5088) (6.860M)   : 0, 6859674
    master (6.909M)   : 0, 6909369

    section Version Conflict
    This PR (5088) (6.137M)   : 0, 6137352
    master (6.090M)   : 0, 6090260

gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    master (7.762M)   : 0, 7761523
    benchmarks/2.9.0 (7.448M)   : 0, 7447634

    section No attack
    master (1.792M)   : 0, 1791629
    benchmarks/2.9.0 (3.135M)   : 0, 3134564

    section Attack
    master (1.416M)   : 0, 1415708
    benchmarks/2.9.0 (2.468M)   : 0, 2467773

    section Blocking
    master (3.120M)   : 0, 3120029

    section IAST default
    master (6.490M)   : 0, 6489771

    section IAST full
    master (5.606M)   : 0, 5605809

    section Base vuln
    master (0.943M)   : 0, 943169

    section IAST vuln
    master (0.885M)   : 0, 885243

[CIVisibility] TestPlatform AssemblyResolver .ctor integration

fdb124c

tonyredondo self-assigned this Jan 19, 2024

github-actions bot added the area:ci-visibility label Jan 19, 2024

tonyredondo added 2 commits January 19, 2024 12:21

Changes

8fa8e76

more logs

1cb6a5c

tonyredondo marked this pull request as ready for review January 19, 2024 12:02

tonyredondo requested review from a team as code owners January 19, 2024 12:02

kevingosse approved these changes Jan 19, 2024

View reviewed changes

Fix build

8d99fb2

andrewlock approved these changes Jan 19, 2024

View reviewed changes

zacharycmontoya approved these changes Jan 19, 2024

View reviewed changes

tonyredondo merged commit 05b39c1 into master Jan 19, 2024
57 checks passed

tonyredondo deleted the tony/testplatform-assemblyresolver-ctor-integration branch January 19, 2024 21:43

github-actions bot added this to the vNext milestone Jan 19, 2024

andrewlock added the type:bug label Jan 24, 2024

andrewlock mentioned this pull request Feb 16, 2024

[Test Package Versions Bump] Updating package versions #4972

Merged

andrewlock mentioned this pull request Apr 22, 2024

Ignore expected CI Visibility error #5482

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[CIVisibility] TestPlatform AssemblyResolver .ctor integration #5088

[CIVisibility] TestPlatform AssemblyResolver .ctor integration #5088

tonyredondo commented Jan 19, 2024 •

edited

Loading

datadog-ddstaging bot commented Jan 19, 2024 •

edited

Loading

andrewlock commented Jan 19, 2024 •

edited

Loading

andrewlock commented Jan 19, 2024

Raw results

Raw results

Faster 🎉 in #5088

Raw results

Slower ⚠️ in #5088

Raw results

Raw results

Fewer allocations 🎉 in #5088

Raw results

Faster 🎉 in #5088

Raw results

Raw results

Raw results

Raw results

More allocations ⚠️ in #5088

Fewer allocations 🎉 in #5088

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #5088

Raw results

Slower ⚠️ in #5088

Faster 🎉 in #5088

Raw results

andrewlock left a comment

andrewlock Jan 19, 2024

tonyredondo Jan 19, 2024

andrewlock commented Jan 19, 2024

[CIVisibility] TestPlatform AssemblyResolver .ctor integration #5088

[CIVisibility] TestPlatform AssemblyResolver .ctor integration #5088

Conversation

tonyredondo commented Jan 19, 2024 • edited Loading

Summary of changes

Reason for change

Implementation details

Test coverage

datadog-ddstaging bot commented Jan 19, 2024 • edited Loading

Datadog Report

❌ Failed Tests (1)

⌛ Performance Regressions vs Default Branch (1)

andrewlock commented Jan 19, 2024 • edited Loading

Execution-Time Benchmarks Report ⏱️

andrewlock commented Jan 19, 2024

Benchmarks Report 🐌

Benchmark details

Raw results

Raw results

Faster 🎉 in #5088

Raw results

Slower ⚠️ in #5088

Raw results

Raw results

Fewer allocations 🎉 in #5088

Raw results

Faster 🎉 in #5088

Raw results

Raw results

Raw results

Raw results

More allocations ⚠️ in #5088

Fewer allocations 🎉 in #5088

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #5088

Raw results

Slower ⚠️ in #5088

Faster 🎉 in #5088

Raw results

andrewlock left a comment

Choose a reason for hiding this comment

andrewlock Jan 19, 2024

Choose a reason for hiding this comment

tonyredondo Jan 19, 2024

Choose a reason for hiding this comment

andrewlock commented Jan 19, 2024

Throughput/Crank Report:zap:

tonyredondo commented Jan 19, 2024 •

edited

Loading

datadog-ddstaging bot commented Jan 19, 2024 •

edited

Loading

andrewlock commented Jan 19, 2024 •

edited

Loading