netTcpBinding WCF works fine but Exceptions found in trace Error in .net clients and Biztalk sendports

Question

Hi I am using WCF nettcp binding to connect to a service. The operation completes successfully, but errors are logged when WCF tracing (filter errors) is turned on.

<Exception>
<ExceptionType>System.ServiceModel.CommunicationException, System.ServiceModel, Version=3.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</ExceptionType>
<Message>The socket connection was aborted. This could be caused by an error processing your message or a receive timeout being exceeded by the remote host, or an underlying network resource issue. Local socket timeout was '00:02:30.0000001'.</Message>
<StackTrace>
at System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing)
at System.ServiceModel.Channels.SocketConnection.Close(TimeSpan timeout)
at System.ServiceModel.Channels.BufferedConnection.Close(TimeSpan timeout)
at System.ServiceModel.Channels.ConnectionPool.CloseItem(IConnection item, TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationPool`2.EndpointConnectionPool.CloseItem(TItem item, TimeSpan timeout)
at System.ServiceModel.Channels.IdlingCommunicationPool`2.IdleTimeoutEndpointConnectionPool.CloseItem(TItem item, TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationPool`2.EndpointConnectionPool.CloseIdleConnection(TItem connection, TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationPool`2.EndpointConnectionPool.TakeConnection(TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationPool`2.TakeConnection(EndpointAddress address, Uri via, TimeSpan timeout, TKey&amp; key)
at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnection(TimeSpan timeout)
at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpen(TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannel.OnOpen(TimeSpan timeout)
at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.CallOnce(TimeSpan timeout, CallOnceManager cascade)
at System.ServiceModel.Channels.ServiceChannel.EnsureOpened(TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData&amp; msgData, Int32 type)
...

.....

....

...

.....

....

at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]&amp; outputs)
at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc&amp; rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc&amp; rpc)
at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc&amp; rpc)
at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
at System.ServiceModel.Dispatcher.ChannelHandler.DispatchAndReleasePump(RequestContext request, Boolean cleanThread, OperationContext currentOperationContext)
at System.ServiceModel.Dispatcher.ChannelHandler.HandleRequest(RequestContext request, OperationContext currentOperationContext)
at System.ServiceModel.Dispatcher.ChannelHandler.AsyncMessagePump(IAsyncResult result)
at System.ServiceModel.Diagnostics.Utility.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
at System.ServiceModel.AsyncResult.Complete(Boolean completedSynchronously)
at System.ServiceModel.Channels.InputQueue`1.AsyncQueueReader.Set(Item item)
at System.ServiceModel.Channels.InputQueue`1.EnqueueAndDispatch(Item item, Boolean canDispatchOnThisThread)
at System.ServiceModel.Channels.InputQueue`1.EnqueueAndDispatch(T item, ItemDequeuedCallback dequeuedCallback, Boolean canDispatchOnThisThread)
at System.ServiceModel.Channels.InputQueueChannel`1.EnqueueAndDispatch(TDisposable item, ItemDequeuedCallback dequeuedCallback, Boolean canDispatchOnThisThread)
at System.ServiceModel.Channels.SingletonChannelAcceptor`3.Enqueue(QueueItemType item, ItemDequeuedCallback dequeuedCallback, Boolean canDispatchOnThisThread)
at System.ServiceModel.Channels.SingletonChannelAcceptor`3.Enqueue(QueueItemType item, ItemDequeuedCallback dequeuedCallback)
at System.ServiceModel.Channels.HttpChannelListener.HttpContextReceived(HttpRequestContext context, ItemDequeuedCallback callback)
at System.ServiceModel.Activation.HostedHttpTransportManager.HttpContextReceived(HostedHttpRequestAsyncResult result)
at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.BeginRequest()
at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.OnBeginRequest(Object state)
at System.ServiceModel.Channels.IOThreadScheduler.CriticalHelper.WorkItem.Invoke2()
at System.ServiceModel.Channels.IOThreadScheduler.CriticalHelper.WorkItem.Invoke()
at System.ServiceModel.Channels.IOThreadScheduler.CriticalHelper.ProcessCallbacks()
at System.ServiceModel.Channels.IOThreadScheduler.CriticalHelper.CompletionCallback(Object state)
at System.ServiceModel.Channels.IOThreadScheduler.CriticalHelper.ScheduledOverlapped.IOCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
at System.ServiceModel.Diagnostics.Utility.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
</StackTrace>
<ExceptionString>System.ServiceModel.CommunicationException: The socket connection was aborted. This could be caused by an error processing your message or a receive timeout being exceeded by the remote host, or an underlying network resource issue. Local socket timeout was '00:02:30.0000001'. ---&gt; System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing)
   --- End of inner exception stack trace ---</ExceptionString>
<InnerException>
<ExceptionType>System.Net.Sockets.SocketException, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</ExceptionType>
<Message>An existing connection was forcibly closed by the remote host</Message>
<StackTrace>
at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
at System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing)
</StackTrace>
<ExceptionString>System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing)</ExceptionString>
<NativeErrorCode>2746</NativeErrorCode>
</InnerException>
</Exception>

Binding

<binding name="NetTcpBinding_ITwoWayAsync" closeTimeout="00:05:00"
     openTimeout="00:05:00" receiveTimeout="00:10:00" sendTimeout="00:05:00"
     transactionFlow="false" transferMode="Buffered" transactionProtocol="OleTransactions"
     hostNameComparisonMode="StrongWildcard" listenBacklog="10" maxBufferPoolSize="10485760"
     maxBufferSize="10485760" maxConnections="10" maxReceivedMessageSize="10485760">
     <readerQuotas maxDepth="10485760" maxStringContentLength="10485760" maxArrayLength="10485760"
      maxBytesPerRead="10485760" maxNameTableCharCount="10485760" />
     <reliableSession ordered="true" inactivityTimeout="00:10:00"
      enabled="false" />
     <security mode="Transport">
      <transport clientCredentialType="Windows" protectionLevel="EncryptAndSign" />
      <message clientCredentialType="Windows" />
     </security>
    </binding>

I am also using biztalk to connect to a service via WCF nettcp 2 way send port . When I turn Biztalk WCF tracing on (errors only) I can again see similar errors logged.

 

Please note: the operation is completed successfully in both cases. It is just that these errors , that are probably not relevant???, are logged . It just becomes hard to identify what is a relevant error and what a normal operation is.

Answer 1

Hello, do you see those exceptions logged in every request or just randomly? Sometimes due to various issues (such as network connectivity issues, idle timeout, etc.), you may see some exceptions in the log. It's safe to ignore if everything is working fine. But check if you can do anything to optimize the solution. For example, if you often see idle timeout, consider to reduce the idle timeout setting so old connections can be closed more quickly and server resources are recycled. Your client may not be as active as you might think.

---

Lante, shanaolanxing This posting is provided "AS IS" with no warranties, and confers no rights.
If you have feedback about forum business, please contact [e-mail]. But please do not ask technical questions in the email.

Answer 2

Acutally it is very easy to reproduce

1. Turn tracing on the client  (errors atleast) and server ( information level.)

2. Restart the service exposed via nettcp binding.

3. Invoke the client -  Operation completes succesfully with no errors in trace.

4. Wait for about 2-3 minutes ( depending on when the service timeouts are set to close connections) until the service logs the trace information shown below

5. Invoke the client -  Operation completes succesfully but trace errors recorded

The error reported (see my first post for the trace error) on the client happens after the server logs the following trace information. 

We are an operations team and have set up alerts whenever errors are logged on the server. Such errors are causing unnecessary noise, unless there is way of preventing this error or any ideas on how to filter this noise out?

Server Side Trace  Information

-------------------------

<TraceRecord xmlns="http://schemas.microsoft.com/2004/10/E2ETraceEvent/TraceRecord" Severity="Information"><TraceIdentifier>http://msdn.microsoft.com/en-AU/library/System.ServiceModel.Diagnostics.ThrowingException.aspx</TraceIdentifier><Description>Throwing an exception.</Description><AppDomain>EmailWindowsService.exe</AppDomain><Exception><ExceptionType>System.TimeoutException, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</ExceptionType><Message>The socket was aborted because an asynchronous receive from the socket did not complete within the allotted timeout of 00:02:00. The time allotted to this operation may have been a portion of a longer timeout.</Message><StackTrace>   at System.ServiceModel.Channels.SocketConnection.EndRead()
   at System.ServiceModel.Channels.DelegatingConnection.EndRead()
   at System.ServiceModel.Channels.ConnectionModeReader.GetReadResult()
   at System.ServiceModel.Channels.ConnectionModeReader.ReadCallback(Object state)
   at System.ServiceModel.Channels.SocketConnection.FinishRead()
   at System.ServiceModel.Channels.SocketConnection.AsyncReadCallback(Boolean haveResult, Int32 error, Int32 bytesRead)
   at System.ServiceModel.Channels.OverlappedContext.CompleteCallback(UInt32 error, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
   at System.ServiceModel.Diagnostics.Utility.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
   at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
</StackTrace><ExceptionString>System.TimeoutException: The socket was aborted because an asynchronous receive from the socket did not complete within the allotted timeout of 00:02:00. The time allotted to this operation may have been a portion of a longer timeout. ---&amp;gt; System.Net.Sockets.SocketException: The I/O operation has been aborted because of either a thread exit or an application request
   --- End of inner exception stack trace ---</ExceptionString><InnerException><ExceptionType>System.Net.Sockets.SocketException, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</ExceptionType><Message>The I/O operation has been aborted because of either a thread exit or an application request</Message><StackTrace>   at System.ServiceModel.Channels.SocketConnection.EndRead()
   at System.ServiceModel.Channels.DelegatingConnection.EndRead()
   at System.ServiceModel.Channels.ConnectionModeReader.GetReadResult()
   at System.ServiceModel.Channels.ConnectionModeReader.ReadCallback(Object state)
   at System.ServiceModel.Channels.SocketConnection.FinishRead()
   at System.ServiceModel.Channels.SocketConnection.AsyncReadCallback(Boolean haveResult, Int32 error, Int32 bytesRead)
   at System.ServiceModel.Channels.OverlappedContext.CompleteCallback(UInt32 error, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
   at System.ServiceModel.Diagnostics.Utility.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
   at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
</StackTrace><ExceptionString>System.Net.Sockets.SocketException: The I/O operation has been aborted because of either a thread exit or an application request</ExceptionString><NativeErrorCode>3E3</NativeErrorCode></InnerException></Exception></TraceRecord></DataItem></TraceData></ApplicationData></E2ETraceEvent> 

Answer 3

If you no longer need a client for a while, it is recommended to close it manually. Then you won't see such errors, and you can save a few server resources. Once you want to invoke another service operation, you can create a new instance of the client proxy.

---

Lante, shanaolanxing This posting is provided "AS IS" with no warranties, and confers no rights.
If you have feedback about forum business, please contact [e-mail]. But please do not ask technical questions in the email.

Answer 4

    serviceproxy client = null;
        try
        {
           client = new serviceproxy();
//  Processing Here
      }
        finally
        {
            if (client != null)
            {
                if (client.State == CommunicationState.Faulted) client.Abort();
                else client.Close();
            }
        }

I do close the client, i use the sample code above and I still see the errors.

Also, the error is logged by Biztalk Send port using WCF nettcp binding, again only when WCF tracing (Error level) is turned on, but the operation completes successfully.