Support OnExecuteRequestStep available in new .NET versions for IIS m…

…odules. (#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

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<object, string> _routeDataTemplateGetter;
  private Func<object, decimal> _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<HttpContextBase, 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)

src/integrations/Elastic.Apm.AspNetFullFramework/HttpContextCurrentExecutionSegmentsContainer.cs

@@ -15,10 +15,10 @@ namespace Elastic.Apm.AspNetFullFramework
  /// </summary>
  internal sealed class HttpContextCurrentExecutionSegmentsContainer : ICurrentExecutionSegmentsContainer
  {
- private readonly AsyncLocal<ISpan> _currentSpan = new AsyncLocal<ISpan>();
- private readonly AsyncLocal<ITransaction> _currentTransaction = new AsyncLocal<ITransaction>();
+ private readonly AsyncLocal<ISpan> _currentSpan = new();
+ private readonly AsyncLocal<ITransaction> _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