Measuring solicit-response latency

To measure latency when calling external web services, you can query the tracking database with the following query:

SELECT
    [sf].[Service/Name],
    [sf].[Service/Type],
    [mf].[Event/Port],
    [mf].[Event/URL],
    [mf].[Event/Direction],
    [sf].[ServiceInstance/StartTime],
    [sf].[ServiceInstance/EndTime],
    [sf].[ServiceInstance/Duration]
FROM [dbo].[dtav_ServiceFacts] sf
LEFT JOIN [dbo].[dtav_MessageFacts] mf ON [mf].[ServiceInstance/ActivityID] = [sf].[ServiceInstance/ActivityID] AND [mf].[ServiceInstance/InstanceID] = [sf].[ServiceInstance/InstanceID]
WHERE [ServiceInstance/StartTime] >= ‘2008-10-30 06:00:00’ — Time in UTC
ORDER BY [ServiceInstance/StartTime] ASC

The result will contain four rows for each solicit-respons call similar to these:

Service/Name

Service/Type

Event/Port

Event/URL

Event/Direction

ServiceInstance/StartTime

ServiceInstance/EndTime

ServiceInstance/Duration

Microsoft.BizTalk.DefaultPipelines.PassThruTransmit

Pipeline

GEMIGetTicketData_SOAP_Port

https://***/SecurityApi.asmx

Send

2008-10-13 06:28:50.957

2008-10-13 06:28:56.193

5236

Microsoft.BizTalk.DefaultPipelines.PassThruTransmit

Pipeline

GEMIGetTicketData_SOAP_Port

https://***/SecurityApi.asmx

Receive

2008-10-13 06:28:50.957

2008-10-13 06:28:56.193

5236

Microsoft.BizTalk.DefaultPipelines.XMLReceive

Pipeline

GEMIGetTicketData_SOAP_Port

https://***/SecurityApi.asmx

Send

2008-10-13 06:28:55.443

2008-10-13 06:28:56.193

750

Microsoft.BizTalk.DefaultPipelines.XMLReceive

Pipeline

GEMIGetTicketData_SOAP_Port

https://***/SecurityApi.asmx

Receive

2008-10-13 06:28:55.443

2008-10-13 06:28:56.193

750

As you can see, the duration of the transmit pipeline includes the duration of the receive pipeline (they both have the same end time). Duration is in milliseconds.
 
To get a somewhat cleaner view, you can use BAM. I suggest you define an activity and a view similar to this. (You can copy and paste this into an XML file that you can import in Excel or use directly.)
 
<?xml version="1.0" encoding="UTF-16"?>
<BAMDefinition xmlns="http://schemas.microsoft.com/BizTalkServer/2004/10/BAM">
 <Activity Name="WSLatency" ID="ID39FF3D648BC8445F9982602A1D3704B7">
  <Checkpoint Name="Start" ID="IDF95FC7DB7ABE404888A50F106565BDEC" DataType="DATETIME"/>
  <Checkpoint Name="Finish" ID="ID4212694A199D4B1C8D55937298037328" DataType="DATETIME"/>
  <Checkpoint Name="Location" ID="IDC2D746491A02459DBE5E8537D5D59DB9" DataType="NVARCHAR" DataLength="200"/>
  <Checkpoint Name="Port" ID="ID4E79B424FFFD48359274F4D46BA643AA" DataType="NVARCHAR" DataLength="100"/>
  <Checkpoint Name="Operation" ID="ID32077CA862B54CC8B591549E5D5BEE86" DataType="NVARCHAR" DataLength="50"/>
 </Activity>
 <View Name="WSLatency" ID="IDFF67BCD520D4406889F3AFA11AE6B0B8">
  <ActivityView Name="ViewLatency" ID="ID727CD165367949849DB75050CFBC5CC4" ActivityRef="ID39FF3D648BC8445F9982602A1D3704B7">
   <Alias Name="Finish" ID="IDD6B7518D6BE042F88BF9462B1F432E47">
    <CheckpointRef>ID4212694A199D4B1C8D55937298037328</CheckpointRef>
   </Alias>
   <Alias Name="Start" ID="IDDBCB264F492A48FB998485E1A4C38240">
    <CheckpointRef>IDF95FC7DB7ABE404888A50F106565BDEC</CheckpointRef>
   </Alias>
   <Alias Name="Location" ID="ID187C9D2E6A9D476C80401BB3FD9C6F1A">
    <CheckpointRef>IDC2D746491A02459DBE5E8537D5D59DB9</CheckpointRef>
   </Alias>
   <Alias Name="Port" ID="ID4500F957D1B94F0D834E22615000E072">
    <CheckpointRef>ID4E79B424FFFD48359274F4D46BA643AA</CheckpointRef>
   </Alias>
   <Alias Name="Operation" ID="IDFBBD6CDC94004BAF8922E2D30A6A1B73">
    <CheckpointRef>ID32077CA862B54CC8B591549E5D5BEE86</CheckpointRef>
   </Alias>
   <Duration Name="Duration" ID="IDCD664E2C0046424FA00B856611B03683" TimeResolution="Second">
    <FromAliasRef>IDDBCB264F492A48FB998485E1A4C38240</FromAliasRef>
    <ToAliasRef>IDD6B7518D6BE042F88BF9462B1F432E47</ToAliasRef>
   </Duration>
  </ActivityView>
 </View>
</BAMDefinition>
 
You then define and apply a tracking profile. Here is a template you can use. (Copy, paste and save as a .btt file.)
 
