Hangs with HttpClientHandler and AutomaticDecompression in 2.1 preview

[ayende]

We recently have run into a spate of hangs in our tests when running the full test suite.
We have been able to narrow it down to a consistent hang when an HttpClient is reading from a pretty big stream and Kestrel is sending a pretty big stream.

This is all on the local machine, mind. We weren't able to reproduce this on stand alone tests, but consistently when running the full suite.
These tests pass without issue when running on 2.0.

Eventually we narrowed it down to removing this line:

  var httpMessageHandler = new HttpClientHandler();
  if (httpMessageHandler.SupportsAutomaticDecompression)
  {
      //httpMessageHandler.AutomaticDecompression =
          //useCompression ?
              //DecompressionMethods.GZip | DecompressionMethods.Deflate
              //: DecompressionMethods.None;
  }

On the server side, compression is done using:

 app.UseWhen(
     context => true, 
     appBuilder => appBuilder.UseResponseCompression());

Is this a known issue? Any other details that I can provide?

2.1.300-preview2-008533

[karelz]

@ayende thanks for your report!
This is not a known issue. Can you please share stack traces and/or repro with us ASAP? Thanks!

cc @geoffkizer @davidsh

[stephentoub]

@ayende, are the failures with both http and https, or just https maybe? And is it possible something is causing the connection to be closed with partial data written by the server? I'm just wondering if this may be dotnet/corefx#29344. Long shot, as I would expect that to cause problems even without automatic decompression, but figured I'd ask.

[ayende]

Stack trace for the hang, client side:

 	System.Private.CoreLib.dll!System.Threading.ManualResetEventSlim.Wait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.SpinThenBlockingWait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.InternalWaitCore(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)	Unknown
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.ValueTaskAwaiter<int>.GetResult()	Unknown
	System.Net.Http.dll!System.Net.Http.HttpConnection.HttpContentReadStream.Read(byte[] buffer, int offset, int count)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.DeflateStream.ReadCore(System.Span<byte> buffer)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.DeflateStream.Read(byte[] array, int offset, int count)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.GZipStream.Read(byte[] array, int offset, int count)	Unknown
 	Sparrow.dll!Sparrow.PeepingTomStream.Read(byte[] buffer, int offset, int count) Line 27	C#
 	Sparrow.dll!Sparrow.Json.Parsing.UnmanagedJsonParserHelper.Read(Sparrow.PeepingTomStream stream, Sparrow.Json.Parsing.UnmanagedJsonParser parser, Sparrow.Json.Parsing.JsonParserState state, Sparrow.Json.JsonOperationContext.ManagedPinnedBuffer buffer) Line 30	C#
 	Raven.Client.dll!Raven.Client.Documents.Session.Operations.StreamOperation.SetResult(Raven.Client.Documents.Commands.StreamResult response) Line 89	C#
 	Raven.Client.dll!Raven.Client.Documents.Session.DocumentSession.Stream<>(string startsWith, string matches, int start, int pageSize, string startAfter) Line 129	C#

The URL is: http://127.0.0.1:56383

This is reading from System.Net.Http.HttpConnection.ChunkedEncodingReadStream.

I'm trying to reproduce this again in a way that I can send a dump.

[stephentoub]

@ayende, you mentioned you're only able to repro this as part of your full suite, not isolated. Can you tell what else is going on in the process, and in particular, what the threads in the thread pool look like? This stack trace shows that it's using the synchronous methods on these streams, but the synchronous methods on HttpClientHandler are all implemented as blocking on top of the async operations. I'm wondering if you're blocking all threads in the thread pool waiting for additional threads to be introduced to unblock whatever operation will allow these synchronous methods to continue. What does your process' thread count look like when you get these hangs? Is it slowly ticking up at 1 or 2 threads per second?

[ayende]

I left this running overnight, and I don't think this is it. There are a 112 threads, but not a lot of them.

