Add client disconnect logs (#1521)

src/Microsoft.AspNetCore.Server.IIS/Core/IISHttpContext.IO.cs

@@ -6,6 +6,7 @@ using System.Buffers;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Connections;
+using Microsoft.AspNetCore.Http.Features;
 
 namespace Microsoft.AspNetCore.Server.IIS.Core
 {
@@ -121,6 +122,7 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
             catch (Exception ex)
             {
                 error = ex;
+                Log.UnexpectedError(_logger, nameof(IISHttpContext), ex);
             }
             finally
             {
@@ -174,6 +176,7 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
             catch (Exception ex)
             {
                 error = ex;
+                Log.UnexpectedError(_logger, nameof(IISHttpContext), ex);
             }
             finally
             {
@@ -199,9 +202,9 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
                     {
                         cts.Cancel();
                     }
-                    catch (Exception)
+                    catch (Exception ex)
                     {
-                        // ignore
+                        Log.ApplicationError(_logger, ((IHttpConnectionFeature)this).ConnectionId, TraceIdentifier, ex);
                     }
                 });
             }
@@ -219,6 +222,7 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
         internal void ConnectionReset()
         {
             AbortIO();
+            Log.ConnectionDisconnect(_logger, ((IHttpConnectionFeature)this).ConnectionId);
         }
     }
 }

src/Microsoft.AspNetCore.Server.IIS/Core/IISHttpContext.Log.cs

@@ -0,0 +1,39 @@
+// 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.Runtime.CompilerServices;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.AspNetCore.Server.IIS.Core
+{
+    internal abstract partial class IISHttpContext
+    {
+        private static class Log
+        {
+            private static readonly Action<ILogger, string, Exception> _connectionDisconnect =
+                LoggerMessage.Define<string>(LogLevel.Debug, new EventId(1, "ConnectionDisconnect"), @"Connection ID ""{ConnectionId}"" disconnecting.");
+
+            private static readonly Action<ILogger, string, string, Exception> _applicationError =
+                LoggerMessage.Define<string, string>(LogLevel.Error, new EventId(2, "ApplicationError"), @"Connection ID ""{ConnectionId}"", Request ID ""{TraceIdentifier}"": An unhandled exception was thrown by the application.");
+
+            private static readonly Action<ILogger, string, string, Exception> _unexpectedError =
+                LoggerMessage.Define<string, string>(LogLevel.Error, new EventId(3, "UnexpectedError"), @"Unexpected exception in ""{ClassName}.{MethodName}"".");
+
+            public static void ConnectionDisconnect(ILogger logger, string connectionId)
+            {
+                _connectionDisconnect(logger, connectionId, null);
+            }
+
+            public static void ApplicationError(ILogger logger, string connectionId, string traceIdentifier, Exception ex)
+            {
+                _applicationError(logger, connectionId, traceIdentifier, ex);
+            }
+
+            public static void UnexpectedError(ILogger logger, string className, Exception ex, [CallerMemberName] string methodName = null)
+            {
+                _unexpectedError(logger, className, methodName, ex);
+            }
+        }
+    }
+}

src/Microsoft.AspNetCore.Server.IIS/Core/IISHttpContext.cs

@@ -17,9 +17,11 @@ using System.Threading.Tasks;
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Connections;
 using Microsoft.AspNetCore.Http;
+using Microsoft.AspNetCore.Http.Features;
 using Microsoft.AspNetCore.HttpSys.Internal;
 using Microsoft.AspNetCore.Server.IIS.Core.IO;
 using Microsoft.AspNetCore.WebUtilities;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Server.IIS.Core
 {
@@ -50,6 +52,8 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
         private readonly MemoryPool<byte> _memoryPool;
         private readonly IISHttpServer _server;
 
+        private readonly ILogger _logger;
+
         private GCHandle _thisHandle;
         protected Task _readBodyTask;
         protected Task _writeBodyTask;
@@ -69,13 +73,15 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
             MemoryPool<byte> memoryPool,
             IntPtr pInProcessHandler,
             IISServerOptions options,
-            IISHttpServer server)
+            IISHttpServer server,
+            ILogger logger)
             : base((HttpApiTypes.HTTP_REQUEST*)NativeMethods.HttpGetRawRequest(pInProcessHandler))
         {
             _memoryPool = memoryPool;
             _pInProcessHandler = pInProcessHandler;
             _options = options;
             _server = server;
+            _logger = logger;
         }
 
         public Version HttpVersion { get; set; }
@@ -450,6 +456,8 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
             {
                 _applicationException = new AggregateException(_applicationException, ex);
             }
+
+            Log.ApplicationError(_logger, ((IHttpConnectionFeature)this).ConnectionId, TraceIdentifier, ex);
         }
 
         public void PostCompletion(NativeMethods.REQUEST_NOTIFICATION_STATUS requestNotificationStatus)

