Measure elapsed times for domain event handlers on Azure with using Application Insight telemetry

howto
1

In this article, we introduce the basic technique how to measure the elapsed time for VirtoCommerce domain handlers with using Microsoft Azure Monitoring Logs.

The domain events and their side effects (the actions triggered afterwards that are managed by event handlers) can be synchronous or asynchronous. But you should prefer asynchronous handlers on synchronous since the big amount of synchronous handles or their long execution can increase the execution time for the logical transaction or operation where this event is raised.

Sometimes it’s very helpful to see how long the event handler takes to execute, especially if you faced with performance issues on production on Azure that hard to reproduce locally or in another environment.

Luckily, the VC platform measures all execution times for all registered event handlers and writes them in the ILogger interface, which can be later read and analyzed.

To capture elapsed execution times for event handlers and instrument your app with the Application Insights you have to set this setting in the appsettings.{Environment}.json

{
"Logging" : {
     "ApplicationInsights" : {
        "LogLevel" :  {
            "VirtoCommerce.Platform.Core.Bus.InProcessBus" : "Information"
        }
     }
}

or set as one line in an Azure App configuration

Logging:ApplicationInsights:LogLevel:VirtoCommerce.Platform.Core.Bus.InProcessBus = Information

image
image1083×511 23.7 KB

Afterwards you can analyze the resulting logs in the Log queries in Azure Monitor

By executed this Kusto script:

union isfuzzy=true traces
| where timestamp > datetime("2021-05-03T09:15:16.814Z")
| where * has "VirtoCommerce.Platform.Core.Bus.InProcessBus"
| take 100
| project timestamp, Event = extract("event:([^\\s]+)", 1, message), Module = extract("module:([^\\s]+)", 1, message), Duration = toint(extract("overall_elapsed:([0-9.]+)", 1, message))
| order by Duration desc

image
image1820×808 266 KB

With these statistics, you can better diagnose the performance problem for your solution.