Avoid logging bad requests as application errors if the connection was aborted (dotnet#60359)

Author: adityamandaleeka

src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs

@@ -702,7 +702,15 @@ private async Task ProcessRequests<TContext>(IHttpApplication<TContext> applicat
                 // This has to be caught here so StatusCode is set properly before disposing the HttpContext
                 // (DisposeContext logs StatusCode).
                 SetBadRequestState(ex);
-                ReportApplicationError(ex);
+
+                if (!_connectionAborted)
+                {
+                    // Only report bad requests as error-level logs here if the connection hasn't been aborted. This
+                    // prevents noise in the logs for common types of client errors, and we already have a mechanism
+                    // for logging these at a higher level if needed by increasing the log level for
+                    // "Microsoft.AspNetCore.Server.Kestrel.BadRequests".
+                    ReportApplicationError(ex);
+                }
             }
             catch (Exception ex)
             {

src/Servers/Kestrel/test/FunctionalTests/RequestTests.cs

@@ -399,6 +399,68 @@ await connection.Receive(
         Assert.False(loggedHigherThanDebug);
     }
 
+    [Fact]
+    public async Task IncompleteRequestBodyDoesNotLogAsApplicationError()
+    {
+        var appErrorLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
+        var badRequestLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
+        var connectionStoppedLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
+
+        const int badRequestEventId = 17;
+        const int appErrorEventId = 13;
+        const int connectionStopEventId = 2;
+
+        // Listen for the expected log message
+        TestSink.MessageLogged += context =>
+        {
+            if (context.LoggerName == "Microsoft.AspNetCore.Server.Kestrel.BadRequests"
+                && context.EventId == badRequestEventId
+                && context.LogLevel == LogLevel.Debug)
+            {
+                badRequestLogged.TrySetResult();
+            }
+            else if (context.LoggerName == "Microsoft.AspNetCore.Server.Kestrel"
+                    && context.EventId.Id == appErrorEventId
+                    && context.LogLevel > LogLevel.Debug)
+            {
+                appErrorLogged.TrySetResult();
+            }
+            else if (context.LoggerName == "Microsoft.AspNetCore.Server.Kestrel.Connections"
+                    && context.EventId == connectionStopEventId)
+            {
+                connectionStoppedLogged.TrySetResult();
+            }
+        };
+
+        await using var server = new TestServer(async context =>
+        {
+            var buffer = new byte[1024];
+
+            // Attempt to read more of the body than will show up.
+            await context.Request.Body.ReadAsync(buffer, 0, buffer.Length);
+        }, new TestServiceContext(LoggerFactory));
+
+        using (var connection = server.CreateConnection())
+        {
+            await connection.Send(
+                "POST / HTTP/1.1",
+                "Host:",
+                "Connection: keep-alive",
+                "Content-Type: application/json",
+                "Content-Length: 100",  // Declare a larger body than will be sent
+                "",
+                "");
+        }
+
+        await connectionStoppedLogged.Task.DefaultTimeout();
+
+        // Bad request log message should have fired.
+        await badRequestLogged.Task.DefaultTimeout();
+
+        // App error log message should not have fired.
+        Assert.False(appErrorLogged.Task.IsCompleted);
+    }
+
     [Fact]
     public async Task ConnectionResetBetweenRequestsIsLoggedAsDebug()
     {

src/Servers/Kestrel/test/InMemory.FunctionalTests/ChunkedRequestTests.cs

@@ -740,6 +740,9 @@ await connection.ReceiveEnd(
                     "",
                     "");
             }
+
+            // The 400 response should have been logged by default at Error level since the connection wasn't aborted when the bad request was handled.
+            Assert.Contains(TestSink.Writes, w => w.LoggerName == "Microsoft.AspNetCore.Server.Kestrel" && w.EventId.Id == 13 && w.LogLevel > LogLevel.Debug);
         }
     }