public void RequestEnd(ProtoContext 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;
var currentTimestamp = 0L;
// 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();
}
public void ContextDisposed(HostingApplication.Context context)
{
if (context.EventLogEnabled)
{
// Non-inline
HostingEventSource.Log.RequestStop();
}
}
public void BeginRequest(ProtoContext httpContext, ref HostingApplication.Context context)
{
var startTimestamp = 0L;
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 loggingEnabled = _logger.IsEnabled(LogLevel.Critical);
if (diagnosticListenerEnabled)
{
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 (loggingEnabled)
{
// Get the request ID (first try TraceParent header otherwise Request-ID header
if (!httpContext.Request.Headers.TryGetValue(TraceParentHeaderName, out var correlationId))
{
httpContext.Request.Headers.TryGetValue(RequestIdHeaderName, out correlationId);
}
// 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, correlationId);
if (_logger.IsEnabled(LogLevel.Information))
{
if (startTimestamp == 0)
{
startTimestamp = Stopwatch.GetTimestamp();
}
// Non-inline
LogRequestStarting(httpContext);
}
}
context.StartTimestamp = startTimestamp;
}