<?xml version="1.0" encoding="utf-16"?>
<TrackingProfile xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" VersionGuid="00000000-0000-0000-0000-000000000000" Name="WSLatency">
 <Dimension Name="ActivityID" DataType="TraceID" />
 <Dimension Name="Start" DataType="DATETIME">
  <DataLevel Name="PortStartTime" SourceTypeSelected="Messaging Property" SchemaName="Messaging Property Schema" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’MessageProperties&#8217; and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’PortStartTime&#8217; and namespace-uri()=”]" XPath="/*[local-name()=’MessageProperties’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’PortStartTime&#8217; and namespace-uri()=”]">
  </DataLevel>
 </Dimension>
 <Dimension Name="Finish" DataType="DATETIME">
  <DataLevel Name="PortEndTime" SourceTypeSelected="Messaging Property" SchemaName="Messaging Property Schema" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’MessageProperties&#8217; and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’PortEndTime&#8217; and namespace-uri()=”]" XPath="/*[local-name()=’MessageProperties’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’PortEndTime&#8217; and namespace-uri()=”]">
  </DataLevel>
 </Dimension>
 <Dimension Name="Location" DataType="NVARCHAR">
  <DataLevel Name="OutboundTransportLocation" SourceTypeSelected="Messaging Context Property" SchemaName="BTS.bts_system_properties,Microsoft.BizTalk.GlobalPropertySchemas, Version=3.0.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D/*%5Blocal-name()=’OutboundTransportLocation&#8217; and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D&quot; XPath="/*[local-name()=’OutboundTransportLocation’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D"&gt;
  </DataLevel>
  <DataLevel Name="InboundTransportLocation" SourceTypeSelected="Messaging Context Property" SchemaName="BTS.bts_system_properties,Microsoft.BizTalk.GlobalPropertySchemas, Version=3.0.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D/*%5Blocal-name()=’InboundTransportLocation&#8217; and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D&quot; XPath="/*[local-name()=’InboundTransportLocation’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D"&gt;
  </DataLevel>
 </Dimension>
 <Dimension Name="Port" DataType="NVARCHAR">
  <DataLevel Name="SPName" SourceTypeSelected="Messaging Context Property" SchemaName="BTS.bts_system_properties,Microsoft.BizTalk.GlobalPropertySchemas, Version=3.0.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D/*%5Blocal-name()=’SPName&#8217; and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D&quot; XPath="/*[local-name()=’SPName’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D"&gt;
  </DataLevel>
  <DataLevel Name="ReceivePortName" SourceTypeSelected="Messaging Context Property" SchemaName="BTS.bts_system_properties,Microsoft.BizTalk.GlobalPropertySchemas, Version=3.0.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D/*%5Blocal-name()=’ReceivePortName&#8217; and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D&quot; XPath="/*[local-name()=’ReceivePortName’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2003/system-properties’%5D"&gt;
  </DataLevel>
 </Dimension>
 <Dimension Name="Operation" DataType="NVARCHAR">
  <DataLevel Name="Action" SourceTypeSelected="Messaging Context Property" SchemaName="WCF.WCFPropertySchema,Microsoft.BizTalk.GlobalPropertySchemas, Version=3.0.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2006/01/Adapters/WCF-properties’%5D/*%5Blocal-name()=’Action&#8217; and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2006/01/Adapters/WCF-properties’%5D&quot; XPath="/*[local-name()=’Action’ and namespace-uri()=’http://schemas.microsoft.com/BizTalk/2006/01/Adapters/WCF-properties’%5D"&gt;
  </DataLevel>
 </Dimension>
 <Dimension Name="Continuation" DataType="Continuation">
  <DataLevel Name="InstanceID" SourceTypeSelected="Messaging Property" SchemaName="Messaging Property Schema" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’MessageProperties&#8217; and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’InstanceID&#8217; and namespace-uri()=”]" XPath="/*[local-name()=’MessageProperties’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’InstanceID&#8217; and namespace-uri()=”]">
  </DataLevel>
 </Dimension>
 <Dimension Name="Continuation" DataType="ContinuationID">
  <DataLevel Name="InstanceID" SourceTypeSelected="Messaging Property" SchemaName="Messaging Property Schema" SomXPath="/*[local-name()=’&lt;Schema&gt;’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’MessageProperties&#8217; and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’InstanceID&#8217; and namespace-uri()=”]" XPath="/*[local-name()=’MessageProperties’ and namespace-uri()=’http://OrderProcess.Schema1′%5D/*%5Blocal-name()=’InstanceID&#8217; and namespace-uri()=”]">
  </DataLevel>
 </Dimension>
 <Dimension Name="CustomData" DataType="NVARCHAR" />
</TrackingProfile>
 
Perform the following port mappings:

• PortStartTime: All send ports (direction send) and all receive ports (direction receive)
• PortEndTime:  All send ports (direction receive) and all receive ports (direction send)
• OutboundTransportLocation: All send ports (direction send)
• InboundTransportLocation: All receive ports (direction receive)
• SPName: All send ports (direction send)
• ReceivePortName: All receive ports (direction receive)
• Action: All receive ports (direction receive)
• Continuation InstanceID: All send ports (direction send) and all receive ports (direction receive)
• Continuation ID Instance ID: All send ports (direction receive) and all receive ports (direction send)

Either use BAM portal to view the results, or use the following database query:

use BAMPrimaryImport

select Port, Location, Operation, Start, Finish, PortDuration = (CAST(Finish AS FLOAT) – CAST(Start AS FLOAT))*86400000
from bam_wslatency_allinstances
where start >= ‘2008-10-30 06:00:00’ — Time in UTC
order by Start ASC