The server side stack trace is:

 	System.Private.CoreLib.dll!System.Threading.ManualResetEventSlim.Wait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.SpinThenBlockingWait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.InternalWaitCore(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)	Unknown
 	Microsoft.AspNetCore.Server.Kestrel.Core.dll!Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpResponseStream.Write(byte[] buffer, int offset, int count)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.DeflateStream.WriteDeflaterOutput()	Unknown
 	System.IO.Compression.dll!System.IO.Compression.DeflateStream.WriteCore(System.ReadOnlySpan<byte> buffer)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.DeflateStream.Write(byte[] array, int offset, int count)	Unknown
 	System.IO.Compression.dll!System.IO.Compression.GZipStream.Write(byte[] array, int offset, int count)	Unknown
 	Microsoft.AspNetCore.ResponseCompression.dll!Microsoft.AspNetCore.ResponseCompression.BodyWrapperStream.Write(byte[] buffer, int offset, int count)	Unknown
>	Sparrow.dll!Sparrow.Json.AbstractBlittableJsonTextWriter.Flush() Line 515	C#
 	Sparrow.dll!Sparrow.Json.AbstractBlittableJsonTextWriter.EnsureBuffer(int len) Line 506	C#
 	Sparrow.dll!Sparrow.Json.AbstractBlittableJsonTextWriter.WriteString(Sparrow.Json.LazyStringValue str, bool skipEscaping) Line 268	C#
 	Raven.Server.dll!Raven.Server.Json.BlittableJsonTextWriterExtensions.WriteMetadata(Sparrow.Json.AbstractBlittableJsonTextWriter writer, Raven.Server.Documents.Document document, Sparrow.Json.BlittableJsonReaderObject metadata) Line 1206	C#
 	Raven.Server.dll!Raven.Server.Json.BlittableJsonTextWriterExtensions.WriteDocumentProperties(Sparrow.Json.AbstractBlittableJsonTextWriter writer, Sparrow.Json.JsonOperationContext context, Raven.Server.Documents.Document document) Line 1264	C#
 	Raven.Server.dll!Raven.Server.Json.BlittableJsonTextWriterExtensions.WriteDocumentInternal(Sparrow.Json.AbstractBlittableJsonTextWriter writer, Sparrow.Json.JsonOperationContext context, Raven.Server.Documents.Document document) Line 1229	C#
 	Raven.Server.dll!Raven.Server.Json.BlittableJsonTextWriterExtensions.WriteDocument(Sparrow.Json.AbstractBlittableJsonTextWriter writer, Sparrow.Json.JsonOperationContext context, Raven.Server.Documents.Document document, bool metadataOnly) Line 1000	C#
 	Raven.Server.dll!Raven.Server.Documents.Queries.StreamJsonDocumentQueryResultWriter.AddResult(Raven.Server.Documents.Document res) Line 56	C#

This is reproducible by two specific tests that stream a few tens of thousands of records.
I'm pretty sure that the Gzip is related to this somehow, because I can't reproduce this without it or on 2.0.

I have a dump file (154MB compressed) that I'm uploading now.

[stephentoub]

I'm pretty sure that the Gzip is related to this somehow, because I can't reproduce this without it or on 2.0

Have you tried mixing and matching, e.g. a 2.0 client with a 2.1 server, and a 2.1 client with a 2.0 server? Wondering if that would help to narrow it down.

[ayende]

Okay, something that might be related.

System.Threading.SynchronizationContext.Current = {Xunit.Sdk.AsyncTestSyncContext}

Looking here:
https://github.com/dotnet/corefx/blob/master/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpContentReadStream.cs#L40

Is it possible that there is a missing ConfigureAwait(false) that is causing this to deadlock?

[ayende]

Link to the dump file: https://drive.google.com/file/d/1dS9xAMgHz7B5ncTvlLdRvSDCanRWmjRs/view?usp=sharing

[stephentoub]

Is it possible that there is a missing ConfigureAwait(false) that is causing this to deadlock?

Yes. Are you able to build System.Net.Http.dll to try out a fix? Can you try adding .ConfigureAwait(false) to this line:
https://github.com/dotnet/corefx/blob/6906dbfe66609dd606c84b09462dc1ce1936ef7e/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/ChunkedEncodingReadStream.cs#L107
and see if that fixes your issue? Regardless, I'm going to fix that.

[stephentoub]

Re-opening to track 2.1 port.

[stephentoub]

Fixed in release/2.1 in PR dotnet/corefx#29470.