Track your Azure Analysis Services Processing Times per Table

With Kusto Queries and Diagnostic Logs

Recently I have been working with Azure Analysis Services (AAS) quite a lot. The number of tables in our model was quickly growing and processing times were fluctuating and increasing as well. Reason enough for me to find out a little bit more about which tables were taking up the most processing time from the AAS perspective.

Here I will explain the steps I took to get detailed information about the processing steps for an Azure Analysis Services Full Process from a Log Analytics workspace into a Power BI report.

  • Setting up Diagnostics Logging to Log Analytics workspace
  • Exploring the Logs with the Kusto Query language
  • Getting the data into Power BI

Diagnostic Logs

The starting point, as always, was the Microsoft documentation. Okay, actually it was Google or Bing. But quickly I landed on the documentation pages that include all the need steps to start. The link is listed below.

The configuration of the Diagnostics Settings, to send the logs to a Log Analytics workspace, was already done in this case. If you still need to do this, the docs include the needed actions. It’s pretty straight forward.

Exploring the Logs

The next step is exploring the logs in our Log Analytics workspace (LAW) by writing a query to get the information we are looking for. The first example query from the documentation was a good starting point. But not exactly what we are looking for, since we are looking for the Refresh of the model. And not the query times.

In the end, I wrote two queries and join these together in Power BI. In the first query, I am specifically looking for the highest level of the refresh process.

The value ‘CommandEnd’ in the ‘OperationName’ field and the ‘TextData_s’ field filtered on ‘<Refresh ’ does the trick in this case. Below is the query, if you want to use it, don’t forget to add your own server and database name in the second line.

let window = AzureDiagnostics
| where ResourceProvider == "MICROSOFT.ANALYSISSERVICES" and Resource =~ "<MyServerName>" and DatabaseName_s =~ "<MyDatabaseName>"
| where TimeGenerated > ago(14d);
window
| where OperationName has "CommandEnd" and TextData_s has "<Refresh "
| extend DurationMs=extract(@"([^,]*)", 1,Duration_s, typeof(long))
| project StartTime_t,EndTime_t,ServerName_s,OperationName,RootActivityId_g,TextData_s,DatabaseName_s,ApplicationName_s,Duration_s,Success_s,EffectiveUsername_s,User_s,EventSubclass_s,DurationMs
| order by StartTime_t desc

In the second query, we get the details of the refresh and we want to filter out as many operations that we do not use. This query results in all the detailed information we are looking for.

let window = AzureDiagnostics
| where ResourceProvider == "MICROSOFT.ANALYSISSERVICES" and Resource =~ "<MyServerName>" and DatabaseName_s =~ "<MyDatabaseName>"
| where OperationName !hasprefix "Discover" and OperationName !hasprefix "VertiPaq" and OperationName !hasprefix "LogMetric"
| where TimeGenerated > ago(14d);
window
| extend DurationMs=extract(@"([^,]*)", 1,Duration_s, typeof(long))
| project TimeGenerated,RootActivityId_g, ResourceId, OperationName, DatabaseName_s, level_d, EventClass_s, EventSubclass_s, StartTime_t, EndTime_t, ProgressTotal_s, ObjectReference_s, ObjectName_s, ObjectID_s, ObjectPath_s, Duration_s, CPUTime_s, Severity_s, Success_s, Error_s, TextData_s,DurationMs
| order by TimeGenerated desc

Another option, to get fewer results in the last query, is to join it to the first query on the ‘RootActivityId_g’. That way you make sure you only get data that relates to the first query.

Another option, to get fewer results in the last query, is to join it to the first query on the ‘RootActivityId_g’. That way you make sure you only get data that relates to the first query.

Visualize in Power BI

The Log Analytics workspace offers the possibility to export the written query to the M language and includes some help on how to use the script in Power BI.

Image for post
Export Kursto query to Power BI (Image by Author)

After adding the two Kusto queries to a Power BI report, a relationship is created on the ‘RootActivityId_g’ between the two tables. From the ‘ObjectReference_s’, the TableName could be derived. Lastly, I added a measure to calculate the duration in minutes.

The data in the model gives insight into the duration per refresh operation, identifiable through the ‘RootActivityId_g’ from the first query. Detailed information can be visualized per table from the second query.

Image for post
First Query; Status per Refresh (Image by Author)

If we look at ‘ObjectName_s’ = ‘Partition’ and ‘EventSubclass_s’ = 59 The steps per table include:

  • Querying the source
  • Reading the data and processing the partition
  • Analyzing and encoding
  • Compression per segment per column
  • Processing hierarchy per column

Here is an example of a simple demo model. The first row shows the complete duration for the selected table. See the start and end times.

Image for post
Second Query; Detailed Refresh information per Table (Image by Author)

Conclusion

Being able to analyze the different steps in the refreshing process and pinpointing the time-consuming steps is very valuable to me.

There is tons of information about your Analysis Services Instance in the Diagnostic Logs. For example information about the usage of ‘query processing units’ (qpu_metric) and memory usage.

From my perspective, as a Data Engineer, monitoring Azure Analysis Services with the Diagnostic Logs in Power BI, is a great alternative for the Azure Portal. You are in control of designing the whole process and could provide the monitoring solution to the end-users of your BI products, without the need to login to the Azure portal.

Please let me know what you think or if you have any tips for me! Thank you!

References:

Diagnostic logging for Azure Analysis Services

Overview of Azure platform logs

Getting started with Kusto

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

%d bloggers like this:
search previous next tag category expand menu location phone mail time cart zoom edit close