public void ContextDisposed(HostingApplication.Context context)
{
if (context.EventLogEnabled)
{
// Non-inline
HostingEventSource.Log.RequestStop();
}
}
public void BeginRequest(HttpContext httpContext, 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);
}
var diagnosticListenerEnabled = _diagnosticListener.IsEnabled();
var diagnosticListenerActivityCreationEnabled = (diagnosticListenerEnabled && _diagnosticListener.IsEnabled(ActivityName, httpContext));
var loggingEnabled = _logger.IsEnabled(LogLevel.Critical);
if (loggingEnabled || diagnosticListenerActivityCreationEnabled || _activitySource.HasListeners())
{
context.Activity = StartActivity(httpContext, loggingEnabled, diagnosticListenerActivityCreationEnabled, out var hasDiagnosticListener);
context.HasDiagnosticListener = hasDiagnosticListener;
}
if (diagnosticListenerEnabled)
{
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 (loggingEnabled)
{
// 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(context);
}
}
context.StartTimestamp = startTimestamp;
}
private void LogRequestStarting(HostingApplication.Context context)
{
// IsEnabled is checked in the caller, so if we are here just log
var startLog = new HostingRequestStartingLog(context.HttpContext);
context.StartLog = startLog;
_logger.Log(
logLevel: LogLevel.Information,
eventId: LoggerEventIds.RequestStarting,
state: startLog,
exception: null,
formatter: HostingRequestStartingLog.Callback);
}
private void LogRequestFinished(HostingApplication.Context context, 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 if we logged the start event
if (context.StartLog != null)
{
var elapsed = new TimeSpan((long)(TimestampToTicks * (currentTimestamp - startTimestamp)));
_logger.Log(
logLevel: LogLevel.Information,
eventId: LoggerEventIds.RequestFinished,
state: new HostingRequestFinishedLog(context, elapsed),
exception: null,
formatter: HostingRequestFinishedLog.Callback);
}
}
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 calculated 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(context, startTimestamp, currentTimestamp);
}
if (_diagnosticListener.IsEnabled())
{
if (currentTimestamp == 0)
{
currentTimestamp = Stopwatch.GetTimestamp();
}
if (exception == null)
{
// No exception was thrown, request was successful
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, context.HasDiagnosticListener);
}
if (context.EventLogEnabled)
{
if (exception != null)
{
// Non-inline
HostingEventSource.Log.UnhandledException();
}
// Count 500 as failed requests
if (httpContext.Response.StatusCode >= 500)
{
HostingEventSource.Log.RequestFailed();
}
}
// Logging Scope is finshed with
context.Scope?.Dispose();
}
