AsyncResult rethrows exceptions and NetTCP's SocketConnectionInitiator does not throw relevant exceptions

[EricEzaM]

Describe the bug
Many different types of connection issues are reported as "No IPEndpoints were found for host XYZ", including configuration issues (e.g. incorrect address) and other runtime issues (e.g. port exhaustion). This makes it incredibly difficult to debug, as relevant exceptions are either re-thrown, losing the stack trace, or completely swallowed by WCF and never thrown at all. I was able to track this down to 2 things:

1. AsyncResult
Here we can see async result re-throwing the exception from the IAsyncResult object, completely removing its stack trace.

wcf/src/System.ServiceModel.Primitives/src/Internals/System/Runtime/AsyncResult.cs

Lines 349 to 352 in ed1bd7a

	if (asyncResult._exception != null)
	{
	throw Fx.Exception.AsError(asyncResult._exception);
	}

2. SocketConnectionInitiator
Here we can see that at the the end of this method if socketConnection == null is checked first, before if lastException != null. If CreateConnectionAsync throws an exception, of course socketConnection will be null, and thus EndpointNotFoundException will be thrown, rather than the exception throw by CreateConnectionAsync. The important information inside lastException which describes why the connection failed is never made available.

wcf/src/System.ServiceModel.NetTcp/src/System/ServiceModel/Channels/SocketConnection.cs

Lines 937 to 986 in ed1bd7a

	public async ValueTask<IConnection> ConnectAsync(Uri uri, TimeSpan timeout)
	{
	int port = uri.Port;
	IPAddress[] addresses = await GetIPAddressesAsync(uri);
	IConnection socketConnection = null;
	SocketException lastException = null;
	if (port == -1)
	{
	port = TcpUri.DefaultPort;
	}
	int invalidAddressCount = 0;
	TimeoutHelper timeoutHelper = new TimeoutHelper(timeout);
	for (int i = 0; i < addresses.Length; i++)
	{
	if (timeoutHelper.RemainingTime() == TimeSpan.Zero)
	{
	throw DiagnosticUtility.ExceptionUtility.ThrowHelperError(
	CreateTimeoutException(uri, timeoutHelper.OriginalTimeout, addresses, invalidAddressCount, lastException));
	}
	try
	{
	socketConnection = await CreateConnectionAsync(addresses[i], port);
	lastException = null;
	break;
	}
	catch (SocketException socketException)
	{
	invalidAddressCount++;
	lastException = socketException;
	}
	}
	if (socketConnection == null)
	{
	throw DiagnosticUtility.ExceptionUtility.ThrowHelperError(
	new EndpointNotFoundException(SR.Format(SR.NoIPEndpointsFoundForHost, uri.Host)));
	}
	if (lastException != null)
	{
	throw DiagnosticUtility.ExceptionUtility.ThrowHelperError(
	SocketConnectionInitiator.ConvertConnectException(lastException, uri,
	timeoutHelper.ElapsedTime(), lastException));
	}
	return socketConnection;
	}

To Reproduce
GH-5697 MRP Projects.zip

I have attached some projects which you should add to the WCF solution in this repository. The WCF service is not important for this demonstration, it is just there to provide a service we can communicate with.

1. Run the service, then the client. You should have the following printed to the console:

Starting...
You entered: 456

