Azure / DotNetty

DotNetty project – a port of netty, event-driven asynchronous network application framework
Other
4.09k stars 977 forks source link

SniHandlerTest TlsRead(Write) timeout on net452 and netcoreapp2.1(preview)? #353

Closed yyjdelete closed 6 years ago

yyjdelete commented 6 years ago

I mean the test with net452, but my system is win10x64(17083 Insider Preview), so the runtime should be net471. And I doesn't see that with net452 on ci server.

Not sure happened, will try and attach some debug info latter.

BTW: Why the test for DotNetty.Buffers is 20 times slower in net452 than netcoreapp1.1?


Update:

  1. That only happen with (isClient: True).
  2. I comment out TaskExtensions.WithTimeout(TimeSpan) and watch all FirstChanceException. 2.1 Seems it will never finish. 2.2 An FirstChanceException throw at AuthenticateAsServerAsync(Not throw to DotNetty's code) (Translate to English by Google) System.Security.Authentication.AuthenticationException: 'The call to SSPI failed, see internal exception. ' Internal exception: Win32Exception: The client and server can not communicate because of different algorithms May be related to https://github.com/dotnet/corefx/issues/26186 ?
``` System.dll!System.Net.Security.SslState.StartSendAuthResetSignal(System.Net.Security.ProtocolToken message, System.Net.AsyncProtocolRequest asyncRequest, System.Exception exception) System.dll!System.Net.Security.SslState.CheckCompletionBeforeNextReceive(System.Net.Security.ProtocolToken message, System.Net.AsyncProtocolRequest asyncRequest) System.dll!System.Net.Security.SslState.StartSendBlob(byte[] incoming, int count, System.Net.AsyncProtocolRequest asyncRequest) System.dll!System.Net.Security.SslState.ProcessReceivedBlob(byte[] buffer, int count, System.Net.AsyncProtocolRequest asyncRequest) System.dll!System.Net.Security.SslState.StartReadFrame(byte[] buffer, int readBytes, System.Net.AsyncProtocolRequest asyncRequest) System.dll!System.Net.Security.SslState.PartialFrameCallback(System.Net.AsyncProtocolRequest asyncRequest = {System.Net.AsyncProtocolRequest}) System.dll!System.Net.AsyncProtocolRequest.CompleteRequest(int result) System.dll!System.Net.FixedSizeReader.CheckCompletionBeforeNextRead(int bytes) System.dll!System.Net.FixedSizeReader.ReadCallback(System.IAsyncResult transportResult) > DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.MediationStream.ExpandSource(int count = 781) Line 726 DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.Unwrap(DotNetty.Transport.Channels.IChannelHandlerContext ctx = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer packet = {DotNetty.Buffers.UnpooledHeapByteBuffer}, int offset = 0, int length = 781, System.Collections.Generic.List packetLengths = Count = 1, System.Collections.Generic.List output = Count = 0) Line 329 DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.Decode(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer input = {DotNetty.Buffers.UnpooledHeapByteBuffer}, System.Collections.Generic.List output = Count = 0) Line 267 DotNetty.Codecs.dll!DotNetty.Codecs.ByteToMessageDecoder.CallDecode(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer input = {DotNetty.Buffers.UnpooledHeapByteBuffer}, System.Collections.Generic.List output = Count = 0) Line 320 DotNetty.Codecs.dll!DotNetty.Codecs.ByteToMessageDecoder.ChannelRead(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, object message = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 194 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.InvokeChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 524 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.InvokeChannelRead(DotNetty.Transport.Channels.AbstractChannelHandlerContext next = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 510 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.FireChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 498 DotNetty.Transport.dll!DotNetty.Transport.Channels.DefaultChannelPipeline.FireChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 808 DotNetty.Transport.dll!DotNetty.Transport.Channels.Embedded.EmbeddedChannel.WriteInbound(object[] msgs = {object[1]}) Line 258 DotNetty.Handlers.Tests.dll!DotNetty.Handlers.Tests.AsIsWriteStrategy.WriteToChannelAsync(DotNetty.Transport.Channels.Embedded.EmbeddedChannel channel = {DotNetty.Transport.Channels.Embedded.EmbeddedChannel}, System.ArraySegment input = {System.ArraySegment}) Line 16 DotNetty.Handlers.Tests.dll!DotNetty.Handlers.Tests.SniHandlerTest.SetupStreamAndChannelAsync.AnonymousMethod__10() Line 233 ... ```

2.3 Another FirstChanceException throw at AuthenticateAsServerAsync(Not throw to DotNetty's code), almost the same as 2.2 (Translate to English by Google) System.Security.Authentication.AuthenticationException: 'The call to SSPI failed, see internal exception. ' Internal exception: Win32Exception: The client and server can not communicate because of different algorithms

``` System.dll!System.Net.Security.SslState.InternalEndProcessAuthentication(System.Net.LazyAsyncResult lazyResult) System.dll!System.Net.Security.SslState.EndProcessAuthentication(System.IAsyncResult result) System.dll!System.Net.Security.SslStream.EndAuthenticateAsClient(System.IAsyncResult asyncResult) mscorlib.dll!System.Threading.Tasks.TaskFactory.FromAsyncCoreLogic(System.IAsyncResult iar, System.Func endFunction, System.Action endAction, System.Threading.Tasks.Task promise = Id = 167, Status = WaitingForActivation, Method = "{null}", Result = "{尚未计算}", bool requiresSynchronization = true) mscorlib.dll!System.Threading.Tasks.TaskFactory.FromAsyncImpl.AnonymousMethod__0(System.IAsyncResult iar) System.dll!System.Net.LazyAsyncResult.Complete(System.IntPtr userToken) System.dll!System.Net.LazyAsyncResult.ProtectedInvokeCallback(object result, System.IntPtr userToken) System.dll!System.Net.Security.SslState.FinishHandshake(System.Exception e = {"调用 SSPI 失败,请参见内部异常。"}, System.Net.AsyncProtocolRequest asyncRequest = {System.Net.AsyncProtocolRequest}) System.dll!System.Net.Security.SslState.PartialFrameCallback(System.Net.AsyncProtocolRequest asyncRequest) System.dll!System.Net.AsyncProtocolRequest.CompleteRequest(int result) System.dll!System.Net.FixedSizeReader.CheckCompletionBeforeNextRead(int bytes) System.dll!System.Net.FixedSizeReader.ReadCallback(System.IAsyncResult transportResult) > DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.MediationStream.ExpandSource(int count = 781) Line 726 DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.Unwrap(DotNetty.Transport.Channels.IChannelHandlerContext ctx = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer packet = {DotNetty.Buffers.UnpooledHeapByteBuffer}, int offset = 0, int length = 781, System.Collections.Generic.List packetLengths = Count = 1, System.Collections.Generic.List output = Count = 0) Line 329 DotNetty.Handlers.dll!DotNetty.Handlers.Tls.TlsHandler.Decode(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer input = {DotNetty.Buffers.UnpooledHeapByteBuffer}, System.Collections.Generic.List output = Count = 0) Line 267 DotNetty.Codecs.dll!DotNetty.Codecs.ByteToMessageDecoder.CallDecode(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, DotNetty.Buffers.IByteBuffer input = {DotNetty.Buffers.UnpooledHeapByteBuffer}, System.Collections.Generic.List output = Count = 0) Line 320 DotNetty.Codecs.dll!DotNetty.Codecs.ByteToMessageDecoder.ChannelRead(DotNetty.Transport.Channels.IChannelHandlerContext context = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, object message = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 194 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.InvokeChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 524 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.InvokeChannelRead(DotNetty.Transport.Channels.AbstractChannelHandlerContext next = {DotNetty.Transport.Channels.DefaultChannelHandlerContext}, object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 510 DotNetty.Transport.dll!DotNetty.Transport.Channels.AbstractChannelHandlerContext.FireChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 498 DotNetty.Transport.dll!DotNetty.Transport.Channels.DefaultChannelPipeline.FireChannelRead(object msg = {DotNetty.Buffers.UnpooledHeapByteBuffer}) Line 808 DotNetty.Transport.dll!DotNetty.Transport.Channels.Embedded.EmbeddedChannel.WriteInbound(object[] msgs = {object[1]}) Line 258 DotNetty.Handlers.Tests.dll!DotNetty.Handlers.Tests.AsIsWriteStrategy.WriteToChannelAsync(DotNetty.Transport.Channels.Embedded.EmbeddedChannel channel = {DotNetty.Transport.Channels.Embedded.EmbeddedChannel}, System.ArraySegment input = {System.ArraySegment}) Line 16 DotNetty.Handlers.Tests.dll!DotNetty.Handlers.Tests.SniHandlerTest.SetupStreamAndChannelAsync.AnonymousMethod__10() Line 233 ... ```

2.4 The 3rd FirstChanceException, timeout, but won't stop the test.(Exception not set to MediationStream.BeginRead) Xunit.Sdk.TrueException: 'Did not reach expected state in time.'

> 
DotNetty.Tests.Common.dll!DotNetty.Tests.Common.AssertEx.EventuallyAsync(Func<Task<bool>> testFunc = {Task<bool> <ReadOutboundAsync>b__0()}, TimeSpan interval = {0.01s}, TimeSpan timeout = {10s}) Line 26
StormHub commented 6 years ago

Can you try upgrade xunit and run again to find out? I vaguely remember saw something like that in the past

yyjdelete commented 6 years ago

I can also reprouduct this with ConsoleApp and the same code. And I Found it's net472(preview) in my pc.

CLIENT(BAD) +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 16 03 03 00 C3 01 00 00 BF 03 03 5A 73 01 65 C2 |...........Zs.e.| |100000010| 7F 7D 72 B8 B5 6D 1D 3E F7 62 7A 8B B4 09 8D 0A |.}r..m.>.bz.....| |100000020| 13 20 CD B2 FF 28 73 5F 08 F6 A5 20 5B 42 00 00 |. ...(s_... [B..| |100000030| 45 54 E1 E6 32 15 6E 21 F9 A0 9C E4 4D 6B 10 F3 |ET..2.n!....Mk..| |100000040| 19 BE 2C 33 AE BE EF CC 12 C1 64 28 00 2A C0 2C |..,3......d(.*.,| |100000050| C0 2B C0 30 C0 2F 00 9F 00 9E C0 24 C0 23 C0 28 |.+.0./.....$.#.(| |100000060| C0 27 C0 0A C0 09 C0 14 C0 13 00 9D 00 9C 00 3D |.'.............=| |100000070| 00 3C 00 35 00 2F 00 0A 01 00 00 4C 00 00 00 11 |.<.5./.....L....| |100000080| 00 0F 00 00 0C 64 6F 74 6E 65 74 74 79 2E 63 6F |.....dotnetty.co| |100000090| 6D 00 0A 00 08 00 06 00 1D 00 17 00 18 00 0B 00 |m...............| |1000000A0| 02 01 00 00 0D 00 14 00 12 04 01 05 01 02 01 04 |................| |1000000B0| 03 05 03 02 03 02 02 06 01 06 03 00 23 00 00 00 |............#...| |1000000C0| 17 00 00 FF 01 00 01 00 |........ | +--------+-------------------------------------------------+----------------+ +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 16 03 01 03 08 02 00 00 51 03 01 5A 73 01 65 32 |........Q..Zs.e2| |100000010| 3B C6 38 A5 2C 7E 78 90 2E 08 AD 7C 6A 93 C5 3E |;.8.,~x....|j..>| |100000020| 7B 10 A0 C2 7B E3 5E 9C 26 A6 8C 20 73 21 00 00 |{...{.^.&.. s!..| |100000030| F9 BE 96 4C 23 D9 F0 6D 6B 67 8A AD 66 91 9E 62 |...L#..mkg..f..b| |100000040| 09 BE D9 AC 6B 17 F3 8A 01 6E 0C 95 C0 14 00 00 |....k....n......| |100000050| 09 00 17 00 00 FF 01 00 01 00 0B 00 02 01 00 01 |................| |100000060| FE 00 01 FB 30 82 01 F7 30 82 01 64 A0 03 02 01 |....0...0..d....| |100000070| 02 02 10 70 B4 FB 67 91 CA 19 96 4E 2C 3F D9 93 |...p..g....N,?..| |100000080| E7 0F 32 30 09 06 05 2B 0E 03 02 1D 05 00 30 17 |..20...+......0.| |100000090| 31 15 30 13 06 03 55 04 03 13 0C 64 6F 74 6E 65 |1.0...U....dotne| |1000000A0| 74 74 79 2E 63 6F 6D 30 1E 17 0D 31 35 30 31 30 |tty.com0...15010| |1000000B0| 31 30 37 30 30 30 30 5A 17 0D 32 35 30 31 30 31 |1070000Z..250101| |1000000C0| 30 37 30 30 30 30 5A 30 17 31 15 30 13 06 03 55 |070000Z0.1.0...U| |1000000D0| 04 03 13 0C 64 6F 74 6E 65 74 74 79 2E 63 6F 6D |....dotnetty.com| |1000000E0| 30 81 9F 30 0D 06 09 2A 86 48 86 F7 0D 01 01 01 |0..0...*.H......| |1000000F0| 05 00 03 81 8D 00 30 81 89 02 81 81 00 D1 30 DF |......0.......0.| |100000100| 08 06 C5 3F B9 91 FA BE A9 6C 37 0A BB F6 33 78 |...?.....l7...3x| |100000110| BA 3F 51 8C C4 E1 B4 E0 0D 7E 75 81 B3 31 80 95 |.?Q......~u..1..| |100000120| 60 2E 31 4F B9 BE 80 FA 37 4F 82 60 DC 22 24 57 |`.1O....7O.`."$W| |100000130| 39 E9 6A 63 0C D5 82 0E E1 AD E5 DD BD 5C 5A E2 |9.jc.........\Z.| |100000140| 8E 82 5C 9D 30 EA 3F 4C 24 6F F5 84 39 8F A3 5E |..\.0.?L$o..9..^| |100000150| C9 6F 04 56 35 AF FC 5C 9E 5D 2A 94 8E 77 D0 55 |.o.V5..\.]*..w.U| |100000160| D5 F5 07 BB 2F 0B EB 00 BC B1 81 45 8C F8 C5 AE |..../......E....| |100000170| D8 73 CE DD 95 89 01 99 6A 39 63 32 49 02 03 01 |.s......j9c2I...| |100000180| 00 01 A3 4C 30 4A 30 48 06 03 55 1D 01 04 41 30 |...L0J0H..U...A0| |100000190| 3F 80 10 4D 9C 37 E8 DB DF 95 19 35 1E 1C 11 81 |?..M.7.....5....| |1000001A0| A1 97 64 A1 19 30 17 31 15 30 13 06 03 55 04 03 |..d..0.1.0...U..| |1000001B0| 13 0C 64 6F 74 6E 65 74 74 79 2E 63 6F 6D 82 10 |..dotnetty.com..| |1000001C0| 70 B4 FB 67 91 CA 19 96 4E 2C 3F D9 93 E7 0F 32 |p..g....N,?....2| |1000001D0| 30 09 06 05 2B 0E 03 02 1D 05 00 03 81 81 00 47 |0...+..........G| |1000001E0| 38 1C E4 C1 BC E4 CE A4 27 E1 B7 B3 34 7A 2B EC |8.......'...4z+.| |1000001F0| C1 2F BE EF C4 63 49 DB DF C8 DB 14 B6 73 26 39 |./...cI......s&9| |100000200| 7A DC 7F E8 02 E9 B0 D2 B1 F7 7A C0 08 BE 30 67 |z.........z...0g| |100000210| A2 AB D7 E2 8E 48 A9 2D 64 1E 0C 3C FA DD 91 6A |.....H.-d..<...j| |100000220| 33 8D 8C 65 CB 77 67 6E 57 82 36 D1 B0 10 D9 CD |3..e.wgnW.6.....| |100000230| B5 64 FF 64 1B C6 DB D8 9A 7E E9 71 F6 37 74 E0 |.d.d.....~.q.7t.| |100000240| 39 E7 51 7B E8 7C 35 BE 1F 64 3B 01 CC 1F AB 89 |9.Q{.|5..d;.....| |100000250| 14 B1 FF 20 FA F8 A7 A2 19 BE C3 04 3F 5C EA 0C |... ........?\..| |100000260| 00 00 A6 03 00 1D 20 F4 B7 DF 48 CB A5 69 CA 08 |...... ...H..i..| |100000270| 72 41 CB 47 F8 6E 49 60 EF C3 15 18 E5 FE 12 EA |rA.G.nI`........| |100000280| C9 27 A1 D8 E5 45 00 00 80 2B 29 6D F7 B1 99 32 |.'...E...+)m...2| |100000290| B1 D0 20 BB 74 68 86 DC 1D 83 FB 8E ED C8 14 45 |.. .th.........E| |1000002A0| 59 C0 16 1C A9 26 5D E2 1B EC A9 5D 4F CF A0 60 |Y....&]....]O..`| |1000002B0| 26 3A 2F 65 97 C6 25 BD D7 48 E8 3E 68 51 33 BB |&:/e..%..H.>hQ3.| |1000002C0| F8 F7 B4 A6 8F A6 3C FD 6B 1C 03 CF A8 75 13 D0 |......<.k....u..| |1000002D0| 80 3A 68 24 D3 2D 8B 61 D5 F8 85 F9 0C 23 01 23 |.:h$.-.a.....#.#| |1000002E0| E1 38 6A 44 2C 64 3C F5 63 95 0E 82 EE 11 3C 08 |.8jD,d<.c.....<.| |1000002F0| E9 E3 2A 42 79 92 BB A4 5A 1A B2 BE EF 1A 2E 1E |..*By...Z.......| |100000300| BF 7B 79 DC B3 16 86 00 B4 0E 00 00 00 |.{y.......... | +--------+-------------------------------------------------+----------------+ ************************************************ SERVER(GOOD) +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 16 03 03 00 A3 01 00 00 9F 03 03 5A 73 01 64 B5 |...........Zs.d.| |100000010| D3 38 93 40 6C 97 AC 03 BF 83 D8 93 E8 AB B2 3D |.8.@l..........=| |100000020| B3 53 B3 AB 10 4D 96 7D A8 3D E3 00 00 2A C0 2C |.S...M.}.=...*.,| |100000030| C0 2B C0 30 C0 2F 00 9F 00 9E C0 24 C0 23 C0 28 |.+.0./.....$.#.(| |100000040| C0 27 C0 0A C0 09 C0 14 C0 13 00 9D 00 9C 00 3D |.'.............=| |100000050| 00 3C 00 35 00 2F 00 0A 01 00 00 4C 00 00 00 11 |.<.5./.....L....| |100000060| 00 0F 00 00 0C 64 6F 74 6E 65 74 74 79 2E 63 6F |.....dotnetty.co| |100000070| 6D 00 0A 00 08 00 06 00 1D 00 17 00 18 00 0B 00 |m...............| |100000080| 02 01 00 00 0D 00 14 00 12 04 01 05 01 02 01 04 |................| |100000090| 03 05 03 02 03 02 02 06 01 06 03 00 23 00 00 00 |............#...| |1000000A0| 17 00 00 FF 01 00 01 00 |........ | +--------+-------------------------------------------------+----------------+ +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 16 03 03 03 0A 02 00 00 51 03 03 5A 73 01 64 E2 |........Q..Zs.d.| |100000010| FA 21 0E EE 56 AF 38 AC 03 8D A1 74 95 DA A7 AD |.!..V.8....t....| |100000020| 6E F5 7A DE 09 DF 23 4A B4 F0 4E 20 5B 42 00 00 |n.z...#J..N [B..| |100000030| 45 54 E1 E6 32 15 6E 21 F9 A0 9C E4 4D 6B 10 F3 |ET..2.n!....Mk..| |100000040| 19 BE 2C 33 AE BE EF CC 12 C1 64 28 C0 30 00 00 |..,3......d(.0..| |100000050| 09 00 17 00 00 FF 01 00 01 00 0B 00 02 01 00 01 |................| |100000060| FE 00 01 FB 30 82 01 F7 30 82 01 64 A0 03 02 01 |....0...0..d....| |100000070| 02 02 10 70 B4 FB 67 91 CA 19 96 4E 2C 3F D9 93 |...p..g....N,?..| |100000080| E7 0F 32 30 09 06 05 2B 0E 03 02 1D 05 00 30 17 |..20...+......0.| |100000090| 31 15 30 13 06 03 55 04 03 13 0C 64 6F 74 6E 65 |1.0...U....dotne| |1000000A0| 74 74 79 2E 63 6F 6D 30 1E 17 0D 31 35 30 31 30 |tty.com0...15010| |1000000B0| 31 30 37 30 30 30 30 5A 17 0D 32 35 30 31 30 31 |1070000Z..250101| |1000000C0| 30 37 30 30 30 30 5A 30 17 31 15 30 13 06 03 55 |070000Z0.1.0...U| |1000000D0| 04 03 13 0C 64 6F 74 6E 65 74 74 79 2E 63 6F 6D |....dotnetty.com| |1000000E0| 30 81 9F 30 0D 06 09 2A 86 48 86 F7 0D 01 01 01 |0..0...*.H......| |1000000F0| 05 00 03 81 8D 00 30 81 89 02 81 81 00 D1 30 DF |......0.......0.| |100000100| 08 06 C5 3F B9 91 FA BE A9 6C 37 0A BB F6 33 78 |...?.....l7...3x| |100000110| BA 3F 51 8C C4 E1 B4 E0 0D 7E 75 81 B3 31 80 95 |.?Q......~u..1..| |100000120| 60 2E 31 4F B9 BE 80 FA 37 4F 82 60 DC 22 24 57 |`.1O....7O.`."$W| |100000130| 39 E9 6A 63 0C D5 82 0E E1 AD E5 DD BD 5C 5A E2 |9.jc.........\Z.| |100000140| 8E 82 5C 9D 30 EA 3F 4C 24 6F F5 84 39 8F A3 5E |..\.0.?L$o..9..^| |100000150| C9 6F 04 56 35 AF FC 5C 9E 5D 2A 94 8E 77 D0 55 |.o.V5..\.]*..w.U| |100000160| D5 F5 07 BB 2F 0B EB 00 BC B1 81 45 8C F8 C5 AE |..../......E....| |100000170| D8 73 CE DD 95 89 01 99 6A 39 63 32 49 02 03 01 |.s......j9c2I...| |100000180| 00 01 A3 4C 30 4A 30 48 06 03 55 1D 01 04 41 30 |...L0J0H..U...A0| |100000190| 3F 80 10 4D 9C 37 E8 DB DF 95 19 35 1E 1C 11 81 |?..M.7.....5....| |1000001A0| A1 97 64 A1 19 30 17 31 15 30 13 06 03 55 04 03 |..d..0.1.0...U..| |1000001B0| 13 0C 64 6F 74 6E 65 74 74 79 2E 63 6F 6D 82 10 |..dotnetty.com..| |1000001C0| 70 B4 FB 67 91 CA 19 96 4E 2C 3F D9 93 E7 0F 32 |p..g....N,?....2| |1000001D0| 30 09 06 05 2B 0E 03 02 1D 05 00 03 81 81 00 47 |0...+..........G| |1000001E0| 38 1C E4 C1 BC E4 CE A4 27 E1 B7 B3 34 7A 2B EC |8.......'...4z+.| |1000001F0| C1 2F BE EF C4 63 49 DB DF C8 DB 14 B6 73 26 39 |./...cI......s&9| |100000200| 7A DC 7F E8 02 E9 B0 D2 B1 F7 7A C0 08 BE 30 67 |z.........z...0g| |100000210| A2 AB D7 E2 8E 48 A9 2D 64 1E 0C 3C FA DD 91 6A |.....H.-d..<...j| |100000220| 33 8D 8C 65 CB 77 67 6E 57 82 36 D1 B0 10 D9 CD |3..e.wgnW.6.....| |100000230| B5 64 FF 64 1B C6 DB D8 9A 7E E9 71 F6 37 74 E0 |.d.d.....~.q.7t.| |100000240| 39 E7 51 7B E8 7C 35 BE 1F 64 3B 01 CC 1F AB 89 |9.Q{.|5..d;.....| |100000250| 14 B1 FF 20 FA F8 A7 A2 19 BE C3 04 3F 5C EA 0C |... ........?\..| |100000260| 00 00 A8 03 00 1D 20 4B 87 A0 04 71 C0 CC F0 67 |...... K...q...g| |100000270| FC AA BB 86 AC 10 EB 34 39 F2 3A 15 2C E7 DE B9 |.......49.:.,...| |100000280| 42 DD 50 50 FE 9B 56 04 01 00 80 78 40 5F F0 12 |B.PP..V....x@_..| |100000290| 7D C2 50 94 5A A0 96 FD 43 15 49 8C C5 B2 2F FD |}.P.Z...C.I.../.| |1000002A0| 06 5D F2 57 9F 96 B9 7A 8A 2B E7 98 37 D2 27 B2 |.].W...z.+..7.'.| |1000002B0| 8B 58 89 73 8A E0 1E C0 B8 6D B1 2E 7C BF 7A 7D |.X.s.....m..|.z}| |1000002C0| 64 F0 4F B6 B8 13 B3 6A 73 02 A4 C9 52 5B E2 E8 |d.O....js...R[..| |1000002D0| 33 E3 71 64 4C 93 5F 45 E0 BF 68 6A B7 31 44 C4 |3.qdL._E..hj.1D.| |1000002E0| 62 F9 A8 70 E2 64 D7 2F F1 70 C0 77 88 A6 DA 3E |b..p.d./.p.w...>| |1000002F0| E0 BD CE 03 6F 88 30 3C A8 1A CD 7D BF 62 2C 46 |....o.0<...}.b,F| |100000300| 96 D5 A0 9F 24 D7 AE CB 9B 4C BB 0E 00 00 00 |....$....L..... | +--------+-------------------------------------------------+----------------+ +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 16 03 03 00 25 10 00 00 21 20 BE 3A 5E AA AD 99 |....%...! .:^...| |100000010| 31 2C 45 45 DF 04 60 14 D0 E0 3A 5C 24 57 97 97 |1,EE..`...:\$W..| |100000020| 57 11 F3 F5 AA 02 2A 15 7A 2A 14 03 03 00 01 01 |W.....*.z*......| |100000030| 16 03 03 00 28 00 00 00 00 00 00 00 00 D0 B1 15 |....(...........| |100000040| 77 04 07 76 E6 0D C4 DF 02 69 6C 0F 91 F7 C4 D2 |w..v.....il.....| |100000050| F4 5C D9 B1 DE 47 91 4A 1D 97 24 39 45 |.\...G.J..$9E | +--------+-------------------------------------------------+----------------+ +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |100000000| 14 03 03 00 01 01 16 03 03 00 28 00 00 00 00 00 |..........(.....| |100000010| 00 00 00 79 93 39 BA AB 2F 5E 83 14 36 66 D2 A1 |...y.9../^..6f..| |100000020| B1 BC 8B 47 C7 A2 8F BB 51 50 59 DF DA C1 88 B1 |...G....QPY.....| |100000030| BD EE 39 |..9 | +--------+-------------------------------------------------+----------------+

Seems when isClient == true, the client ask with tls12 and the server reply with tls10, which lead to the AuthenticationException.
An workaround is change https://github.com/Azure/DotNetty/blob/1d3eda9a748125784efe2a74449bf7a18ab9c604/test/DotNetty.Handlers.Tests/SniHandlerTest.cs#L237
to something special the protocol await Task.Run(() => driverStream.AuthenticateAsServerAsync(CertificateSelector(targetHost).Result.Certificate, false, protocol, false).WithTimeout(TimeSpan.FromSeconds(5)));

May be relate to THIS, and after I change the TargetFramework it works well.



***And seems it's only an test related issue, and not affact the main library*** ~~~, so leave it here to see if it will also happen with the stable version.~~~

---

Also found it timeout with `netcoreapp2.1`(preview), but no `AuthenticationException`.
An workaround is change
https://github.com/Azure/DotNetty/blob/1d3eda9a748125784efe2a74449bf7a18ab9c604/test/DotNetty.Handlers.Tests/SniHandlerTest.cs#L96
to
`await ReadOutboundAsync(async () => ch.ReadOutbound<IByteBuffer>(), output.Count - readResultBuffer.ReadableBytes, readResultBuffer, TimeSpan.FromSeconds(1));`
, which used by https://github.com/Azure/DotNetty/blob/1d3eda9a748125784efe2a74449bf7a18ab9c604/test/DotNetty.Handlers.Tests/SniHandlerTest.cs#L166-L172
that may ask more bytes to read than expected, and maybe the same thing for TlsHanderTest.
yyjdelete commented 6 years ago

Sorry I test with the wrong file, this also happen on net471/462.

Test program

Still not sure why this not happen on ci server, maybe it enable strong cryptography by default for safe?

StormHub commented 6 years ago

@yyjdelete Have you found anything yet? I think it might be in https://github.com/Azure/DotNetty/blob/dev/src/DotNetty.Handlers/Tls/TlsHandler.cs

caozhiyuan commented 6 years ago

netcoreapp2.1 has this issue , https://github.com/dotnet/corefx/issues/27675 you can run? @yyjdelete

StormHub commented 6 years ago

@caozhiyuan I am not sure it’s related or not to the .net issue. For the threading problem, let me try to create some minimal repro.

yyjdelete commented 6 years ago

@caozhiyuan I'm not sure, but all unit tests pass with 2.1. What's the repro code and expected behavior with DotNetty?

And what's more, I use the daily preview builds 2.1.300-preview2-008293 instead of preview1 now. Tested with Echo.Server(libuv=false), and see the same stack as you attached as .net core 2.0

caozhiyuan commented 6 years ago

2.1 i run preview1 or daily build all dead lock @yyjdelete httpserver

caozhiyuan commented 6 years ago

@StormHub i just talk about 2.1, i don't konw this issue about.

yyjdelete commented 6 years ago

@caozhiyuan Ok, I can see it with VScode and dotnet run and attach, but not on VS 😕......

But Task does can be continue with TrySetResult before netcoreapp2.1, see https://github.com/Azure/DotNetty/issues/218#issuecomment-289268031

Seems TaskScheduler.TryExecuteTaskInline is not call in netcoreapp2.1

caozhiyuan commented 6 years ago

@yyjdelete #218 not this , it because 2.1 task continue , give TaskCreationOptions.RunContinuationsAsynchronously to TaskCompletionSource can work same as core 2.0(thread stack is same). 2.1 TrySetResult Continue in netty loop thread.

yyjdelete commented 6 years ago
using System;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;

namespace ConsoleApp1
{
    class Program
    {
        private static ExecutorTaskScheduler scheduler;

        static void Main(string[] args)
        {
            //typeof(Task).GetField("s_asyncDebuggingEnabled", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic)?.SetValue(null, true);

            scheduler = new ExecutorTaskScheduler();
            MainAsync().Wait();
        }

        private static async Task MainAsync()
        {
            Console.WriteLine("MainAsync-Pre->" + Thread.CurrentThread.ManagedThreadId);
            await X1();
            Console.WriteLine("MainAsync-Post, and block->" + Thread.CurrentThread.ManagedThreadId);
            //Console.WriteLine(Environment.StackTrace);
            Console.ReadLine();

        }

        private static Task X1()
        {
            Console.WriteLine("X1->" + Thread.CurrentThread.ManagedThreadId);
            var tmp = new TaskCompletionSource<int>();
            Task.Factory.StartNew(() =>
            {
                Console.WriteLine("Task->" + Thread.CurrentThread.ManagedThreadId);
                tmp.TrySetResult(0);
                Console.WriteLine("Do something else.");
                while (true)
                {
                    Thread.Sleep(100);
                }
            }, CancellationToken.None, TaskCreationOptions.LongRunning, scheduler);
            return tmp.Task;
        }

        public sealed class ExecutorTaskScheduler : TaskScheduler
        {

            protected override void QueueTask(Task task)
            {
                ThreadPool.QueueUserWorkItem((state) =>
                {
                    this.TryExecuteTask(task);
                });
            }

            protected override bool TryExecuteTaskInline(Task task, bool taskWasPreviouslyQueued)
            {
                return false;
            }

            protected override IEnumerable<Task> GetScheduledTasks() => null;

            protected override bool TryDequeue(Task task) => false;
        }
    }
}
caozhiyuan commented 6 years ago

https://github.com/Azure/DotNetty/blob/dev/src/DotNetty.Transport/Bootstrapping/AbstractBootstrap.cs#L232 this code , DoBind0Async promise trysetresult deadlock , you can copy netty code to core2.1 project

yyjdelete commented 6 years ago

@caozhiyuan I already make another repro code without DotNetty. You can run the code I attached with netcoreapp2.0 and 2.1, and see Do something else. is never show in 2.1 before press Enter.

caozhiyuan commented 6 years ago

because you change the code , dotnetty ExecutorTaskScheduler TryExecuteTask cause deaklock. but i can't reproduce in my minimal repro , in 2.0 TryExecuteTaskInline will not be called , 2.1 be called and cause deaklock, when add TaskCreationOptions.RunContinuationsAsynchronously to TaskCompletionSource , TryExecuteTaskInline will not be called

yyjdelete commented 6 years ago

@caozhiyuan But seems it's an internal behavior and may not run well in all runtimes. (for example, Mono < 4.0.0, version after 4.0 use the code from coreclr)

caozhiyuan commented 6 years ago

add TaskCreationOptions.RunContinuationsAsynchronously ?

yyjdelete commented 6 years ago

Not sure.

  1. There is no RunContinuationsAsynchronously in net452
  2. When I modified all TaskCompletionSource and TaskCompletionSource<T>, all test in TlsHandleTest and End2End timeout...(Do not change the one in MediationStream)
  3. IdleStateHandlerTest.TestObserveWriterIdle failed for now the writeListener also run in async. See all TaskContinuationOptions.ExecuteSynchronously expect LinkOutcome.

xunit use an custom SynchronizationContext so seem not be affacted by inline, but unknown why timeout.

caozhiyuan commented 6 years ago

2.0 continuationObject is action , 2.1 is ITaskCompletionAction . add RunContinuationsAsynchronously and conditional build can solve this

   private void RunContinuations(object continuationObject) // separated out of FinishContinuations to enable it to be inlined
        {
            Debug.Assert(continuationObject != null);

            TplEtwProvider etw = TplEtwProvider.Log;
            bool tplEtwProviderLoggingEnabled = etw.IsEnabled();
            if (tplEtwProviderLoggingEnabled)
            {
                etw.RunningContinuation(Id, continuationObject);
            }

            if (AsyncCausalityTracer.LoggingOn)
                AsyncCausalityTracer.TraceSynchronousWorkStart(CausalityTraceLevel.Required, this.Id, CausalitySynchronousWork.CompletionNotification);

            // Skip synchronous execution of continuations if this task's thread was aborted
            bool bCanInlineContinuations = !(((m_stateFlags & TASK_STATE_THREAD_WAS_ABORTED) != 0) ||
                                              (RuntimeThread.CurrentThread.ThreadState == ThreadState.AbortRequested) ||
                                              ((m_stateFlags & (int)TaskCreationOptions.RunContinuationsAsynchronously) != 0));

            // Handle the single-Action case
            Action singleAction = continuationObject as Action;
            if (singleAction != null)
            {
                AwaitTaskContinuation.RunOrScheduleAction(singleAction, bCanInlineContinuations, ref t_currentTask);
                LogFinishCompletionNotification();
                return;
            }

            // Handle the single-ITaskCompletionAction case
            ITaskCompletionAction singleTaskCompletionAction = continuationObject as ITaskCompletionAction;
            if (singleTaskCompletionAction != null)
            {
                if (bCanInlineContinuations || !singleTaskCompletionAction.InvokeMayRunArbitraryCode)
                {
                    singleTaskCompletionAction.Invoke(this);
                }
                else
                {
                    ThreadPool.UnsafeQueueCustomWorkItem(new CompletionActionInvoker(singleTaskCompletionAction, this), forceGlobal: false);
                }
                LogFinishCompletionNotification();
                return;
            }

            // Handle the single-TaskContinuation case
            TaskContinuation singleTaskContinuation = continuationObject as TaskContinuation;
            if (singleTaskContinuation != null)
            {
                singleTaskContinuation.Run(this, bCanInlineContinuations);
                LogFinishCompletionNotification();
                return;
            }

            // Not a single; it must be a list.
            List<object> continuations = (List<object>)continuationObject;

            //
            // Begin processing of continuation list
            //

            // Wait for any concurrent adds or removes to be retired
            lock (continuations) { }
            int continuationCount = continuations.Count;

            // Fire the asynchronous continuations first ...
            for (int i = 0; i < continuationCount; i++)
            {
                // Synchronous continuation tasks will have the ExecuteSynchronously option,
                // and we're looking for asynchronous tasks...
                var tc = continuations[i] as StandardTaskContinuation;
                if (tc != null && (tc.m_options & TaskContinuationOptions.ExecuteSynchronously) == 0)
                {
                    if (tplEtwProviderLoggingEnabled)
                    {
                        etw.RunningContinuationList(Id, i, tc);
                    }
                    continuations[i] = null; // so that we can skip this later
                    tc.Run(this, bCanInlineContinuations);
                }
            }

            // ... and then fire the synchronous continuations (if there are any).
            // This includes ITaskCompletionAction, AwaitTaskContinuations, and
            // Action delegates, which are all by default implicitly synchronous.
            for (int i = 0; i < continuationCount; i++)
            {
                object currentContinuation = continuations[i];
                if (currentContinuation == null) continue;
                continuations[i] = null; // to enable free'ing up memory earlier
                if (tplEtwProviderLoggingEnabled)
                {
                    etw.RunningContinuationList(Id, i, currentContinuation);
                }

                // If the continuation is an Action delegate, it came from an await continuation,
                // and we should use AwaitTaskContinuation to run it.
                Action ad = currentContinuation as Action;
                if (ad != null)
                {
                    AwaitTaskContinuation.RunOrScheduleAction(ad, bCanInlineContinuations, ref t_currentTask);
                }
                else
                {
                    // If it's a TaskContinuation object of some kind, invoke it.
                    TaskContinuation tc = currentContinuation as TaskContinuation;
                    if (tc != null)
                    {
                        // We know that this is a synchronous continuation because the
                        // asynchronous ones have been weeded out
                        tc.Run(this, bCanInlineContinuations);
                    }
                    // Otherwise, it must be an ITaskCompletionAction, so invoke it.
                    else
                    {
                        Debug.Assert(currentContinuation is ITaskCompletionAction, "Expected continuation element to be Action, TaskContinuation, or ITaskContinuationAction");
                        var action = (ITaskCompletionAction)currentContinuation;

                        if (bCanInlineContinuations || !action.InvokeMayRunArbitraryCode)
                        {
                            action.Invoke(this);
                        }
                        else
                        {
                            ThreadPool.UnsafeQueueCustomWorkItem(new CompletionActionInvoker(action, this), forceGlobal: false);
                        }
                    }
                }
            }

            LogFinishCompletionNotification();
        }