Http2_DataSentBeforeServerPreface_ProtocolError - failed

[ViktorHofer]

Test: System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError

https://dev.azure.com/dnceng/public/_build/results?buildId=180254&view=ms.vss-test-web.build-test-results-tab&runId=4352366&resultId=324794&paneView=debug

netcoreapp-OSX-Debug-x64-OSX.1012.Amd64.Open

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError

Assert.Contains() Failure\nNot found: PROTOCOL_ERROR\nIn value: System.Net.Http.HttpRequestException: Exception of type 'System.Net.Http.HttpRequestException' was thrown.\n at System.Net.Http.Http2Connection.AddStream(HttpRequestMessage request) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1411\n at System.Net.Http.Http2Connection.SendHeadersAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 975\n at System.Threading.Tasks.ValueTask`1.get_Result() in /Users/vsts/agent/2.150.3/work/1/s/src/System.Private.CoreLib/shared/System/Threading/Tasks/ValueTask.cs:line 759\n at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1356\n at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs:line 525\n at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs:line 33\n at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 496\n at Xunit.Assert.RecordExceptionAsync(Func`1 testCode) in C:\\projects\\xunit\\src\\xunit.assert\\Asserts\\Record.cs:line 82

   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.AssertProtocolErrorAsync(Task task, ProtocolErrors errorCode) in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 35
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError() in /Users/vsts/agent/2.150.3/work/1/s/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 119
--- End of stack trace from previous location where exception was thrown ---

cc @stephentoub @davidsh

[danmoseley]

Btw @ViktorHofer can you figure out why there are literal \n there? It would be nice to make these more readable (not specific to this test obviously).

[ViktorHofer]

Yeah the Unix logs produce \n and AzDO doesn't transform them to line breaks. Will open an issue on their side for it.

[ViktorHofer]

https://dev.azure.com/dnceng/internal/_workitems/edit/149

[AriNuer]

Same test System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError failed with similar exception:

Error message
Assert.Contains() Failure\nNot found: PROTOCOL_ERROR\nIn value: System.Net.Http.HttpRequestException: An error occurred while sending the request.\n ---> System.IO.IOException: The request was aborted.\n at System.Net.Http.Http2Connection.AcquireWriteLockAsync(CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 827\n at System.Net.Http.Http2Connection.StartWriteAsync(Int32 writeBytes, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 734\n at System.Net.Http.Http2Connection.SendHeadersAsync(HttpRequestMessage request, CancellationToken cancellationToken, Boolean mustFlush) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1184\n at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1658\n --- End of inner exception stack trace ---\n at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1725\n at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs:line 540\n at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs:line 33\n at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts) in /_/src/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 521\n at Xunit.Assert.RecordExceptionAsync(Func`1 testCode) in C:\\Dev\\xunit\\xunit\\src\\xunit.assert\\Asserts\\Record.cs:line 82

Stack trace
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.AssertProtocolErrorAsync[T](Task task, ProtocolErrors errorCode) in /_/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 39
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError() in /_/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 136
--- End of stack trace from previous location where exception was thrown ---

Details:
https://dnceng.visualstudio.com/public/_build/results?buildId=316080&view=ms.vss-test-web.build-test-results-tab&runId=9143904&resultId=160440&paneView=debug

[ViktorHofer]

@wfurt this is still failing in CI: https://dev.azure.com/dnceng/public/_build/results?buildId=334703&view=ms.vss-test-web.build-test-results-tab&runId=9856420&resultId=101223&paneView=debug (release/3.0 branch)

Assert.Contains() Failure\nNot found: PROTOCOL_ERROR\nIn value: System.Net.Http.HttpRequestException: An error occurred while sending the request.\n ---> System.IO.IOException: The request was aborted.\n at System.Net.Http.Http2Connection.AcquireWriteLockAsync(CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 825\n at System.Net.Http.Http2Connection.StartWriteAsync(Int32 writeBytes, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 700\n at System.Net.Http.Http2Connection.SendHeadersAsync(HttpRequestMessage request, CancellationToken cancellationToken, Boolean mustFlush) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1184\n at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1658\n --- End of inner exception stack trace ---\n at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1725\n at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs:line 541\n at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /_/src/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs:line 33\n at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts) in /_/src/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 521\n at Xunit.Assert.RecordExceptionAsync(Func`1 testCode) in C:\\Dev\\xunit\\xunit\\src\\xunit.assert\\Asserts\\Record.cs:line 88

   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.AssertProtocolErrorAsync[T](Task task, ProtocolErrors errorCode) in /_/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 39
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.Http2_DataSentBeforeServerPreface_ProtocolError() in /_/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs:line 135
--- End of stack trace from previous location where exception was thrown ---

[wfurt]

This failure is different than original one. I was able to reproduce by adding delay to SendHeadersAsync().

[karelz]

@wfurt are you still working on it? Or can @aik-jahoda take a look?

[wfurt]

he can certainly look :) I had some ideas but I'm focusing on ssl right now.