From 35a9fcf2ecd0c7a4700a945e0488a7f78e176748 Mon Sep 17 00:00:00 2001 From: Martijn Laarman Date: Wed, 18 Oct 2023 09:15:18 +0200 Subject: [PATCH] Support OnExecuteRequestStep available in new .NET versions for IIS modules. (#2196) * Support OnExecuteRequestStep available in new .NET versions for IIS modules. This more aggressively logs and attempts to restore HttpContext items. This also more gracefully exits if we detect the module running under classic pipeline mode * dotnet format * add url to logging --- .../ElasticApmModule.cs | 107 ++++++++++++++++++ ...ontextCurrentExecutionSegmentsContainer.cs | 6 +- 2 files changed, 110 insertions(+), 3 deletions(-) diff --git a/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs b/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs index 8d4c9bc3a..8137c2452 100644 --- a/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs +++ b/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs @@ -8,6 +8,7 @@ using System.Collections.Specialized; using System.Data.SqlClient; using System.Linq; +using System.Reflection; using System.Security.Claims; using System.Threading; using System.Web; @@ -34,6 +35,8 @@ public class ElasticApmModule : IHttpModule // ReSharper disable once RedundantDefaultMemberInitializer private static readonly DbgInstanceNameGenerator DbgInstanceNameGenerator = new(); private static readonly LazyContextualInit InitOnceHelper = new(); + private static readonly MethodInfo OnExecuteRequestStepMethodInfo = typeof(HttpApplication).GetMethod("OnExecuteRequestStep"); + private readonly string _dbgInstanceName; private HttpApplication _application; @@ -45,6 +48,7 @@ public class ElasticApmModule : IHttpModule private Func _routeDataTemplateGetter; private Func _routePrecedenceGetter; + public ElasticApmModule() => // ReSharper disable once ImpureMethodCallOnReadonlyValueField _dbgInstanceName = DbgInstanceNameGenerator.Generate($"{nameof(ElasticApmModule)}.#"); @@ -101,6 +105,15 @@ private void InitImpl(HttpApplication application) if (!Agent.Config.Enabled) return; + if (!HttpRuntime.UsingIntegratedPipeline) + { + _logger.Error() + ?.Log("Skipping Initialization. Elastic APM Module requires the application pool to run under an Integrated Pipeline." + + " .NET runtime: {DotNetRuntimeDescription}; IIS: {IisVersion}", + PlatformDetection.DotNetRuntimeDescription, HttpRuntime.IISVersion); + return; + } + if (isInitedByThisCall) { _logger.Debug() @@ -114,6 +127,100 @@ private void InitImpl(HttpApplication application) _application.BeginRequest += OnBeginRequest; _application.EndRequest += OnEndRequest; _application.Error += OnError; + + if (OnExecuteRequestStepMethodInfo != null) + { + // OnExecuteRequestStep is available starting with 4.7.1 + try + { + OnExecuteRequestStepMethodInfo.Invoke(application, new object[] { (Action)OnExecuteRequestStep }); + } + catch (Exception e) + { + _logger.Error() + ?.LogException(e, "Failed to invoke OnExecuteRequestStep. .NET runtime: {DotNetRuntimeDescription}; IIS: {IisVersion}", + PlatformDetection.DotNetRuntimeDescription, HttpRuntime.IISVersion); + } + } + } + + private void RestoreContextIfNeeded(HttpContextBase context) + { + string EventName() => Enum.GetName(typeof(RequestNotification), context.CurrentNotification); + + var urlPath = TryGetUrlPath(context); + var ignoreUrls = Agent.Instance?.Configuration.TransactionIgnoreUrls; + if (urlPath != null && ignoreUrls != null && WildcardMatcher.IsAnyMatch(ignoreUrls, urlPath)) + return; + + + if (Agent.Instance == null) + { + _logger.Trace()?.Log($"Agent.Instance is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + return; + } + if (Agent.Instance.Tracer == null) + { + _logger.Trace()?.Log($"Agent.Instance.Tracer is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + return; + } + var transaction = Agent.Instance?.Tracer?.CurrentTransaction; + if (transaction != null) + return; + if (Agent.Config.LogLevel <= LogLevel.Trace) + return; + + var transactionInCurrent = HttpContext.Current?.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey] is not null; + var transactionInApplicationInstance = context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey] is not null; + var spanInCurrent = HttpContext.Current?.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey] is not null; + var spanInApplicationInstance = context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey] is not null; + + _logger.Trace()? + .Log($"{nameof(ITracer.CurrentTransaction)} is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath} " + + $"(HttpContext.Current Span: {spanInCurrent}, Transaction: {transactionInCurrent})" + + $"(ApplicationContext Span: {spanInApplicationInstance}, Transaction: {transactionInApplicationInstance})"); + + if (HttpContext.Current == null) + { + _logger.Trace()? + .Log($"HttpContext.Current is null during {nameof(OnExecuteRequestStep)}:{EventName()}. Unable to attempt to restore transaction. url: {urlPath}"); + return; + } + + if (!transactionInCurrent && transactionInApplicationInstance) + { + HttpContext.Current.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey] = + context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey]; + _logger.Trace()?.Log($"Restored transaction to HttpContext.Current.Items {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + } + if (!spanInCurrent && spanInApplicationInstance) + { + HttpContext.Current.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey] = + context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey]; + _logger.Trace()?.Log($"Restored span to HttpContext.Current.Items {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + } + + } + + private string TryGetUrlPath(HttpContextBase context) + { + try + { + return context.Request.Unvalidated.Path; + } + catch + { + //ignore + return string.Empty; + } + + } + + private void OnExecuteRequestStep(HttpContextBase context, Action step) + { + + RestoreContextIfNeeded(context); + step(); } private void OnBeginRequest(object sender, EventArgs e) diff --git a/src/integrations/Elastic.Apm.AspNetFullFramework/HttpContextCurrentExecutionSegmentsContainer.cs b/src/integrations/Elastic.Apm.AspNetFullFramework/HttpContextCurrentExecutionSegmentsContainer.cs index 2e7288c0a..046e35e4f 100644 --- a/src/integrations/Elastic.Apm.AspNetFullFramework/HttpContextCurrentExecutionSegmentsContainer.cs +++ b/src/integrations/Elastic.Apm.AspNetFullFramework/HttpContextCurrentExecutionSegmentsContainer.cs @@ -15,10 +15,10 @@ namespace Elastic.Apm.AspNetFullFramework /// internal sealed class HttpContextCurrentExecutionSegmentsContainer : ICurrentExecutionSegmentsContainer { - private readonly AsyncLocal _currentSpan = new AsyncLocal(); - private readonly AsyncLocal _currentTransaction = new AsyncLocal(); + private readonly AsyncLocal _currentSpan = new(); + private readonly AsyncLocal _currentTransaction = new(); - private const string CurrentSpanKey = "Elastic.Apm.Agent.CurrentSpan"; + internal const string CurrentSpanKey = "Elastic.Apm.Agent.CurrentSpan"; internal const string CurrentTransactionKey = "Elastic.Apm.Agent.CurrentTransaction"; public ISpan CurrentSpan