Don't log ConnectionAbortedExceptions in HttpProtocol/Http2Connection as warning

[halter73]

ConnectionAbortedExceptions are already logged by the transport. If these are logged at all by the input processing loop, these shouldn't be logged as warning. Examples:

[0.002s] [TestLifetime] [Information] Starting test ResponseBodyWriteAsyncCanBeCancelled at 2018-10-12T17:51:42
[0.009s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Debug] Hosting starting
[0.009s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Debug] Hosting started
[0.009s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Debug] Loaded hosting startup assembly testhost
[0.010s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLHGDDCK10TF" started.
[0.011s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request starting HTTP/1.1 GET http:///  
[0.025s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLHGDDCK10TF" closing because: "The connection or stream was aborted because a write operation was aborted with a CancellationToken."
[0.025s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLHGDDCK10TF" disconnecting.
[0.026s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLHGDDCK10TF" completed keep alive response.
[0.026s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Information] Request finished in 14.8892ms 200 
[0.028s] [Microsoft.AspNetCore.Hosting.Internal.WebHost] [Debug] Hosting shutdown
[0.046s] [Microsoft.AspNetCore.Server.Kestrel] [Warning] Connection processing ended abnormally.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: The connection or stream was aborted because a write operation was aborted with a CancellationToken. ---> System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at System.IO.Pipelines.Pipe.GetFlushResult(FlushResult& result)
   at System.IO.Pipelines.Pipe.GetFlushAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeWriter.GetResult(Int16 token)
   at System.Threading.Tasks.ValueTask`1.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.TimingPipeFlusher.TimeFlushAsync(MinDataRate minRate, Int64 count, IHttpOutputAborter outputAborter, CancellationToken cancellationToken) in G:\dev\aspnet\KestrelHttpServer\src\Kestrel.Core\Internal\Infrastructure\TimingPipeFlusher.cs:line 82
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.ReadAsync(CancellationToken token)
   at System.IO.Pipelines.Pipe.DefaultPipeReader.ReadAsync(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.BeginRead(ValueTask`1& awaitable) in G:\dev\aspnet\KestrelHttpServer\src\Kestrel.Core\Internal\Http\Http1Connection.cs:line 454
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application) in G:\dev\aspnet\KestrelHttpServer\src\Kestrel.Core\Internal\Http\HttpProtocol.cs:line 523
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application) in G:\dev\aspnet\KestrelHttpServer\src\Kestrel.Core\Internal\Http\HttpProtocol.cs:line 472
[0.048s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HLHGDDCK10TF" stopped.
[0.055s] [TestLifetime] [Information] Finished test ResponseBodyWriteAsyncCanBeCancelled in 0.0533177s

[0.002s] [TestLifetime] [Information] Starting test HEADERS_ReceivedWithoutAllCONTINUATIONs_WithinRequestHeadersTimeout_AbortsConnection at 2018-10-12T17:51:34
[0.039s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" sending SETTINGS frame for stream ID 0 with length 18 and flags NONE
[0.040s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" sending WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0
[0.062s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" received SETTINGS frame for stream ID 0 with length 0 and flags NONE
[0.062s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" sending SETTINGS frame for stream ID 0 with length 0 and flags ACK
[0.067s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" received HEADERS frame for stream ID 1 with length 318 and flags NONE
[0.071s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" received CONTINUATION frame for stream ID 1 with length 0 and flags NONE
[0.079s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" received CONTINUATION frame for stream ID 1 with length 0 and flags NONE
[0.081s] [Microsoft.AspNetCore.Server.Kestrel] [Information] Connection id "null" bad request data: "Reading the request headers timed out."
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Reading the request headers timed out.
[0.083s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "null" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0
[0.083s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "null" is closed. The last processed stream ID was 1.
[0.090s] [Microsoft.AspNetCore.Server.Kestrel] [Warning] Connection processing ended abnormally.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: Reading the request headers timed out.
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.PipeCompletion.IsCompletedOrThrow()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at System.Threading.Tasks.ValueTask`1.get_Result()
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Connection.ProcessRequestsAsync[TContext](IHttpApplication`1 application) in G:\dev\aspnet\KestrelHttpServer\src\Kestrel.Core\Internal\Http2\Http2Connection.cs:line 209
[0.093s] [TestLifetime] [Information] Finished test HEADERS_ReceivedWithoutAllCONTINUATIONs_WithinRequestHeadersTimeout_AbortsConnection in 0.0912812s

[analogrelay]

Just about changing from Warning to Debug?

[halter73]

The reason these are Warning logs is because they're unexpected, or at least they were unexpected when the code was originally written. That's why the message is the super generic: "Connection processing ended abnormally."

I think we just need to catch ConnectionAbortedExceptions specifically in Http2Connection.ProcessRequestsAsync() and log those as Debug. We can keep other Exception types as Warnings for now.