src/Microsoft.AspNetCore.Server.IIS/Core/IISHttpContextOfT.cs

@@ -7,6 +7,7 @@ using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Builder;
 using Microsoft.AspNetCore.Hosting.Server;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Server.IIS.Core
 {
@@ -14,8 +15,8 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
     {
         private readonly IHttpApplication<TContext> _application;
 
-        public IISHttpContextOfT(MemoryPool<byte> memoryPool, IHttpApplication<TContext> application, IntPtr pInProcessHandler, IISServerOptions options, IISHttpServer server)
+        public IISHttpContextOfT(MemoryPool<byte> memoryPool, IHttpApplication<TContext> application, IntPtr pInProcessHandler, IISServerOptions options, IISHttpServer server, ILogger logger)
-            : base(memoryPool, pInProcessHandler, options, server)
+            : base(memoryPool, pInProcessHandler, options, server, logger)
         {
             _application = application;
         }

src/Microsoft.AspNetCore.Server.IIS/Core/IISHttpServer.cs

@@ -82,7 +82,7 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
         {
             _httpServerHandle = GCHandle.Alloc(this);
 
-            _iisContextFactory = new IISContextFactory<TContext>(_memoryPool, application, _options, this);
+            _iisContextFactory = new IISContextFactory<TContext>(_memoryPool, application, _options, this, _logger);
             _nativeApplication.RegisterCallbacks(_requestHandler, _shutdownHandler, _onDisconnect, _onAsyncCompletion, (IntPtr)_httpServerHandle, (IntPtr)_httpServerHandle);
             return Task.CompletedTask;
         }
@@ -260,18 +260,20 @@ namespace Microsoft.AspNetCore.Server.IIS.Core
             private readonly MemoryPool<byte> _memoryPool;
             private readonly IISServerOptions _options;
             private readonly IISHttpServer _server;
+            private readonly ILogger _logger;
 
-            public IISContextFactory(MemoryPool<byte> memoryPool, IHttpApplication<T> application, IISServerOptions options, IISHttpServer server)
+            public IISContextFactory(MemoryPool<byte> memoryPool, IHttpApplication<T> application, IISServerOptions options, IISHttpServer server, ILogger logger)
             {
                 _application = application;
                 _memoryPool = memoryPool;
                 _options = options;
                 _server = server;
+                _logger = logger;
             }
 
             public IISHttpContext CreateHttpContext(IntPtr pInProcessHandler)
             {
-                return new IISHttpContextOfT<T>(_memoryPool, _application, pInProcessHandler, _options, _server);
+                return new IISHttpContextOfT<T>(_memoryPool, _application, pInProcessHandler, _options, _server, _logger);
             }
         }
     }

test/IIS.Tests/ClientDisconnectTests.cs

@@ -17,7 +17,6 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
     [OSSkipCondition(OperatingSystems.Windows, WindowsVersions.Win7, "https://github.com/aspnet/IISIntegration/issues/866")]
     public class ClientDisconnectTests : StrictTestServerTests
     {
-
         [ConditionalFact]
         public async Task WritesSucceedAfterClientDisconnect()
         {
@@ -48,6 +47,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
 
                 await requestCompletedCompletionSource.Task.DefaultTimeout();
             }
+
+            AssertConnectionDisconnectLog();
         }
 
         [ConditionalFact]
@@ -88,6 +89,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
 
                 Assert.IsType<OperationCanceledException>(exception);
             }
+
+            AssertConnectionDisconnectLog();
         }
 
         [ConditionalFact]
@@ -125,6 +128,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
 
             Assert.IsType<ConnectionResetException>(exception);
             Assert.Equal("The client has disconnected", exception.Message);
+
+            AssertConnectionDisconnectLog();
         }
 
         [ConditionalFact]
@@ -202,6 +207,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 }
                 Assert.IsType<OperationCanceledException>(exception);
             }
+
+            AssertConnectionDisconnectLog();
         }
 
         [ConditionalFact]
@@ -253,6 +260,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
 
             Assert.IsType<ConnectionResetException>(exception);
             Assert.Equal("The client has disconnected", exception.Message);
+            AssertConnectionDisconnectLog();
         }
 
         [ConditionalFact]
@@ -275,7 +283,15 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 }
                 await requestAborted.Task;
             }
+
+            AssertConnectionDisconnectLog();
         }
+
+        private void AssertConnectionDisconnectLog()
+        {
+            Assert.Contains(TestSink.Writes, w => w.EventId.Name == "ConnectionDisconnect");
+        }
+
         private static async Task SendContentLength1Post(TestConnection connection)
         {
             await connection.Send(