Fun with BAM and orchestration execution time
Abstract: I’ve using BAM to measure execution time in some orchestrations. I cannot use HAT because I needed to do some calculations to rest waiting time of the external processes. It’s extremely easy. Things get funny when we needed to get more that one row per orchestration instance (because of loops which are there…)
Today I’ve doing this BAM at a customer’s. I’m going back home in a high velocity train, but it’s a long trip, so I think this post is going to get long… I’ll divide it in 2 parts:
Part 1- The easy sample
The scenario is quite simple: some orchestrations provide a synchronous web service façade for a legacy system. The logic for integration with lecagy includes files interchange, sockets comminications and some transformations from/to Xml and HL7 flat files.
What we want: stress the solution and get detailed information about orchestration execution time. This execution measured time should not include web service communications or file interchange with the legacy system, because the intention is to measure BizTalk performance, regardless of network bandwidth or external dependencies.
Here is the sample:
In the simplified sample (actual processes are a little more complex :-), we must measure time between start (Receive 1) and Send 1, and time between Receive 2 and last send back (Send 2). Time between Send 1 and Receive 2 must be taken away.
All this information is in tracking database, and can be queried at a basic level with HAT. Probably it’s not very complex to query the tracking database to get these values. Since each shape has a start and end time, it’s just a question of making the right queries.
Anyways, as I have only one working day to prepare the environment for the tests, I don’t have time to study the tracking DB internals. I’ve done the easy way: BAM milestones. It’s easy because there’s no need to know about BizTalk internals (tracking db design) and flexible because BAM definitions can be designed and deployed independently to the orchestration development.
So, I’ll show how to do it in just 10 minutes (for the above sample):
1- Create BAM definition with the BAM Structures Mega Designer (aka the little Excel sheet :-). These definitions include 4 Activity Items, all of them as milestones. I’ll not use duration view items to catch intervals, instead I’ll do a Transact/SQL DATEDIFF later.
Time estimated: 3 minutes
2- Export the BAM definition to an Xml file, and deploy it in the server with BAM Management Utility (bm.exe).
Use the Tracking Profile Editor to assign each activity item to orchestration shapes.
Don’t forget to assign an Activity Id, tipically an Id field takes from the message schema.
Deploy the profiles to the server.
Time estimated: 3 minutes
3- Only have 4 minutes left, so I’ll assume there is some test automation :-).
Launch the tests (with NUnit in my case).
Open SQL Server Query Analyzer, connect to the DB server, switch to the BAMPrimaryImport database and open the corresponding BAM view. There you can see the milestones catched.
Now you can calculate execution times with basic date adds and rests. It you want to do it with SQL DATEDIFFs, execute something like this:
SELECT [fields],
DATEDIFF(ms, [Milestone1], [Milestone2]) As Segment1,
DATEDIFF(ms, [Milestone3], [Milestone4]) As Segment2,
(Segment1+Segment2) As TotalTime
Time estimated: 5 minutes (ouch, 1 minute late!)
well, actually the last part is not true… you cannot use Segment1 and Segment2 aliases in the last line, so you’ll need to repeat the DATEDIFF statements. I've included in this way to improve readability.
Also, another nice way to do it is query the standard views with Excel and play with columns and formulas.
Now we are ready to launch stress tests and query orchestration execution times easily. The stress tests will be launched via Application Center Test, so we can control concurrent users, test timing, etc.
Part 2- I have a Loop and BAM Activity items cannot be assigned
The second orchestration has been more tricky. It’s a 1-to-many façade, so it has a loop to send many messages to the legacy systems. Something like:
The problem: Activity items cannot be assigned to shapes inside the loop. Why? because each activity item is a row, and the Activity Id is taken from a message field that is unique for the orchestration.
The solution: use the API to add new BAM rows for each loop iteration. The Activity Id of each child-row will be the parent Activity Id plus the counter of the loop, so they can be related easily in a query.
The BAM API is very straightforward. One object, three methods: The EventStream object is used to create a new activity (BeginActivity method), update rows (UpdateActivity) of close the activity (EndActivity).
You can use a DirectEventStream object that writes the data in the BAMPrimaryImport database directly. This can impact the performance because it’s synchronous.
You can either use the BufferedEventStream object that use a asynchronous store-and-forward. It does not guarantee that the event will be inserted in BAM immediately, but it does not affect caller performance.
Here is the tricky thing: There is a property called ConnectionString that points to the database. If you use the DirectEventStream, ConnectionString points to BAMPrimaryImport database. But if you use BufferedEventStream, its ConnectionString points to the MessageBox database, because it’s used for store-and-forward.
My code between the orchestration and a helper component does more or less the following:
For each loop iteration:
- Begin an new Activity, using [ActivityId].[LoopCounter]
- Update with a milestone before sending to legacy
- Update with a milestone after receiving from legacy
- Close the Activity
So, for each orchestration instance, I have in the BAM database:
- One row with
- Orchestration Activity Id
- Milestones for BeginOrch and EndOrch
- Many “child” rows (the loop) with
- Orchestration Activity Id + Counter
- Milestones for BeginSend and EndReceive
The query to aggregate everything (courtesy of
eXtreme.net, because I don’t have quick Transact/SQL skills), return a single row with the calculated fields for
TotalTime and
TotalTimeWithoutLegacyStuff. It uses DATEDIFF for the differences, and SUBSTRING to relate different parent and child Activity IDs
