diff --git a/src/Components/Components/src/RenderTree/Renderer.Log.cs b/src/Components/Components/src/RenderTree/Renderer.Log.cs index da658e5aaee6..5df1c0a572ce 100644 --- a/src/Components/Components/src/RenderTree/Renderer.Log.cs +++ b/src/Components/Components/src/RenderTree/Renderer.Log.cs @@ -14,16 +14,16 @@ public abstract partial class Renderer internal static class Log { private static readonly Action _initializingChildComponent = - LoggerMessage.Define(LogLevel.Debug, new EventId(1, "InitializingChildComponent"), "Initializing component {ComponentId} ({ComponentType}) as child of {ParentComponentId} ({ParentComponentId})"); + LoggerMessage.Define(LogLevel.Debug, new EventId(1, "InitializingChildComponent"), "Initializing component {ComponentId} ({ComponentType}) as child of {ParentComponentId} ({ParentComponentId})", skipEnabledCheck: true); private static readonly Action _initializingRootComponent = - LoggerMessage.Define(LogLevel.Debug, new EventId(2, "InitializingRootComponent"), "Initializing root component {ComponentId} ({ComponentType})"); + LoggerMessage.Define(LogLevel.Debug, new EventId(2, "InitializingRootComponent"), "Initializing root component {ComponentId} ({ComponentType})", skipEnabledCheck: true); private static readonly Action _renderingComponent = - LoggerMessage.Define(LogLevel.Debug, new EventId(3, "RenderingComponent"), "Rendering component {ComponentId} of type {ComponentType}"); + LoggerMessage.Define(LogLevel.Debug, new EventId(3, "RenderingComponent"), "Rendering component {ComponentId} of type {ComponentType}", skipEnabledCheck: true); private static readonly Action _disposingComponent = - LoggerMessage.Define(LogLevel.Debug, new EventId(4, "DisposingComponent"), "Disposing component {ComponentId} of type {ComponentType}"); + LoggerMessage.Define(LogLevel.Debug, new EventId(4, "DisposingComponent"), "Disposing component {ComponentId} of type {ComponentType}", skipEnabledCheck: true); private static readonly Action _handlingEvent = LoggerMessage.Define(LogLevel.Debug, new EventId(5, "HandlingEvent"), "Handling event {EventId} of type '{EventType}'"); diff --git a/src/Hosting/Hosting/src/Internal/HostingLoggerExtensions.cs b/src/Hosting/Hosting/src/Internal/HostingLoggerExtensions.cs index c8902d659e4d..7dcf39bce16c 100644 --- a/src/Hosting/Hosting/src/Internal/HostingLoggerExtensions.cs +++ b/src/Hosting/Hosting/src/Internal/HostingLoggerExtensions.cs @@ -14,7 +14,7 @@ namespace Microsoft.AspNetCore.Hosting internal static class HostingLoggerExtensions { private static readonly Action _startupAssemblyLoaded = - LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.HostingStartupAssemblyLoaded, "Loaded hosting startup assembly {assemblyName}"); + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.HostingStartupAssemblyLoaded, "Loaded hosting startup assembly {assemblyName}", skipEnabledCheck: true); private static readonly Action _listeningOnAddress = LoggerMessage.Define(LogLevel.Information, LoggerEventIds.ServerListeningOnAddresses, "Now listening on: {address}"); diff --git a/src/Http/Routing/src/DefaultLinkGenerator.cs b/src/Http/Routing/src/DefaultLinkGenerator.cs index 68155ca27c2e..ea14bcf0e0e2 100644 --- a/src/Http/Routing/src/DefaultLinkGenerator.cs +++ b/src/Http/Routing/src/DefaultLinkGenerator.cs @@ -355,7 +355,8 @@ public static class EventIds private static readonly Action, object, Exception> _endpointsFound = LoggerMessage.Define, object>( LogLevel.Debug, EventIds.EndpointsFound, - "Found the endpoints {Endpoints} for address {Address}"); + "Found the endpoints {Endpoints} for address {Address}", + skipEnabledCheck: true); private static readonly Action _endpointsNotFound = LoggerMessage.Define( LogLevel.Debug, @@ -372,30 +373,35 @@ public static class EventIds EventIds.TemplateFailedRequiredValues, "Failed to process the template {Template} for {Endpoint}. " + "A required route value is missing, or has a different value from the required default values. " + - "Supplied ambient values {AmbientValues} and {Values} with default values {Defaults}"); + "Supplied ambient values {AmbientValues} and {Values} with default values {Defaults}", + skipEnabledCheck: true); private static readonly Action _templateFailedConstraint = LoggerMessage.Define( LogLevel.Debug, EventIds.TemplateFailedConstraint, "Failed to process the template {Template} for {Endpoint}. " + - "The constraint {Constraint} for parameter {ParameterName} failed with values {Values}"); + "The constraint {Constraint} for parameter {ParameterName} failed with values {Values}", + skipEnabledCheck: true); private static readonly Action _templateFailedExpansion = LoggerMessage.Define( LogLevel.Debug, EventIds.TemplateFailedExpansion, "Failed to process the template {Template} for {Endpoint}. " + "The failure occurred while expanding the template with values {Values} " + - "This is usually due to a missing or empty value in a complex segment"); + "This is usually due to a missing or empty value in a complex segment", + skipEnabledCheck: true); private static readonly Action, string, Exception> _linkGenerationSucceeded = LoggerMessage.Define, string>( LogLevel.Debug, EventIds.LinkGenerationSucceeded, - "Link generation succeeded for endpoints {Endpoints} with result {URI}"); + "Link generation succeeded for endpoints {Endpoints} with result {URI}", + skipEnabledCheck: true); private static readonly Action, Exception> _linkGenerationFailed = LoggerMessage.Define>( LogLevel.Debug, EventIds.LinkGenerationFailed, - "Link generation failed for endpoints {Endpoints}"); + "Link generation failed for endpoints {Endpoints}", + skipEnabledCheck: true); public static void EndpointsFound(ILogger logger, object address, IEnumerable endpoints) { diff --git a/src/Http/Routing/src/DefaultLinkParser.cs b/src/Http/Routing/src/DefaultLinkParser.cs index 07aaacbb0371..50f2c7db6fb3 100644 --- a/src/Http/Routing/src/DefaultLinkParser.cs +++ b/src/Http/Routing/src/DefaultLinkParser.cs @@ -184,7 +184,8 @@ public static class EventIds private static readonly Action, object, Exception> _endpointsFound = LoggerMessage.Define, object>( LogLevel.Debug, EventIds.EndpointsFound, - "Found the endpoints {Endpoints} for address {Address}"); + "Found the endpoints {Endpoints} for address {Address}", + skipEnabledCheck: true); private static readonly Action _endpointsNotFound = LoggerMessage.Define( LogLevel.Debug, @@ -194,12 +195,14 @@ public static class EventIds private static readonly Action _pathParsingSucceeded = LoggerMessage.Define( LogLevel.Debug, EventIds.PathParsingSucceeded, - "Path parsing succeeded for endpoint {Endpoint} and URI path {URI}"); + "Path parsing succeeded for endpoint {Endpoint} and URI path {URI}", + skipEnabledCheck: true); private static readonly Action, string, Exception> _pathParsingFailed = LoggerMessage.Define, string>( LogLevel.Debug, EventIds.PathParsingFailed, - "Path parsing failed for endpoints {Endpoints} and URI path {URI}"); + "Path parsing failed for endpoints {Endpoints} and URI path {URI}", + skipEnabledCheck: true); public static void EndpointsFound(ILogger logger, object address, IEnumerable endpoints) { diff --git a/src/Http/Routing/src/Matching/DfaMatcher.cs b/src/Http/Routing/src/Matching/DfaMatcher.cs index e40e21e252a9..9cc6ae2ab94f 100644 --- a/src/Http/Routing/src/Matching/DfaMatcher.cs +++ b/src/Http/Routing/src/Matching/DfaMatcher.cs @@ -339,32 +339,38 @@ private static class Logger private static readonly Action _candidatesNotFound = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidatesNotFound, - "No candidates found for the request path '{Path}'"); + "No candidates found for the request path '{Path}'", + skipEnabledCheck: true); private static readonly Action _candidatesFound = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidatesFound, - "{CandidateCount} candidate(s) found for the request path '{Path}'"); + "{CandidateCount} candidate(s) found for the request path '{Path}'", + skipEnabledCheck: true); private static readonly Action _candidateRejectedByComplexSegment = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidateRejectedByComplexSegment, - "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by complex segment '{Segment}' for the request path '{Path}'"); + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by complex segment '{Segment}' for the request path '{Path}'", + skipEnabledCheck: true); private static readonly Action _candidateRejectedByConstraint = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidateRejectedByConstraint, - "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by constraint '{ConstraintName}':'{Constraint}' with value '{RouteValue}' for the request path '{Path}'"); + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' was rejected by constraint '{ConstraintName}':'{Constraint}' with value '{RouteValue}' for the request path '{Path}'", + skipEnabledCheck: true); private static readonly Action _candidateNotValid = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidateNotValid, - "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is not valid for the request path '{Path}'"); + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is not valid for the request path '{Path}'", + skipEnabledCheck: true); private static readonly Action _candidateValid = LoggerMessage.Define( LogLevel.Debug, EventIds.CandidateValid, - "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is valid for the request path '{Path}'"); + "Endpoint '{Endpoint}' with route pattern '{RoutePattern}' is valid for the request path '{Path}'", + skipEnabledCheck: true); public static void CandidatesNotFound(ILogger logger, string path) { diff --git a/src/Middleware/HostFiltering/src/LoggerExtensions.cs b/src/Middleware/HostFiltering/src/LoggerExtensions.cs index 1c6559e5573a..fa763b00cab0 100644 --- a/src/Middleware/HostFiltering/src/LoggerExtensions.cs +++ b/src/Middleware/HostFiltering/src/LoggerExtensions.cs @@ -12,7 +12,7 @@ internal static class LoggerExtensions LoggerMessage.Define(LogLevel.Debug, new EventId(0, "WildcardDetected"), "Wildcard detected, all requests with hosts will be allowed."); private static readonly Action _allowedHosts = - LoggerMessage.Define(LogLevel.Debug, new EventId(1, "AllowedHosts"), "Allowed hosts: {Hosts}"); + LoggerMessage.Define(LogLevel.Debug, new EventId(1, "AllowedHosts"), "Allowed hosts: {Hosts}", skipEnabledCheck: true); private static readonly Action _allHostsAllowed = LoggerMessage.Define(LogLevel.Trace, new EventId(2, "AllHostsAllowed"), "All hosts are allowed."); diff --git a/src/Middleware/Session/src/LoggingExtensions.cs b/src/Middleware/Session/src/LoggingExtensions.cs index 3a8e6e47c07e..2d36b21c129c 100644 --- a/src/Middleware/Session/src/LoggingExtensions.cs +++ b/src/Middleware/Session/src/LoggingExtensions.cs @@ -34,11 +34,13 @@ static LoggingExtensions() _sessionStarted = LoggerMessage.Define( eventId: new EventId(3, "SessionStarted"), logLevel: LogLevel.Information, - formatString: "Session started; Key:{sessionKey}, Id:{sessionId}"); + formatString: "Session started; Key:{sessionKey}, Id:{sessionId}", + skipEnabledCheck: true); _sessionLoaded = LoggerMessage.Define( eventId: new EventId(4, "SessionLoaded"), logLevel: LogLevel.Debug, - formatString: "Session loaded; Key:{sessionKey}, Id:{sessionId}, Count:{count}"); + formatString: "Session loaded; Key:{sessionKey}, Id:{sessionId}, Count:{count}", + skipEnabledCheck: true); _sessionStored = LoggerMessage.Define( eventId: new EventId(5, "SessionStored"), logLevel: LogLevel.Debug, @@ -46,7 +48,8 @@ static LoggingExtensions() _sessionCacheReadException = LoggerMessage.Define( eventId: new EventId(6, "SessionCacheReadException"), logLevel: LogLevel.Error, - formatString: "Session cache read exception, Key:{sessionKey}"); + formatString: "Session cache read exception, Key:{sessionKey}", + skipEnabledCheck: true); _errorUnprotectingCookie = LoggerMessage.Define( eventId: new EventId(7, "ErrorUnprotectingCookie"), logLevel: LogLevel.Warning, diff --git a/src/Mvc/Mvc.Core/src/Infrastructure/ObjectResultExecutor.cs b/src/Mvc/Mvc.Core/src/Infrastructure/ObjectResultExecutor.cs index 75a4dc9f9f78..d4a634d4e94d 100644 --- a/src/Mvc/Mvc.Core/src/Infrastructure/ObjectResultExecutor.cs +++ b/src/Mvc/Mvc.Core/src/Infrastructure/ObjectResultExecutor.cs @@ -168,15 +168,11 @@ private static void InferContentTypes(ActionContext context, ObjectResult result private static class Log { - private static readonly Action _bufferingAsyncEnumerable; - - static Log() - { - _bufferingAsyncEnumerable = LoggerMessage.Define( - LogLevel.Debug, - new EventId(1, "BufferingAsyncEnumerable"), - "Buffering IAsyncEnumerable instance of type '{Type}'."); - } + private static readonly Action _bufferingAsyncEnumerable = LoggerMessage.Define( + LogLevel.Debug, + new EventId(1, "BufferingAsyncEnumerable"), + "Buffering IAsyncEnumerable instance of type '{Type}'.", + skipEnabledCheck: true); public static void BufferingAsyncEnumerable(ILogger logger, object asyncEnumerable) { diff --git a/src/Mvc/Mvc.Core/src/Infrastructure/SystemTextJsonResultExecutor.cs b/src/Mvc/Mvc.Core/src/Infrastructure/SystemTextJsonResultExecutor.cs index 6672925961a8..563927356d0a 100644 --- a/src/Mvc/Mvc.Core/src/Infrastructure/SystemTextJsonResultExecutor.cs +++ b/src/Mvc/Mvc.Core/src/Infrastructure/SystemTextJsonResultExecutor.cs @@ -144,12 +144,14 @@ private static class Log private static readonly Action _jsonResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "JsonResultExecuting"), - "Executing JsonResult, writing value of type '{Type}'."); + "Executing JsonResult, writing value of type '{Type}'.", + skipEnabledCheck: true); private static readonly Action _bufferingAsyncEnumerable = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "BufferingAsyncEnumerable"), - "Buffering IAsyncEnumerable instance of type '{Type}'."); + "Buffering IAsyncEnumerable instance of type '{Type}'.", + skipEnabledCheck: true); public static void JsonResultExecuting(ILogger logger, object? value) { diff --git a/src/Mvc/Mvc.Core/src/MvcCoreLoggerExtensions.cs b/src/Mvc/Mvc.Core/src/MvcCoreLoggerExtensions.cs index a49c0ff31c53..b9e1a02e2944 100644 --- a/src/Mvc/Mvc.Core/src/MvcCoreLoggerExtensions.cs +++ b/src/Mvc/Mvc.Core/src/MvcCoreLoggerExtensions.cs @@ -161,42 +161,50 @@ static MvcCoreLoggerExtensions() _controllerFactoryExecuting = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "ControllerFactoryExecuting"), - "Executing controller factory for controller {Controller} ({AssemblyName})"); + "Executing controller factory for controller {Controller} ({AssemblyName})", + skipEnabledCheck: true); _controllerFactoryExecuted = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "ControllerFactoryExecuted"), - "Executed controller factory for controller {Controller} ({AssemblyName})"); + "Executed controller factory for controller {Controller} ({AssemblyName})", + skipEnabledCheck: true); _actionExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ActionExecuting"), - "Route matched with {RouteData}. Executing action {ActionName}"); + "Route matched with {RouteData}. Executing action {ActionName}", + skipEnabledCheck: true); _controllerActionExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(3, "ControllerActionExecuting"), - "Route matched with {RouteData}. Executing controller action with signature {MethodInfo} on controller {Controller} ({AssemblyName})."); + "Route matched with {RouteData}. Executing controller action with signature {MethodInfo} on controller {Controller} ({AssemblyName}).", + skipEnabledCheck: true); _actionExecuted = LoggerMessage.Define( LogLevel.Information, new EventId(2, "ActionExecuted"), - "Executed action {ActionName} in {ElapsedMilliseconds}ms"); + "Executed action {ActionName} in {ElapsedMilliseconds}ms", + skipEnabledCheck: true); _pageExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(3, "PageExecuting"), - "Route matched with {RouteData}. Executing page {PageName}"); + "Route matched with {RouteData}. Executing page {PageName}", + skipEnabledCheck: true); _pageExecuted = LoggerMessage.Define( LogLevel.Information, new EventId(4, "PageExecuted"), - "Executed page {PageName} in {ElapsedMilliseconds}ms"); + "Executed page {PageName} in {ElapsedMilliseconds}ms", + skipEnabledCheck: true); _challengeResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ChallengeResultExecuting"), - "Executing ChallengeResult with authentication schemes ({Schemes})."); + "Executing ChallengeResult with authentication schemes ({Schemes}).", + skipEnabledCheck: true); _contentResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -206,22 +214,26 @@ static MvcCoreLoggerExtensions() _actionMethodExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ActionMethodExecuting"), - "Executing action method {ActionName} - Validation state: {ValidationState}"); + "Executing action method {ActionName} - Validation state: {ValidationState}", + skipEnabledCheck: true); _actionMethodExecutingWithArguments = LoggerMessage.Define( LogLevel.Trace, new EventId(1, "ActionMethodExecutingWithArguments"), - "Executing action method {ActionName} with arguments ({Arguments})"); + "Executing action method {ActionName} with arguments ({Arguments})", + skipEnabledCheck: true); _actionMethodExecuted = LoggerMessage.Define( LogLevel.Information, new EventId(2, "ActionMethodExecuted"), - "Executed action method {ActionName}, returned result {ActionResult} in {ElapsedMilliseconds}ms."); + "Executed action method {ActionName}, returned result {ActionResult} in {ElapsedMilliseconds}ms.", + skipEnabledCheck: true); _logFilterExecutionPlan = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "FilterExecutionPlan"), - "Execution plan of {FilterType} filters (in the following order): {Filters}"); + "Execution plan of {FilterType} filters (in the following order): {Filters}", + skipEnabledCheck: true); _beforeExecutingMethodOnFilter = LoggerMessage.Define( LogLevel.Trace, @@ -256,12 +268,14 @@ static MvcCoreLoggerExtensions() _executingFileResult = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ExecutingFileResult"), - "Executing {FileResultType}, sending file '{FileDownloadPath}' with download name '{FileDownloadName}' ..."); + "Executing {FileResultType}, sending file '{FileDownloadPath}' with download name '{FileDownloadName}' ...", + skipEnabledCheck: true); _executingFileResultWithNoFileName = LoggerMessage.Define( LogLevel.Information, new EventId(2, "ExecutingFileResultWithNoFileName"), - "Executing {FileResultType}, sending file with download name '{FileDownloadName}' ..."); + "Executing {FileResultType}, sending file with download name '{FileDownloadName}' ...", + skipEnabledCheck: true); _authorizationFailure = LoggerMessage.Define( LogLevel.Information, @@ -291,7 +305,8 @@ static MvcCoreLoggerExtensions() _forbidResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ForbidResultExecuting"), - formatString: $"Executing {nameof(ForbidResult)} with authentication schemes ({{Schemes}})."); + formatString: $"Executing {nameof(ForbidResult)} with authentication schemes ({{Schemes}}).", + skipEnabledCheck: true); _signInResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -301,7 +316,8 @@ static MvcCoreLoggerExtensions() _signOutResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "SignOutResultExecuting"), - formatString: $"Executing {nameof(SignOutResult)} with authentication schemes ({{Schemes}})."); + formatString: $"Executing {nameof(SignOutResult)} with authentication schemes ({{Schemes}}).", + skipEnabledCheck: true); _httpStatusCodeResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -316,17 +332,20 @@ static MvcCoreLoggerExtensions() _noFormatter = LoggerMessage.Define>( LogLevel.Warning, new EventId(1, "NoFormatter"), - "No output formatter was found for content types '{ContentTypes}' to write the response."); + "No output formatter was found for content types '{ContentTypes}' to write the response.", + skipEnabledCheck: true); _objectResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ObjectResultExecuting"), - "Executing {ObjectResultType}, writing value of type '{Type}'."); + "Executing {ObjectResultType}, writing value of type '{Type}'.", + skipEnabledCheck: true); _formatterSelected = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "FormatterSelected"), - "Selected output formatter '{OutputFormatter}' and content type '{ContentType}' to write the response."); + "Selected output formatter '{OutputFormatter}' and content type '{ContentType}' to write the response.", + skipEnabledCheck: true); _skippedContentNegotiation = LoggerMessage.Define( LogLevel.Debug, @@ -346,22 +365,26 @@ static MvcCoreLoggerExtensions() _inputFormatterSelected = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "InputFormatterSelected"), - "Selected input formatter '{InputFormatter}' for content type '{ContentType}'."); + "Selected input formatter '{InputFormatter}' for content type '{ContentType}'.", + skipEnabledCheck: true); _inputFormatterRejected = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "InputFormatterRejected"), - "Rejected input formatter '{InputFormatter}' for content type '{ContentType}'."); + "Rejected input formatter '{InputFormatter}' for content type '{ContentType}'.", + skipEnabledCheck: true); _noInputFormatterSelected = LoggerMessage.Define( LogLevel.Debug, new EventId(3, "NoInputFormatterSelected"), - "No input formatter was found to support the content type '{ContentType}' for use with the [FromBody] attribute."); + "No input formatter was found to support the content type '{ContentType}' for use with the [FromBody] attribute.", + skipEnabledCheck: true); _removeFromBodyAttribute = LoggerMessage.Define( LogLevel.Debug, new EventId(4, "RemoveFromBodyAttribute"), - "To use model binding, remove the [FromBody] attribute from the property or parameter named '{ModelName}' with model type '{ModelType}'."); + "To use model binding, remove the [FromBody] attribute from the property or parameter named '{ModelName}' with model type '{ModelType}'.", + skipEnabledCheck: true); _redirectResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -386,7 +409,8 @@ static MvcCoreLoggerExtensions() _noActionsMatched = LoggerMessage.Define( LogLevel.Debug, new EventId(3, "NoActionsMatched"), - "No actions matched the current request. Route values: {RouteValues}"); + "No actions matched the current request. Route values: {RouteValues}", + skipEnabledCheck: true); _featureNotFound = LoggerMessage.Define( LogLevel.Warning, @@ -426,7 +450,8 @@ static MvcCoreLoggerExtensions() _inferredParameterSource = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "InferredParameterSource"), - "Inferred binding source for '{ParameterName}` on `{ActionName}` as {BindingSource}."); + "Inferred binding source for '{ParameterName}` on `{ActionName}` as {BindingSource}.", + skipEnabledCheck: true); _unsupportedFormatFilterContentType = LoggerMessage.Define( LogLevel.Debug, @@ -496,22 +521,26 @@ static MvcCoreLoggerExtensions() _attemptingToBindPropertyModel = LoggerMessage.Define( LogLevel.Debug, new EventId(13, "AttemptingToBindPropertyModel"), - "Attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' using the name '{ModelName}' in request data ..."); + "Attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' using the name '{ModelName}' in request data ...", + skipEnabledCheck: true); _doneAttemptingToBindPropertyModel = LoggerMessage.Define( LogLevel.Debug, new EventId(14, "DoneAttemptingToBindPropertyModel"), - "Done attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'."); + "Done attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'.", + skipEnabledCheck: true); _foundNoValueForPropertyInRequest = LoggerMessage.Define( LogLevel.Debug, new EventId(15, "FoundNoValueForPropertyInRequest"), - "Could not find a value in the request with name '{ModelName}' for binding property '{PropertyContainerType}.{ModelFieldName}' of type '{ModelType}'."); + "Could not find a value in the request with name '{ModelName}' for binding property '{PropertyContainerType}.{ModelFieldName}' of type '{ModelType}'.", + skipEnabledCheck: true); _foundNoValueForParameterInRequest = LoggerMessage.Define( LogLevel.Debug, new EventId(16, "FoundNoValueForParameterInRequest"), - "Could not find a value in the request with name '{ModelName}' for binding parameter '{ModelFieldName}' of type '{ModelType}'."); + "Could not find a value in the request with name '{ModelName}' for binding parameter '{ModelFieldName}' of type '{ModelType}'.", + skipEnabledCheck: true); _noPublicSettableProperties = LoggerMessage.Define( LogLevel.Debug, @@ -541,32 +570,38 @@ static MvcCoreLoggerExtensions() _attemptingToBindParameter = LoggerMessage.Define( LogLevel.Debug, new EventId(22, "AttemptingToBindParameter"), - "Attempting to bind parameter '{ParameterName}' of type '{ModelType}' ..."); + "Attempting to bind parameter '{ParameterName}' of type '{ModelType}' ...", + skipEnabledCheck: true); _doneAttemptingToBindParameter = LoggerMessage.Define( LogLevel.Debug, new EventId(23, "DoneAttemptingToBindParameter"), - "Done attempting to bind parameter '{ParameterName}' of type '{ModelType}'."); + "Done attempting to bind parameter '{ParameterName}' of type '{ModelType}'.", + skipEnabledCheck: true); _attemptingToBindModel = LoggerMessage.Define( LogLevel.Debug, new EventId(24, "AttemptingToBindModel"), - "Attempting to bind model of type '{ModelType}' using the name '{ModelName}' in request data ..."); + "Attempting to bind model of type '{ModelType}' using the name '{ModelName}' in request data ...", + skipEnabledCheck: true); _doneAttemptingToBindModel = LoggerMessage.Define( LogLevel.Debug, new EventId(25, "DoneAttemptingToBindModel"), - "Done attempting to bind model of type '{ModelType}' using the name '{ModelName}'."); + "Done attempting to bind model of type '{ModelType}' using the name '{ModelName}'.", + skipEnabledCheck: true); _attemptingToValidateParameter = LoggerMessage.Define( LogLevel.Debug, new EventId(26, "AttemptingToValidateParameter"), - "Attempting to validate the bound parameter '{ParameterName}' of type '{ModelType}' ..."); + "Attempting to validate the bound parameter '{ParameterName}' of type '{ModelType}' ...", + skipEnabledCheck: true); _doneAttemptingToValidateParameter = LoggerMessage.Define( LogLevel.Debug, new EventId(27, "DoneAttemptingToValidateParameter"), - "Done attempting to validate the bound parameter '{ParameterName}' of type '{ModelType}'."); + "Done attempting to validate the bound parameter '{ParameterName}' of type '{ModelType}'.", + skipEnabledCheck: true); _noNonIndexBasedFormatFoundForCollection = LoggerMessage.Define( LogLevel.Debug, @@ -579,7 +614,8 @@ static MvcCoreLoggerExtensions() "Attempting to bind model using indices. Example formats include: " + "[0]=value1&[1]=value2, " + "{ModelName}[0]=value1&{ModelName}[1]=value2, " + - "{ModelName}.index=zero&{ModelName}.index=one&{ModelName}[zero]=value1&{ModelName}[one]=value2"); + "{ModelName}.index=zero&{ModelName}.index=one&{ModelName}[zero]=value1&{ModelName}[one]=value2", + skipEnabledCheck: true); _attemptingToBindCollectionOfKeyValuePair = LoggerMessage.Define( LogLevel.Debug, @@ -587,7 +623,8 @@ static MvcCoreLoggerExtensions() "Attempting to bind collection of KeyValuePair. Example formats include: " + "[0].Key=key1&[0].Value=value1&[1].Key=key2&[1].Value=value2, " + "{ModelName}[0].Key=key1&{ModelName}[0].Value=value1&{ModelName}[1].Key=key2&{ModelName}[1].Value=value2, " + - "{ModelName}[key1]=value1&{ModelName}[key2]=value2"); + "{ModelName}[key1]=value1&{ModelName}[key2]=value2", + skipEnabledCheck: true); _noKeyValueFormatForDictionaryModelBinder = LoggerMessage.Define( LogLevel.Debug, @@ -622,22 +659,26 @@ static MvcCoreLoggerExtensions() _attemptingToBindProperty = LoggerMessage.Define( LogLevel.Debug, new EventId(39, "AttemptingToBindProperty"), - "Attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' ..."); + "Attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' ...", + skipEnabledCheck: true); _doneAttemptingToBindProperty = LoggerMessage.Define( LogLevel.Debug, new EventId(40, "DoneAttemptingToBindProperty"), - "Done attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'."); + "Done attempting to bind property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'.", + skipEnabledCheck: true); _attemptingToValidateProperty = LoggerMessage.Define( LogLevel.Debug, new EventId(41, "AttemptingToValidateProperty"), - "Attempting to validate the bound property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' ..."); + "Attempting to validate the bound property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}' ...", + skipEnabledCheck: true); _doneAttemptingToValidateProperty = LoggerMessage.Define( LogLevel.Debug, new EventId(42, "DoneAttemptingToValidateProperty"), - "Done attempting to validate the bound property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'."); + "Done attempting to validate the bound property '{PropertyContainerType}.{PropertyName}' of type '{ModelType}'.", + skipEnabledCheck: true); _cannotCreateHeaderModelBinderCompatVersion_2_0 = LoggerMessage.Define( LogLevel.Debug, @@ -647,27 +688,32 @@ static MvcCoreLoggerExtensions() _attemptingToBindParameterModel = LoggerMessage.Define( LogLevel.Debug, new EventId(44, "AttemptingToBindParameterModel"), - "Attempting to bind parameter '{ParameterName}' of type '{ModelType}' using the name '{ModelName}' in request data ..."); + "Attempting to bind parameter '{ParameterName}' of type '{ModelType}' using the name '{ModelName}' in request data ...", + skipEnabledCheck: true); _doneAttemptingToBindParameterModel = LoggerMessage.Define( LogLevel.Debug, new EventId(45, "DoneAttemptingToBindParameterModel"), - "Done attempting to bind parameter '{ParameterName}' of type '{ModelType}'."); + "Done attempting to bind parameter '{ParameterName}' of type '{ModelType}'.", + skipEnabledCheck: true); _foundNoValueInRequest = LoggerMessage.Define( LogLevel.Debug, new EventId(46, "FoundNoValueInRequest"), - "Could not find a value in the request with name '{ModelName}' of type '{ModelType}'."); + "Could not find a value in the request with name '{ModelName}' of type '{ModelType}'.", + skipEnabledCheck: true); _parameterBinderRequestPredicateShortCircuitOfProperty = LoggerMessage.Define( LogLevel.Debug, new EventId(47, "ParameterBinderRequestPredicateShortCircuitOfProperty"), - "Skipped binding property '{PropertyContainerType}.{PropertyName}' since its binding information disallowed it for the current request."); + "Skipped binding property '{PropertyContainerType}.{PropertyName}' since its binding information disallowed it for the current request.", + skipEnabledCheck: true); _parameterBinderRequestPredicateShortCircuitOfParameter = LoggerMessage.Define( LogLevel.Debug, new EventId(48, "ParameterBinderRequestPredicateShortCircuitOfParameter"), - "Skipped binding parameter '{ParameterName}' since its binding information disallowed it for the current request."); + "Skipped binding parameter '{ParameterName}' since its binding information disallowed it for the current request.", + skipEnabledCheck: true); _transformingClientError = LoggerMessage.Define( LogLevel.Trace, diff --git a/src/Mvc/Mvc.NewtonsoftJson/src/NewtonsoftJsonResultExecutor.cs b/src/Mvc/Mvc.NewtonsoftJson/src/NewtonsoftJsonResultExecutor.cs index cfbc124c893d..2091b8494a9d 100644 --- a/src/Mvc/Mvc.NewtonsoftJson/src/NewtonsoftJsonResultExecutor.cs +++ b/src/Mvc/Mvc.NewtonsoftJson/src/NewtonsoftJsonResultExecutor.cs @@ -178,21 +178,17 @@ private JsonSerializerSettings GetSerializerSettings(JsonResult result) private static class Log { - private static readonly Action _jsonResultExecuting; - private static readonly Action _bufferingAsyncEnumerable; - - static Log() - { - _jsonResultExecuting = LoggerMessage.Define( - LogLevel.Information, - new EventId(1, "JsonResultExecuting"), - "Executing JsonResult, writing value of type '{Type}'."); - - _bufferingAsyncEnumerable = LoggerMessage.Define( - LogLevel.Debug, - new EventId(1, "BufferingAsyncEnumerable"), - "Buffering IAsyncEnumerable instance of type '{Type}'."); - } + private static readonly Action _jsonResultExecuting = LoggerMessage.Define( + LogLevel.Information, + new EventId(1, "JsonResultExecuting"), + "Executing JsonResult, writing value of type '{Type}'.", + skipEnabledCheck: true); + + private static readonly Action _bufferingAsyncEnumerable = LoggerMessage.Define( + LogLevel.Debug, + new EventId(1, "BufferingAsyncEnumerable"), + "Buffering IAsyncEnumerable instance of type '{Type}'.", + skipEnabledCheck: true); public static void JsonResultExecuting(ILogger logger, object? value) { diff --git a/src/Mvc/Mvc.Razor.RuntimeCompilation/src/RazorRuntimeCompilationLoggerExtensions.cs b/src/Mvc/Mvc.Razor.RuntimeCompilation/src/RazorRuntimeCompilationLoggerExtensions.cs index dd644942409f..e6fe639e2f6e 100644 --- a/src/Mvc/Mvc.Razor.RuntimeCompilation/src/RazorRuntimeCompilationLoggerExtensions.cs +++ b/src/Mvc/Mvc.Razor.RuntimeCompilation/src/RazorRuntimeCompilationLoggerExtensions.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// 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; @@ -99,7 +99,8 @@ static MvcRazorLoggerExtensions() _malformedPageDirective = LoggerMessage.Define( LogLevel.Warning, new EventId(104, "MalformedPageDirective"), - "The page directive at '{FilePath}' is malformed. Please fix the following issues: {Diagnostics}"); + "The page directive at '{FilePath}' is malformed. Please fix the following issues: {Diagnostics}", + skipEnabledCheck: true); } public static void ViewCompilerLocatedCompiledView(this ILogger logger, string view) @@ -177,4 +178,4 @@ public static void MalformedPageDirective(this ILogger logger, string filePath, } } } -} \ No newline at end of file +} diff --git a/src/Mvc/Mvc.Razor/src/MvcRazorLoggerExtensions.cs b/src/Mvc/Mvc.Razor/src/MvcRazorLoggerExtensions.cs index c6b40a1c9be1..1a8edbcb3ce2 100644 --- a/src/Mvc/Mvc.Razor/src/MvcRazorLoggerExtensions.cs +++ b/src/Mvc/Mvc.Razor/src/MvcRazorLoggerExtensions.cs @@ -41,7 +41,8 @@ static MvcRazorLoggerExtensions() _viewCompilerEndCodeGeneration = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "ViewCompilerEndCodeGeneration"), - "Code generation for the Razor file at '{FilePath}' completed in {ElapsedMilliseconds}ms."); + "Code generation for the Razor file at '{FilePath}' completed in {ElapsedMilliseconds}ms.", + skipEnabledCheck: true); _viewCompilerLocatedCompiledView = LoggerMessage.Define( LogLevel.Debug, @@ -98,17 +99,20 @@ static MvcRazorLoggerExtensions() _generatedCodeToAssemblyCompilationEnd = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "GeneratedCodeToAssemblyCompilationEnd"), - "Compilation of the generated code for the Razor file at '{FilePath}' completed in {ElapsedMilliseconds}ms."); + "Compilation of the generated code for the Razor file at '{FilePath}' completed in {ElapsedMilliseconds}ms.", + skipEnabledCheck: true); _tagHelperComponentInitialized = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "TagHelperComponentInitialized"), - "Tag helper component '{ComponentName}' initialized."); + "Tag helper component '{ComponentName}' initialized.", + skipEnabledCheck: true); _tagHelperComponentProcessed = LoggerMessage.Define( LogLevel.Debug, new EventId(3, "TagHelperComponentProcessed"), - "Tag helper component '{ComponentName}' processed."); + "Tag helper component '{ComponentName}' processed.", + skipEnabledCheck: true); } public static void ViewCompilerStartCodeGeneration(this ILogger logger, string filePath) @@ -119,7 +123,7 @@ public static void ViewCompilerStartCodeGeneration(this ILogger logger, string f public static void ViewCompilerEndCodeGeneration(this ILogger logger, string filePath, long startTimestamp) { // Don't log if logging wasn't enabled at start of request as time will be wildly wrong. - if (startTimestamp != 0) + if (startTimestamp != 0 && logger.IsEnabled(LogLevel.Debug)) { var currentTimestamp = Stopwatch.GetTimestamp(); var elapsed = new TimeSpan((long)(TimestampToTicks * (currentTimestamp - startTimestamp))); @@ -190,7 +194,7 @@ public static void TagHelperComponentProcessed(this ILogger logger, string compo public static void GeneratedCodeToAssemblyCompilationEnd(this ILogger logger, string filePath, long startTimestamp) { // Don't log if logging wasn't enabled at start of request as time will be wildly wrong. - if (startTimestamp != 0) + if (startTimestamp != 0 && logger.IsEnabled(LogLevel.Debug)) { var currentTimestamp = Stopwatch.GetTimestamp(); var elapsed = new TimeSpan((long)(TimestampToTicks * (currentTimestamp - startTimestamp))); diff --git a/src/Mvc/Mvc.RazorPages/src/PageLoggerExtensions.cs b/src/Mvc/Mvc.RazorPages/src/PageLoggerExtensions.cs index d07e1ea65a8b..e3d9e8d4c48f 100644 --- a/src/Mvc/Mvc.RazorPages/src/PageLoggerExtensions.cs +++ b/src/Mvc/Mvc.RazorPages/src/PageLoggerExtensions.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// 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; @@ -36,47 +36,56 @@ static PageLoggerExtensions() _pageModelFactoryExecuting = LoggerMessage.Define( LogLevel.Debug, new EventId(101, "ExecutingModelFactory"), - "Executing page model factory for page {Page} ({AssemblyName})"); + "Executing page model factory for page {Page} ({AssemblyName})", + skipEnabledCheck: true); _pageModelFactoryExecuted = LoggerMessage.Define( LogLevel.Debug, new EventId(102, "ExecutedModelFactory"), - "Executed page model factory for page {Page} ({AssemblyName})"); + "Executed page model factory for page {Page} ({AssemblyName})", + skipEnabledCheck: true); _pageFactoryExecuting = LoggerMessage.Define( LogLevel.Debug, new EventId(101, "ExecutingPageFactory"), - "Executing page factory for page {Page} ({AssemblyName})"); + "Executing page factory for page {Page} ({AssemblyName})", + skipEnabledCheck: true); _pageFactoryExecuted = LoggerMessage.Define( LogLevel.Debug, new EventId(102, "ExecutedPageFactory"), - "Executed page factory for page {Page} ({AssemblyName})"); + "Executed page factory for page {Page} ({AssemblyName})", + skipEnabledCheck: true); _handlerMethodExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(101, "ExecutingHandlerMethod"), - "Executing handler method {HandlerName} - ModelState is {ValidationState}"); + "Executing handler method {HandlerName} - ModelState is {ValidationState}", + skipEnabledCheck: true); _handlerMethodExecutingWithArguments = LoggerMessage.Define( LogLevel.Trace, new EventId(103, "HandlerMethodExecutingWithArguments"), - "Executing handler method {HandlerName} with arguments ({Arguments})"); + "Executing handler method {HandlerName} with arguments ({Arguments})", + skipEnabledCheck: true); _handlerMethodExecuted = LoggerMessage.Define( LogLevel.Information, new EventId(102, "ExecutedHandlerMethod"), - "Executed handler method {HandlerName}, returned result {ActionResult}."); + "Executed handler method {HandlerName}, returned result {ActionResult}.", + skipEnabledCheck: true); _implicitHandlerMethodExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(103, "ExecutingImplicitHandlerMethod"), - "Executing an implicit handler method - ModelState is {ValidationState}"); + "Executing an implicit handler method - ModelState is {ValidationState}", + skipEnabledCheck: true); _implicitHandlerMethodExecuted = LoggerMessage.Define( LogLevel.Information, new EventId(104, "ExecutedImplicitHandlerMethod"), - "Executed an implicit handler method, returned result {ActionResult}."); + "Executed an implicit handler method, returned result {ActionResult}.", + skipEnabledCheck: true); _pageFilterShortCircuit = LoggerMessage.Define( LogLevel.Debug, diff --git a/src/Mvc/Mvc.ViewFeatures/src/MvcViewFeaturesLoggerExtensions.cs b/src/Mvc/Mvc.ViewFeatures/src/MvcViewFeaturesLoggerExtensions.cs index 19671f344fd4..a8529f818999 100644 --- a/src/Mvc/Mvc.ViewFeatures/src/MvcViewFeaturesLoggerExtensions.cs +++ b/src/Mvc/Mvc.ViewFeatures/src/MvcViewFeaturesLoggerExtensions.cs @@ -44,13 +44,15 @@ static MvcViewFeaturesLoggerExtensions() _viewComponentExecuting = LoggerMessage.Define( LogLevel.Debug, new EventId(1, "ViewComponentExecuting"), - "Executing view component {ViewComponentName} with arguments ({Arguments})."); + "Executing view component {ViewComponentName} with arguments ({Arguments}).", + skipEnabledCheck: true); _viewComponentExecuted = LoggerMessage.Define( LogLevel.Debug, new EventId(2, "ViewComponentExecuted"), "Executed view component {ViewComponentName} in {ElapsedMilliseconds}ms and returned " + - "{ViewComponentResult}"); + "{ViewComponentResult}", + skipEnabledCheck: true); _partialViewResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -80,7 +82,8 @@ static MvcViewFeaturesLoggerExtensions() _viewComponentResultExecuting = LoggerMessage.Define( LogLevel.Information, new EventId(1, "ViewComponentResultExecuting"), - "Executing ViewComponentResult, running {ViewComponentName}."); + "Executing ViewComponentResult, running {ViewComponentName}.", + skipEnabledCheck: true); _viewResultExecuting = LoggerMessage.Define( LogLevel.Information, @@ -135,8 +138,11 @@ public static void ViewComponentExecuting( ViewComponentContext context, object[] arguments) { - var formattedArguments = GetFormattedArguments(arguments); - _viewComponentExecuting(logger, context.ViewComponentDescriptor.DisplayName, formattedArguments, null); + if (logger.IsEnabled(LogLevel.Debug)) + { + var formattedArguments = GetFormattedArguments(arguments); + _viewComponentExecuting(logger, context.ViewComponentDescriptor.DisplayName, formattedArguments, null); + } } private static string[] GetFormattedArguments(object[] arguments) @@ -162,12 +168,15 @@ public static void ViewComponentExecuted( object result) { // Don't log if logging wasn't enabled at start of request as time will be wildly wrong. - _viewComponentExecuted( - logger, - context.ViewComponentDescriptor.DisplayName, - timespan.TotalMilliseconds, - Convert.ToString(result, CultureInfo.InvariantCulture), - null); + if (logger.IsEnabled(LogLevel.Debug)) + { + _viewComponentExecuted( + logger, + context.ViewComponentDescriptor.DisplayName, + timespan.TotalMilliseconds, + Convert.ToString(result, CultureInfo.InvariantCulture), + null); + } } public static void PartialViewFound( diff --git a/src/Servers/HttpSys/src/LoggerEventIds.cs b/src/Servers/HttpSys/src/LoggerEventIds.cs index 883997c0e54a..03cb50e839f5 100644 --- a/src/Servers/HttpSys/src/LoggerEventIds.cs +++ b/src/Servers/HttpSys/src/LoggerEventIds.cs @@ -4,53 +4,53 @@ namespace Microsoft.AspNetCore.Server.HttpSys { internal static class LoggerEventIds { - public static EventId HttpSysListenerCtorError = new EventId(1, "HttpSysListenerCtorError"); - public static EventId BindingToDefault = new EventId(2, "BindingToDefault"); - public static EventId ClearedPrefixes = new EventId(3, "ClearedPrefixes"); - public static EventId AcceptErrorStopping = new EventId(4, "AcceptErrorStopping"); - public static EventId AcceptError = new EventId(5, "AcceptError"); - public static EventId RequestProcessError = new EventId(6, "RequestProcessError"); - public static EventId RequestsDrained = new EventId(7, "RequestsDrained"); - public static EventId StopCancelled = new EventId(8, "StopCancelled"); - public static EventId WaitingForRequestsToDrain = new EventId(9, "WaitingForRequestsToDrain"); - public static EventId DisconnectRegistrationError = new EventId(10, "DisconnectRegistrationError"); - public static EventId RegisterDisconnectListener = new EventId(11, "RegisterDisconnectListener"); - public static EventId UnknownDisconnectError = new EventId(12, "UnknownDisconnectError"); - public static EventId DisconnectHandlerError = new EventId(13, "DisconnectHandlerError"); - public static EventId ListenerStarting = new EventId(14, "ListenerStarting"); - public static EventId ListenerDisposeError = new EventId(15, "ListenerDisposeError"); - public static EventId RequestListenerProcessError = new EventId(16, "RequestListenerProcessError"); - public static EventId AttachedToQueue = new EventId(17, "AttachedToQueue"); - public static EventId SetUrlPropertyError = new EventId(18, "SetUrlPropertyError"); - public static EventId RegisteringPrefix = new EventId(19, "RegisteringPrefix"); - public static EventId UnregisteringPrefix = new EventId(20, "UnregisteringPrefix"); - public static EventId CloseUrlGroupError = new EventId(21, "CloseUrlGroupError"); - public static EventId ChannelBindingUnsupported = new EventId(22, "ChannelBindingUnSupported"); - public static EventId ChannelBindingMissing = new EventId(23, "ChannelBindingMissing"); - public static EventId RequestError = new EventId(24, "RequestError"); - public static EventId ErrorInReadingCertificate = new EventId(25, "ErrorInReadingCertificate"); - public static EventId ChannelBindingNeedsHttps = new EventId(26, "ChannelBindingNeedsHttps"); - public static EventId ChannelBindingRetrieved = new EventId(27, "ChannelBindingRetrived"); - public static EventId AbortError = new EventId(28, "AbortError"); - public static EventId ErrorWhileRead = new EventId(29, "ErrorWhileRead"); - public static EventId ErrorWhenReadBegun = new EventId(30, "ErrorWhenReadBegun"); - public static EventId ErrorWhenReadAsync = new EventId(31, "ErrorWhenReadAsync"); - public static EventId ErrorWhenFlushAsync = new EventId(32, "ErrorWhenFlushAsync"); - public static EventId FewerBytesThanExpected = new EventId(33, "FewerBytesThanExpected"); - public static EventId WriteError = new EventId(34, "WriteError"); - public static EventId WriteErrorIgnored = new EventId(35, "WriteFlushedIgnored"); - public static EventId WriteFlushCancelled = new EventId(36, "WriteFlushCancelled"); - public static EventId ClearedAddresses = new EventId(37, "ClearedAddresses"); - public static EventId FileSendAsyncError = new EventId(38, "FileSendAsyncError"); - public static EventId FileSendAsyncCancelled = new EventId(39, "FileSendAsyncCancelled"); - public static EventId FileSendAsyncErrorIgnored = new EventId(40, "FileSendAsyncErrorIgnored"); - public static EventId WriteCancelled = new EventId(41, "WriteCancelled"); - public static EventId ListenerStopping = new EventId(42, "ListenerStopping"); - public static EventId ListenerStartError = new EventId(43, "ListenerStartError"); - public static EventId DisconnectTriggered = new EventId(44, "DisconnectTriggered"); - public static EventId ListenerStopError = new EventId(45, "ListenerStopError"); - public static EventId ListenerDisposing = new EventId(46, "ListenerDisposing"); - public static EventId RequestValidationFailed = new EventId(47, "RequestValidationFailed"); - public static EventId CreateDisconnectTokenError = new EventId(48, "CreateDisconnectTokenError"); + public static readonly EventId HttpSysListenerCtorError = new EventId(1, "HttpSysListenerCtorError"); + public static readonly EventId BindingToDefault = new EventId(2, "BindingToDefault"); + public static readonly EventId ClearedPrefixes = new EventId(3, "ClearedPrefixes"); + public static readonly EventId AcceptErrorStopping = new EventId(4, "AcceptErrorStopping"); + public static readonly EventId AcceptError = new EventId(5, "AcceptError"); + public static readonly EventId RequestProcessError = new EventId(6, "RequestProcessError"); + public static readonly EventId RequestsDrained = new EventId(7, "RequestsDrained"); + public static readonly EventId StopCancelled = new EventId(8, "StopCancelled"); + public static readonly EventId WaitingForRequestsToDrain = new EventId(9, "WaitingForRequestsToDrain"); + public static readonly EventId DisconnectRegistrationError = new EventId(10, "DisconnectRegistrationError"); + public static readonly EventId RegisterDisconnectListener = new EventId(11, "RegisterDisconnectListener"); + public static readonly EventId UnknownDisconnectError = new EventId(12, "UnknownDisconnectError"); + public static readonly EventId DisconnectHandlerError = new EventId(13, "DisconnectHandlerError"); + public static readonly EventId ListenerStarting = new EventId(14, "ListenerStarting"); + public static readonly EventId ListenerDisposeError = new EventId(15, "ListenerDisposeError"); + public static readonly EventId RequestListenerProcessError = new EventId(16, "RequestListenerProcessError"); + public static readonly EventId AttachedToQueue = new EventId(17, "AttachedToQueue"); + public static readonly EventId SetUrlPropertyError = new EventId(18, "SetUrlPropertyError"); + public static readonly EventId RegisteringPrefix = new EventId(19, "RegisteringPrefix"); + public static readonly EventId UnregisteringPrefix = new EventId(20, "UnregisteringPrefix"); + public static readonly EventId CloseUrlGroupError = new EventId(21, "CloseUrlGroupError"); + public static readonly EventId ChannelBindingUnsupported = new EventId(22, "ChannelBindingUnSupported"); + public static readonly EventId ChannelBindingMissing = new EventId(23, "ChannelBindingMissing"); + public static readonly EventId RequestError = new EventId(24, "RequestError"); + public static readonly EventId ErrorInReadingCertificate = new EventId(25, "ErrorInReadingCertificate"); + public static readonly EventId ChannelBindingNeedsHttps = new EventId(26, "ChannelBindingNeedsHttps"); + public static readonly EventId ChannelBindingRetrieved = new EventId(27, "ChannelBindingRetrived"); + public static readonly EventId AbortError = new EventId(28, "AbortError"); + public static readonly EventId ErrorWhileRead = new EventId(29, "ErrorWhileRead"); + public static readonly EventId ErrorWhenReadBegun = new EventId(30, "ErrorWhenReadBegun"); + public static readonly EventId ErrorWhenReadAsync = new EventId(31, "ErrorWhenReadAsync"); + public static readonly EventId ErrorWhenFlushAsync = new EventId(32, "ErrorWhenFlushAsync"); + public static readonly EventId FewerBytesThanExpected = new EventId(33, "FewerBytesThanExpected"); + public static readonly EventId WriteError = new EventId(34, "WriteError"); + public static readonly EventId WriteErrorIgnored = new EventId(35, "WriteFlushedIgnored"); + public static readonly EventId WriteFlushCancelled = new EventId(36, "WriteFlushCancelled"); + public static readonly EventId ClearedAddresses = new EventId(37, "ClearedAddresses"); + public static readonly EventId FileSendAsyncError = new EventId(38, "FileSendAsyncError"); + public static readonly EventId FileSendAsyncCancelled = new EventId(39, "FileSendAsyncCancelled"); + public static readonly EventId FileSendAsyncErrorIgnored = new EventId(40, "FileSendAsyncErrorIgnored"); + public static readonly EventId WriteCancelled = new EventId(41, "WriteCancelled"); + public static readonly EventId ListenerStopping = new EventId(42, "ListenerStopping"); + public static readonly EventId ListenerStartError = new EventId(43, "ListenerStartError"); + public static readonly EventId DisconnectTriggered = new EventId(44, "DisconnectTriggered"); + public static readonly EventId ListenerStopError = new EventId(45, "ListenerStopError"); + public static readonly EventId ListenerDisposing = new EventId(46, "ListenerDisposing"); + public static readonly EventId RequestValidationFailed = new EventId(47, "RequestValidationFailed"); + public static readonly EventId CreateDisconnectTokenError = new EventId(48, "CreateDisconnectTokenError"); } } diff --git a/src/Servers/HttpSys/src/MessagePump.Log.cs b/src/Servers/HttpSys/src/MessagePump.Log.cs index e5e06b42286f..673431bb3a59 100644 --- a/src/Servers/HttpSys/src/MessagePump.Log.cs +++ b/src/Servers/HttpSys/src/MessagePump.Log.cs @@ -23,10 +23,10 @@ private static class Log LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.BindingToDefault, $"No listening endpoints were configured. Binding to {Constants.DefaultServerAddress} by default."); private static readonly Action _clearedAddresses = - LoggerMessage.Define(LogLevel.Warning, LoggerEventIds.ClearedAddresses, $"Overriding address(es) '{{ServerAddresses)}}'. Binding to endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} instead."); + LoggerMessage.Define(LogLevel.Warning, LoggerEventIds.ClearedAddresses, $"Overriding address(es) '{{ServerAddresses)}}'. Binding to endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} instead.", skipEnabledCheck: true); private static readonly Action _clearedPrefixes = - LoggerMessage.Define(LogLevel.Warning, LoggerEventIds.ClearedPrefixes, $"Overriding endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} since {nameof(IServerAddressesFeature.PreferHostingUrls)} is set to true. Binding to address(es) '{{ServerAddresses}}' instead. "); + LoggerMessage.Define(LogLevel.Warning, LoggerEventIds.ClearedPrefixes, $"Overriding endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} since {nameof(IServerAddressesFeature.PreferHostingUrls)} is set to true. Binding to address(es) '{{ServerAddresses}}' instead.", skipEnabledCheck: true); private static readonly Action _requestListenerProcessError = LoggerMessage.Define(LogLevel.Error, LoggerEventIds.RequestListenerProcessError, "ProcessRequestAsync"); diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelTrace.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelTrace.cs index e814d8e58551..abb064a320bc 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelTrace.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelTrace.cs @@ -59,10 +59,10 @@ internal class KestrelTrace : IKestrelTrace LoggerMessage.Define(LogLevel.Warning, new EventId(24, "ConnectionRejected"), @"Connection id ""{ConnectionId}"" rejected because the maximum number of concurrent connections has been reached."); private static readonly Action _requestBodyStart = - LoggerMessage.Define(LogLevel.Debug, new EventId(25, "RequestBodyStart"), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": started reading request body."); + LoggerMessage.Define(LogLevel.Debug, new EventId(25, "RequestBodyStart"), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": started reading request body.", skipEnabledCheck: true); private static readonly Action _requestBodyDone = - LoggerMessage.Define(LogLevel.Debug, new EventId(26, "RequestBodyDone"), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": done reading request body."); + LoggerMessage.Define(LogLevel.Debug, new EventId(26, "RequestBodyDone"), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": done reading request body.", skipEnabledCheck: true); private static readonly Action _requestBodyMinimumDataRateNotSatisfied = LoggerMessage.Define(LogLevel.Debug, new EventId(27, "RequestBodyMinimumDataRateNotSatisfied"), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": the request timed out because it was not sent by the client at a minimum of {Rate} bytes/second."); @@ -102,11 +102,13 @@ internal class KestrelTrace : IKestrelTrace private static readonly Action _http2FrameReceived = LoggerMessage.Define(LogLevel.Trace, new EventId(37, "Http2FrameReceived"), - @"Connection id ""{ConnectionId}"" received {type} frame for stream ID {id} with length {length} and flags {flags}."); + @"Connection id ""{ConnectionId}"" received {type} frame for stream ID {id} with length {length} and flags {flags}.", + skipEnabledCheck: true); private static readonly Action _http2FrameSending = LoggerMessage.Define(LogLevel.Trace, new EventId(49, "Http2FrameSending"), - @"Connection id ""{ConnectionId}"" sending {type} frame for stream ID {id} with length {length} and flags {flags}."); + @"Connection id ""{ConnectionId}"" sending {type} frame for stream ID {id} with length {length} and flags {flags}.", + skipEnabledCheck: true); private static readonly Action _hpackEncodingError = LoggerMessage.Define(LogLevel.Information, new EventId(38, "HPackEncodingError"), @@ -136,15 +138,18 @@ internal class KestrelTrace : IKestrelTrace private static readonly Action _http3StreamAbort = LoggerMessage.Define(LogLevel.Debug, new EventId(45, "Http3StreamAbort"), - @"Trace id ""{TraceIdentifier}"": HTTP/3 stream error ""{error}"". An abort is being sent to the stream."); + @"Trace id ""{TraceIdentifier}"": HTTP/3 stream error ""{error}"". An abort is being sent to the stream.", + skipEnabledCheck: true); private static readonly Action _http3FrameReceived = LoggerMessage.Define(LogLevel.Trace, new EventId(46, "Http3FrameReceived"), - @"Connection id ""{ConnectionId}"" received {type} frame for stream ID {id} with length {length}."); + @"Connection id ""{ConnectionId}"" received {type} frame for stream ID {id} with length {length}.", + skipEnabledCheck: true); private static readonly Action _http3FrameSending = LoggerMessage.Define(LogLevel.Trace, new EventId(47, "Http3FrameSending"), - @"Connection id ""{ConnectionId}"" sending {type} frame for stream ID {id} with length {length}."); + @"Connection id ""{ConnectionId}"" sending {type} frame for stream ID {id} with length {length}.", + skipEnabledCheck: true); protected readonly ILogger _logger; diff --git a/src/Servers/Kestrel/Transport.Quic/src/Internal/IQuicTrace.cs b/src/Servers/Kestrel/Transport.Quic/src/Internal/IQuicTrace.cs index 8657b5e59dac..17d4238dc737 100644 --- a/src/Servers/Kestrel/Transport.Quic/src/Internal/IQuicTrace.cs +++ b/src/Servers/Kestrel/Transport.Quic/src/Internal/IQuicTrace.cs @@ -2,19 +2,20 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; +using Microsoft.AspNetCore.Connections; using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Experimental.Quic.Internal { internal interface IQuicTrace : ILogger { - void AcceptedConnection(string connectionId); - void AcceptedStream(string streamId); - void ConnectionError(string connectionId, Exception ex); - void StreamError(string streamId, Exception ex); - void StreamPause(string streamId); - void StreamResume(string streamId); - void StreamShutdownWrite(string streamId, string reason); - void StreamAbort(string streamId, string reason); + void AcceptedConnection(BaseConnectionContext connection); + void AcceptedStream(QuicStreamContext streamContext); + void ConnectionError(BaseConnectionContext connection, Exception ex); + void StreamError(QuicStreamContext streamContext, Exception ex); + void StreamPause(QuicStreamContext streamContext); + void StreamResume(QuicStreamContext streamContext); + void StreamShutdownWrite(QuicStreamContext streamContext, string reason); + void StreamAbort(QuicStreamContext streamContext, string reason); } } diff --git a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicConnectionContext.cs b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicConnectionContext.cs index 4c73ad4084be..dc8a25b02e98 100644 --- a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicConnectionContext.cs +++ b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicConnectionContext.cs @@ -32,7 +32,7 @@ public QuicConnectionContext(QuicConnection connection, QuicTransportContext con Features.Set(new FakeTlsConnectionFeature()); Features.Set(this); - _log.AcceptedConnection(ConnectionId); + _log.AcceptedConnection(this); } public ValueTask StartUnidirectionalStreamAsync() diff --git a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicStreamContext.cs b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicStreamContext.cs index eb0525b2c4e5..8b22fc8c85c9 100644 --- a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicStreamContext.cs +++ b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicStreamContext.cs @@ -70,28 +70,12 @@ public QuicStreamContext(QuicStream stream, QuicConnectionContext connection, Qu public bool CanRead { get; } public bool CanWrite { get; } - public long StreamId - { - get - { - return _stream.StreamId; - } - } + public long StreamId => _stream.StreamId; public override string ConnectionId { - get - { - if (_connectionId == null) - { - _connectionId = $"{_connection.ConnectionId}:{StreamId}"; - } - return _connectionId; - } - set - { - _connectionId = value; - } + get => _connectionId ??= $"{_connection.ConnectionId}:{StreamId}"; + set => _connectionId = value; } public long Error { get; set; } @@ -147,7 +131,7 @@ private async Task DoReceive() { // This is unexpected. error = ex; - _log.StreamError(ConnectionId, error); + _log.StreamError(this, error); } finally { @@ -182,14 +166,14 @@ private async Task ProcessReceives() if (paused) { - _log.StreamPause(ConnectionId); + _log.StreamPause(this); } var result = await flushTask; if (paused) { - _log.StreamResume(ConnectionId); + _log.StreamResume(this); } if (result.IsCompleted || result.IsCanceled) @@ -250,7 +234,7 @@ private async Task DoSend() { shutdownReason = ex; unexpectedError = ex; - _log.ConnectionError(ConnectionId, unexpectedError); + _log.ConnectionError(this, unexpectedError); } finally { @@ -307,7 +291,7 @@ public override void Abort(ConnectionAbortedException abortReason) _aborted = true; - _log.StreamAbort(ConnectionId, abortReason.Message); + _log.StreamAbort(this, abortReason.Message); lock (_shutdownLock) { @@ -327,8 +311,8 @@ private async ValueTask ShutdownWrite(Exception? shutdownReason) { // TODO: Exception is always allocated. Consider only allocating if receive hasn't completed. _shutdownReason = shutdownReason ?? new ConnectionAbortedException("The Quic transport's send loop completed gracefully."); + _log.StreamShutdownWrite(this, _shutdownReason.Message); - _log.StreamShutdownWrite(ConnectionId, _shutdownReason.Message); _stream.Shutdown(); } diff --git a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicTrace.cs b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicTrace.cs index cf15ab090f31..4a071e232ab7 100644 --- a/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicTrace.cs +++ b/src/Servers/Kestrel/Transport.Quic/src/Internal/QuicTrace.cs @@ -2,6 +2,7 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; +using Microsoft.AspNetCore.Connections; using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Experimental.Quic.Internal @@ -9,21 +10,21 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Experimental.Quic.Intern internal class QuicTrace : IQuicTrace { private static readonly Action _acceptedConnection = - LoggerMessage.Define(LogLevel.Debug, new EventId(1, "AcceptedConnection"), @"Connection id ""{ConnectionId}"" accepted."); + LoggerMessage.Define(LogLevel.Debug, new EventId(1, "AcceptedConnection"), @"Connection id ""{ConnectionId}"" accepted.", skipEnabledCheck: true); private static readonly Action _acceptedStream = - LoggerMessage.Define(LogLevel.Debug, new EventId(2, "AcceptedStream"), @"Stream id ""{ConnectionId}"" accepted."); + LoggerMessage.Define(LogLevel.Debug, new EventId(2, "AcceptedStream"), @"Stream id ""{ConnectionId}"" accepted.", skipEnabledCheck: true); private static readonly Action _connectionError = - LoggerMessage.Define(LogLevel.Debug, new EventId(3, "ConnectionError"), @"Connection id ""{ConnectionId}"" unexpected error."); + LoggerMessage.Define(LogLevel.Debug, new EventId(3, "ConnectionError"), @"Connection id ""{ConnectionId}"" unexpected error.", skipEnabledCheck: true); private static readonly Action _streamError = - LoggerMessage.Define(LogLevel.Debug, new EventId(4, "StreamError"), @"Stream id ""{ConnectionId}"" unexpected error."); + LoggerMessage.Define(LogLevel.Debug, new EventId(4, "StreamError"), @"Stream id ""{ConnectionId}"" unexpected error.", skipEnabledCheck: true); private static readonly Action _streamPause = - LoggerMessage.Define(LogLevel.Debug, new EventId(5, "StreamPause"), @"Stream id ""{ConnectionId}"" paused."); + LoggerMessage.Define(LogLevel.Debug, new EventId(5, "StreamPause"), @"Stream id ""{ConnectionId}"" paused.", skipEnabledCheck: true); private static readonly Action _streamResume = - LoggerMessage.Define(LogLevel.Debug, new EventId(6, "StreamResume"), @"Stream id ""{ConnectionId}"" resumed."); + LoggerMessage.Define(LogLevel.Debug, new EventId(6, "StreamResume"), @"Stream id ""{ConnectionId}"" resumed.", skipEnabledCheck: true); private static readonly Action _streamShutdownWrite = - LoggerMessage.Define(LogLevel.Debug, new EventId(7, "StreamShutdownWrite"), @"Stream id ""{ConnectionId}"" shutting down writes because: ""{Reason}""."); + LoggerMessage.Define(LogLevel.Debug, new EventId(7, "StreamShutdownWrite"), @"Stream id ""{ConnectionId}"" shutting down writes because: ""{Reason}"".", skipEnabledCheck: true); private static readonly Action _streamAborted = - LoggerMessage.Define(LogLevel.Debug, new EventId(8, "StreamAbort"), @"Stream id ""{ConnectionId}"" aborted by application because: ""{Reason}""."); + LoggerMessage.Define(LogLevel.Debug, new EventId(8, "StreamAbort"), @"Stream id ""{ConnectionId}"" aborted by application because: ""{Reason}"".", skipEnabledCheck: true); private ILogger _logger; @@ -39,44 +40,68 @@ public QuicTrace(ILogger logger) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) => _logger.Log(logLevel, eventId, state, exception, formatter); - public void AcceptedConnection(string connectionId) + public void AcceptedConnection(BaseConnectionContext connection) { - _acceptedConnection(_logger, connectionId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _acceptedConnection(_logger, connection.ConnectionId, null); + } } - public void AcceptedStream(string streamId) + public void AcceptedStream(QuicStreamContext streamContext) { - _acceptedStream(_logger, streamId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _acceptedStream(_logger, streamContext.ConnectionId, null); + } } - public void ConnectionError(string connectionId, Exception ex) + public void ConnectionError(BaseConnectionContext connection, Exception ex) { - _connectionError(_logger, connectionId, ex); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionError(_logger, connection.ConnectionId, ex); + } } - public void StreamError(string streamId, Exception ex) + public void StreamError(QuicStreamContext streamContext, Exception ex) { - _streamError(_logger, streamId, ex); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _streamError(_logger, streamContext.ConnectionId, ex); + } } - public void StreamPause(string streamId) + public void StreamPause(QuicStreamContext streamContext) { - _streamPause(_logger, streamId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _streamPause(_logger, streamContext.ConnectionId, null); + } } - public void StreamResume(string streamId) + public void StreamResume(QuicStreamContext streamContext) { - _streamResume(_logger, streamId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _streamResume(_logger, streamContext.ConnectionId, null); + } } - public void StreamShutdownWrite(string streamId, string reason) + public void StreamShutdownWrite(QuicStreamContext streamContext, string reason) { - _streamShutdownWrite(_logger, streamId, reason, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _streamShutdownWrite(_logger, streamContext.ConnectionId, reason, null); + } } - public void StreamAbort(string streamId, string reason) + public void StreamAbort(QuicStreamContext streamContext, string reason) { - _streamAborted(_logger, streamId, reason, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _streamAborted(_logger, streamContext.ConnectionId, reason, null); + } } } } diff --git a/src/Servers/Kestrel/Transport.Sockets/src/Internal/ISocketsTrace.cs b/src/Servers/Kestrel/Transport.Sockets/src/Internal/ISocketsTrace.cs index 38fa46104ac6..13ec2f1fcab5 100644 --- a/src/Servers/Kestrel/Transport.Sockets/src/Internal/ISocketsTrace.cs +++ b/src/Servers/Kestrel/Transport.Sockets/src/Internal/ISocketsTrace.cs @@ -8,16 +8,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal { internal interface ISocketsTrace : ILogger { - void ConnectionReadFin(string connectionId); + void ConnectionReadFin(SocketConnection connection); - void ConnectionWriteFin(string connectionId, string reason); + void ConnectionWriteFin(SocketConnection connection, string reason); - void ConnectionError(string connectionId, Exception ex); + void ConnectionError(SocketConnection connection, Exception ex); void ConnectionReset(string connectionId); + void ConnectionReset(SocketConnection connection); - void ConnectionPause(string connectionId); + void ConnectionPause(SocketConnection connection); - void ConnectionResume(string connectionId); + void ConnectionResume(SocketConnection connection); } } diff --git a/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketConnection.cs b/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketConnection.cs index d72ccc50f7a2..49f6c24f6446 100644 --- a/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketConnection.cs +++ b/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketConnection.cs @@ -156,7 +156,7 @@ private async Task DoReceive() if (bytesReceived == 0) { // FIN - _trace.ConnectionReadFin(ConnectionId); + _trace.ConnectionReadFin(this); break; } @@ -168,14 +168,14 @@ private async Task DoReceive() if (paused) { - _trace.ConnectionPause(ConnectionId); + _trace.ConnectionPause(this); } var result = await flushTask; if (paused) { - _trace.ConnectionResume(ConnectionId); + _trace.ConnectionResume(this); } if (result.IsCompleted || result.IsCanceled) @@ -194,7 +194,7 @@ private async Task DoReceive() // Both logs will have the same ConnectionId. I don't think it's worthwhile to lock just to avoid this. if (!_socketDisposed) { - _trace.ConnectionReset(ConnectionId); + _trace.ConnectionReset(this); } } catch (Exception ex) @@ -207,14 +207,14 @@ private async Task DoReceive() if (!_socketDisposed) { // This is unexpected if the socket hasn't been disposed yet. - _trace.ConnectionError(ConnectionId, error); + _trace.ConnectionError(this, error); } } catch (Exception ex) { // This is unexpected. error = ex; - _trace.ConnectionError(ConnectionId, error); + _trace.ConnectionError(this, error); } finally { @@ -265,7 +265,7 @@ private async Task DoSend() catch (SocketException ex) when (IsConnectionResetError(ex.SocketErrorCode)) { shutdownReason = new ConnectionResetException(ex.Message, ex); - _trace.ConnectionReset(ConnectionId); + _trace.ConnectionReset(this); } catch (Exception ex) when ((ex is SocketException socketEx && IsConnectionAbortError(socketEx.SocketErrorCode)) || @@ -278,7 +278,7 @@ private async Task DoSend() { shutdownReason = ex; unexpectedError = ex; - _trace.ConnectionError(ConnectionId, unexpectedError); + _trace.ConnectionError(this, unexpectedError); } finally { @@ -330,8 +330,7 @@ private void Shutdown(Exception? shutdownReason) // ever observe the nondescript ConnectionAbortedException except for connection middleware attempting // to half close the connection which is currently unsupported. _shutdownReason = shutdownReason ?? new ConnectionAbortedException("The Socket transport's send loop completed gracefully."); - - _trace.ConnectionWriteFin(ConnectionId, _shutdownReason.Message); + _trace.ConnectionWriteFin(this, _shutdownReason.Message); try { diff --git a/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketsTrace.cs b/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketsTrace.cs index 78b28e1d4892..ac97800fe82b 100644 --- a/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketsTrace.cs +++ b/src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketsTrace.cs @@ -11,26 +11,26 @@ internal class SocketsTrace : ISocketsTrace // ConnectionRead: Reserved: 3 private static readonly Action _connectionPause = - LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ConnectionPause"), @"Connection id ""{ConnectionId}"" paused."); + LoggerMessage.Define(LogLevel.Debug, new EventId(4, "ConnectionPause"), @"Connection id ""{ConnectionId}"" paused.", skipEnabledCheck: true); private static readonly Action _connectionResume = - LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ConnectionResume"), @"Connection id ""{ConnectionId}"" resumed."); + LoggerMessage.Define(LogLevel.Debug, new EventId(5, "ConnectionResume"), @"Connection id ""{ConnectionId}"" resumed.", skipEnabledCheck: true); private static readonly Action _connectionReadFin = - LoggerMessage.Define(LogLevel.Debug, new EventId(6, "ConnectionReadFin"), @"Connection id ""{ConnectionId}"" received FIN."); + LoggerMessage.Define(LogLevel.Debug, new EventId(6, "ConnectionReadFin"), @"Connection id ""{ConnectionId}"" received FIN.", skipEnabledCheck: true); private static readonly Action _connectionWriteFin = - LoggerMessage.Define(LogLevel.Debug, new EventId(7, "ConnectionWriteFin"), @"Connection id ""{ConnectionId}"" sending FIN because: ""{Reason}"""); + LoggerMessage.Define(LogLevel.Debug, new EventId(7, "ConnectionWriteFin"), @"Connection id ""{ConnectionId}"" sending FIN because: ""{Reason}""", skipEnabledCheck: true); // ConnectionWrite: Reserved: 11 // ConnectionWriteCallback: Reserved: 12 private static readonly Action _connectionError = - LoggerMessage.Define(LogLevel.Debug, new EventId(14, "ConnectionError"), @"Connection id ""{ConnectionId}"" communication error."); + LoggerMessage.Define(LogLevel.Debug, new EventId(14, "ConnectionError"), @"Connection id ""{ConnectionId}"" communication error.", skipEnabledCheck: true); private static readonly Action _connectionReset = - LoggerMessage.Define(LogLevel.Debug, new EventId(19, "ConnectionReset"), @"Connection id ""{ConnectionId}"" reset."); + LoggerMessage.Define(LogLevel.Debug, new EventId(19, "ConnectionReset"), @"Connection id ""{ConnectionId}"" reset.", skipEnabledCheck: true); private readonly ILogger _logger; @@ -39,37 +39,46 @@ public SocketsTrace(ILogger logger) _logger = logger; } - public void ConnectionRead(string connectionId, int count) + public void ConnectionRead(SocketConnection connection, int count) { // Don't log for now since this could be *too* verbose. // Reserved: Event ID 3 } - public void ConnectionReadFin(string connectionId) + public void ConnectionReadFin(SocketConnection connection) { - _connectionReadFin(_logger, connectionId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionReadFin(_logger, connection.ConnectionId, null); + } } - public void ConnectionWriteFin(string connectionId, string reason) + public void ConnectionWriteFin(SocketConnection connection, string reason) { - _connectionWriteFin(_logger, connectionId, reason, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionWriteFin(_logger, connection.ConnectionId, reason, null); + } } - public void ConnectionWrite(string connectionId, int count) + public void ConnectionWrite(SocketConnection connection, int count) { // Don't log for now since this could be *too* verbose. // Reserved: Event ID 11 } - public void ConnectionWriteCallback(string connectionId, int status) + public void ConnectionWriteCallback(SocketConnection connection, int status) { // Don't log for now since this could be *too* verbose. // Reserved: Event ID 12 } - public void ConnectionError(string connectionId, Exception ex) + public void ConnectionError(SocketConnection connection, Exception ex) { - _connectionError(_logger, connectionId, ex); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionError(_logger, connection.ConnectionId, ex); + } } public void ConnectionReset(string connectionId) @@ -77,14 +86,28 @@ public void ConnectionReset(string connectionId) _connectionReset(_logger, connectionId, null); } - public void ConnectionPause(string connectionId) + public void ConnectionReset(SocketConnection connection) { - _connectionPause(_logger, connectionId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionReset(_logger, connection.ConnectionId, null); + } } - public void ConnectionResume(string connectionId) + public void ConnectionPause(SocketConnection connection) { - _connectionResume(_logger, connectionId, null); + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionPause(_logger, connection.ConnectionId, null); + } + } + + public void ConnectionResume(SocketConnection connection) + { + if (_logger.IsEnabled(LogLevel.Debug)) + { + _connectionResume(_logger, connection.ConnectionId, null); + } } public IDisposable BeginScope(TState state) => _logger.BeginScope(state); diff --git a/src/Servers/Kestrel/shared/TransportConnection.cs b/src/Servers/Kestrel/shared/TransportConnection.cs index 8a1d2b7f16bf..217001b7c545 100644 --- a/src/Servers/Kestrel/shared/TransportConnection.cs +++ b/src/Servers/Kestrel/shared/TransportConnection.cs @@ -29,19 +29,8 @@ public TransportConnection() public override string ConnectionId { - get - { - if (_connectionId == null) - { - _connectionId = CorrelationIdGenerator.GetNextId(); - } - - return _connectionId; - } - set - { - _connectionId = value; - } + get => _connectionId ??= CorrelationIdGenerator.GetNextId(); + set => _connectionId = value; } public override IFeatureCollection Features => this; diff --git a/src/Servers/Kestrel/shared/TransportMultiplexedConnection.cs b/src/Servers/Kestrel/shared/TransportMultiplexedConnection.cs index 084ad298d848..a1990c5d46f5 100644 --- a/src/Servers/Kestrel/shared/TransportMultiplexedConnection.cs +++ b/src/Servers/Kestrel/shared/TransportMultiplexedConnection.cs @@ -26,19 +26,8 @@ public TransportMultiplexedConnection() public override string ConnectionId { - get - { - if (_connectionId == null) - { - _connectionId = CorrelationIdGenerator.GetNextId(); - } - - return _connectionId; - } - set - { - _connectionId = value; - } + get => _connectionId ??= CorrelationIdGenerator.GetNextId(); + set => _connectionId = value; } public override IFeatureCollection Features => this; diff --git a/src/SignalR/clients/csharp/Client.Core/src/HubConnection.Log.cs b/src/SignalR/clients/csharp/Client.Core/src/HubConnection.Log.cs index b6483062223b..3be7d5a44bc3 100644 --- a/src/SignalR/clients/csharp/Client.Core/src/HubConnection.Log.cs +++ b/src/SignalR/clients/csharp/Client.Core/src/HubConnection.Log.cs @@ -22,19 +22,19 @@ private static class Log LoggerMessage.Define(LogLevel.Debug, new EventId(3, "RegisteringInvocation"), "Registering Invocation ID '{InvocationId}' for tracking."); private static readonly Action _issuingInvocation = - LoggerMessage.Define(LogLevel.Trace, new EventId(4, "IssuingInvocation"), "Issuing Invocation '{InvocationId}': {ReturnType} {MethodName}({Args})."); + LoggerMessage.Define(LogLevel.Trace, new EventId(4, "IssuingInvocation"), "Issuing Invocation '{InvocationId}': {ReturnType} {MethodName}({Args}).", skipEnabledCheck: true); private static readonly Action _sendingMessage = - LoggerMessage.Define(LogLevel.Debug, new EventId(5, "SendingMessage"), "Sending {MessageType} message '{InvocationId}'."); + LoggerMessage.Define(LogLevel.Debug, new EventId(5, "SendingMessage"), "Sending {MessageType} message '{InvocationId}'.", skipEnabledCheck: true); private static readonly Action _messageSent = - LoggerMessage.Define(LogLevel.Debug, new EventId(6, "MessageSent"), "Sending {MessageType} message '{InvocationId}' completed."); + LoggerMessage.Define(LogLevel.Debug, new EventId(6, "MessageSent"), "Sending {MessageType} message '{InvocationId}' completed.", skipEnabledCheck: true); private static readonly Action _failedToSendInvocation = LoggerMessage.Define(LogLevel.Error, new EventId(7, "FailedToSendInvocation"), "Sending Invocation '{InvocationId}' failed."); private static readonly Action _receivedInvocation = - LoggerMessage.Define(LogLevel.Trace, new EventId(8, "ReceivedInvocation"), "Received Invocation '{InvocationId}': {MethodName}({Args})."); + LoggerMessage.Define(LogLevel.Trace, new EventId(8, "ReceivedInvocation"), "Received Invocation '{InvocationId}': {MethodName}({Args}).", skipEnabledCheck: true); private static readonly Action _droppedCompletionMessage = LoggerMessage.Define(LogLevel.Warning, new EventId(9, "DroppedCompletionMessage"), "Dropped unsolicited Completion message for invocation '{InvocationId}'."); @@ -142,7 +142,7 @@ private static class Log LoggerMessage.Define(LogLevel.Debug, new EventId(47, "ReceiveLoopStarting"), "Receive loop starting."); private static readonly Action _startingServerTimeoutTimer = - LoggerMessage.Define(LogLevel.Debug, new EventId(48, "StartingServerTimeoutTimer"), "Starting server timeout timer. Duration: {ServerTimeout:0.00}ms"); + LoggerMessage.Define(LogLevel.Debug, new EventId(48, "StartingServerTimeoutTimer"), "Starting server timeout timer. Duration: {ServerTimeout:0.00}ms", skipEnabledCheck: true); private static readonly Action _notUsingServerTimeout = LoggerMessage.Define(LogLevel.Debug, new EventId(49, "NotUsingServerTimeout"), "Not using server timeout because the transport inherently tracks server availability."); @@ -175,10 +175,10 @@ private static class Log LoggerMessage.Define(LogLevel.Debug, new EventId(58, "RemovingHandlers"), "Removing handlers for client method '{MethodName}'."); private static readonly Action _sendingMessageGeneric = - LoggerMessage.Define(LogLevel.Debug, new EventId(59, "SendingMessageGeneric"), "Sending {MessageType} message."); + LoggerMessage.Define(LogLevel.Debug, new EventId(59, "SendingMessageGeneric"), "Sending {MessageType} message.", skipEnabledCheck: true); private static readonly Action _messageSentGeneric = - LoggerMessage.Define(LogLevel.Debug, new EventId(60, "MessageSentGeneric"), "Sending {MessageType} message completed."); + LoggerMessage.Define(LogLevel.Debug, new EventId(60, "MessageSentGeneric"), "Sending {MessageType} message completed.", skipEnabledCheck: true); private static readonly Action _acquiredConnectionLockForPing = LoggerMessage.Define(LogLevel.Trace, new EventId(61, "AcquiredConnectionLockForPing"), "Acquired the Connection Lock in order to ping the server."); diff --git a/src/SignalR/clients/csharp/Http.Connections.Client/src/HttpConnection.Log.cs b/src/SignalR/clients/csharp/Http.Connections.Client/src/HttpConnection.Log.cs index 032057a76a2c..db1a1a560da9 100644 --- a/src/SignalR/clients/csharp/Http.Connections.Client/src/HttpConnection.Log.cs +++ b/src/SignalR/clients/csharp/Http.Connections.Client/src/HttpConnection.Log.cs @@ -30,7 +30,7 @@ private static class Log LoggerMessage.Define(LogLevel.Information, new EventId(6, "Disposed"), "HttpConnection Disposed."); private static readonly Action _startingTransport = - LoggerMessage.Define(LogLevel.Debug, new EventId(7, "StartingTransport"), "Starting transport '{Transport}' with Url: {Url}."); + LoggerMessage.Define(LogLevel.Debug, new EventId(7, "StartingTransport"), "Starting transport '{Transport}' with Url: {Url}.", skipEnabledCheck: true); private static readonly Action _establishingConnection = LoggerMessage.Define(LogLevel.Debug, new EventId(8, "EstablishingConnection"), "Establishing connection with server at '{Url}'."); @@ -48,13 +48,13 @@ private static class Log LoggerMessage.Define(LogLevel.Debug, new EventId(12, "TransportNotSupported"), "Skipping transport {TransportName} because it is not supported by this client."); private static readonly Action _transportDoesNotSupportTransferFormat = - LoggerMessage.Define(LogLevel.Debug, new EventId(13, "TransportDoesNotSupportTransferFormat"), "Skipping transport {TransportName} because it does not support the requested transfer format '{TransferFormat}'."); + LoggerMessage.Define(LogLevel.Debug, new EventId(13, "TransportDoesNotSupportTransferFormat"), "Skipping transport {TransportName} because it does not support the requested transfer format '{TransferFormat}'.", skipEnabledCheck: true); private static readonly Action _transportDisabledByClient = - LoggerMessage.Define(LogLevel.Debug, new EventId(14, "TransportDisabledByClient"), "Skipping transport {TransportName} because it was disabled by the client."); + LoggerMessage.Define(LogLevel.Debug, new EventId(14, "TransportDisabledByClient"), "Skipping transport {TransportName} because it was disabled by the client.", skipEnabledCheck: true); private static readonly Action _transportFailed = - LoggerMessage.Define(LogLevel.Debug, new EventId(15, "TransportFailed"), "Skipping transport {TransportName} because it failed to initialize."); + LoggerMessage.Define(LogLevel.Debug, new EventId(15, "TransportFailed"), "Skipping transport {TransportName} because it failed to initialize.", skipEnabledCheck: true); private static readonly Action _webSocketsNotSupportedByOperatingSystem = LoggerMessage.Define(LogLevel.Debug, new EventId(16, "WebSocketsNotSupportedByOperatingSystem"), "Skipping WebSockets because they are not supported by the operating system."); diff --git a/src/SignalR/clients/csharp/Http.Connections.Client/src/Internal/LongPollingTransport.Log.cs b/src/SignalR/clients/csharp/Http.Connections.Client/src/Internal/LongPollingTransport.Log.cs index 0193ddba2299..86fcdc2f9ddb 100644 --- a/src/SignalR/clients/csharp/Http.Connections.Client/src/Internal/LongPollingTransport.Log.cs +++ b/src/SignalR/clients/csharp/Http.Connections.Client/src/Internal/LongPollingTransport.Log.cs @@ -42,7 +42,8 @@ private static class Log // long? does properly format as "(null)" when null. private static readonly Action _pollResponseReceived = LoggerMessage.Define(LogLevel.Trace, new EventId(10, "PollResponseReceived"), - "Poll response with status code {StatusCode} received from server. Content length: {ContentLength}."); + "Poll response with status code {StatusCode} received from server. Content length: {ContentLength}.", + skipEnabledCheck: true); private static readonly Action _sendingDeleteRequest = LoggerMessage.Define(LogLevel.Debug, new EventId(11, "SendingDeleteRequest"), "Sending DELETE request to '{PollUrl}'."); diff --git a/src/SignalR/server/Core/src/Internal/DefaultHubDispatcherLog.cs b/src/SignalR/server/Core/src/Internal/DefaultHubDispatcherLog.cs index 2ce3d89a5f65..464748039b44 100644 --- a/src/SignalR/server/Core/src/Internal/DefaultHubDispatcherLog.cs +++ b/src/SignalR/server/Core/src/Internal/DefaultHubDispatcherLog.cs @@ -28,7 +28,7 @@ internal static class DefaultHubDispatcherLog LoggerMessage.Define(LogLevel.Trace, new EventId(6, "StreamingResult"), "InvocationId {InvocationId}: Streaming result of type '{ResultType}'."); private static readonly Action _sendingResult = - LoggerMessage.Define(LogLevel.Trace, new EventId(7, "SendingResult"), "InvocationId {InvocationId}: Sending result of type '{ResultType}'."); + LoggerMessage.Define(LogLevel.Trace, new EventId(7, "SendingResult"), "InvocationId {InvocationId}: Sending result of type '{ResultType}'.", skipEnabledCheck: true); private static readonly Action _failedInvokingHubMethod = LoggerMessage.Define(LogLevel.Error, new EventId(8, "FailedInvokingHubMethod"), "Failed to invoke hub method '{HubMethod}'."); diff --git a/src/SignalR/server/StackExchangeRedis/src/Internal/RedisLog.cs b/src/SignalR/server/StackExchangeRedis/src/Internal/RedisLog.cs index f2cedee09326..451087d0a9b1 100644 --- a/src/SignalR/server/StackExchangeRedis/src/Internal/RedisLog.cs +++ b/src/SignalR/server/StackExchangeRedis/src/Internal/RedisLog.cs @@ -13,7 +13,7 @@ namespace Microsoft.AspNetCore.SignalR.StackExchangeRedis.Internal internal static class RedisLog { private static readonly Action _connectingToEndpoints = - LoggerMessage.Define(LogLevel.Information, new EventId(1, "ConnectingToEndpoints"), "Connecting to Redis endpoints: {Endpoints}. Using Server Name: {ServerName}"); + LoggerMessage.Define(LogLevel.Information, new EventId(1, "ConnectingToEndpoints"), "Connecting to Redis endpoints: {Endpoints}. Using Server Name: {ServerName}", skipEnabledCheck: true); private static readonly Action _connected = LoggerMessage.Define(LogLevel.Information, new EventId(2, "Connected"), "Connected to Redis."); @@ -47,12 +47,9 @@ internal static class RedisLog public static void ConnectingToEndpoints(ILogger logger, EndPointCollection endpoints, string serverName) { - if (logger.IsEnabled(LogLevel.Information)) + if (logger.IsEnabled(LogLevel.Information) && endpoints.Count > 0) { - if (endpoints.Count > 0) - { - _connectingToEndpoints(logger, string.Join(", ", endpoints.Select(e => EndPointCollection.ToString(e))), serverName, null); - } + _connectingToEndpoints(logger, string.Join(", ", endpoints.Select(e => EndPointCollection.ToString(e))), serverName, null); } }