Add Activity tracking to HostingApplication (#964)
This commit is contained in:
Pavel Krymets
GitHub
parent
db7095bc90
commit
7890fdbf94
|
|
@ -6,6 +6,7 @@
|
|||
<NetStandardImplicitPackageVersion>1.6.1</NetStandardImplicitPackageVersion>
|
||||
<RuntimeFrameworkVersion>2.0.0-*</RuntimeFrameworkVersion>
|
||||
<SystemReflectionMetadataVersion>1.4.2</SystemReflectionMetadataVersion>
|
||||
<SystemDiagnosticsDiagnosticSourceVersion>4.4.0-*</SystemDiagnosticsDiagnosticSourceVersion>
|
||||
<TestSdkVersion>15.0.0</TestSdkVersion>
|
||||
<WebAdministrationVersion>7.0.0</WebAdministrationVersion>
|
||||
<WindowsApiSetsVersion>1.0.1</WindowsApiSetsVersion>
|
||||
|
|
|
|||
|
|
@ -3,7 +3,6 @@
|
|||
|
||||
using System;
|
||||
using System.Diagnostics;
|
||||
using System.Runtime.CompilerServices;
|
||||
using System.Threading.Tasks;
|
||||
using Microsoft.AspNetCore.Hosting.Server;
|
||||
using Microsoft.AspNetCore.Http;
|
||||
|
|
@ -14,70 +13,31 @@ namespace Microsoft.AspNetCore.Hosting.Internal
|
|||
{
|
||||
public class HostingApplication : IHttpApplication<HostingApplication.Context>
|
||||
{
|
||||
private const string DiagnosticsBeginRequestKey = "Microsoft.AspNetCore.Hosting.BeginRequest";
|
||||
private const string DiagnosticsEndRequestKey = "Microsoft.AspNetCore.Hosting.EndRequest";
|
||||
private const string DiagnosticsUnhandledExceptionKey = "Microsoft.AspNetCore.Hosting.UnhandledException";
|
||||
|
||||
private static readonly double TimestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
|
||||
|
||||
private readonly RequestDelegate _application;
|
||||
private readonly ILogger _logger;
|
||||
private readonly DiagnosticSource _diagnosticSource;
|
||||
private readonly IHttpContextFactory _httpContextFactory;
|
||||
private HostingApplicationDiagnostics _diagnostics;
|
||||
|
||||
public HostingApplication(
|
||||
RequestDelegate application,
|
||||
ILogger logger,
|
||||
DiagnosticSource diagnosticSource,
|
||||
DiagnosticListener diagnosticSource,
|
||||
IHttpContextFactory httpContextFactory)
|
||||
{
|
||||
_application = application;
|
||||
_logger = logger;
|
||||
_diagnosticSource = diagnosticSource;
|
||||
_diagnostics = new HostingApplicationDiagnostics(logger, diagnosticSource);
|
||||
_httpContextFactory = httpContextFactory;
|
||||
}
|
||||
|
||||
// Set up the request
|
||||
public Context CreateContext(IFeatureCollection contextFeatures)
|
||||
{
|
||||
var context = new Context();
|
||||
var httpContext = _httpContextFactory.Create(contextFeatures);
|
||||
|
||||
// These enabled checks are virtual dispatch and used twice and so cache to locals
|
||||
var diagnoticsEnabled = _diagnosticSource.IsEnabled(DiagnosticsBeginRequestKey);
|
||||
var loggingEnabled = _logger.IsEnabled(LogLevel.Information);
|
||||
_diagnostics.BeginRequest(httpContext, ref context);
|
||||
|
||||
if (HostingEventSource.Log.IsEnabled())
|
||||
{
|
||||
// To keep the hot path short we defer logging in this function to non-inlines
|
||||
RecordRequestStartEventLog(httpContext);
|
||||
}
|
||||
|
||||
// Only make call GetTimestamp if its value will be used, i.e. of the listenters is enabled
|
||||
var startTimestamp = (diagnoticsEnabled || loggingEnabled) ? Stopwatch.GetTimestamp() : 0;
|
||||
|
||||
// Scope may be relevant for a different level of logging, so we always create it
|
||||
// see: https://github.com/aspnet/Hosting/pull/944
|
||||
var scope = _logger.RequestScope(httpContext);
|
||||
|
||||
if (loggingEnabled)
|
||||
{
|
||||
// Non-inline
|
||||
LogRequestStarting(httpContext);
|
||||
}
|
||||
|
||||
if (diagnoticsEnabled)
|
||||
{
|
||||
// Non-inline
|
||||
RecordBeginRequestDiagnostics(httpContext, startTimestamp);
|
||||
}
|
||||
|
||||
// Create and return the request Context
|
||||
return new Context
|
||||
{
|
||||
HttpContext = httpContext,
|
||||
Scope = scope, // Scope can be null if logging is not on.
|
||||
StartTimestamp = startTimestamp,
|
||||
};
|
||||
context.HttpContext = httpContext;
|
||||
return context;
|
||||
}
|
||||
|
||||
// Execute the request
|
||||
|
|
@ -89,138 +49,10 @@ namespace Microsoft.AspNetCore.Hosting.Internal
|
|||
// Clean up the request
|
||||
public void DisposeContext(Context context, Exception exception)
|
||||
{
|
||||
// Local cache items resolved multiple items, in order of use so they are primed in cpu pipeline when used
|
||||
var hostingEventLog = HostingEventSource.Log;
|
||||
var startTimestamp = context.StartTimestamp;
|
||||
var httpContext = context.HttpContext;
|
||||
var eventLogEnabled = hostingEventLog.IsEnabled();
|
||||
|
||||
// If startTimestamp is 0, don't call GetTimestamp, likely don't need the value
|
||||
var currentTimestamp = (startTimestamp != 0) ? Stopwatch.GetTimestamp() : 0;
|
||||
|
||||
// To keep the hot path short we defer logging to non-inlines
|
||||
if (exception == null)
|
||||
{
|
||||
// No exception was thrown, request was sucessful
|
||||
if (_diagnosticSource.IsEnabled(DiagnosticsEndRequestKey))
|
||||
{
|
||||
// Diagnostics is enabled for EndRequest, but it may not be for BeginRequest
|
||||
// so call GetTimestamp if currentTimestamp is zero (from above)
|
||||
RecordEndRequestDiagnostics(
|
||||
httpContext,
|
||||
(currentTimestamp != 0) ? currentTimestamp : Stopwatch.GetTimestamp());
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
// Exception was thrown from request
|
||||
if (_diagnosticSource.IsEnabled(DiagnosticsUnhandledExceptionKey))
|
||||
{
|
||||
// Diagnostics is enabled for UnhandledException, but it may not be for BeginRequest
|
||||
// so call GetTimestamp if currentTimestamp is zero (from above)
|
||||
RecordUnhandledExceptionDiagnostics(
|
||||
httpContext,
|
||||
(currentTimestamp != 0) ? currentTimestamp : Stopwatch.GetTimestamp(),
|
||||
exception);
|
||||
}
|
||||
|
||||
if (eventLogEnabled)
|
||||
{
|
||||
// Non-inline
|
||||
hostingEventLog.UnhandledException();
|
||||
}
|
||||
}
|
||||
|
||||
// If startTimestamp was 0, then Information logging wasn't enabled at for this request (and calcuated time will be wildly wrong)
|
||||
// Is used as proxy to reduce calls to virtual: _logger.IsEnabled(LogLevel.Information)
|
||||
if (startTimestamp != 0)
|
||||
{
|
||||
// Non-inline
|
||||
LogRequestFinished(httpContext, startTimestamp, currentTimestamp);
|
||||
}
|
||||
|
||||
// Logging Scope and context are finshed with
|
||||
context.Scope?.Dispose();
|
||||
_diagnostics.RequestEnd(httpContext, exception, context);
|
||||
_httpContextFactory.Dispose(httpContext);
|
||||
|
||||
if (eventLogEnabled)
|
||||
{
|
||||
// Non-inline
|
||||
hostingEventLog.RequestStop();
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void LogRequestStarting(HttpContext httpContext)
|
||||
{
|
||||
// IsEnabled is checked in the caller, so if we are here just log
|
||||
_logger.Log(
|
||||
logLevel: LogLevel.Information,
|
||||
eventId: LoggerEventIds.RequestStarting,
|
||||
state: new HostingRequestStartingLog(httpContext),
|
||||
exception: null,
|
||||
formatter: HostingRequestStartingLog.Callback);
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void LogRequestFinished(HttpContext httpContext, long startTimestamp, long currentTimestamp)
|
||||
{
|
||||
// IsEnabled isn't checked in the caller, startTimestamp > 0 is used as a fast proxy check
|
||||
// but that may be because diagnostics are enabled, which also uses startTimestamp, so check here
|
||||
if (_logger.IsEnabled(LogLevel.Information))
|
||||
{
|
||||
var elapsed = new TimeSpan((long)(TimestampToTicks * (currentTimestamp - startTimestamp)));
|
||||
|
||||
_logger.Log(
|
||||
logLevel: LogLevel.Information,
|
||||
eventId: LoggerEventIds.RequestFinished,
|
||||
state: new HostingRequestFinishedLog(httpContext, elapsed),
|
||||
exception: null,
|
||||
formatter: HostingRequestFinishedLog.Callback);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordBeginRequestDiagnostics(HttpContext httpContext, long startTimestamp)
|
||||
{
|
||||
_diagnosticSource.Write(
|
||||
DiagnosticsBeginRequestKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = startTimestamp
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordEndRequestDiagnostics(HttpContext httpContext, long currentTimestamp)
|
||||
{
|
||||
_diagnosticSource.Write(
|
||||
DiagnosticsEndRequestKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = currentTimestamp
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordUnhandledExceptionDiagnostics(HttpContext httpContext, long currentTimestamp, Exception exception)
|
||||
{
|
||||
_diagnosticSource.Write(
|
||||
DiagnosticsUnhandledExceptionKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = currentTimestamp,
|
||||
exception = exception
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private static void RecordRequestStartEventLog(HttpContext httpContext)
|
||||
{
|
||||
HostingEventSource.Log.RequestStart(httpContext.Request.Method, httpContext.Request.Path);
|
||||
_diagnostics.ContextDisposed(context);
|
||||
}
|
||||
|
||||
public struct Context
|
||||
|
|
@ -228,6 +60,8 @@ namespace Microsoft.AspNetCore.Hosting.Internal
|
|||
public HttpContext HttpContext { get; set; }
|
||||
public IDisposable Scope { get; set; }
|
||||
public long StartTimestamp { get; set; }
|
||||
public bool EventLogEnabled { get; set; }
|
||||
public Activity Activity { get; set; }
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -0,0 +1,273 @@
|
|||
// Copyright (c) .NET Foundation. All rights reserved.
|
||||
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
|
||||
|
||||
using System;
|
||||
using System.Diagnostics;
|
||||
using System.Runtime.CompilerServices;
|
||||
using Microsoft.AspNetCore.Http;
|
||||
using Microsoft.Extensions.Logging;
|
||||
using Microsoft.Extensions.Primitives;
|
||||
using Microsoft.Net.Http.Headers;
|
||||
|
||||
namespace Microsoft.AspNetCore.Hosting.Internal
|
||||
{
|
||||
internal class HostingApplicationDiagnostics
|
||||
{
|
||||
private static readonly double TimestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
|
||||
|
||||
private const string ActivityName = "Microsoft.AspNetCore.Hosting.HttpRequestIn";
|
||||
private const string ActivityStartKey = "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start";
|
||||
|
||||
private const string DeprecatedDiagnosticsBeginRequestKey = "Microsoft.AspNetCore.Hosting.BeginRequest";
|
||||
private const string DeprecatedDiagnosticsEndRequestKey = "Microsoft.AspNetCore.Hosting.EndRequest";
|
||||
private const string DiagnosticsUnhandledExceptionKey = "Microsoft.AspNetCore.Hosting.UnhandledException";
|
||||
|
||||
private const string RequestIdHeaderName = "Request-Id";
|
||||
private const string CorrelationContextHeaderName = "Correlation-Context";
|
||||
|
||||
private readonly DiagnosticListener _diagnosticListener;
|
||||
private readonly ILogger _logger;
|
||||
|
||||
public HostingApplicationDiagnostics(ILogger logger, DiagnosticListener diagnosticListener)
|
||||
{
|
||||
_logger = logger;
|
||||
_diagnosticListener = diagnosticListener;
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.AggressiveInlining)]
|
||||
public void BeginRequest(HttpContext httpContext, ref HostingApplication.Context context)
|
||||
{
|
||||
long startTimestamp = 0;
|
||||
|
||||
if (HostingEventSource.Log.IsEnabled())
|
||||
{
|
||||
context.EventLogEnabled = true;
|
||||
// To keep the hot path short we defer logging in this function to non-inlines
|
||||
RecordRequestStartEventLog(httpContext);
|
||||
}
|
||||
|
||||
|
||||
if (_diagnosticListener.IsEnabled())
|
||||
{
|
||||
if (_diagnosticListener.IsEnabled(ActivityName, httpContext))
|
||||
{
|
||||
context.Activity = StartActivity(httpContext);
|
||||
}
|
||||
if (_diagnosticListener.IsEnabled(DeprecatedDiagnosticsBeginRequestKey))
|
||||
{
|
||||
startTimestamp = Stopwatch.GetTimestamp();
|
||||
RecordBeginRequestDiagnostics(httpContext, startTimestamp);
|
||||
}
|
||||
}
|
||||
|
||||
// To avoid allocation, return a null scope if the logger is not on at least to some degree.
|
||||
if (_logger.IsEnabled(LogLevel.Critical))
|
||||
{
|
||||
// Scope may be relevant for a different level of logging, so we always create it
|
||||
// see: https://github.com/aspnet/Hosting/pull/944
|
||||
// Scope can be null if logging is not on.
|
||||
context.Scope = _logger.RequestScope(httpContext);
|
||||
|
||||
if (_logger.IsEnabled(LogLevel.Information))
|
||||
{
|
||||
if (startTimestamp == 0)
|
||||
{
|
||||
startTimestamp = Stopwatch.GetTimestamp();
|
||||
}
|
||||
|
||||
// Non-inline
|
||||
LogRequestStarting(httpContext);
|
||||
}
|
||||
}
|
||||
|
||||
context.StartTimestamp = startTimestamp;
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.AggressiveInlining)]
|
||||
public void RequestEnd(HttpContext httpContext, Exception exception, HostingApplication.Context context)
|
||||
{
|
||||
// Local cache items resolved multiple items, in order of use so they are primed in cpu pipeline when used
|
||||
var startTimestamp = context.StartTimestamp;
|
||||
long currentTimestamp = 0;
|
||||
|
||||
// If startTimestamp was 0, then Information logging wasn't enabled at for this request (and calcuated time will be wildly wrong)
|
||||
// Is used as proxy to reduce calls to virtual: _logger.IsEnabled(LogLevel.Information)
|
||||
if (startTimestamp != 0)
|
||||
{
|
||||
currentTimestamp = Stopwatch.GetTimestamp();
|
||||
// Non-inline
|
||||
LogRequestFinished(httpContext, startTimestamp, currentTimestamp);
|
||||
}
|
||||
|
||||
if (_diagnosticListener.IsEnabled())
|
||||
{
|
||||
if (currentTimestamp == 0)
|
||||
{
|
||||
currentTimestamp = Stopwatch.GetTimestamp();
|
||||
}
|
||||
|
||||
if (exception == null)
|
||||
{
|
||||
// No exception was thrown, request was sucessful
|
||||
if (_diagnosticListener.IsEnabled(DeprecatedDiagnosticsEndRequestKey))
|
||||
{
|
||||
// Diagnostics is enabled for EndRequest, but it may not be for BeginRequest
|
||||
// so call GetTimestamp if currentTimestamp is zero (from above)
|
||||
RecordEndRequestDiagnostics(httpContext, currentTimestamp);
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
// Exception was thrown from request
|
||||
if (_diagnosticListener.IsEnabled(DiagnosticsUnhandledExceptionKey))
|
||||
{
|
||||
// Diagnostics is enabled for UnhandledException, but it may not be for BeginRequest
|
||||
// so call GetTimestamp if currentTimestamp is zero (from above)
|
||||
RecordUnhandledExceptionDiagnostics(httpContext, currentTimestamp, exception);
|
||||
}
|
||||
|
||||
}
|
||||
|
||||
var activity = context.Activity;
|
||||
// Always stop activity if it was started
|
||||
if (activity != null)
|
||||
{
|
||||
StopActivity(httpContext, activity);
|
||||
}
|
||||
}
|
||||
|
||||
if (context.EventLogEnabled && exception != null)
|
||||
{
|
||||
// Non-inline
|
||||
HostingEventSource.Log.UnhandledException();
|
||||
}
|
||||
|
||||
// Logging Scope is finshed with
|
||||
context.Scope?.Dispose();
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.AggressiveInlining)]
|
||||
public void ContextDisposed(HostingApplication.Context context)
|
||||
{
|
||||
if (context.EventLogEnabled)
|
||||
{
|
||||
// Non-inline
|
||||
HostingEventSource.Log.RequestStop();
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void LogRequestStarting(HttpContext httpContext)
|
||||
{
|
||||
// IsEnabled is checked in the caller, so if we are here just log
|
||||
_logger.Log(
|
||||
logLevel: LogLevel.Information,
|
||||
eventId: LoggerEventIds.RequestStarting,
|
||||
state: new HostingRequestStartingLog(httpContext),
|
||||
exception: null,
|
||||
formatter: HostingRequestStartingLog.Callback);
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void LogRequestFinished(HttpContext httpContext, long startTimestamp, long currentTimestamp)
|
||||
{
|
||||
// IsEnabled isn't checked in the caller, startTimestamp > 0 is used as a fast proxy check
|
||||
// but that may be because diagnostics are enabled, which also uses startTimestamp, so check here
|
||||
if (_logger.IsEnabled(LogLevel.Information))
|
||||
{
|
||||
var elapsed = new TimeSpan((long)(TimestampToTicks * (currentTimestamp - startTimestamp)));
|
||||
|
||||
_logger.Log(
|
||||
logLevel: LogLevel.Information,
|
||||
eventId: LoggerEventIds.RequestFinished,
|
||||
state: new HostingRequestFinishedLog(httpContext, elapsed),
|
||||
exception: null,
|
||||
formatter: HostingRequestFinishedLog.Callback);
|
||||
}
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordBeginRequestDiagnostics(HttpContext httpContext, long startTimestamp)
|
||||
{
|
||||
_diagnosticListener.Write(
|
||||
DeprecatedDiagnosticsBeginRequestKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = startTimestamp
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordEndRequestDiagnostics(HttpContext httpContext, long currentTimestamp)
|
||||
{
|
||||
_diagnosticListener.Write(
|
||||
DeprecatedDiagnosticsEndRequestKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = currentTimestamp
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void RecordUnhandledExceptionDiagnostics(HttpContext httpContext, long currentTimestamp, Exception exception)
|
||||
{
|
||||
_diagnosticListener.Write(
|
||||
DiagnosticsUnhandledExceptionKey,
|
||||
new
|
||||
{
|
||||
httpContext = httpContext,
|
||||
timestamp = currentTimestamp,
|
||||
exception = exception
|
||||
});
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private static void RecordRequestStartEventLog(HttpContext httpContext)
|
||||
{
|
||||
HostingEventSource.Log.RequestStart(httpContext.Request.Method, httpContext.Request.Path);
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private Activity StartActivity(HttpContext httpContext)
|
||||
{
|
||||
var activity = new Activity(ActivityName);
|
||||
if (httpContext.Request.Headers.TryGetValue(RequestIdHeaderName, out var requestId))
|
||||
{
|
||||
activity.SetParentId(requestId);
|
||||
|
||||
// We expect baggage to be empty by default
|
||||
// Only very advanced users will be using it in near future, we encouradge them to keep baggage small (few items)
|
||||
string[] baggage = httpContext.Request.Headers.GetCommaSeparatedValues(CorrelationContextHeaderName);
|
||||
if (baggage != StringValues.Empty)
|
||||
{
|
||||
foreach (var item in baggage)
|
||||
{
|
||||
if (NameValueHeaderValue.TryParse(item, out var baggageItem))
|
||||
{
|
||||
activity.AddBaggage(baggageItem.Name, baggageItem.Value);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
if (_diagnosticListener.IsEnabled(ActivityStartKey))
|
||||
{
|
||||
_diagnosticListener.StartActivity(activity, new { HttpContext = httpContext });
|
||||
}
|
||||
else
|
||||
{
|
||||
activity.Start();
|
||||
}
|
||||
|
||||
return activity;
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.NoInlining)]
|
||||
private void StopActivity(HttpContext httpContext, Activity activity)
|
||||
{
|
||||
_diagnosticListener.StopActivity(activity, new { HttpContext = httpContext });
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -15,12 +15,8 @@ namespace Microsoft.AspNetCore.Hosting.Internal
|
|||
{
|
||||
public static IDisposable RequestScope(this ILogger logger, HttpContext httpContext)
|
||||
{
|
||||
// To avoid allocation, return a null scope if the logger is not on at least to some degree.
|
||||
if (logger.IsEnabled(LogLevel.Critical))
|
||||
{
|
||||
return logger.BeginScope(new HostingLogScope(httpContext));
|
||||
}
|
||||
return null;
|
||||
|
||||
return logger.BeginScope(new HostingLogScope(httpContext));
|
||||
}
|
||||
|
||||
public static void ApplicationError(this ILogger logger, Exception exception)
|
||||
|
|
|
|||
|
|
@ -110,7 +110,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
|
|||
|
||||
_applicationLifetime = _applicationServices.GetRequiredService<IApplicationLifetime>() as ApplicationLifetime;
|
||||
_hostedServiceExecutor = _applicationServices.GetRequiredService<HostedServiceExecutor>();
|
||||
var diagnosticSource = _applicationServices.GetRequiredService<DiagnosticSource>();
|
||||
var diagnosticSource = _applicationServices.GetRequiredService<DiagnosticListener>();
|
||||
var httpContextFactory = _applicationServices.GetRequiredService<IHttpContextFactory>();
|
||||
Server.Start(new HostingApplication(_application, _logger, diagnosticSource, httpContextFactory));
|
||||
|
||||
|
|
|
|||
|
|
@ -30,7 +30,7 @@
|
|||
<PackageReference Include="Microsoft.Extensions.RuntimeEnvironment.Sources" Version="$(AspNetCoreVersion)" PrivateAssets="All" />
|
||||
<PackageReference Include="Microsoft.Extensions.StackTrace.Sources" Version="$(AspNetCoreVersion)" PrivateAssets="All" />
|
||||
<PackageReference Include="Microsoft.Extensions.TypeNameHelper.Sources" Version="$(AspNetCoreVersion)" PrivateAssets="All" />
|
||||
<PackageReference Include="System.Diagnostics.DiagnosticSource" Version="$(CoreFxVersion)" />
|
||||
<PackageReference Include="System.Diagnostics.DiagnosticSource" Version="$(SystemDiagnosticsDiagnosticSourceVersion)" />
|
||||
<PackageReference Include="System.Diagnostics.StackTrace" Version="$(CoreFxVersion)" />
|
||||
<PackageReference Include="System.Reflection.Metadata" Version="$(SystemReflectionMetadataVersion)" />
|
||||
<PackageReference Include="System.Reflection.TypeExtensions" Version="$(CoreFxVersion)" />
|
||||
|
|
|
|||
|
|
@ -2,7 +2,9 @@
|
|||
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
|
||||
|
||||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Diagnostics;
|
||||
using System.Reflection;
|
||||
using System.Threading.Tasks;
|
||||
using Microsoft.AspNetCore.Hosting.Internal;
|
||||
using Microsoft.AspNetCore.Http;
|
||||
|
|
@ -20,16 +22,263 @@ namespace Microsoft.AspNetCore.Hosting.Tests
|
|||
public void DisposeContextDoesNotThrowWhenContextScopeIsNull()
|
||||
{
|
||||
// Arrange
|
||||
var httpContextFactory = new HttpContextFactory(new DefaultObjectPoolProvider(), Options.Create(new FormOptions()), new HttpContextAccessor());
|
||||
var hostingApplication = new HostingApplication(ctx => Task.FromResult(0), new NullScopeLogger(), new NoopDiagnosticSource(), httpContextFactory);
|
||||
var features = new FeatureCollection();
|
||||
features.Set<IHttpRequestFeature>(new HttpRequestFeature());
|
||||
var hostingApplication = CreateApplication(out var features);
|
||||
var context = hostingApplication.CreateContext(features);
|
||||
|
||||
// Act/Assert
|
||||
hostingApplication.DisposeContext(context, null);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsNotCreatedWhenIsEnabledForActivityIsFalse()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool eventsFired = false;
|
||||
bool isEnabledActivityFired = false;
|
||||
bool isEnabledStartFired = false;
|
||||
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
eventsFired |= pair.Key.StartsWith("Microsoft.AspNetCore.Hosting.HttpRequestIn");
|
||||
}), (s, o, arg3) =>
|
||||
{
|
||||
if (s == "Microsoft.AspNetCore.Hosting.HttpRequestIn")
|
||||
{
|
||||
Assert.IsAssignableFrom<HttpContext>(o);
|
||||
isEnabledActivityFired = true;
|
||||
}
|
||||
if (s == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")
|
||||
{
|
||||
isEnabledStartFired = true;
|
||||
}
|
||||
return false;
|
||||
});
|
||||
|
||||
hostingApplication.CreateContext(features);
|
||||
Assert.Null(Activity.Current);
|
||||
Assert.True(isEnabledActivityFired);
|
||||
Assert.False (isEnabledStartFired);
|
||||
Assert.False(eventsFired);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsCreatedButNotLoggedWhenIsEnabledForActivityStartIsFalse()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool eventsFired = false;
|
||||
bool isEnabledStartFired = false;
|
||||
bool isEnabledActivityFired = false;
|
||||
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
eventsFired |= pair.Key.StartsWith("Microsoft.AspNetCore.Hosting.HttpRequestIn");
|
||||
}), (s, o, arg3) =>
|
||||
{
|
||||
if (s == "Microsoft.AspNetCore.Hosting.HttpRequestIn")
|
||||
{
|
||||
Assert.IsAssignableFrom<HttpContext>(o);
|
||||
isEnabledActivityFired = true;
|
||||
return true;
|
||||
}
|
||||
|
||||
if (s == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")
|
||||
{
|
||||
isEnabledStartFired = true;
|
||||
return false;
|
||||
}
|
||||
return true;
|
||||
});
|
||||
|
||||
hostingApplication.CreateContext(features);
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.True(isEnabledActivityFired);
|
||||
Assert.True(isEnabledStartFired);
|
||||
Assert.False(eventsFired);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsCreatedAndLogged()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool startCalled = false;
|
||||
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
if (pair.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")
|
||||
{
|
||||
startCalled = true;
|
||||
Assert.NotNull(pair.Value);
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
AssertProperty<HttpContext>(pair.Value, "HttpContext");
|
||||
}
|
||||
}));
|
||||
|
||||
hostingApplication.CreateContext(features);
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.True(startCalled);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsStoppedDuringStopCall()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool endCalled = false;
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
if (pair.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop")
|
||||
{
|
||||
endCalled = true;
|
||||
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.True(Activity.Current.Duration > TimeSpan.Zero);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
AssertProperty<HttpContext>(pair.Value, "HttpContext");
|
||||
}
|
||||
}));
|
||||
|
||||
var context = hostingApplication.CreateContext(features);
|
||||
hostingApplication.DisposeContext(context, null);
|
||||
Assert.True(endCalled);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsStoppedDuringUnhandledExceptionCall()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool endCalled = false;
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
if (pair.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop")
|
||||
{
|
||||
endCalled = true;
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.True(Activity.Current.Duration > TimeSpan.Zero);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
AssertProperty<HttpContext>(pair.Value, "HttpContext");
|
||||
}
|
||||
}));
|
||||
|
||||
var context = hostingApplication.CreateContext(features);
|
||||
hostingApplication.DisposeContext(context, new Exception());
|
||||
Assert.True(endCalled);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsAvailableDuringUnhandledExceptionCall()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
bool endCalled = false;
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair =>
|
||||
{
|
||||
if (pair.Key == "Microsoft.AspNetCore.Hosting.UnhandledException")
|
||||
{
|
||||
endCalled = true;
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
}
|
||||
}));
|
||||
|
||||
var context = hostingApplication.CreateContext(features);
|
||||
hostingApplication.DisposeContext(context, new Exception());
|
||||
Assert.True(endCalled);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityIsAvailibleDuringRequest()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair => { }),
|
||||
s =>
|
||||
{
|
||||
if (s.StartsWith("Microsoft.AspNetCore.Hosting.HttpRequestIn"))
|
||||
{
|
||||
return true;
|
||||
}
|
||||
return false;
|
||||
});
|
||||
|
||||
hostingApplication.CreateContext(features);
|
||||
|
||||
Assert.NotNull(Activity.Current);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void ActivityParentIdAndBaggeReadFromHeaders()
|
||||
{
|
||||
var diagnosticSource = new DiagnosticListener("DummySource");
|
||||
var hostingApplication = CreateApplication(out var features, diagnosticSource: diagnosticSource);
|
||||
|
||||
diagnosticSource.Subscribe(new CallbackDiagnosticListener(pair => { }),
|
||||
s =>
|
||||
{
|
||||
if (s.StartsWith("Microsoft.AspNetCore.Hosting.HttpRequestIn"))
|
||||
{
|
||||
return true;
|
||||
}
|
||||
return false;
|
||||
});
|
||||
|
||||
features.Set<IHttpRequestFeature>(new HttpRequestFeature()
|
||||
{
|
||||
Headers = new HeaderDictionary()
|
||||
{
|
||||
{"Request-Id", "ParentId1"},
|
||||
{"Correlation-Context", "Key1=value1, Key2=value2"}
|
||||
}
|
||||
});
|
||||
hostingApplication.CreateContext(features);
|
||||
Assert.Equal("Microsoft.AspNetCore.Hosting.HttpRequestIn", Activity.Current.OperationName);
|
||||
Assert.Equal("ParentId1", Activity.Current.ParentId);
|
||||
Assert.Contains(Activity.Current.Baggage, pair => pair.Key == "Key1" && pair.Value == "value1");
|
||||
Assert.Contains(Activity.Current.Baggage, pair => pair.Key == "Key2" && pair.Value == "value2");
|
||||
}
|
||||
|
||||
private static void AssertProperty<T>(object o, string name)
|
||||
{
|
||||
Assert.NotNull(o);
|
||||
var property = o.GetType().GetTypeInfo().GetProperty(name, BindingFlags.Instance | BindingFlags.Public);
|
||||
Assert.NotNull(property);
|
||||
var value = property.GetValue(o);
|
||||
Assert.NotNull(value);
|
||||
Assert.IsAssignableFrom<T>(value);
|
||||
}
|
||||
|
||||
private static HostingApplication CreateApplication(out FeatureCollection features,
|
||||
DiagnosticListener diagnosticSource = null)
|
||||
{
|
||||
var httpContextFactory = new HttpContextFactory(
|
||||
new DefaultObjectPoolProvider(),
|
||||
Options.Create(new FormOptions()),
|
||||
new HttpContextAccessor());
|
||||
|
||||
var hostingApplication = new HostingApplication(
|
||||
ctx => Task.FromResult(0),
|
||||
new NullScopeLogger(),
|
||||
diagnosticSource ?? new NoopDiagnosticSource(),
|
||||
httpContextFactory);
|
||||
|
||||
features = new FeatureCollection();
|
||||
features.Set<IHttpRequestFeature>(new HttpRequestFeature());
|
||||
|
||||
return hostingApplication;
|
||||
}
|
||||
|
||||
private class NullScopeLogger : ILogger
|
||||
{
|
||||
public IDisposable BeginScope<TState>(TState state) => null;
|
||||
|
|
@ -41,13 +290,40 @@ namespace Microsoft.AspNetCore.Hosting.Tests
|
|||
}
|
||||
}
|
||||
|
||||
private class NoopDiagnosticSource : DiagnosticSource
|
||||
private class NoopDiagnosticSource : DiagnosticListener
|
||||
{
|
||||
public NoopDiagnosticSource() : base("DummyListener")
|
||||
{
|
||||
}
|
||||
|
||||
public override bool IsEnabled(string name) => true;
|
||||
|
||||
public override void Write(string name, object value)
|
||||
{
|
||||
}
|
||||
}
|
||||
|
||||
private class CallbackDiagnosticListener : IObserver<KeyValuePair<string, object>>
|
||||
{
|
||||
private readonly Action<KeyValuePair<string, object>> _callback;
|
||||
|
||||
public CallbackDiagnosticListener(Action<KeyValuePair<string, object>> callback)
|
||||
{
|
||||
_callback = callback;
|
||||
}
|
||||
|
||||
public void OnNext(KeyValuePair<string, object> value)
|
||||
{
|
||||
_callback(value);
|
||||
}
|
||||
|
||||
public void OnError(Exception error)
|
||||
{
|
||||
}
|
||||
|
||||
public void OnCompleted()
|
||||
{
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
|||
Loading…
Reference in New Issue