Connection closing sometimes leads to SocketException

[martinmine]

I have been running SuperSocket 2.0 in production now for soon a week and it seems to run buttery smooth. My logfiles do however show that there are a few things that is a bit off. When connections are closed it might be that we get some socket exceptions. Specifically 10052, 10053, 10054, and 10060:

ERROR IChannel - Exception happened in ReceiveAsync
System.Net.Sockets.SocketException (10060): A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
   at SuperSocket.Channel.TcpPipeChannel`1.ReceiveAsync(Socket socket, Memory`1 memory, SocketFlags socketFlags, CancellationToken cancellationToken)
   at SuperSocket.Channel.TcpPipeChannel`1.FillPipeWithDataAsync(Memory`1 memory, CancellationToken cancellationToken)
   at SuperSocket.Channel.PipeChannel`1.FillPipeAsync(PipeWriter writer)

ERROR IChannel - Exception happened in ReceiveAsync
System.IO.IOException: Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond..
 ---> System.Net.Sockets.SocketException (10060): A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
   --- End of inner exception stack trace ---
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
   at System.Net.Security.SslStream.<FillBufferAsync>g__InternalFillBufferAsync|215_0[TReadAdapter](TReadAdapter adap, ValueTask`1 task, Int32 min, Int32 initial)
   at System.Net.Security.SslStream.ReadAsyncInternal[TReadAdapter](TReadAdapter adapter, Memory`1 buffer)
   at SuperSocket.Channel.StreamPipeChannel`1.FillPipeWithDataAsync(Memory`1 memory, CancellationToken cancellationToken)
   at SuperSocket.Channel.PipeChannel`1.FillPipeAsync(PipeWriter writer)

ERROR IChannel - Exception happened in ReceiveAsync
System.Net.Sockets.SocketException (10053): An established connection was aborted by the software in your host machine.
   at SuperSocket.Channel.TcpPipeChannel`1.ReceiveAsync(Socket socket, Memory`1 memory, SocketFlags socketFlags, CancellationToken cancellationToken)
   at SuperSocket.Channel.TcpPipeChannel`1.FillPipeWithDataAsync(Memory`1 memory, CancellationToken cancellationToken)
   at SuperSocket.Channel.PipeChannel`1.FillPipeAsync(PipeWriter writer)

ERROR UdpChannelCreator - Listener[Ip=Any, Port=900, Security=None, Path=, BackLog=0, NoDelay=False] failed to receive udp data
System.Net.Sockets.SocketException (10052): The connection has been broken due to keep-alive activity detecting a failure while the operation was in progress.
   at System.Net.Sockets.Socket.UpdateStatusAfterSocketErrorAndThrowException(SocketError error, String callerName)
   at System.Net.Sockets.Socket.EndReceiveFrom(IAsyncResult asyncResult, EndPoint& endPoint)
   at System.Net.Sockets.Socket.<>c.<ReceiveFromAsync>b__283_0(IAsyncResult iar)
--- End of stack trace from previous location where exception was thrown ---
   at SuperSocket.Udp.UdpChannelCreator.KeepAccept(Socket listenSocket)

ERROR UdpChannelCreator - Listener[Ip=Any, Port=900, Security=None, Path=, BackLog=0, NoDelay=False] failed to receive udp data
System.Net.Sockets.SocketException (10052): The connection has been broken due to keep-alive activity detecting a failure while the operation was in progress.
   at System.Net.Sockets.Socket.DoBeginReceiveFrom(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags, EndPoint endPointSnapshot, SocketAddress socketAddress, OriginalAddressOverlappedAsyncResult asyncResult)
   at System.Net.Sockets.Socket.BeginReceiveFrom(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags, EndPoint& remoteEP, AsyncCallback callback, Object state)
   at System.Net.Sockets.Socket.ReceiveFromAsync(ArraySegment`1 buffer, SocketFlags socketFlags, EndPoint remoteEndPoint)
   at SuperSocket.Udp.UdpChannelCreator.KeepAccept(Socket listenSocket)

System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
 ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
   --- End of inner exception stack trace ---
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
   at System.Net.FixedSizeReader.ReadPacketAsync(Stream transport, AsyncProtocolRequest request)
   at System.Net.Security.SslStream.EndProcessAuthentication(IAsyncResult result)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at SuperSocket.Server.TcpChannelCreatorFactory.<>c__DisplayClass3_0`1.<<CreateChannelCreator>b__1>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at SuperSocket.Server.TcpChannelCreator.OnNewClientAccept(Socket socket)

ERROR IChannel - Unhandled exception in the method PipeChannel.Run.
System.ArgumentException: The tasks argument included a null value. (Parameter 'tasks')
   at System.Threading.Tasks.Task.WhenAll(Task[] tasks)
   at SuperSocket.Channel.PipeChannel`1.HandleClosing()

(these are just examples, I can get for example 463 instances of error 10060 in the past 24 hours)

I am aware that I can configure the logging framework to not log events like these but it seems rather odd. It would be really great if these scenarios where the client might for example not complete the final handshake completely that we don't get error events and our log files are not filled up with noise.

[kerryjiang]

I found some interesting logs. I will investigate them.

[martinmine]

Cool, looking forward to see what you find out. Let me know if you need any more info.

[kerryjiang]

There are two interesting issues:

1) 10052 error of UDP; 2) the unhandled exception in the method PipeChannel.Run;

Did you find any other exceptions which might be related with the second issue?

[martinmine]

I have looked over a few more logs and haven't seen anything. I have looked a bit on the PipeChannel class and I don't see how we can enter HandleClosing() before Start() has been executed. Might be something that calls a Close or Detach method before Start has been executed?