More feedback.

- Log writes on responses to HEAD requests only once.

Author: Cesar Blum Silveira

src/Microsoft.AspNetCore.Server.Kestrel/Internal/Http/Frame.cs

@@ -75,6 +75,8 @@ public abstract partial class Frame : IFrameControl
         protected readonly long _keepAliveMilliseconds;
         private readonly long _requestHeadersTimeoutMilliseconds;
 
+        private int _responseBytesWritten;
+
         public Frame(ConnectionContext context)
         {
             ConnectionContext = context;
@@ -347,6 +349,8 @@ public void Reset()
 
             _remainingRequestHeadersBytesAllowed = ServerOptions.Limits.MaxRequestHeadersTotalSize;
             _requestHeadersParsed = 0;
+
+            _responseBytesWritten = 0;
         }
 
         /// <summary>
@@ -513,6 +517,7 @@ public async Task FlushAsync(CancellationToken cancellationToken)
         public void Write(ArraySegment<byte> data)
         {
             ProduceStartAndFireOnStarting().GetAwaiter().GetResult();
+            _responseBytesWritten += data.Count;
 
             if (_canHaveBody)
             {
@@ -531,7 +536,7 @@ public void Write(ArraySegment<byte> data)
             }
             else
             {
-                HandleNonBodyResponseWrite(data.Count);
+                HandleNonBodyResponseWrite();
             }
         }
 
@@ -542,6 +547,8 @@ public Task WriteAsync(ArraySegment<byte> data, CancellationToken cancellationTo
                 return WriteAsyncAwaited(data, cancellationToken);
             }
 
+            _responseBytesWritten += data.Count;
+
             if (_canHaveBody)
             {
                 if (_autoChunk)
@@ -559,14 +566,15 @@ public Task WriteAsync(ArraySegment<byte> data, CancellationToken cancellationTo
             }
             else
             {
-                HandleNonBodyResponseWrite(data.Count);
+                HandleNonBodyResponseWrite();
                 return TaskCache.CompletedTask;
             }
         }
 
         public async Task WriteAsyncAwaited(ArraySegment<byte> data, CancellationToken cancellationToken)
         {
             await ProduceStartAndFireOnStarting();
+            _responseBytesWritten += data.Count;
 
             if (_canHaveBody)
             {
@@ -585,7 +593,7 @@ public async Task WriteAsyncAwaited(ArraySegment<byte> data, CancellationToken c
             }
             else
             {
-                HandleNonBodyResponseWrite(data.Count);
+                HandleNonBodyResponseWrite();
                 return;
             }
         }
@@ -740,6 +748,11 @@ private Task WriteSuffix()
                 ConnectionControl.End(ProduceEndType.ConnectionKeepAlive);
             }
 
+            if (HttpMethods.IsHead(Method) && _responseBytesWritten > 0)
+            {
+                Log.ConnectionHeadResponseBodyWrite(ConnectionId, _responseBytesWritten);
+            }
+
             return TaskCache.CompletedTask;
         }
 
@@ -1324,14 +1337,10 @@ private void SetErrorResponseHeaders(int statusCode)
             }
         }
 
-        public void HandleNonBodyResponseWrite(int count)
+        public void HandleNonBodyResponseWrite()
         {
-            if (Method == "HEAD")
-            {
-                // Don't write to body for HEAD requests.
-                Log.ConnectionHeadResponseBodyWrite(ConnectionId, count);
-            }
-            else
+            // Writes to HEAD response are ignored and logged at the end of the request
+            if (Method != "HEAD")
             {
                 // Throw Exception for 204, 205, 304 responses.
                 throw new InvalidOperationException($"Write to non-body {StatusCode} response.");

test/Microsoft.AspNetCore.Server.KestrelTests/EngineTests.cs

@@ -620,6 +620,35 @@ await connection.ReceiveEnd(
             }
         }
 
+        [Theory]
+        [MemberData(nameof(ConnectionFilterData))]
+        public async Task WriteOnHeadResponseLoggedOnlyOnce(TestServiceContext testContext)
+        {
+            using (var server = new TestServer(async httpContext =>
+            {
+                await httpContext.Response.WriteAsync("hello, ");
+                await httpContext.Response.WriteAsync("world");
+                await httpContext.Response.WriteAsync("!");
+            }, testContext))
+            {
+                using (var connection = server.CreateConnection())
+                {
+                    await connection.SendEnd(
+                        "HEAD / HTTP/1.1",
+                        "",
+                        "");
+                    await connection.ReceiveEnd(
+                        "HTTP/1.1 200 OK",
+                        $"Date: {testContext.DateHeaderValue}",
+                        "",
+                        "");
+                }
+
+                Assert.Equal(1, ((TestKestrelTrace)testContext.Log).HeadResponseWrites);
+                Assert.Equal(13, ((TestKestrelTrace)testContext.Log).HeadResponseWriteByteCount);
+            }
+        }
+
         [Theory]
         [MemberData(nameof(ConnectionFilterData))]
         public async Task ThrowingResultsIn500Response(TestServiceContext testContext)

test/shared/TestKestrelTrace.cs

@@ -13,6 +13,10 @@ public TestKestrelTrace(ILogger testLogger) : base(testLogger)
         {
         }
 
+        public int HeadResponseWrites { get; set; }
+
+        public int HeadResponseWriteByteCount { get; set; }
+
         public override void ConnectionRead(string connectionId, int count)
         {
             //_logger.LogDebug(1, @"Connection id ""{ConnectionId}"" recv {count} bytes.", connectionId, count);
@@ -27,5 +31,11 @@ public override void ConnectionWriteCallback(string connectionId, int status)
         {
             //_logger.LogDebug(1, @"Connection id ""{ConnectionId}"" send finished with status {status}.", connectionId, status);
         }
+
+        public override void ConnectionHeadResponseBodyWrite(string connectionId, int count)
+        {
+            HeadResponseWrites++;
+            HeadResponseWriteByteCount = count;
+        }
     }
 }