none
BizTalk Receive port error with trabnsaction RRS feed

  • Question

  • Hi,

    I have a WCF service and it is calling BizTalk receive port (Net-Tcp Binding). The WCF service calles BizTalk receive port in a loop with transaction following way

     

    using (TransactionScope scope = new TransactionScope(

    TransactionScopeOption.RequiresNew))

    {

              for (i=0; i< 500; i++)

    {

                 [BixTalk Proxy].Update(versionData);

                 }

     

        scope.Complete();

    }

     

    I ma getting following errors after some time in BizTalk log

     

    The adapter "WCF-NetTcp" raised an error message. Details "System.ApplicationException: System.Runtime.InteropServices.COMException (0x80004005): Error HRESULT E_FAIL has been returned from a call to a COM component.

       at Microsoft.BizTalk.Adapter.Wcf.Runtime.BizTalkAsyncResult.End()

       at Microsoft.BizTalk.Adapter.Wcf.Runtime.BizTalkServiceInstance.EndOperation(IAsyncResult result)

       at Microsoft.BizTalk.Adapter.Wcf.Runtime.BizTalkServiceInstance.Microsoft.BizTalk.Adapter.Wcf.Runtime.ITwoWayAsyncVoidTxn.EndTwoWayMethod(IAsyncResult result)

       at AsyncInvokeEndEndTwoWayMethod(Object , Object[] , IAsyncResult )

       at System.ServiceModel.Dispatcher.InvokeEndDelegate.Invoke(Object target, Object[] outputs, IAsyncResult result)

       at System.ServiceModel.Dispatcher.AsyncMethodInvoker.InvokeEnd(Object instance, Object[]& outputs, IAsyncResult result)

       at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeEnd(MessageRpc& rpc)

       at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage7(MessageRpc& rpc)

       at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)".

     

     

    The adapter "WCF-NetTcp" raised an error message. Details "System.ObjectDisposedException: Cannot access a disposed object.

    Object name: 'TransactionScope'.

       at System.Transactions.TransactionScope.Complete()

       at System.ServiceModel.Dispatcher.TransactionRpcFacet.ThreadLeave()

       at System.ServiceModel.Dispatcher.TransactionBehavior.ClearCallContext(MessageRpc& rpc)

       at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage7(MessageRpc& rpc)

       at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)".

     

     

    Service site getting following error

     

    Mcd.Rdm.Common.ExceptionHandling.RdmServiceException: Failed to send the configuration information to RdmClient - {0}. ---> System.ServiceModel.CommunicationObjectFaultedException: The communication object, System.ServiceModel.Channels.ServiceChannel, cannot be used for communication because it is in the Faulted state.

       at System.ServiceModel.Channels.CommunicationObject.Close(TimeSpan timeout)

       at System.ServiceModel.Channels.ServiceChannelFactory.OnClose(TimeSpan timeout)

       at System.ServiceModel.Channels.ServiceChannelFactory.TypedServiceChannelFactory`1.OnClose(TimeSpan timeout)

       at System.ServiceModel.Channels.CommunicationObject.Close(TimeSpan timeout)

       at System.ServiceModel.ChannelFactory.OnClose(TimeSpan timeout)

       at System.ServiceModel.Channels.CommunicationObject.Close(TimeSpan timeout)

       at System.ServiceModel.Channels.CommunicationObject.Close()

       at System.ServiceModel.ChannelFactory.System.IDisposable.Dispose()

       at Mcd.Rdm.Server.CentralManager.DomainObjects.DomainObjectBase.Invoke(RdmMessage rdmMessage)

       at Mcd.Rdm.Server.CentralManager.DomainObjects.ClientConfiguration.Send(Int32 clientId, String configuration, String guid)

     

    Please give your thoughts

     

    Thanks

     

    Ans

     

     

     

    Thursday, January 31, 2008 4:06 PM

Answers

  • Hi Ans,

    By looking at the transaction log entry "the limit on the number of children has been reached at the local transaction manager", it looks like you're hitting the MSDTC issue described in the following post

     

     

    http://forums.microsoft.com/MSDN/ShowPost.aspx?PostID=2781878&SiteID=1

     

    and, the issue was resolved with the hotfix 912818 that is part of Windows 2003 R2 SP2

    http://support.microsoft.com/kb/912818/

     

    I also tested the WCF NetTcp adapter receive location with the code below, and everything worked fine for me.

     

    Code Snippet

    [ServiceContract]

    public interface IUpdate

    {

    [OperationContractAttribute(ReplyAction = "*")]

    [TransactionFlowAttribute(System.ServiceModel.TransactionFlowOption.Mandatory)]

    void Update(Message msg);

    }

     

    static void SimpleTxn()

    {

    string uri = "net.tcp://localhost/myservice1";

    NetTcpBinding binding = new NetTcpBinding(SecurityMode.None);

    binding.TransactionFlow = true;

    binding.TransactionProtocol = TransactionProtocol.WSAtomicTransactionOctober2004;

    Message inputMessage;

    ChannelFactory<IUpdate> factory = new ChannelFactory<IUpdate>(binding, new EndpointAddress(uri));

    IUpdate channel = factory.CreateChannel();

    ((IChannel)channel).Open();

    using (TransactionScope ts = new TransactionScope(TransactionScopeOption.RequiresNew))

    {

    for (int i = 0; i < 500; i++)

    {

    inputMessage = Message.CreateMessage(MessageVersion.Soap12WSAddressing10,

    "http://tempuri.org/IUpdate/Update",

    "test message");

    channel.Update(inputMessage);

    }

    ts.Complete();

    }

    }

     

     

    Friday, February 8, 2008 1:20 AM

All replies

  • Turn tracing on for your WCF Receive adapter, you have a channel fault, so you have to determine why your channel is faulting.

     

    You can turn tracing on using the BTSNTSVC.exe.config file and apply WCF Tracing settings.

     

    HTH

     

    Friday, February 1, 2008 6:40 AM
  • Hi Dwight,

    I have enabled the MSDTC tracing both SQL Server and BizTalk Server machines, following is the error part of the the trace log.

     

    BizTalk Server MSDTC Trace Log.

     

    pid=1444 ;tid=3876 ;time=01/31/2008-17:49:01.318 ;seq=2628 ;eventid=TRACING_STARTED ;;"MSDTC is resuming the tracing of long - lived transactions"

    pid=1444 ;tid=1488 ;time=01/31/2008-17:49:56.067 ;seq=2629 ;eventid=TRACING_STOPPED ;;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    pid=1444 ;tid=3876 ;time=01/31/2008-17:50:51.129 ;seq=2630 ;eventid=TRACING_STARTED ;;"MSDTC is resuming the tracing of long - lived transactions"

    pid=1444 ;tid=1488 ;time=01/31/2008-17:51:45.878 ;seq=2631 ;eventid=TRACING_STOPPED ;;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    pid=1444 ;tid=3976 ;time=01/31/2008-21:07:40.195 ;seq=2632 ;eventid=TRACING_STARTED ;;"MSDTC is resuming the tracing of long - lived transactions"

    pid=1444 ;tid=5468 ;time=01/31/2008-21:07:42.398 ;seq=2633 ;eventid=TRANSACTION_PROPOGATED_FROM_PARENT ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"transaction propagated from parent node 'CT-DEVSQLSVR01', Description = ''"

    pid=1444 ;tid=6080 ;time=01/31/2008-21:08:40.617 ;seq=2634 ;eventid=TRANSACTION_PROPOGATION_FAILED_TOO_MANY_CHILDREN_ON_LOCAL_TM ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"failed to propogate transaction to child node 'CT-DEVSQLSVR01' because the limit on the number of children has been reached at the local transaction manager"

    pid=1444 ;tid=3876 ;time=01/31/2008-21:08:40.617 ;seq=2635 ;eventid=TRANSACTION_PROPOGATION_FAILED_TOO_MANY_CHILDREN_ON_LOCAL_TM ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"failed to propogate transaction to child node 'CT-DEVSQLSVR01' because the limit on the number of children has been reached at the local transaction manager"

    pid=1444 ;tid=6080 ;time=01/31/2008-21:08:40.632 ;seq=2636 ;eventid=TRANSACTION_ABORTING ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"transaction is aborting"

    pid=1444 ;tid=6080 ;time=01/31/2008-21:08:40.632 ;seq=2637 ;eventid=TRANSACTION_ABORTED ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"transaction has been aborted"

    pid=1444 ;tid=5468 ;time=01/31/2008-21:08:40.648 ;seq=2638 ;eventid=RECEIVED_ABORT_FROM_PARENT ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"child node received abort request from parent node 'CT-DEVSQLSVR01'"

    pid=1444 ;tid=5468 ;time=01/31/2008-21:08:40.648 ;seq=2639 ;eventid=ACKNOWLEDGING_ABORT_TO_PARENT ;tx_guid=f4089384-c048-4d6d-80ec-ed6e326c4bdb ;"child node achnowledging the delivery of abort request from parent node 'CT-DEVSQLSVR01'"

    pid=1444 ;tid=1488 ;time=01/31/2008-21:09:29.771 ;seq=2640 ;eventid=TRACING_STOPPED ;;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    pid=1444 ;tid=6080 ;time=01/31/2008-21:26:22.915 ;seq=2641 ;eventid=TRACING_STARTED ;;"MSDTC is resuming the tracing of long - lived transactions"

    pid=1444 ;tid=3976 ;time=01/31/2008-21:26:24.040 ;seq=2642 ;eventid=CHECKPOINTING_STARTED ;;"MSDTC is resuming the checkpointing of transactions "

    pid=1444 ;tid=1488 ;time=01/31/2008-21:27:17.695 ;seq=2643 ;eventid=TRACING_STOPPED ;;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    pid=1444 ;tid=6080 ;time=01/31/2008-21:27:30.039 ;seq=2644 ;eventid=TRACING_STARTED ;;"MSDTC is resuming the tracing of long - lived transactions"

    pid=1444 ;tid=1488 ;time=01/31/2008-21:28:13.585 ;seq=2645 ;eventid=CHECKPOINTING_STOPPED ;;"MSDTC is suspending the checkpointing of transactions due to lack of activity"

    pid=1444 ;tid=1488 ;time=01/31/2008-21:28:24.741 ;seq=2646 ;eventid=TRACING_STOPPED ;;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    pid=1444 ;tid=3868 ;time=01/31/2008-21:27:32.102 ;seq=2647 ;eventid=TRANSACTION_PROPOGATED_FROM_PARENT ;tx_guid=d6a912f1-fb57-45a5-81de-8179dafa7bd8 ;"transaction propagated from parent node 'CT-DEVSQLSVR01', Description = '08:40.617'"

     

     

    SQL Server MSDTC Trace Log.

     

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:47.051 ;seq=380005 ;eventid=RM_ISSUED_ABORT ;tx_guid=84647d52-fa5e-420e-a667-8d93f8167493 ;"abort request issued to resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:47.051 ;seq=380006 ;eventid=RM_ACKNOWLEDGED_ABORT ;tx_guid=84647d52-fa5e-420e-a667-8d93f8167493 ;"received acknowledgement of abort request from the resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:47.051 ;seq=380007 ;eventid=TRANSACTION_ABORTED ;tx_guid=84647d52-fa5e-420e-a667-8d93f8167493 ;"transaction has been aborted"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.020 ;seq=380008 ;eventid=TRANSACTION_PROPOGATED_FROM_PARENT ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"transaction propagated from parent node 'CT-DEVBIZSVR01', Description = 'e8ce8ebef'"

    pid=4876 ;tid=5304 ;time=01/16/2008-20:01:48.020 ;seq=380009 ;eventid=RM_ENLISTED_IN_TRANSACTION ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '8e96f9a2-914b-45f0-aba1-beee8ce8ebef'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.035 ;seq=380010 ;eventid=RECEIVED_ABORT_FROM_PARENT ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"child node received abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.035 ;seq=380011 ;eventid=TRANSACTION_ABORTING ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"transaction is aborting"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.035 ;seq=380012 ;eventid=ACKNOWLEDGING_ABORT_TO_PARENT ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"child node achnowledging the delivery of abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.035 ;seq=380013 ;eventid=RM_ISSUED_ABORT ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"abort request issued to resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:48.035 ;seq=380014 ;eventid=RM_ACKNOWLEDGED_ABORT ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"received acknowledgement of abort request from the resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:48.035 ;seq=380015 ;eventid=TRANSACTION_ABORTED ;tx_guid=a5c1bf09-6e73-43e9-87ca-61226f24c01b ;"transaction has been aborted"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.801 ;seq=380016 ;eventid=TRANSACTION_PROPOGATED_FROM_PARENT ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"transaction propagated from parent node 'CT-DEVBIZSVR01', Description = 'e8ce8ebef'"

    pid=4876 ;tid=5304 ;time=01/16/2008-20:01:48.801 ;seq=380017 ;eventid=RM_ENLISTED_IN_TRANSACTION ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '8e96f9a2-914b-45f0-aba1-beee8ce8ebef'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.816 ;seq=380018 ;eventid=RECEIVED_ABORT_FROM_PARENT ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"child node received abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.816 ;seq=380019 ;eventid=TRANSACTION_ABORTING ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"transaction is aborting"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.816 ;seq=380020 ;eventid=ACKNOWLEDGING_ABORT_TO_PARENT ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"child node achnowledging the delivery of abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:48.816 ;seq=380021 ;eventid=RM_ISSUED_ABORT ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"abort request issued to resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:48.816 ;seq=380022 ;eventid=RM_ACKNOWLEDGED_ABORT ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"received acknowledgement of abort request from the resource manager #1001 for transaction enlistment #1"

    pid=4876 ;tid=5240 ;time=01/16/2008-20:01:48.816 ;seq=380023 ;eventid=TRANSACTION_ABORTED ;tx_guid=03a88d02-f701-4ced-b7c1-b902e2384e3e ;"transaction has been aborted"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:49.239 ;seq=380024 ;eventid=TRANSACTION_PROPOGATED_FROM_PARENT ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"transaction propagated from parent node 'CT-DEVBIZSVR01', Description = 'e8ce8ebef'"

    pid=4876 ;tid=5304 ;time=01/16/2008-20:01:49.239 ;seq=380025 ;eventid=RM_ENLISTED_IN_TRANSACTION ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '8e96f9a2-914b-45f0-aba1-beee8ce8ebef'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:49.396 ;seq=380026 ;eventid=RECEIVED_ABORT_FROM_PARENT ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"child node received abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:49.396 ;seq=380027 ;eventid=TRANSACTION_ABORTING ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"transaction is aborting"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:49.396 ;seq=380028 ;eventid=ACKNOWLEDGING_ABORT_TO_PARENT ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"child node achnowledging the delivery of abort request from parent node 'CT-DEVBIZSVR01'"

    pid=4876 ;tid=4884 ;time=01/16/2008-20:01:49.396 ;seq=380029 ;eventid=RM_ISSUED_ABORT ;tx_guid=cb53f1fb-c05d-49d4-901a-6b8633ad8a18 ;"abort request issued to resource manager #1001 for transaction enlistment #1"

     

     

    Thanks

     

    Ans

    Friday, February 1, 2008 3:44 PM
  • Hi Ans,

    How is your receive location configured? Did you enable transactions on the receive location?

    Does your proxy contract have TransactionFlowAttribute?

    Tuesday, February 5, 2008 1:28 AM
  • Hi Karahan,

    Thanks for the reply, I have enabled the transaction in receive location as well as the proxy. I applied following attributes  TransactionFlowAttribute.Mandatory for contract.

     

    Thanks

     

    Ansl

     

     

     

    Tuesday, February 5, 2008 5:51 AM
  • Hi Ans,

    By looking at the transaction log entry "the limit on the number of children has been reached at the local transaction manager", it looks like you're hitting the MSDTC issue described in the following post

     

     

    http://forums.microsoft.com/MSDN/ShowPost.aspx?PostID=2781878&SiteID=1

     

    and, the issue was resolved with the hotfix 912818 that is part of Windows 2003 R2 SP2

    http://support.microsoft.com/kb/912818/

     

    I also tested the WCF NetTcp adapter receive location with the code below, and everything worked fine for me.

     

    Code Snippet

    [ServiceContract]

    public interface IUpdate

    {

    [OperationContractAttribute(ReplyAction = "*")]

    [TransactionFlowAttribute(System.ServiceModel.TransactionFlowOption.Mandatory)]

    void Update(Message msg);

    }

     

    static void SimpleTxn()

    {

    string uri = "net.tcp://localhost/myservice1";

    NetTcpBinding binding = new NetTcpBinding(SecurityMode.None);

    binding.TransactionFlow = true;

    binding.TransactionProtocol = TransactionProtocol.WSAtomicTransactionOctober2004;

    Message inputMessage;

    ChannelFactory<IUpdate> factory = new ChannelFactory<IUpdate>(binding, new EndpointAddress(uri));

    IUpdate channel = factory.CreateChannel();

    ((IChannel)channel).Open();

    using (TransactionScope ts = new TransactionScope(TransactionScopeOption.RequiresNew))

    {

    for (int i = 0; i < 500; i++)

    {

    inputMessage = Message.CreateMessage(MessageVersion.Soap12WSAddressing10,

    "http://tempuri.org/IUpdate/Update",

    "test message");

    channel.Update(inputMessage);

    }

    ts.Complete();

    }

    }

     

     

    Friday, February 8, 2008 1:20 AM