BAM Tracking not working correctly with custom pipeline component when message type is unknown
We recently received a problem reported by our customer that BAM tracking doesn't work correctly with custom pipeline component when message type is unknown. Below are the details.
The problem:
We are using Microsoft Biztalk Server 2013 R2. The problem that I am having is to do with BAM. BAM isn’t "continuing" correctly if the Send Port contains a custom "Send Pipeline". It works fine with the default "PassThruTransmit" Send Pipeline
BAM scenario that “continues” OK (correlates the Receive and Send Port activities)
1) A Receive Port picks up a zip file that contains binary data. It uses a FILE Adapter and a “PassThruReceive” pipeline
2) A Send Port subscribes to the ReceivePortName property. It uses a FILE Adapter and a “PassThruTransmit” pipeline
3) A BAM activity has been created on the Receive Port and the Send Port.
4) There is a BAM tracking profile setup on the Receive Port and the Send Port. It uses the InterchangeID for continuation
5) If I drop a file in the Biztalk ReceiveLocation, then the Send Port continuation is being recorded in the BAM Activity tables OK
BAM scenario that breaks “continuation”
I change the Send Port so that it has a
- Custom send pipeline
- i.
- That contains a single pipeline component (with no properties) created with the “Pipeline Component Project” supplied with Visual Studio
- i.
- And this pipeline component just has the default implementation of the IComponent.Execute method (created by the Pipeline Component Wizard)
Once I change the Send Port to use this pipeline then the Send Port does not continue correctly (using the same BAM activity and tracking profile as before)
Debugging of custom pipeline component scenario:
In the TTT trace I captured, I can clearly see the following call stack of DoBamTracking() API when a msg with *known* message type triggered BAM tracking. As you can see, the AddBamTrackingXPath() and LoadBAMConfig() calls are properly invoked by ProcessXmlNodes() to retrieve and add the BAM data of the send port .
Working Callstack:
=================================
13> kc
#
00 Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Messaging.BAMArtifactCache.LoadBAMConfig(System.String, Int32, System.String, System.String)
01 Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Messaging.BAMMessagingInterceptorBase.LoadTrackPointInformationByMessageType(System.Guid, System.String)
02 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmReader.AddBamTrackingXPath(System.Guid, System.String, Microsoft.BizTalk.Message.Interop.IBaseMessageContext, Microsoft.BizTalk.Component.Interop.IPipelineContext, Microsoft.BizTalk.Component.XPathAnnotationCollection)
03 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmReader.Read()
04 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmStreamWrapper.ProcessXmlNodes(Int32)
05 Microsoft_BizTalk_Streaming!Microsoft.BizTalk.Streaming.XmlBufferedReaderStream.Process()
06 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmStreamWrapper.ReadInternal(Byte[], Int32, Int32)
07 Microsoft_BizTalk_Streaming!Microsoft.BizTalk.Streaming.EventingReadStream.Read(Byte[], Int32, Int32)
08 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetOutputData(System.IO.Stream, System.String)
09 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetNext2(Microsoft.BizTalk.Component.Interop.IPipelineContext)
0a Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetNext(Microsoft.BizTalk.Component.Interop.IPipelineContext)
0b Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Internal.ComponentWrapper.GetNext(Microsoft.BizTalk.Component.Interop.IPipelineContext)
0c Microsoft_BizTalk_Pipeline!Microsoft.BizTalk.PipelineOM.Pipeline.DoBamTracking(Microsoft.BizTalk.Message.Interop.IBaseMessage, BamTrackingMode, Boolean, Boolean)
Message with valid schema:
0:013> !DumpObj /d 0fde7c54
Name: System.Byte[]
MethodTable: 736a6d34
EEClass: 7330cb44
Size: 268(0x10c) bytes
Array: Rank 1, Number of elements 256, Type Byte (Print Array)
Content: ...<ns0:Root xmlns:ns0="https://EmptyCustomPipeline.Schema1".....................................................................
Fields:
None
However in the case of input message without valid message type, I found the AddBamTrackingXPath() and LoadBAMConfig() functions will never be called.
Non-working callstack:
=================================
0:013> kc
#
00 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmReader.Read()
01 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmStreamWrapper.ProcessXmlNodes(Int32)
Unable to load image Microsoft.BizTalk.Streaming.dll, Win32 error 0n2
*** ERROR: Module load completed but symbols could not be loaded for Microsoft.BizTalk.Streaming.dll
02 Microsoft_BizTalk_Streaming!Microsoft.BizTalk.Streaming.XmlBufferedReaderStream.Process()
03 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmStreamWrapper.ReadInternal(Byte[], Int32, Int32)
04 Microsoft_BizTalk_Streaming!Microsoft.BizTalk.Streaming.EventingReadStream.Read(Byte[], Int32, Int32)
05 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetOutputData(System.IO.Stream, System.String)
06 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetNext2(Microsoft.BizTalk.Component.Interop.IPipelineContext)
07 Microsoft_BizTalk_Pipeline_Components!Microsoft.BizTalk.Component.XmlDasmComp.GetNext(Microsoft.BizTalk.Component.Interop.IPipelineContext)
08 Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Internal.ComponentWrapper.GetNext(Microsoft.BizTalk.Component.Interop.IPipelineContext)
09 Microsoft_BizTalk_Pipeline!Microsoft.BizTalk.PipelineOM.Pipeline.DoBamTracking(Microsoft.BizTalk.Message.Interop.IBaseMessage, BamTrackingMode, Boolean, Boolean)
Message without valid schema:
0:013> !DumpObj /d 0fdd6c48
Name: System.Byte[]
MethodTable: 736a6d34
EEClass: 7330cb44
Size: 268(0x10c) bytes
Array: Rank 1, Number of elements 256, Type Byte (Print Array)
Content: ...<Root........................................................................................................................
Fields:
None
Then I dig into the code of XmlDasmStreamWrapper.ProcessXmlNodes() and XmlDasmReader.Read() and confirm it does only process BAM tracking data for recognized messages. Please refer to the code snippet below.
Reflected code:
=================================
// Microsoft.BizTalk.Component.XmlDasmReader
public override bool Read()
{
bool flag = true;
if (this.m_state == XmlDasmReader.ProcessingState.finish)
{
flag = false;
}
else
{
if (this.m_bNewDoc)
{
NodeProcessor current = this.m_npStk.Current;
if (current.RecognizedMessage && this.BAMTrackingNeeded)
{
XmlDasmReader.AddBamTrackingXPath(this.BAMTrackingID, current.DocType, current.MessageContext, this.PipelineContext, current.XPathAnnotations);
}
if (this.HasAttributes)
{
this.DoAttributeProcessing(current);
}
}
…
Debugging of passthrough pipeline scenario:
Just as the assumption, the default passthrough pipeline’s code path/callstack to write BAM tracking data is different.
0:013> kc
#
00 Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Messaging.BAMArtifactCache.LoadBAMConfig(System.String, Int32, System.String, System.String)
01 Microsoft_BizTalk_Messaging!Microsoft.BizTalk.Messaging.BAMMessagingInterceptorBase.LoadTrackPointInformationByMessageType(System.Guid, System.String)
02 Microsoft_BizTalk_Pipeline!Microsoft.BizTalk.PipelineOM.Pipeline.IsMessageContentTracking(Microsoft.BizTalk.PipelineOM.IBAMMessagingInterceptorInt, System.Guid, System.String)
03 Microsoft_BizTalk_Pipeline!Microsoft.BizTalk.PipelineOM.Pipeline.DoBamTracking(Microsoft.BizTalk.Message.Interop.IBaseMessage, BamTrackingMode, Boolean, Boolean)
By comparing to the previous TTT, the IsMessageContentTracking() functionnever gets called incustom empty pipeline’s scenario.
1b7e81d3 8b4d98 mov ecx,dword ptr [ebp-68h]
1b7e81d6 ff157c040901 call dword ptr ds:[109047Ch] (CLRStub[VSD_DispatchStub]@89f608b90109848a)
1b7e81dc 8d45b8 lea eax,[ebp-48h]
1b7e81df 83ec10 sub esp,10h
1b7e81e2 f30f7e00 movq xmm0,mmword ptr [eax]
1b7e81e6 660fd60424 movq mmword ptr [esp],xmm0
1b7e81eb f30f7e4008 movq xmm0,mmword ptr [eax+8]
1b7e81f0 660fd6442408 movq mmword ptr [esp+8],xmm0
1b7e81f6 56 push esi
1b7e81f7 8b4db0 mov ecx,dword ptr [ebp-50h]
1b7e81fa 8b559c mov edx,dword ptr [ebp-64h]
1b7e81fd ff15300a701a call dword ptr ds:[1A700A30h] (Microsoft.BizTalk.PipelineOM.Pipeline.IsMessageContentTracking(Microsoft.BizTalk.PipelineOM.IBAMMessagingInterceptorInt, System.Guid, System.String), mdToken: 060006e6)
1b7e8203 85c0 test eax,eax
The code snippet is like below. The reason is that in passthrough pipeline, stage count is 0. But in custom pipeline with our empty pipeline component, the stage count is 1. So the code jumps/goto to IL_1C7 and skips the call of IsMessageContentTracking().
if (this.StageCount != 0)
{
if (!messagingEngineSettings.get_DontRemoveXmlDeclarationHeaders())
{
goto IL_1C7;
}
}
try
{
if (string.IsNullOrEmpty(obj2 as string))
{
obj2 = Utils.GetDocType(markableForwardOnlyEventingReadStream);
}
}
catch (Exception)
{
}
try
{
string text = obj2 as string;
if (this.IsMessageContentTracking(iBAMMessagingInterceptorInt, iBTMPipelineContext.BAMGuid, text) && text != null && this.PipelineContext.GetDocumentSpecByType(text) != null)
{
flag4 = true;
}
}
catch (Exception)
{
}
if (flag4)
{
baseMessageContext.Promote("RecoverableInterchangeProcessing", "https://schemas.microsoft.com/BizTalk/2003/xmlnorm-properties", true);
}
IL_1C7:
object obj3 = baseMessageContext.Read("ErrorType", "https://schemas.microsoft.com/BizTalk/2005/error-report");
if (((supportOnlyContextTracking && !flag4) || (handleNonXmlErrorMessages && obj3 != null && string.Compare((string)obj3, "FailedMessage", StringComparison.OrdinalIgnoreCase) == 0)) && stream != null)
{
baseMessageContext.Promote("RecoverableInterchangeProcessing", "https://schemas.microsoft.com/BizTalk/2003/xmlnorm-properties", true);
flag2 = true;
}
Stages in Passthrough pipeline:
==================================
0:013> !DumpObj /d 07b1a73c
Name: Microsoft.BizTalk.DefaultPipelines.PassThruTransmit
MethodTable: 1a704e50
EEClass: 1a719e6c
Size: 32(0x20) bytes
File: C:\windows\assembly\GAC_MSIL\Microsoft.BizTalk.DefaultPipelines\3.0.1.0__31bf3856ad364e35\Microsoft.BizTalk.DefaultPipelines.dll
Fields:
MT Field Offset Type VT Attr Value Name
1acfff14 400025d 14 System.Int32 1 instance 1 kind
736a560c 400025e 18 System.Int32 1 instance 2 pipelineAssemblyId
1a701240 400025f 4 ...M.PipelineContext 0 instance 07b1a82c pipelineContext
736a13bc 4000260 8 ...ections.ArrayList 0 instance 07b1a75c stages
736a60f0 4000261 c ...ections.Hashtable 0 instance 07b1a774 components
1a701aec 4000262 10 ...ncePipelineConfig 0 instance 07b1a7d8 PipelinePerInstanceConfig
0:013> !DumpObj /d 07b1a75c
Name: System.Collections.ArrayList
MethodTable: 736a13bc
EEClass: 7330ac44
Size: 24(0x18) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
73660cbc 4000c37 4 System.Object[] 0 instance 01af253c _items
736a560c 4000c38 c System.Int32 1 instance 0 _size
736a560c 4000c39 10 System.Int32 1 instance 0 _version
736a41b8 4000c3a 8 System.Object 0 instance 00000000 _syncRoot
73660cbc 4000c3b 2fc System.Object[] 0 shared static emptyArray
>> Domain:Value 005633f0:01af253c <<
Stages in my custom pipeline:
==================================
0:013> !DumpObj /d 0fdd8174
Name: EmptyCustomPipeline.EmptyPipeline
MethodTable: 1b0f4e70
EEClass: 1b0eb1d8
Size: 32(0x20) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_MSIL\EmptyCustomPipeline\v4.0_1.0.0.0__d89f3063b443ebd1\EmptyCustomPipeline.dll
Fields:
MT Field Offset Type VT Attr Value Name
1b29fa60 400025d 14 System.Int32 1 instance 1 kind
736a560c 400025e 18 System.Int32 1 instance 2067 pipelineAssemblyId
1b0f0ec0 400025f 4 ...M.PipelineContext 0 instance 0fddb770 pipelineContext
736a13bc 4000260 8 ...ections.ArrayList 0 instance 0fdd8194 stages
736a60f0 4000261 c ...ections.Hashtable 0 instance 0fdd81ac components
1b0f176c 4000262 10 ...ncePipelineConfig 0 instance 0fdd8210 PipelinePerInstanceConfig
0:013> !DumpObj /d 0fdd8194
Name: System.Collections.ArrayList
MethodTable: 736a13bc
EEClass: 7330ac44
Size: 24(0x18) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
73660cbc 4000c37 4 System.Object[] 0 instance 0fdd82cc _items
736a560c 4000c38 c System.Int32 1 instance 1 _size
736a560c 4000c39 10 System.Int32 1 instance 1 _version
736a41b8 4000c3a 8 System.Object 0 instance 00000000 _syncRoot
73660cbc 4000c3b 2fc System.Object[] 0 shared static emptyArray
>> Domain:Value 009233f0:01dd253c <<
I then went ahead to test by creating an *actual empty* pipeline without any component and the result of it is equal to the passthrough pipeline.
Currently a bug has been created and we are working on this issue.
Best regards,
WenJun Zhang