search

dotnet / aspnetcore

ASP.NET Core is a cross-platform .NET framework for building modern cloud-based web applications on Windows, Mac, or Linux.
https://asp.net
MIT License
35.19k stars 9.93k forks source link

LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps test failure #38086

Open captainsafia opened 2 years ago

captainsafia commented 2 years ago

Failing Test(s)

Error Message

System.IO.InvalidDataException : No StatusCode found in ''

Stacktrace

```text at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStatus(String response) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 114 at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.ReadResponse(Stream stream) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 98 at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStringAsync(Uri requestUri, Boolean validateCertificate) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 44 at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStringAsync(String requestUri, Boolean validateCertificate) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 30 at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) in /_/src/Shared/TaskExtensions.cs:line 90 at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.LoggingConnectionMiddlewareTests.LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps() in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/LoggingConnectionMiddlewareTests.cs:line 33 at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.LoggingConnectionMiddlewareTests.LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps() in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/LoggingConnectionMiddlewareTests.cs:line 35 --- End of stack trace from previous location --- ```

Logs

```text | [0.001s] TestLifetime Information: Starting test LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps at 2021-11-02T19:54:41 | [0.002s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting starting | [0.013s] Microsoft.Hosting.Lifetime Information: Now listening on: https://127.0.0.1:0 | [0.014s] Microsoft.AspNetCore.Hosting.Diagnostics Debug: Loaded hosting startup assembly InMemory.FunctionalTests | [0.014s] Microsoft.Hosting.Lifetime Information: Application started. Press Ctrl+C to shut down. | [0.014s] Microsoft.Hosting.Lifetime Information: Hosting environment: Production | [0.014s] Microsoft.Hosting.Lifetime Information: Content root path: C:\h\w\A9790944\w\B0920975\e\ | [0.014s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting started | [0.309s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMCU7AE8FEER" accepted. | [2.342s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMCU7AE8FEER" started. | [2.348s] Microsoft.AspNetCore.Server.Kestrel.Core.Internal.LoggingConnectionMiddleware Debug: ReadAsync[264] | 16 03 01 01 03 01 00 00 FF 03 03 BB 07 97 0B D1 ........ ÿ..»...Ñ | 18 57 11 0E 90 CB 91 AE EB 7D 2C E5 71 9B 5E 6F .W...Ë.® ë},åq.^o | 91 D4 9C C6 99 3B 8A 6E 6B F5 AF 20 BA 04 C8 C6 .Ô.Æ.;.n kõ¯ º.ÈÆ | 7F 52 35 D9 C3 16 6A 35 F8 9A 7E 65 D5 0B D9 78 .R5ÙÃ.j5 ø.~eÕ.Ùx | 0A E2 22 BD AF 92 C6 6B 49 05 25 6F 00 2C 13 02 .â"½¯.Æk I.%o.,.. | 13 01 C0 2C C0 2B C0 30 C0 2F 00 9F 00 9E C0 24 ..À,À+À0 À/....À$ | C0 23 C0 28 C0 27 C0 0A C0 09 C0 14 C0 13 00 9D À#À(À'À. À.À.À... | 00 9C 00 3D 00 3C 00 35 00 2F 01 00 00 8A 00 00 ...=.<.5 ./...... | 00 0E 00 0C 00 00 09 6C 6F 63 61 6C 68 6F 73 74 .......l ocalhost | 00 2B 00 09 08 03 04 03 03 03 02 03 01 00 0D 00 .+...... ........ | 1A 00 18 08 04 08 05 08 06 04 01 05 01 02 01 04 ........ ........ | 03 05 03 02 03 02 02 06 01 06 03 00 23 00 00 00 ........ ....#... | 0A 00 08 00 06 00 1D 00 17 00 18 00 33 00 26 00 ........ ....3.&. | 24 00 1D 00 20 CA C1 D9 5D 70 36 12 32 9E F2 1F $... ÊÁÙ ]p6.2.ò. | FF 93 26 5C F1 AF D7 6E 75 E7 20 4C 40 04 DA E3 ÿ.&\ñ¯×n uç L@.Úã | 03 84 F9 A6 37 00 31 00 00 00 17 00 00 FF 01 00 ..ù¦7.1. .....ÿ.. | 01 00 00 2D 00 02 01 01 ...-.... | [2.356s] Microsoft.AspNetCore.Server.Kestrel.Core.Internal.LoggingConnectionMiddleware Debug: WriteAsync[1276] | 16 03 03 00 7A 02 00 00 76 03 03 2A 42 51 A3 6D ....z... v..*BQ£m | 8C E1 9D 0E 45 5B 45 35 95 7F 99 B7 87 99 31 F1 .á..E[E5 ...·..1ñ | 98 CB CC 50 4C 62 E3 E7 C2 55 78 20 BA 04 C8 C6 .ËÌPLbãç ÂUx º.ÈÆ | 7F 52 35 D9 C3 16 6A 35 F8 9A 7E 65 D5 0B D9 78 .R5ÙÃ.j5 ø.~eÕ.Ùx | 0A E2 22 BD AF 92 C6 6B 49 05 25 6F 13 02 00 00 .â"½¯.Æk I.%o.... | 2E 00 2B 00 02 03 04 00 33 00 24 00 1D 00 20 EB ..+..... 3.$... ë | A0 A5 88 6A 06 A1 16 EE 08 AD 21 40 D1 62 DE 32  ¥.j.¡.î .­!@ÑbÞ2 | 4C F8 5E 1B 8D 4C 8E AD B2 0C 69 60 F5 DE 58 14 Lø^..L.­ ².i`õÞX. | 03 03 00 01 01 17 03 03 04 72 09 C6 7B 87 EF 65 ........ .r.Æ{.ïe | 6C FC 84 F8 C5 C7 B9 41 81 C2 3D C8 EB A5 40 30 lü.øÅǹA .Â=Èë¥@0 | 2F 56 D6 ED 37 59 F4 7C 73 A8 34 C1 69 79 40 A3 /VÖí7Yô| s¨4Áiy@£ | D2 59 E4 08 5B E0 C6 10 E2 75 EB E0 5C 76 9E 45 ÒYä.[àÆ. âuëà\v.E | 65 41 D4 91 BC E1 E3 06 17 77 96 6B 8F 77 0D 33 eAÔ.¼áã. .w.k.w.3 | 45 5B 21 4D 09 4C 65 E5 C5 E8 93 B4 6D 76 80 0C E[!M.Leå Åè.´mv.. | 2B 8F CE 0D 0B DE 7E CE D2 5B F3 EA 54 48 85 05 +.Î..Þ~Î Ò[óêTH.. | 2A 95 6F 91 53 D5 A2 C0 13 0D E9 C8 11 AA B9 6D *.o.SÕ¢À ..éÈ.ª¹m | 31 D0 1B A3 74 BF ED 73 FC 94 8D BC 61 BC 03 26 1Ð.£t¿ís ü..¼a¼.& | 38 27 46 2F B1 81 43 57 BE 8A 18 9B 5F 86 99 7B 8'F/±.CW ¾..._..{ | 58 B7 A9 71 4B 87 FB B3 78 31 95 1A 22 C8 92 CC X·©qK.û³ x1.."È.Ì | 2E 33 C6 85 06 90 6A E6 7E 3A BD FC 76 4A A9 18 .3Æ...jæ ~:½üvJ©. | 0F 21 46 9B 73 38 FB 92 AA 68 07 39 78 86 57 A9 .!F.s8û. ªh.9x.W© | 37 86 76 E4 3A 49 EC C6 48 93 76 29 79 0E 0D 60 7.vä:IìÆ H.v)y..` | 69 A8 FF D4 DC B9 31 32 07 12 B1 40 CB E0 04 B5 i¨ÿÔܹ12 ..±@Ëà.µ | 31 CA C9 A3 81 9C C1 4B BF 15 B0 99 78 37 B2 4E 1ÊÉ£..ÁK ¿.°.x7²N | A6 56 0E DC 84 88 35 9F F0 79 B3 2B DB 5E 56 22 ¦V.Ü..5. ðy³+Û^V" | 4A 96 8D BA CD A2 94 7B 7E 2F FA A0 40 0D 0E C2 J..ºÍ¢.{ ~/ú @.. | 6E DB F9 C3 22 EF 13 28 2B 23 DF 76 C3 14 D8 1D nÛùÃ"ï.( +#ßvÃ.Ø. | 25 6A B4 1C 49 4A 2A 72 1E 3E 7A 92 5E 5F A9 C5 %j´.IJ*r .>z.^_©Å | 86 CB 70 B0 89 53 4B 74 8C C5 6D 42 E2 24 19 04 .Ëp°.SKt .ÅmBâ$.. | D1 FD 76 B7 A9 A6 27 37 5F A3 CF A9 EE 2D 7A EF Ñýv·©¦'7 _£Ï©î-zï | 1C 53 42 3A 1B 15 B5 0A EB 77 5A 3B DE F8 66 65 .SB:..µ. ëwZ;Þøfe | 77 D4 59 FC AD 0E 19 3C 61 DF A2 55 44 A8 96 47 wÔYü­..< aߢUD¨.G | AA F8 42 31 C5 A6 07 F3 A3 51 97 8B E8 9D 58 CE ªøB1Ŧ.ó £Q..è.XÎ | AF 82 11 6B EC BA 99 61 F9 9B 48 16 6C 76 17 4A ¯..kìº.a ù.H.lv.J | 88 22 D0 93 E3 D2 FE 4E 83 D1 72 BC 2A 19 FA BB ."Ð.ãÒþN .Ñr¼*.ú» | 1A 27 4E 77 84 C0 73 6B 3B 85 4B 04 A3 29 81 3F .'Nw.Àsk ;.K.£).? | 2D 9B CC CF FB 8A B8 FE 5E A1 1A 0F 85 2C B4 E7 -.ÌÏû.¸þ ^¡...,´ç | FF 77 04 49 D8 52 D9 F7 9A 17 F9 49 7B 9B 9A B5 ÿw.IØRÙ÷ ..ùI{..µ | 82 ED 90 7B 67 85 F7 A6 5A 0B E3 D0 46 13 9D 84 .í.{g.÷¦ Z.ãÐF... | 90 2D D2 C1 0F 35 AA BF 4B 56 94 AF F6 F3 64 19 .-ÒÁ.5ª¿ KV.¯öód. | 46 5C C1 01 81 06 98 28 B1 A6 3D E5 45 9F B9 E9 F\Á....( ±¦=åE.¹é | F8 80 69 73 63 EA 56 5C 5B 1C 6F C6 AB 74 7C 35 ø.iscêV\ [.oÆ«t|5 | F4 24 BC FB 07 5E DF 8A 7D B5 BB 23 64 8F 99 E4 ô$¼û.^ß. }µ»#d..ä | 51 A4 47 8D 02 84 EE C6 F6 A8 A7 86 0F 9F 94 77 Q¤G...îÆ ö¨§....w | 7A 26 D1 72 3F CC B8 9B 0B BD 61 FE 2D 42 6D 07 z&Ñr?̸. .½aþ-Bm. | 3C 08 7F 2A 8A 50 B5 B4 57 C8 AF 3E C0 07 1B 78 <..*.Pµ´ Wȯ>À..x | 65 3A 2F F7 8F 23 59 1E 21 90 D3 98 8C D8 60 8A e:/÷.#Y. !.Ó..Ø`. | 10 9E 93 49 19 7A ED C2 60 4B AF 20 D4 31 36 A3 ...I.zí `K¯ Ô16£ | C9 76 C2 B2 5C 02 9B DA FC B9 E9 71 A8 6E 6B 4C Év²\..Ú ü¹éq¨nkL | 02 E2 3B A8 81 0F 50 F7 B4 C5 60 A6 F8 37 31 7A .â;¨..P÷ ´Å`¦ø71z | 2B CC 6A C4 E0 A3 D1 4E 23 8A 23 40 AB AC 5A 29 +ÌjÄà£ÑN #.#@«¬Z) | 3C 26 7B 7D F2 C4 9C 34 AA 3F 6F 70 1A C4 6D D8 <&{}òÄ.4 ª?op.ÄmØ | 6A D8 47 88 FF 8F B4 35 21 9B C9 E4 E7 F8 A3 6B jØG.ÿ.´5 !.Éäçø£k | DD 6B 88 BB D8 3A DD 92 0F 9E 2B C4 C8 CC 3B C4 Ýk.»Ø:Ý. ..+ÄÈÌ;Ä | 31 06 89 27 6F C2 16 A9 88 53 D1 70 93 E9 77 F1 1..'oÂ.© .SÑp.éwñ | BE 00 66 E0 7F E5 2F 3A F8 4F 0D C9 2A E6 0B 68 ¾.fà.å/: øO.É*æ.h | E5 A4 AA EC 96 51 E0 AD D1 E9 F9 3B 80 4E D7 60 太ì.Qà­ Ñéù;.N×` | E8 13 65 B2 96 3B 81 11 F0 31 12 7C F1 D6 0D F1 è.e².;.. ð1.|ñÖ.ñ | C5 4B DC 88 98 ED 86 62 B4 AE BC 10 D8 0A 1A 99 ÅKÜ..í.b ´®¼.Ø... | 4E 75 F4 17 C9 37 A9 B8 EE BE A9 65 29 70 AE 31 Nuô.É7©¸ e)p®1 | 73 91 9B 9F 5D B1 59 72 7A 50 D8 E3 14 B7 5F 04 s...]±Yr zPØã.·_. | CD CD 92 0C 37 F1 8D 08 48 F3 87 D5 5E EF BC 5D ÍÍ..7ñ.. Hó.Õ^ï¼] | E3 CA D1 E6 7A A1 EF 15 46 09 D5 FA 5E 89 DB 3F ãÊÑæz¡ï. F.Õú^.Û? | 10 9F 4B E7 E7 B2 1B 53 3F C1 61 CF 9B BA 78 DF ..Kçç².S ?ÁaÏ.ºxß | 07 43 DC 80 30 C2 98 32 12 6D 92 E5 39 AA D3 7C .CÜ.0Â.2 .m.å9ªÓ| | 4D 90 F3 74 97 52 AD 42 22 6A 2D 21 7F D5 51 9D M.ót.R­B "j-!.ÕQ. | 03 A4 31 C6 99 00 EB D3 07 BC 5F 5E A4 D7 81 91 .¤1Æ..ëÓ .¼_^¤×.. | 87 E4 4F 5E 51 A7 4E CC 55 A9 32 32 F9 22 FC 69 .äO^Q§NÌ U©22ù"üi | 8C E9 0E 8E 69 B6 4F 61 EE FD 23 1C 15 27 5F B9 .é..i¶Oa îý#..'_¹ | 54 4A 8D 2A E4 B7 3D 81 EF 56 67 C8 DB 3F 3E 67 TJ.*ä·=. ïVgÈÛ?>g | 5C 85 B4 E0 CA 3B 28 24 C8 F7 C4 D3 63 5A 7E 85 \.´àÊ;($ È÷ÄÓcZ~. | F3 06 36 78 45 61 22 A8 8B 2A 78 53 B7 FC AE B5 ó.6xEa"¨ .*xS·ü®µ | 95 21 AC CD E4 A9 AB 6C 51 D7 BF 72 F0 27 CD FC .!¬Íä©«l Q׿rð'Íü | FD FA EE 02 17 F5 FD C4 81 8F A6 8C 32 CD 35 79 ýúî..õýÄ ..¦.2Í5y | BD 26 5B B6 4F 32 BC 8F C3 21 EC 36 4A A7 13 57 ½&[¶O2¼. Ã!ì6J§.W | 36 1A B1 9B CB AB 03 AC 30 5E F5 B0 DB 3A 62 B0 6.±.Ë«.¬ 0^õ°Û:b° | 72 18 8C 07 0F 6A 83 F6 70 B1 DB 32 51 D7 68 48 r....j.ö p±Û2Q×hH | 71 BA 9F BA D8 50 94 CC 04 27 66 57 CB 3B 30 D6 qº.ºØP.Ì .'fWË;0Ö | 21 BC 60 8D 97 FA 22 22 11 6C 06 E1 13 6A 55 58 !¼`..ú"" .l.á.jUX | B4 B6 3F 8A 71 1C 94 A5 F4 0C 71 96 ´¶?.q..¥ ô.q. | [12.789s] Microsoft.AspNetCore.Server.Kestrel.Https.Internal.HttpsConnectionMiddleware Debug: Authentication of the HTTPS connection timed out. | [12.790s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMCU7AE8FEER" stopped. | [13.369s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting stopping | [13.667s] Microsoft.Hosting.Lifetime Information: Application is shutting down... | [13.721s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting stopped | [13.731s] Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.LoggingConnectionMiddlewareTests Error: Test threw an exception. | System.IO.InvalidDataException: No StatusCode found in '' | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStatus(String response) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 114 | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.ReadResponse(Stream stream) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 98 | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStringAsync(Uri requestUri, Boolean validateCertificate) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 44 | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport.InMemoryHttpClientSlim.GetStringAsync(String requestUri, Boolean validateCertificate) in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/InMemoryHttpClientSlim.cs:line 30 | at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) in /_/src/Shared/TaskExtensions.cs:line 90 | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.LoggingConnectionMiddlewareTests.LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps() in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/LoggingConnectionMiddlewareTests.cs:line 33 | at Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.LoggingConnectionMiddlewareTests.LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps() in /_/src/Servers/Kestrel/test/InMemory.FunctionalTests/LoggingConnectionMiddlewareTests.cs:line 35 | at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_1.<b__1>d.MoveNext() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestInvoker.cs:line 273 | --- End of stack trace from previous location --- | at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\ExecutionTimer.cs:line 54 | at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 96 | [14.247s] TestLifetime Information: Finished test LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps in 13.7437883s ```

Build

Tratcher commented 2 years ago

Failed on Win11... Kestrel responded to the client-hello, but then the client never completed the handshake or sent the request. Related to our other Win11 issues?

halter73 commented 2 years ago

Win11 was also the first thing I looked for. The super slow handshake does make me wonder if we're overwhelming the helix agents in the Win11 queue which might be contributing to the other failures. Of course, data corruption isn't acceptable even on an overburdened machine, but it might explain why the other issues have only appeared on this queue if it happens not to be platform-specific.

We still haven't seen data corruption in memory, so we can't rule out an issue at the socket layer. I'm going to look at updating some of the Interop.FunctionalTests to use the in-memory transport and ConnectCallback.

Tratcher commented 2 years ago

One big difference about this test, it's not using HttpClient or Sockets, only HttpClientSlim and SslStream in-memory. Or am I reading it wrong?

Tratcher commented 2 years ago

Ah, there is one difference on Win11 that will explain part of this: TLS 1.3 is enabled by default, and it uses a shorter handshake. There's a single Client-Hello and Server-Hello which matches the log above and explains why the SslStream didn't fail when the connection was closed. (I haven't tried parsing out the raw TLS to confirm this yet)

https://cabulous.medium.com/tls-1-2-andtls-1-3-handshake-walkthrough-4cfd0a798164#3252

Next questions:

ghost commented 2 years ago

Thanks for contacting us.

We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We would like to keep this around to collect more feedback, which can help us with prioritizing this work. We will re-evaluate this issue, during our next planning meeting(s). If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

amcasey commented 9 months ago

Hasn't failed in 30 days.

captainsafia commented 9 months ago

Hasn't failed in 30 days.

Do you happen to know if there is a product change that resulted in the tests passing?

amcasey commented 9 months ago

Nope, but a lot has changed in two years, both in kestrel and in underlying layers.

captainsafia commented 9 months ago

Nope, but a lot has changed in two years, both in kestrel and in underlying layers.

I see. I believe we've recently adopted a pattern of unquarantining things after a test-fixed PR has gone out but considering the age of this one it might be fine to unquarantine and see if they come back.