2. Now, in the WCF repo code, go to the below line of code in SocketConnectionInitiator, and just after new Socket(... , we will simulate ConnectAsync throwing an exception. Insert the following line of code: throw new SocketException((int)SocketError.NoBufferSpaceAvailable);
   

   wcf/src/System.ServiceModel.NetTcp/src/System/ServiceModel/Channels/SocketConnection.cs

   Line 816 in 1985f3c

   socket = new Socket(addressFamily, SocketType.Stream, ProtocolType.Tcp);

3. Run the client again. Now we get the below result. We get our EndpointNotFoundException, which is completely useless. We know we should get an exception about NoBufferSpaceAvailable. This exception is doubly useless since we have no idea where the EndpointNotFoundException originally came from.

Unhandled exception. System.ServiceModel.EndpointNotFoundException: No IPEndpoints were found for host 127.0.0.1.
   at System.Runtime.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.SendAsyncResult.End(SendAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.EndCall(String action, Object[] outs, IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannelProxy.TaskCreator.<>c__DisplayClass1_0.<CreateGenericTask>b__0(IAsyncResult asyncResult)
--- End of stack trace from previous location ---
   at Program.<Main>$(String[] args) in D:\Programming\OpenSource\wcf\TestClient\Program.cs:line 19
   at Program.<Main>(String[] args)

That is all that is needed to reproduce. The below steps go into how I changed the Service Model code to get a useful exception at the call site.

4. In the WCF repo code again, go to the below line of code in AsyncResult. This is where the re-throwing is happening. Replace it instead with ExceptionDispatchInfo to keep the existing stack trace: ExceptionDispatchInfo.Capture(Fx.Exception.AsError(asyncResult._exception)).Throw(); Note that an exception with an InnerException could also be used.
   

   wcf/src/System.ServiceModel.Primitives/src/Internals/System/Runtime/AsyncResult.cs

   Line 351 in 1985f3c

   throw Fx.Exception.AsError(asyncResult._exception);

5. Run the client again. We get the below result. Better, but still not our NoBufferSpaceAvailable. We have more information in the trace and can see that SocketConnectionInitiator is the culprit.

Unhandled exception. System.ServiceModel.EndpointNotFoundException: No IPEndpoints were found for host 127.0.0.1.
   at System.ServiceModel.Channels.SocketConnectionInitiator.ConnectAsync(Uri uri, TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetTcp\src\System\ServiceModel\Channels\SocketConnection.cs:line 977
   at System.ServiceModel.Channels.BufferedConnectionInitiator.ConnectAsync(Uri uri, TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\BufferedConnection.cs:line 255
   at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnectionAsync(TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\ConnectionPoolHelper.cs:line 103
   at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpenAsync(TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\FramingChannels.cs:line 275
   at System.ServiceModel.Channels.CommunicationObject.OnOpenAsyncInternal(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.System.ServiceModel.IAsyncCommunicationObject.OpenAsync(TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.OnOpenAsync(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.OnOpenAsyncInternal(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.System.ServiceModel.IAsyncCommunicationObject.OpenAsync(TimeSpan timeout)
   at System.Runtime.TaskHelpers.ToApmEnd(IAsyncResult iar)
   at System.ServiceModel.Channels.CommunicationObject.EndOpen(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.EndCall(ServiceChannel channel, IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.EndCallOnce(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.EndEnsureOpened(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.SendAsyncResult.FinishEnsureOpen(IAsyncResult result, Boolean completedSynchronously)
--- End of stack trace from previous location ---
   at System.Runtime.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.SendAsyncResult.End(SendAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.EndCall(String action, Object[] outs, IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannelProxy.TaskCreator.<>c__DisplayClass1_0.<CreateGenericTask>b__0(IAsyncResult asyncResult)
--- End of stack trace from previous location ---
   at Program.<Main>$(String[] args) in D:\Programming\OpenSource\wcf\TestClient\Program.cs:line 19
   at Program.<Main>(String[] args)

6. The final issue is to do with the order of exception throwing in SocketConnectionInitiator.ConnectAsync. In the WCF code, go to the below code, and swap the order of the if statements and their contents. That is, lastException != null before socketConnection == null.
   

   wcf/src/System.ServiceModel.NetTcp/src/System/ServiceModel/Channels/SocketConnection.cs

   Lines 974 to 986 in 1985f3c

   	if (socketConnection == null)
   	{
   	throw DiagnosticUtility.ExceptionUtility.ThrowHelperError(
   	new EndpointNotFoundException(SR.Format(SR.NoIPEndpointsFoundForHost, uri.Host)));
   	}
   	if (lastException != null)
   	{
   	throw DiagnosticUtility.ExceptionUtility.ThrowHelperError(
   	SocketConnectionInitiator.ConvertConnectException(lastException, uri,
   	timeoutHelper.ElapsedTime(), lastException));
   	}

7. Run the client again. Now we finally get the stack trace we want:

Unhandled exception. System.InsufficientMemoryException: Insufficient winsock resources available to complete socket connection initiation.
 ---> System.Net.Sockets.SocketException (10055): An operation on a socket could not be performed because the system lacked sufficient buffer space or because a queue was full.
   at System.ServiceModel.Channels.SocketConnectionInitiator.CreateConnectionAsync(IPAddress address, Int32 port) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetTcp\src\System\ServiceModel\Channels\SocketConnection.cs:line 817
   at System.ServiceModel.Channels.SocketConnectionInitiator.ConnectAsync(Uri uri, TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetTcp\src\System\ServiceModel\Channels\SocketConnection.cs:line 964
   --- End of inner exception stack trace ---
   at System.ServiceModel.Channels.SocketConnectionInitiator.ConnectAsync(Uri uri, TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetTcp\src\System\ServiceModel\Channels\SocketConnection.cs:line 977
   at System.ServiceModel.Channels.BufferedConnectionInitiator.ConnectAsync(Uri uri, TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\BufferedConnection.cs:line 255
   at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnectionAsync(TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\ConnectionPoolHelper.cs:line 103
   at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpenAsync(TimeSpan timeout) in D:\Programming\OpenSource\wcf\src\System.ServiceModel.NetFramingBase\src\System\ServiceModel\Channels\FramingChannels.cs:line 275
   at System.ServiceModel.Channels.CommunicationObject.OnOpenAsyncInternal(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.System.ServiceModel.IAsyncCommunicationObject.OpenAsync(TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.OnOpenAsync(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.OnOpenAsyncInternal(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.System.ServiceModel.IAsyncCommunicationObject.OpenAsync(TimeSpan timeout)
   at System.Runtime.TaskHelpers.ToApmEnd(IAsyncResult iar)
   at System.ServiceModel.Channels.CommunicationObject.EndOpen(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.EndCall(ServiceChannel channel, IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.EndCallOnce(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.EndEnsureOpened(IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.SendAsyncResult.FinishEnsureOpen(IAsyncResult result, Boolean completedSynchronously)
--- End of stack trace from previous location ---
   at System.Runtime.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.SendAsyncResult.End(SendAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannel.EndCall(String action, Object[] outs, IAsyncResult result)
   at System.ServiceModel.Channels.ServiceChannelProxy.TaskCreator.<>c__DisplayClass1_0.<CreateGenericTask>b__0(IAsyncResult asyncResult)
--- End of stack trace from previous location ---
   at Program.<Main>$(String[] args) in D:\Programming\OpenSource\wcf\TestClient\Program.cs:line 19
   at Program.<Main>(String[] args)

Please consider changing the code mentioned so that exceptions are made more easily available to developers for debugging purposes.

[mconnew]

Thankyou for the incredibly detailed issue. This is going to make it really easy to make fixes. I'm currently working on fixing a couple of other things which will be released very soon, and with the level of analysis you have provided will make at least some if not all of the issues you raised quick enough to fix in time.

[EricEzaM]

Thank you, glad to help.

It looks like there are no patch versions released for this library. Will we need to wait for 8.2 in order to use this via NuGet?