Order of Transfer out/Stop in ActivityScope

Jan 3, 2016 at 2:46 PM
Edited Jan 3, 2016 at 2:50 PM
The order of events generated when disposing an ActivityScope seems backwards.

ActivityScope generates a 'Transfer In' and then a Start events
On dispose it generates 'Transfer out' and then Stop events.

I was expecting the Stop to be generated before the Transfer out event.

In the image below you can see that the Transfer event is returning the previous ActivityId . However the next Stop event is still associated to the id set within the scope.

Seems like a bug to me let me know otherwise.


Transfer out of current ActivityId

Next event is still associated with the ActivityId!
Feb 14, 2016 at 11:16 PM
The order of events inside ActivityScope.cs is based on the conventions used in (Microsoft) WCF logging and is detailed in the remark comments of the class, i.e. it is as designed (so not a coding bug, although if you still think it is wrong you may consider it a design bug).

The sequence is not symmetrical, it is:

  1. Original activity ID: Log transfer to new ID
  2. Change ID (to Sub)
  3. Sub-activity ID: Log start
  1. Sub-activity ID: Log transfer back to old ID
  2. Sub-activity ID: Log stop
  3. Change ID (to Original)
Rather than treat it as a start/stop pair, look at the sequence of events for the sub-activity: 2-6, or the log events 3-5. Start, last thing before you end do a Transfer, then stop.

This makes more sense in a multi-threaded, multi-tier, or asynchronous environment, where a transfer may not necessarily even transfer back, or could transfer somewhere else entirely.

An example is in the main HelloLogging.cs, where it starts each worker on a separate thread and so there are multiple occurrences of step 1. Original activity ID: Log transfer to new ID.

In a multi-threaded environment, after a transfer back both activity 2 (the child) and activity 1 (the main) could be active, which is why it is okay for activity 2 to log a stop event (even though activity 1 has already been transferred back to). In fact activity 1 may have never stopped being active (as in the HelloLogging.cs example).
Marked as answer by xsolon on 2/21/2016 at 2:08 PM