In this post, I will talk about how we can implement correlated tracking while executing BRE Policies from C# code.
A Little Background
We have two options of executing a MS BRE Policy.
Execute the policy using the calls rules shape in BizTalk orchestration
Execute the policy from a function inside a C# class.
In both the cases we have an ability to track the execution of rules and other activities that the Rule Engine go through.
In case when the policy is executed using a Calls Rules shape, just enabling the policy tracking in BizTalk admin console is sufficient. We can do it as shown below.
We can also track the events when testing the policy in Business Rules Composer. Following screen shot shows a sample of events recorded.
Let us now see how we can track execution events when the policy is called from a function in C# class
Executing policy from a Function
MS BRE gives us a simple way of executing policy from a function in C# class library. This gives us the ability to call Business Rules from non BizTalk services.
Following is a sample showing a programmatic execution of BRE policy
Pretty simple, isn’t it?? But wait, now we have lost the ability to track policy execution
Default tracking for Policy executed from Function
MS BRE comes with a out of the box Debug Tracking interceptor, which records the execution details for us. This interceptor is available in the Microsoft.RuleEngine assembly.
Below is how we can attach the interceptor to the policy execution
When any service executes policy as shown above, output as shown below gets logged.
If we compare this output with the one generated while testing the rules in the compose, we find that they are same.
Yay!! A way to track the policy execution
Correlated tracking for Policy executed from Function
Why use Structured Logging
Sometimes, it is possible that Rules Execution is just a small part of a loosely coupled distributed system. In such systems, it is not always easy to visualize the flow of the message. So it becomes imperative that we have a strong logging in place to debug and address any issues.
Correlated logging is a best practice to log the events across distributed systems. Correlated logging uses a unique id to track the end to end flow of a message in the integration. So, when we have to debug, we just use the unique id and we can trace the entire flow for the message.
In such cases, the DebugTrackingInterceptor is not sufficient as does not allow us to write custom information to the log file.
Fortunately, MS BRE provides us a way to implement a custom interceptor of our own. We need to implement the IRuleSetTrackingInterceptor interface on our custom interceptor class. This interface like the DebugTrackingInterceptor is available in Microsoft.RuleEngine namespace.
so without ado, let us start.
Setting up Log4Net
Let us add the Log4net NuGet package to our solution. If you are not aware of log4net, I suggest you to read https://logging.apache.org/log4net/
Post that we add the log4net information to AssemblyInfo.cs class of our project as shown below.
Now let us add the log for net configuration to our app.config file. The entire app.config looks as below
The log4net logger is configured in code as shown below.
Now let us take a look at how we can implement our custom tracking interceptor.
We implement the logger in the constructor of our custom interface.
We need to implement following methods from the IRuleSetTrackingInterceptor
SetTrackingConfig : We can keep the method body as empty.
TrackAgendaUpdate: Rule engine invokes this method when it either adds or removes a rule from the agenda. Following sample shows how we track agenda update events
TrackConditionEvaluation: Rule Engine calls this method when evaluating the conditions in the rules. This method is invoked for each condition evaluation.
TrackFactActivity: Track the activity of the facts in the rule engine working memory.
TrackRuleFiring: Rule engine invokes this for each of the rule firing.
TrackRuleSetEngineAssociation: Invoked at start of each rule engine execution cycle
Final implementation looks as following
This Interceptor can be passed to policy execution as shown below.
Below is the tracking of execution of policy shown above.
As we can see, we can now track the execution of Policy in a correlated way. Plus it gives us more freedom to log the events as we like.
Summing up
As seen above, we have a lot of different ways of tracking policy execution of MS BRE policy.
Tracking with “Call Rules” shape gives us tracking in tracked instances
Rules Composer shows us the execution of policy
DebugTrackingInterceptor implements the same logic as Rules composer testing. It outputs a simple trace, but we do not have control over the output
We can create custom tracking interceptors using logging framework of our choice.
Custom tracking gives us more control on what and how we want to track the execution events.
