diff --git a/src/Servers/HttpSys/src/HttpSysListener.Log.cs b/src/Servers/HttpSys/src/HttpSysListener.Log.cs new file mode 100644 index 000000000000..82c9ab05ef43 --- /dev/null +++ b/src/Servers/HttpSys/src/HttpSysListener.Log.cs @@ -0,0 +1,78 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class HttpSysListener + { + private static class Log + { + private static readonly Action _listenerDisposeError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ListenerDisposeError, "Dispose"); + + private static readonly Action _listenerDisposing = + LoggerMessage.Define(LogLevel.Trace, LoggerEventIds.ListenerDisposing, "Disposing the listener."); + + private static readonly Action _httpSysListenerCtorError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.HttpSysListenerCtorError, ".Ctor"); + + private static readonly Action _listenerStartError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ListenerStartError, "Start"); + + private static readonly Action _listenerStarting = + LoggerMessage.Define(LogLevel.Trace, LoggerEventIds.ListenerStarting, "Starting the listener."); + + private static readonly Action _listenerStopError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ListenerStopError, "Stop"); + + private static readonly Action _listenerStopping = + LoggerMessage.Define(LogLevel.Trace, LoggerEventIds.ListenerStopping, "Stopping the listener."); + + private static readonly Action _requestValidationFailed = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.RequestValidationFailed, "Error validating request {RequestId}"); + + public static void ListenerDisposeError(ILogger logger, Exception exception) + { + _listenerDisposeError(logger, exception); + } + + public static void ListenerDisposing(ILogger logger) + { + _listenerDisposing(logger, null); + } + + public static void HttpSysListenerCtorError(ILogger logger, Exception exception) + { + _httpSysListenerCtorError(logger, exception); + } + + public static void ListenerStartError(ILogger logger, Exception exception) + { + _listenerStartError(logger, exception); + } + + public static void ListenerStarting(ILogger logger) + { + _listenerStarting(logger, null); + } + + public static void ListenerStopError(ILogger logger, Exception exception) + { + _listenerStopError(logger, exception); + } + + public static void ListenerStopping(ILogger logger) + { + _listenerStopping(logger, null); + } + + public static void RequestValidationFailed(ILogger logger, Exception exception, ulong requestId) + { + _requestValidationFailed(logger, requestId, exception); + } + } + } +} diff --git a/src/Servers/HttpSys/src/HttpSysListener.cs b/src/Servers/HttpSys/src/HttpSysListener.cs index a9a8fd9fdc61..ec3a8d5d314b 100644 --- a/src/Servers/HttpSys/src/HttpSysListener.cs +++ b/src/Servers/HttpSys/src/HttpSysListener.cs @@ -16,7 +16,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys /// /// An HTTP server wrapping the Http.Sys APIs that accepts requests. /// - internal class HttpSysListener : IDisposable + internal partial class HttpSysListener : IDisposable { // Win8# 559317 fixed a bug in Http.sys's HttpReceiveClientCertificate method. // Without this fix IOCP callbacks were not being called although ERROR_IO_PENDING was @@ -92,7 +92,7 @@ public HttpSysListener(HttpSysOptions options, ILoggerFactory loggerFactory) _requestQueue?.Dispose(); _urlGroup?.Dispose(); _serverSession?.Dispose(); - Logger.LogError(LoggerEventIds.HttpSysListenerCtorError, exception, ".Ctor"); + Log.HttpSysListenerCtorError(Logger, exception); throw; } } @@ -135,7 +135,7 @@ public void Start() { CheckDisposed(); - Logger.LogTrace(LoggerEventIds.ListenerStarting, "Starting the listener."); + Log.ListenerStarting(Logger); // Make sure there are no race conditions between Start/Stop/Abort/Close/Dispose. // Start needs to setup all resources. Abort/Stop must not interfere while Start is @@ -177,7 +177,7 @@ public void Start() // Make sure the HttpListener instance can't be used if Start() failed. _state = State.Disposed; DisposeInternal(); - Logger.LogError(LoggerEventIds.ListenerStartError, exception, "Start"); + Log.ListenerStartError(Logger, exception); throw; } } @@ -195,7 +195,7 @@ private void Stop() return; } - Logger.LogTrace(LoggerEventIds.ListenerStopping, "Stopping the listener."); + Log.ListenerStopping(Logger); // If this instance created the queue then remove the URL prefixes before shutting down. if (_requestQueue.Created) @@ -210,7 +210,7 @@ private void Stop() } catch (Exception exception) { - Logger.LogError(LoggerEventIds.ListenerStopError, exception, "Stop"); + Log.ListenerStopError(Logger, exception); throw; } } @@ -238,14 +238,14 @@ private void Dispose(bool disposing) { return; } - Logger.LogTrace(LoggerEventIds.ListenerDisposing, "Disposing the listener."); + Log.ListenerDisposing(Logger); Stop(); DisposeInternal(); } catch (Exception exception) { - Logger.LogError(LoggerEventIds.ListenerDisposeError, exception, "Dispose"); + Log.ListenerDisposeError(Logger, exception); throw; } finally @@ -305,7 +305,7 @@ internal bool ValidateRequest(NativeRequestContext requestMemory) } catch (Exception ex) { - Logger.LogError(LoggerEventIds.RequestValidationFailed, ex, "Error validating request {RequestId}", requestMemory.RequestId); + Log.RequestValidationFailed(Logger, ex, requestMemory.RequestId); return false; } diff --git a/src/Servers/HttpSys/src/LoggerEventIds.cs b/src/Servers/HttpSys/src/LoggerEventIds.cs index 1b66eb889222..883997c0e54a 100644 --- a/src/Servers/HttpSys/src/LoggerEventIds.cs +++ b/src/Servers/HttpSys/src/LoggerEventIds.cs @@ -25,12 +25,12 @@ internal static class LoggerEventIds 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 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 ChannelBindingRetrived = new EventId(27, "ChannelBindingRetrived"); + 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"); @@ -51,5 +51,6 @@ internal static class LoggerEventIds 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"); } } diff --git a/src/Servers/HttpSys/src/MessagePump.Log.cs b/src/Servers/HttpSys/src/MessagePump.Log.cs new file mode 100644 index 000000000000..e5e06b42286f --- /dev/null +++ b/src/Servers/HttpSys/src/MessagePump.Log.cs @@ -0,0 +1,87 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.AspNetCore.Hosting.Server.Features; +using Microsoft.AspNetCore.HttpSys.Internal; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class MessagePump + { + private static class Log + { + private static readonly Action _acceptError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.AcceptError, "Failed to accept a request."); + + private static readonly Action _acceptErrorStopping = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.AcceptErrorStopping, "Failed to accept a request, the server is stopping."); + + private static readonly Action _bindingToDefault = + 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."); + + 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. "); + + private static readonly Action _requestListenerProcessError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.RequestListenerProcessError, "ProcessRequestAsync"); + + private static readonly Action _stopCancelled = + LoggerMessage.Define(LogLevel.Information, LoggerEventIds.StopCancelled, "Canceled, terminating {OutstandingRequests} request(s)."); + + private static readonly Action _waitingForRequestsToDrain = + LoggerMessage.Define(LogLevel.Information, LoggerEventIds.WaitingForRequestsToDrain, "Stopping, waiting for {OutstandingRequests} request(s) to drain."); + + public static void AcceptError(ILogger logger, Exception exception) + { + _acceptError(logger, exception); + } + + public static void AcceptErrorStopping(ILogger logger, Exception exception) + { + _acceptErrorStopping(logger, exception); + } + + public static void BindingToDefault(ILogger logger) + { + _bindingToDefault(logger, null); + } + + public static void ClearedAddresses(ILogger logger, ICollection serverAddresses) + { + if (logger.IsEnabled(LogLevel.Warning)) + { + _clearedAddresses(logger, string.Join(", ", serverAddresses), null); + } + } + + public static void ClearedPrefixes(ILogger logger, ICollection serverAddresses) + { + if (logger.IsEnabled(LogLevel.Warning)) + { + _clearedPrefixes(logger, string.Join(", ", serverAddresses), null); + } + } + + public static void RequestListenerProcessError(ILogger logger, Exception exception) + { + _requestListenerProcessError(logger, exception); + } + + public static void StopCancelled(ILogger logger, int outstandingRequests) + { + _stopCancelled(logger, outstandingRequests, null); + } + + public static void WaitingForRequestsToDrain(ILogger logger, int outstandingRequests) + { + _waitingForRequestsToDrain(logger, outstandingRequests, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/MessagePump.cs b/src/Servers/HttpSys/src/MessagePump.cs index 8c0e9d2ac4f6..3e5bfa226470 100644 --- a/src/Servers/HttpSys/src/MessagePump.cs +++ b/src/Servers/HttpSys/src/MessagePump.cs @@ -17,7 +17,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys { - internal class MessagePump : IServer + internal partial class MessagePump : IServer { private readonly ILogger _logger; private readonly HttpSysOptions _options; @@ -87,8 +87,7 @@ public Task StartAsync(IHttpApplication application, Cancell { if (_options.UrlPrefixes.Count > 0) { - _logger.LogWarning(LoggerEventIds.ClearedPrefixes, $"Overriding endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} since {nameof(IServerAddressesFeature.PreferHostingUrls)} is set to true." + - $" Binding to address(es) '{string.Join(", ", _serverAddresses.Addresses)}' instead. "); + Log.ClearedPrefixes(_logger, _serverAddresses.Addresses); Listener.Options.UrlPrefixes.Clear(); } @@ -99,12 +98,10 @@ public Task StartAsync(IHttpApplication application, Cancell { if (hostingUrlsPresent) { - _logger.LogWarning(LoggerEventIds.ClearedAddresses, $"Overriding address(es) '{string.Join(", ", _serverAddresses.Addresses)}'. " + - $"Binding to endpoints added to {nameof(HttpSysOptions.UrlPrefixes)} instead."); + Log.ClearedAddresses(_logger, _serverAddresses.Addresses); _serverAddresses.Addresses.Clear(); } - } else if (hostingUrlsPresent) { @@ -112,7 +109,7 @@ public Task StartAsync(IHttpApplication application, Cancell } else if (Listener.RequestQueue.Created) { - _logger.LogDebug(LoggerEventIds.BindingToDefault, $"No listening endpoints were configured. Binding to {Constants.DefaultServerAddress} by default."); + Log.BindingToDefault(_logger); Listener.Options.UrlPrefixes.Add(Constants.DefaultServerAddress); } @@ -207,11 +204,11 @@ private async Task ProcessRequestsWorker() Debug.Assert(Stopping); if (Stopping) { - _logger.LogDebug(LoggerEventIds.AcceptErrorStopping, exception, "Failed to accept a request, the server is stopping."); + Log.AcceptErrorStopping(_logger, exception); } else { - _logger.LogError(LoggerEventIds.AcceptError, exception, "Failed to accept a request."); + Log.AcceptError(_logger, exception); } continue; } @@ -223,7 +220,7 @@ private async Task ProcessRequestsWorker() { // Request processing failed to be queued in threadpool // Log the error message, release throttle and move on - _logger.LogError(LoggerEventIds.RequestListenerProcessError, ex, "ProcessRequestAsync"); + Log.RequestListenerProcessError(_logger, ex); } } Interlocked.Decrement(ref _acceptorCounts); @@ -237,7 +234,7 @@ void RegisterCancelation() { if (Interlocked.Exchange(ref _shutdownSignalCompleted, 1) == 0) { - _logger.LogInformation(LoggerEventIds.StopCancelled, "Canceled, terminating " + _outstandingRequests + " request(s)."); + Log.StopCancelled(_logger, _outstandingRequests); _shutdownSignal.TrySetResult(); } }); @@ -255,7 +252,7 @@ void RegisterCancelation() // Wait for active requests to drain if (_outstandingRequests > 0) { - _logger.LogInformation(LoggerEventIds.WaitingForRequestsToDrain, "Stopping, waiting for " + _outstandingRequests + " request(s) to drain."); + Log.WaitingForRequestsToDrain(_logger, _outstandingRequests); RegisterCancelation(); } else diff --git a/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.Log.cs b/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.Log.cs new file mode 100644 index 000000000000..7d0493353e42 --- /dev/null +++ b/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.Log.cs @@ -0,0 +1,62 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class DisconnectListener + { + private static class Log + { + private static readonly Action _disconnectHandlerError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.DisconnectHandlerError, "CreateDisconnectToken Callback"); + + private static readonly Action _createDisconnectTokenError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.CreateDisconnectTokenError, "CreateDisconnectToken"); + + private static readonly Action _disconnectRegistrationError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.DisconnectRegistrationError, "Unable to register for disconnect notifications."); + + private static readonly Action _disconnectTriggered = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.DisconnectTriggered, "CreateDisconnectToken; http.sys disconnect callback fired for connection ID: {ConnectionId}"); + + private static readonly Action _registerDisconnectListener = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.RegisterDisconnectListener, "CreateDisconnectToken; Registering connection for disconnect for connection ID: {ConnectionId}"); + + private static readonly Action _unknownDisconnectError = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.UnknownDisconnectError, "HttpWaitForDisconnectEx"); + + public static void DisconnectHandlerError(ILogger logger, Exception exception) + { + _disconnectHandlerError(logger, exception); + } + + public static void DisconnectRegistrationError(ILogger logger, Exception exception) + { + _disconnectRegistrationError(logger, exception); + } + + public static void CreateDisconnectTokenError(ILogger logger, Exception exception) + { + _createDisconnectTokenError(logger, exception); + } + + public static void DisconnectTriggered(ILogger logger, ulong connectionId) + { + _disconnectTriggered(logger, connectionId, null); + } + + public static void RegisterDisconnectListener(ILogger logger, ulong connectionId) + { + _registerDisconnectListener(logger, connectionId, null); + } + + public static void UnknownDisconnectError(ILogger logger, Exception exception) + { + _unknownDisconnectError(logger, exception); + } + } + } +} diff --git a/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.cs b/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.cs index 9f1ea7a20e75..12f3ac0c0f7f 100644 --- a/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.cs +++ b/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.cs @@ -10,7 +10,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys { - internal class DisconnectListener + internal partial class DisconnectListener { private readonly ConcurrentDictionary _connectionCancellationTokens = new(); @@ -32,7 +32,7 @@ internal CancellationToken GetTokenForConnection(ulong connectionId) } catch (Win32Exception exception) { - _logger.LogError(LoggerEventIds.DisconnectRegistrationError, exception, "Unable to register for disconnect notifications."); + Log.DisconnectRegistrationError(_logger, exception); return CancellationToken.None; } } @@ -56,7 +56,7 @@ private ConnectionCancellation GetCreatedConnectionCancellation(ulong connection private unsafe CancellationToken CreateDisconnectToken(ulong connectionId) { - _logger.LogDebug(LoggerEventIds.RegisterDisconnectListener, "CreateDisconnectToken; Registering connection for disconnect for connection ID: {0}", connectionId); + Log.RegisterDisconnectListener(_logger, connectionId); // Create a nativeOverlapped callback so we can register for disconnect callback var cts = new CancellationTokenSource(); @@ -72,7 +72,7 @@ private unsafe CancellationToken CreateDisconnectToken(ulong connectionId) // Instead, we're going to use lower level APIs to get access to UnsafePack (which avoids the capture) var nativeOverlapped = overlapped.UnsafePack((errorCode, numBytes, pOverlapped) => { - _logger.LogDebug(LoggerEventIds.DisconnectTriggered, "CreateDisconnectToken; http.sys disconnect callback fired for connection ID: {0}", connectionId); + Log.DisconnectTriggered(_logger, connectionId); // Free the overlapped Overlapped.Free(pOverlapped); @@ -85,7 +85,7 @@ private unsafe CancellationToken CreateDisconnectToken(ulong connectionId) } catch (AggregateException exception) { - _logger.LogError(LoggerEventIds.DisconnectHandlerError, exception, "CreateDisconnectToken Callback"); + Log.DisconnectHandlerError(_logger, exception); } }, null); @@ -99,7 +99,7 @@ private unsafe CancellationToken CreateDisconnectToken(ulong connectionId) catch (Win32Exception exception) { statusCode = (uint)exception.NativeErrorCode; - _logger.LogError(LoggerEventIds.DisconnectRegistrationError, exception, "CreateDisconnectToken"); + Log.CreateDisconnectTokenError(_logger, exception); } if (statusCode != UnsafeNclNativeMethods.ErrorCodes.ERROR_IO_PENDING && @@ -108,7 +108,7 @@ private unsafe CancellationToken CreateDisconnectToken(ulong connectionId) // We got an unknown result, assume the connection has been closed. Overlapped.Free(nativeOverlapped); _connectionCancellationTokens.TryRemove(connectionId, out _); - _logger.LogDebug(LoggerEventIds.UnknownDisconnectError, new Win32Exception((int)statusCode), "HttpWaitForDisconnectEx"); + Log.UnknownDisconnectError(_logger, new Win32Exception((int)statusCode)); cts.Cancel(); } diff --git a/src/Servers/HttpSys/src/NativeInterop/RequestQueue.cs b/src/Servers/HttpSys/src/NativeInterop/RequestQueue.cs index d4c62c1fcd44..b73ad9758874 100644 --- a/src/Servers/HttpSys/src/NativeInterop/RequestQueue.cs +++ b/src/Servers/HttpSys/src/NativeInterop/RequestQueue.cs @@ -105,7 +105,7 @@ private RequestQueue(UrlGroup urlGroup, string? requestQueueName, RequestQueueMo if (!Created) { - _logger.LogInformation(LoggerEventIds.AttachedToQueue, "Attached to an existing request queue '{requestQueueName}', some options do not apply.", requestQueueName); + Log.AttachedToQueue(_logger, requestQueueName); } } @@ -207,5 +207,16 @@ private void CheckDisposed() throw new ObjectDisposedException(this.GetType().FullName); } } + + private static class Log + { + private static readonly Action _attachedToQueue = + LoggerMessage.Define(LogLevel.Information, LoggerEventIds.AttachedToQueue, "Attached to an existing request queue '{RequestQueueName}', some options do not apply."); + + public static void AttachedToQueue(ILogger logger, string? requestQueueName) + { + _attachedToQueue(logger, requestQueueName, null); + } + } } } diff --git a/src/Servers/HttpSys/src/NativeInterop/UrlGroup.Log.cs b/src/Servers/HttpSys/src/NativeInterop/UrlGroup.Log.cs new file mode 100644 index 000000000000..604f7b2181e2 --- /dev/null +++ b/src/Servers/HttpSys/src/NativeInterop/UrlGroup.Log.cs @@ -0,0 +1,46 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class UrlGroup + { + private static class Log + { + private static readonly Action _closeUrlGroupError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.CloseUrlGroupError, "HttpCloseUrlGroup; Result: {StatusCode}"); + + private static readonly Action _registeringPrefix = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.RegisteringPrefix, "Listening on prefix: {UriPrefix}"); + + private static readonly Action _setUrlPropertyError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.SetUrlPropertyError, "SetUrlGroupProperty"); + + private static readonly Action _unregisteringPrefix = + LoggerMessage.Define(LogLevel.Information, LoggerEventIds.UnregisteringPrefix, "Stop listening on prefix: {UriPrefix}"); + + public static void CloseUrlGroupError(ILogger logger, uint statusCode) + { + _closeUrlGroupError(logger, statusCode, null); + } + + public static void RegisteringPrefix(ILogger logger, string uriPrefix) + { + _registeringPrefix(logger, uriPrefix, null); + } + + public static void SetUrlPropertyError(ILogger logger, Exception exception) + { + _setUrlPropertyError(logger, exception); + } + + public static void UnregisteringPrefix(ILogger logger, string uriPrefix) + { + _unregisteringPrefix(logger, uriPrefix, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/NativeInterop/UrlGroup.cs b/src/Servers/HttpSys/src/NativeInterop/UrlGroup.cs index 9a7a2d04f25c..b2a5f68e2034 100644 --- a/src/Servers/HttpSys/src/NativeInterop/UrlGroup.cs +++ b/src/Servers/HttpSys/src/NativeInterop/UrlGroup.cs @@ -9,7 +9,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys { - internal class UrlGroup : IDisposable + internal partial class UrlGroup : IDisposable { private static readonly int QosInfoSize = Marshal.SizeOf(); @@ -102,7 +102,7 @@ internal void SetProperty(HttpApiTypes.HTTP_SERVER_PROPERTY property, IntPtr inf if (statusCode != UnsafeNclNativeMethods.ErrorCodes.ERROR_SUCCESS) { var exception = new HttpSysException((int)statusCode); - _logger.LogError(LoggerEventIds.SetUrlPropertyError, exception, "SetUrlGroupProperty"); + Log.SetUrlPropertyError(_logger, exception); if (throwOnError) { throw exception; @@ -112,7 +112,7 @@ internal void SetProperty(HttpApiTypes.HTTP_SERVER_PROPERTY property, IntPtr inf internal void RegisterPrefix(string uriPrefix, int contextId) { - _logger.LogDebug(LoggerEventIds.RegisteringPrefix, "Listening on prefix: {0}" , uriPrefix); + Log.RegisteringPrefix(_logger, uriPrefix); CheckDisposed(); var statusCode = HttpApi.HttpAddUrlToUrlGroup(Id, uriPrefix, (ulong)contextId, 0); @@ -132,7 +132,7 @@ internal void RegisterPrefix(string uriPrefix, int contextId) internal bool UnregisterPrefix(string uriPrefix) { - _logger.LogInformation(LoggerEventIds.UnregisteringPrefix, "Stop listening on prefix: {0}" , uriPrefix); + Log.UnregisteringPrefix(_logger, "Stop listening on prefix: {0}"); CheckDisposed(); var statusCode = HttpApi.HttpRemoveUrlFromUrlGroup(Id, uriPrefix, 0); @@ -162,7 +162,7 @@ public void Dispose() if (statusCode != UnsafeNclNativeMethods.ErrorCodes.ERROR_SUCCESS) { - _logger.LogError(LoggerEventIds.CloseUrlGroupError, "HttpCloseUrlGroup; Result: {0}", statusCode); + Log.CloseUrlGroupError(_logger, statusCode); } } diff --git a/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.Log.cs b/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.Log.cs new file mode 100644 index 000000000000..39cd5e4d7428 --- /dev/null +++ b/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.Log.cs @@ -0,0 +1,30 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class ClientCertLoader + { + private static class Log + { + private static readonly Action _channelBindingMissing = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ChannelBindingMissing, "GetChannelBindingFromTls"); + + private static readonly Action _channelBindingUnsupported = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ChannelBindingUnsupported, "GetChannelBindingFromTls; Channel binding is not supported."); + + public static void ChannelBindingMissing(ILogger logger, Exception exception) + { + _channelBindingMissing(logger, exception); + } + + public static void ChannelBindingUnsupported(ILogger logger) + { + _channelBindingUnsupported(logger, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.cs b/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.cs index 633e70d433ad..cc38851b67f1 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/ClientCertLoader.cs @@ -19,7 +19,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys { // This class is used to load the client certificate on-demand. Because client certs are optional, all // failures are handled internally and reported via ClientCertException or ClientCertError. - internal unsafe sealed class ClientCertLoader : IAsyncResult, IDisposable + internal unsafe sealed partial class ClientCertLoader : IAsyncResult, IDisposable { private const uint CertBoblSize = 1500; private static readonly IOCompletionCallback IOCallback = new IOCompletionCallback(WaitCallback); @@ -400,13 +400,13 @@ public bool IsCompleted } else if (statusCode == UnsafeNclNativeMethods.ErrorCodes.ERROR_INVALID_PARAMETER) { - logger.LogError(LoggerEventIds.ChannelBindingUnSupported, "GetChannelBindingFromTls; Channel binding is not supported."); + Log.ChannelBindingUnsupported(logger); return null; // old schannel library which doesn't support CBT } else { // It's up to the consumer to fail if the missing ChannelBinding matters to them. - logger.LogError(LoggerEventIds.ChannelBindingMissing, new HttpSysException((int)statusCode), "GetChannelBindingFromTls"); + Log.ChannelBindingMissing(logger, new HttpSysException((int)statusCode)); break; } } diff --git a/src/Servers/HttpSys/src/RequestProcessing/Request.cs b/src/Servers/HttpSys/src/RequestProcessing/Request.cs index 7a132c97507b..dcb309d0743f 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/Request.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/Request.cs @@ -337,11 +337,11 @@ public X509Certificate2? ClientCertificate } catch (CryptographicException ce) { - RequestContext.Logger.LogDebug(LoggerEventIds.ErrorInReadingCertificate, ce, "An error occurred reading the client certificate."); + Log.ErrorInReadingCertificate(RequestContext.Logger, ce); } catch (SecurityException se) { - RequestContext.Logger.LogDebug(LoggerEventIds.ErrorInReadingCertificate, se, "An error occurred reading the client certificate."); + Log.ErrorInReadingCertificate(RequestContext.Logger, se); } } @@ -451,5 +451,16 @@ internal void SwitchToOpaqueMode() } _nativeStream.SwitchToOpaqueMode(); } + + private static class Log + { + private static readonly Action _errorInReadingCertificate = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.ErrorInReadingCertificate, "An error occurred reading the client certificate."); + + public static void ErrorInReadingCertificate(ILogger logger, Exception exception) + { + _errorInReadingCertificate(logger, exception); + } + } } } diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestContext.Log.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestContext.Log.cs new file mode 100644 index 000000000000..60117bfbd45d --- /dev/null +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestContext.Log.cs @@ -0,0 +1,38 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class RequestContext + { + private static class Log + { + private static readonly Action _abortError = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.AbortError, "Abort"); + + private static readonly Action _channelBindingNeedsHttps = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.ChannelBindingNeedsHttps, "TryGetChannelBinding; Channel binding requires HTTPS."); + + private static readonly Action _channelBindingRetrieved = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.ChannelBindingRetrieved, "Channel binding retrieved."); + + public static void AbortError(ILogger logger, Exception exception) + { + _abortError(logger, exception); + } + + public static void ChannelBindingNeedsHttps(ILogger logger) + { + _channelBindingNeedsHttps(logger, null); + } + + public static void ChannelBindingRetrieved(ILogger logger) + { + _channelBindingRetrieved(logger, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestContext.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestContext.cs index c84dfa116ef5..994d5d130af8 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/RequestContext.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestContext.cs @@ -114,18 +114,17 @@ internal bool TryGetChannelBinding(ref ChannelBinding? value) { if (!Request.IsHttps) { - Logger.LogDebug(LoggerEventIds.ChannelBindingNeedsHttps, "TryGetChannelBinding; Channel binding requires HTTPS."); + Log.ChannelBindingNeedsHttps(Logger); return false; } value = ClientCertLoader.GetChannelBindingFromTls(Server.RequestQueue, Request.UConnectionId, Logger); Debug.Assert(value != null, "GetChannelBindingFromTls returned null even though OS supposedly supports Extended Protection"); - Logger.LogDebug(LoggerEventIds.ChannelBindingRetrived, "Channel binding retrieved."); + Log.ChannelBindingRetrieved(Logger); return value != null; } - /// /// Flushes and completes the response. /// @@ -178,7 +177,7 @@ public void Abort() } catch (Exception ex) { - Logger.LogDebug(LoggerEventIds.AbortError, ex, "Abort"); + Log.AbortError(Logger, ex); } _requestAbortSource.Dispose(); } diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.Log.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.Log.cs new file mode 100644 index 000000000000..f387bf179db4 --- /dev/null +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.Log.cs @@ -0,0 +1,38 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal sealed partial class RequestContext + { + private static class Log + { + private static readonly Action _requestError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.RequestError, "ProcessRequestAsync"); + + private static readonly Action _requestProcessError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.RequestProcessError, "ProcessRequestAsync"); + + private static readonly Action _requestsDrained = + LoggerMessage.Define(LogLevel.Information, LoggerEventIds.RequestsDrained, "All requests drained."); + + public static void RequestError(ILogger logger, Exception exception) + { + _requestError(logger, exception); + } + + public static void RequestProcessError(ILogger logger, Exception exception) + { + _requestProcessError(logger, exception); + } + + public static void RequestsDrained(ILogger logger) + { + _requestsDrained(logger, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.cs index 067c736de9df..1d7eb0412e02 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestContextOfT.cs @@ -2,11 +2,10 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Hosting.Server; using Microsoft.AspNetCore.Http; -using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.HttpSys { - internal sealed class RequestContext : RequestContext where TContext : notnull + internal sealed partial class RequestContext : RequestContext where TContext : notnull { private readonly IHttpApplication _application; private readonly MessagePump _messagePump; @@ -52,7 +51,7 @@ protected override async Task ExecuteAsync() } catch (Exception ex) { - Logger.LogError(LoggerEventIds.RequestProcessError, ex, "ProcessRequestAsync"); + Log.RequestProcessError(Logger, ex); if (context != null) { application.DisposeContext(context, ex); @@ -86,17 +85,16 @@ protected override async Task ExecuteAsync() { if (messagePump.DecrementOutstandingRequest() == 0 && messagePump.Stopping) { - Logger.LogInformation(LoggerEventIds.RequestsDrained, "All requests drained."); + Log.RequestsDrained(Logger); messagePump.SetShutdownSignal(); } } } catch (Exception ex) { - Logger.LogError(LoggerEventIds.RequestError, ex, "ProcessRequestAsync"); + Log.RequestError(Logger, ex); Abort(); } } } - } diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestStream.Log.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestStream.Log.cs new file mode 100644 index 000000000000..762c84c427bc --- /dev/null +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestStream.Log.cs @@ -0,0 +1,38 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class RequestStream + { + private static class Log + { + private static readonly Action _errorWhenReadAsync = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ErrorWhenReadAsync, "ReadAsync"); + + private static readonly Action _errorWhenReadBegun = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ErrorWhenReadBegun, "BeginRead"); + + private static readonly Action _errorWhileRead = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.ErrorWhileRead, "Read"); + + public static void ErrorWhenReadAsync(ILogger logger, Exception exception) + { + _errorWhenReadAsync(logger, exception); + } + + public static void ErrorWhenReadBegun(ILogger logger, Exception exception) + { + _errorWhenReadBegun(logger, exception); + } + + public static void ErrorWhileRead(ILogger logger, Exception exception) + { + _errorWhileRead(logger, exception); + } + } + } +} diff --git a/src/Servers/HttpSys/src/RequestProcessing/RequestStream.cs b/src/Servers/HttpSys/src/RequestProcessing/RequestStream.cs index 2bd60734e7b1..18c974cf99ff 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/RequestStream.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/RequestStream.cs @@ -3,7 +3,6 @@ using System; using System.Diagnostics.CodeAnalysis; -using System.Globalization; using System.IO; using System.Runtime.InteropServices; using System.Threading; @@ -14,7 +13,7 @@ namespace Microsoft.AspNetCore.Server.HttpSys { - internal class RequestStream : Stream + internal partial class RequestStream : Stream { private const int MaxReadSize = 0x20000; // http.sys recommends we limit reads to 128k @@ -167,7 +166,7 @@ public override unsafe int Read([In, Out] byte[] buffer, int offset, int size) if (statusCode != UnsafeNclNativeMethods.ErrorCodes.ERROR_SUCCESS && statusCode != UnsafeNclNativeMethods.ErrorCodes.ERROR_HANDLE_EOF) { Exception exception = new IOException(string.Empty, new HttpSysException((int)statusCode)); - Logger.LogError(LoggerEventIds.ErrorWhileRead, exception, "Read"); + Log.ErrorWhileRead(Logger, exception); Abort(); throw exception; } @@ -244,7 +243,7 @@ public override unsafe IAsyncResult BeginRead(byte[] buffer, int offset, int siz } catch (Exception e) { - Logger.LogError(LoggerEventIds.ErrorWhenReadBegun, e, "BeginRead"); + Log.ErrorWhenReadBegun(Logger, e); asyncResult.Dispose(); throw; } @@ -260,7 +259,7 @@ public override unsafe IAsyncResult BeginRead(byte[] buffer, int offset, int siz else { Exception exception = new IOException(string.Empty, new HttpSysException((int)statusCode)); - Logger.LogError(LoggerEventIds.ErrorWhenReadBegun, exception, "BeginRead"); + Log.ErrorWhenReadBegun(Logger, exception); Abort(); throw exception; } @@ -367,7 +366,7 @@ public override unsafe Task ReadAsync(byte[] buffer, int offset, int size, { asyncResult.Dispose(); Abort(); - Logger.LogError(LoggerEventIds.ErrorWhenReadAsync, e, "ReadAsync"); + Log.ErrorWhenReadAsync(Logger, e); throw; } @@ -388,7 +387,7 @@ public override unsafe Task ReadAsync(byte[] buffer, int offset, int size, else { Exception exception = new IOException(string.Empty, new HttpSysException((int)statusCode)); - Logger.LogError(LoggerEventIds.ErrorWhenReadAsync, exception, "ReadAsync"); + Log.ErrorWhenReadAsync(Logger, exception); Abort(); throw exception; } diff --git a/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.Log.cs b/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.Log.cs new file mode 100644 index 000000000000..33e4b70bbab4 --- /dev/null +++ b/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.Log.cs @@ -0,0 +1,38 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.HttpSys +{ + internal partial class ResponseStreamAsyncResult + { + private static class Log + { + private static readonly Action _writeCancelled = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.WriteCancelled, "FlushAsync.IOCompleted; Write cancelled with error code: {ErrorCode}"); + + private static readonly Action _writeError = + LoggerMessage.Define(LogLevel.Error, LoggerEventIds.WriteError, "FlushAsync.IOCompleted"); + + private static readonly Action _writeErrorIgnored = + LoggerMessage.Define(LogLevel.Debug, LoggerEventIds.WriteErrorIgnored, "FlushAsync.IOCompleted; Ignored write exception: {ErrorCode}"); + + public static void WriteCancelled(ILogger logger, uint errorCode) + { + _writeCancelled(logger, errorCode, null); + } + + public static void WriteError(ILogger logger, Exception exception) + { + _writeError(logger, exception); + } + + public static void WriteErrorIgnored(ILogger logger, uint errorCode) + { + _writeErrorIgnored(logger, errorCode, null); + } + } + } +} diff --git a/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.cs b/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.cs index 6fb829d83bc1..3bfdaba56fa0 100644 --- a/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.cs +++ b/src/Servers/HttpSys/src/RequestProcessing/ResponseStreamAsyncResult.cs @@ -8,11 +8,10 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.HttpSys.Internal; -using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.HttpSys { - internal unsafe class ResponseStreamAsyncResult : IAsyncResult, IDisposable + internal unsafe partial class ResponseStreamAsyncResult : IAsyncResult, IDisposable { private static readonly IOCompletionCallback IOCallback = new IOCompletionCallback(Callback); @@ -233,18 +232,18 @@ private static void IOCompleted(ResponseStreamAsyncResult asyncResult, uint erro { if (asyncResult._cancellationToken.IsCancellationRequested) { - logger.LogDebug(LoggerEventIds.WriteCancelled,$"FlushAsync.IOCompleted; Write cancelled with error code: {errorCode}"); + Log.WriteCancelled(logger, errorCode); asyncResult.Cancel(asyncResult._responseStream.ThrowWriteExceptions); } else if (asyncResult._responseStream.ThrowWriteExceptions) { var exception = new IOException(string.Empty, new HttpSysException((int)errorCode)); - logger.LogError(LoggerEventIds.WriteError, exception, "FlushAsync.IOCompleted"); + Log.WriteError(logger, exception); asyncResult.Fail(exception); } else { - logger.LogDebug(LoggerEventIds.WriteErrorIgnored, $"FlushAsync.IOCompleted; Ignored write exception: {errorCode}"); + Log.WriteErrorIgnored(logger, errorCode); asyncResult.FailSilently(); } } @@ -267,7 +266,7 @@ private static void IOCompleted(ResponseStreamAsyncResult asyncResult, uint erro } catch (Exception e) { - logger.LogError(LoggerEventIds.WriteError, e, "FlushAsync.IOCompleted"); + Log.WriteError(logger, e); asyncResult.Fail(e); } }