Setting timeout to TcpClient with SslStream result in terminating connection

[michaldobrodenka]

I use websocket-sharp in my App. I tried to compile it with Xamarin.Android 10.2.100.7. (In VS2019 16.4.6 it's ok, so we will have to build release apps with VS2019 16.4.6 until this is fixed)

When I compile and deploy app in Release mode everything works, but every 10-15 seconds websocket connection is lost and has to be recreated. Websocket connection is secure. When connection is dropped: this appears in logcat:

03-25 13:41:11.630: I/mono-stdout(23192): 3/25/2020 1:41:11 PM|Fatal|<>c__DisplayClass184_0.<startReceiving>b__2|System.AggregateException: One or more errors occurred. (Unable to read data from the transport connection: Operation on non-blocking socket would block.) ---> System.IO.IOException: Unable to read data from the transport connection: Operation on non-blocking socket would block. ---> System.Net.Sockets.SocketException: Operation on non-blocking socket would block
03-25 13:41:11.631: I/mono-stdout(23192):                              at System.Net.Sockets.Socket.Receive (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags) [0x00016] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                              at System.Net.Sockets.NetworkStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 size) [0x00065] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                               --- End of inner exception stack trace ---
03-25 13:41:11.631: I/mono-stdout(23192):                              at System.Net.Sockets.NetworkStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 size) [0x000ac] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream+<>c__DisplayClass66_0.<InnerRead>b__0 () [0x0002b] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                              at System.Threading.Tasks.Task`1[TResult].InnerInvoke () [0x0000f] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                              at System.Threading.Tasks.Task.Execute () [0x00000] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.631: I/mono-stdout(23192):                            --- End of stack trace from previous location where exception was thrown ---
03-25 13:41:11.631: I/mono-stdout(23192):                            
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream.InnerRead (System.Boolean sync, System.Int32 requestedSize, System.Threading.CancellationToken cancellationToken) [0x00104] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.InnerRead (System.Threading.CancellationToken cancellationToken) [0x000ac] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.ProcessOperation (System.Threading.CancellationToken cancellationToken) [0x00093] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.StartOperation (System.Threading.CancellationToken cancellationToken) [0x0008b] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream.StartOperation (Mono.Net.Security.MobileAuthenticatedStream+OperationType type, Mono.Net.Security.AsyncProtocolRequest asyncRequest, System.Threading.CancellationToken cancellationToken) [0x0024b] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                               --- End of inner exception stack trace ---
03-25 13:41:11.632: I/mono-stdout(23192):                              at System.Threading.Tasks.Task.ThrowIfExceptional (System.Boolean includeTaskCanceledExceptions) [0x00011] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at System.Threading.Tasks.Task`1[TResult].GetResultCore (System.Boolean waitCompletionNotification) [0x0002b] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at System.Threading.Tasks.Task`1[TResult].get_Result () [0x0000f] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00018] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at System.Net.Security.SslStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00006] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.632: I/mono-stdout(23192):                              at System.IO.Stream+<>c.<BeginReadInternal>b__40_0 (System.Object <p0>) [0x0000b] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.Threading.Tasks.Task`1[TResult].InnerInvoke () [0x0002b] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.Threading.Tasks.Task.Execute () [0x00000] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                            --- End of stack trace from previous location where exception was thrown ---
03-25 13:41:11.633: I/mono-stdout(23192):                            
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.IO.Stream.EndRead (System.IAsyncResult asyncResult) [0x0004d] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                              at WebSocketSharp.Ext+<>c__DisplayClass56_0.<ReadBytesAsync>b__0 (System.IAsyncResult ar) [0x00000] in <3bf63c0655194bb9a06516f56f85dca6>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                            ---> (Inner Exception #0) System.IO.IOException: Unable to read data from the transport connection: Operation on non-blocking socket would block. ---> System.Net.Sockets.SocketException: Operation on non-blocking socket would block
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.Net.Sockets.Socket.Receive (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags) [0x00016] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.Net.Sockets.NetworkStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 size) [0x00065] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                               --- End of inner exception stack trace ---
03-25 13:41:11.633: I/mono-stdout(23192):                              at System.Net.Sockets.NetworkStream.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 size) [0x000ac] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.633: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream+<>c__DisplayClass66_0.<InnerRead>b__0 () [0x0002b] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at System.Threading.Tasks.Task`1[TResult].InnerInvoke () [0x0000f] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at System.Threading.Tasks.Task.Execute () [0x00000] in <85796c57878d4472ae49a7e6bc840931>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                            --- End of stack trace from previous location where exception was thrown ---
03-25 13:41:11.634: I/mono-stdout(23192):                            
03-25 13:41:11.634: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream.InnerRead (System.Boolean sync, System.Int32 requestedSize, System.Threading.CancellationToken cancellationToken) [0x00104] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.InnerRead (System.Threading.CancellationToken cancellationToken) [0x000ac] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.ProcessOperation (System.Threading.CancellationToken cancellationToken) [0x00093] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at Mono.Net.Security.AsyncProtocolRequest.StartOperation (System.Threading.CancellationToken cancellationToken) [0x0008b] in <d2095765ef78452e99c8bec310aee22d>:0 
03-25 13:41:11.634: I/mono-stdout(23192):                              at Mono.Net.Security.MobileAuthenticatedStream.StartOperation (Mono.Net.Security.MobileAuthenticatedStream+OperationType type, Mono.Net.Security.AsyncProtocolRequest asyncRequest, System.Threading.CancellationToken cancellationToken) [0x0024b] in <d2095765ef78452e99c8bec310aee22d>:0 <---```

[grendello]

@michaldobrodenka Did you try the code in a console app? If not, please try to see if you will get the same error. From the above stack trace the issue is either in WebSocketSharp (I deem it more likely) or in the Mono BCL. Please let me know what was the result of your investigation with the console app and we'll decide what to do next about the error, thanks!

[michaldobrodenka]

@grendello The same code is used in WPF/Windows, iOS and Android, used by thousands of users.

[michaldobrodenka]

Android throw an exception if blocking socket operation is done in main thread. (I think)
My blocking operations are done in separate background Task.

[grendello]

@michaldobrodenka It's not Android which throws the exception, but the Mono BCL running on Android - which is why I asked you to test the code in a console app. I failed to mention the app should be ran with Mono. And the reason I asked you to do it, is that there's nothing in Xamarin.Android which plays any role in this scenario. Xamarin.Android itself has nothing to do with the Mono networking stack, and this is the component which throws the exception. The console app running on Mono would help in narrowing the likely culprit.

[brendanzagaeski]

Cross-referencing note

This might not quite match, but maybe the following items about a change in the underlying implementation of SslStream.BeginRead and SslStream.BeginWrite to use the default implementations from Stream could be related.

• Change in SslStream.BeginRead/BeginWrite behavior mono/mono#18865
• Default implementation of Stream.BeginRead/BeginWrite runtime#33447

That change from the Mono Framework is present in the Xamarin.Android SDK starting with version 10.2.

[michaldobrodenka]

Interesting, I will

One "solution" is to not to connect secure. If I string replace wss to ws in connect and allow that in server, everything works normally :)

Also it seems, that when I turn off concurent garbage collector, time between disconnects increases.

[michaldobrodenka]

Maybe this problem is new version of this bug:
mono/mono#11023
mono/mono#15462
mono/mono#8350
...

This bug has plagued us for years.

Will this network code be replaced by NET5 in November?

[grendello]

@marek-safar can you assign this issue to someone who's maintaining the Mono networking/TLS stack atm? Thanks!

[marek-safar]

/cc @steveisok

[steveisok]

@baulig Please take a look and see what you can make of it.

[michaldobrodenka]

I'm still trying to narrow down the problem. In small app with websocket-sharp problem doesn't occur. My app has also UDP multicast, UDP broadcast, contacting many restp apis, not only websockets. Maybe something is interfering with sometinhg :)

[michaldobrodenka]

Light at the end of the tunnel. It seems that my fork of websocket-sharp is setting Read and WriteTimeout to TcpClient which causes this problem in new Mono.

That's probably it, but I'll investigate more tomorrow.

[michaldobrodenka]

this I found also in logcat:

03-27 09:36:29.378: W/monodroid-assembly(21223): typemap: unable to find mapping to a managed type from Java type 'java/net/SocketTimeoutException'

[grendello]

@michaldobrodenka this warning is harmless. The managed code will find the correct type in the slow way.

[michaldobrodenka]

If you want to play with it, I made small Xamarin.Android app which demostrate the problem and flood logcat with this problem every 3 seconds. (uses echo.websocket.org)

See class WsConnection, line 50, comment this line and it works normally.

WebsocketDisconnectTest.zip

[michaldobrodenka]

@grendello
I Maybe this cou;ld be relevant? But it's not that frequent in logcat, maybe not even from my app:
(it's about timeouts and sockets :) )

03-26 19:43:38.647: W/Conscrypt(26446): Could not set socket write timeout: java.net.SocketException: Socket closed
03-26 19:43:38.647: W/Conscrypt(26446): Could not set socket write timeout: java.net.SocketException: Socket closed
03-26 19:43:38.649: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):2)
03-26 19:43:38.649: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.ConscryptFileDescriptorSocket.setSoWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):0)
03-26 19:43:38.649: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):2)
03-26 19:43:38.649: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.ConscryptFileDescriptorSocket.setSoWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):0)
03-26 19:43:38.687: W/Conscrypt(26446): Could not set socket write timeout: java.net.SocketException: Socket closed
03-26 19:43:38.688: W/Conscrypt(26446): Could not set socket write timeout: java.net.SocketException: Socket closed
03-26 19:43:38.688: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):2)
03-26 19:43:38.688: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.ConscryptFileDescriptorSocket.setSoWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):0)
03-26 19:43:38.688: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):2)
03-26 19:43:38.688: W/Conscrypt(26446): 	at com.google.android.gms.org.conscrypt.ConscryptFileDescriptorSocket.setSoWriteTimeout(:com.google.android.gms@[email protected] (040400-300565878):0)

[baulig]

If I interpret the stack trace correctly, then SslStream is behaving exactly as expected - calling any synchronous SslStream APIs will result in synchronous calls to the inner stream.

On the above stack trace, there's SslStream.Read() which results in a call to NetworkStream.Read() / Socket.Receive(). If the underlying stream does not support synchronous reads, that's not a problem in SslStream but in whichever code is using it.

[michaldobrodenka]

@baulig Problem is that up until X.A 10.200 this code was perfectly fine. And is also fine with .NET. And this code is also ok in X.A 10.200, if you don't set Receive/Send Timeouts to TcpClient (or it's socket)

[jpobst]

With support for Classic Xamarin.Android ended May 1st, 2024, this issue is likely no longer relevant.

If this still persists in .NET 8+, please open a new issue with updated information based on net8.0-android or greater. Please include a link to this issue for context.