Finding Power BI Semantic Model Refresh Operations In Gateway Logs

The logs for your on-premises data gateway contain a lot of information that is useful for troubleshooting and performance tuning. The contents of the logs are documented here and there a several great solutions out there for reporting on their contents: there’s a Microsoft-provided template and Rui Romano’s more sophisticated monitoring solution here (there’s also another, even better community solution being worked on that will be publicly available soon). To do any troubleshooting or performance tuning, though, you need to link the data generated by Power BI in Log Analytics or Profiler traces to the data in the gateway logs. How can you do this?

Let’s take the refresh of an Import mode semantic model that uses an on-premises SQL Server database as a source as an example. If you have Log Analytics connected to your workspace you can run a KQL query something like this to find the events generated by your semantic model refresh by Power BI:

PowerBIDatasetsWorkspace
| where TimeGenerated > ago(1hr)
| where OperationName in ("CommmandBegin", "CommandEnd", "ProgressReportBegin", "ProgressReportEnd")
//| where OperationName in ("ExecutionMetrics")
| project OperationName, OperationDetailName, EventText, TimeGenerated, XmlaRequestId 
| order by TimeGenerated asc

All the events associated with the refresh command will have the same value in the XmlaRequestId column. If you’re using a Profiler trace to capture the same information the RequestID column will contain the same value.

If you then export the gateway logs and look in the Query Execution Report log file for example (I did it with Power Query – it’s just a CSV file) you can match the XmlaRequestId value from Log Analytics to the value in the RequestId column in the log file:

In this example my semantic model contains two tables sourced from an on-premises SQL Server database, so there are two entries in the Query Execution Report log file, one for each table. Once you’ve found the matching rows in the Query Execution Report log file then you can find all kinds of useful information such as how much time (if any) it took to read data from the source or to spool data to disk. You can do the same thing with the other gateway log files: for example the Open Connection Report will tell you how long it took to open any connections to the data source.

If you have a DirectQuery model connected to an on-premises data source then you do the same thing: all the events associated with a DAX query (such as the Query Begin/End events) will all have the same XmlaRequestId, and again all you need to do is find that value in the RequestId column in the gateway logs.

Monitoring The Opening Of DirectQuery Connections In Power BI

In the past I have blogged about how important the number of connections from a Power BI DirectQuery semantic model to a data source is for performance. It’s also true that in some cases opening a connection, or some of the operations associated with opening a connection, can be very slow. As a result it can be useful to see when your semantic model opens connections to a data source, and you can do this with Log Analytics.

To show this I published a DirectQuery semantic model to a workspace with Log Analytics enabled and opened a report with one table visual on it. Because the model and report had only just been published I could be sure there were no existing connections back to the data source used by the DirectQuery model. I then ran the following KQL query:

PowerBIDatasetsWorkspace
| where TimeGenerated>ago(1hr)
| where OperationName in ('Notification', 'QueryBegin', 'QueryEnd', 'DirectQueryBegin', 'DirectQueryEnd')
| project TimeGenerated, OperationName, OperationDetailName, EventText, DurationMs
| order by TimeGenerated asc

Here’s the output:

Some things to note:

  • I have highlighted in red the events of type Notification and subtype OpenedConnection. These events are fired when the semantic model opens connections back to the data source. There are three of these events so three connections are being opened.
  • There is one DAX query generated for the single visual on the report page. As you would expect there is a single pair of QueryBegin/QueryEnd events.
  • After the QueryBegin event there are two DirectQueryBegin/DirectQueryEnd events, which mean that for this DAX query Power BI ran two SQL queries against the source.
  • Immediately before these two DirectQueryBegin/DirectQueryEnd pairs, and after the QueryBegin event, there are two Notification events which indicate that two connections are being opened to run these queries.
  • Before the DAX query runs, another connection is opened and there is a DirectQueryBegin/DirectQueryEnd pair that is not associated with a DAX query that I have highlighted in blue. The EventText column contains M code rather than SQL code, and a look at this M code shows that it uses the DirectQueryCapabilities.From function which is marked for “internal use only” in the docs. The DirectQueryEnd event from this pair has a duration of 3 seconds which shows that in this case it’s quite expensive. This query is the Power Query engine understanding the DirectQuery capabilities of the source and one of the side effects of this is that it needs to read metadata from the source, which can be quite slow sometimes. Doing things like disabling relationship columns in the connector and, for some sources like Snowflake, connecting with an identity or with a security role that can only see the tables or views used by the model (as mentioned here), can make this a lot faster.

For some reason the Notification events associated with opening connections do not appear in Profiler traces run on models in the Service, although they do appear if you run a trace on a model in Power BI Desktop. This is why I’ve used Log Analytics here.

Power BI pools connections once they are opened and keeps them alive for a certain amount of time and it also caches data source metadata after it has retrieved it, so as a result you may not see the events I have highlighted here when you run a report.

[Thanks to Curt Hagenlocher and Akshai Mirchandani for some of the information in this post]

Power BI DirectQuery, Gateways And SQL Queries That Return Lots Of Rows

Recently I was working with a customer using DirectQuery mode and where all traffic to the data source had to go through an on-premises data gateway for security reasons. They noticed that report performance got worse when traffic went through the gateway and this was particularly true when Power BI generated SQL queries that returned hundreds of thousands of rows. Looking in the gateway logs we found that spooling (see here and here for more details on spooling, and here for information on monitoring spooling in the logs) was taking place, so I advised the customer to set the StreamBeforeRequestCompletes property on the gateway to true. This eliminated the delays from spooling on the gateway (I’m told it helps performance inside the model too) and resulted in some substantial improvements in report performance. As a result, if you’re using DirectQuery and a gateway, you should experiment with the StreamBeforeRequestCompletes property to see if it can help you too.

That said, if you’re using DirectQuery mode you should try to avoid situations where Power BI generates SQL queries that return a large number of rows such as table visuals with scrollbars. Regardless of whether you’re using a gateway or not, moving large amounts of data from your data source to your semantic model can be slow – even if your data source tells you the SQL query itself is fast. You can use Performance Analyzer in Power BI Desktop (see here) to find out how many rows the SQL queries Power BI generates return and how long it takes to read that data.

Why Power BI Table Visuals With Scrollbars Can Cause Problems

Concluding my series of blog posts on seemingly harmless things you can do in a Power BI report that can lead to performance problems and the “This visual has exceeded the available resources” error (see also “Calculate(), Filter() and DAX memory usage” and “DAX measures that never return blank“), in this post I’ll show how table visuals with vertical scrollbars that potentially show thousands of rows can be a Bad Thing.

Using the Import mode semantic model I’ve used in the last two posts, consider this table visual:

The two measures displayed are trivial counts and averages. However there are 538753 combinations of County and Postcode that have data, and so in theory the table can display 538753 rows if you scroll down far enough. That can’t be good, can it?

Those of you who know how Power BI generates DAX queries for table visuals like this might disagree, though. Here’s the DAX query for this table visual:

DEFINE
	VAR __DS0Core = 
		SUMMARIZECOLUMNS(
			'Property Transactions'[County],
			'Property Transactions'[Postcode],
			"Count_Of_Sales", 'Property Transactions'[Count Of Sales],
			"Average_Price_Paid", 'Property Transactions'[Average Price Paid]
		)

	VAR __DS0PrimaryWindowed = 
		TOPN(501, __DS0Core, 'Property Transactions'[County], 1, 'Property Transactions'[Postcode], 1)

EVALUATE
	__DS0PrimaryWindowed

ORDER BY
	'Property Transactions'[County], 'Property Transactions'[Postcode]

As you can see, the query contains a TOPN filter which means that it actually only returns the first 501 rows out of those potential 538753. It’s only if you scroll down far enough that another query is triggered to get the next 501 rows. So maybe it’s not so bad?

Actually it can be bad, even with the TOPN filter. Here are the Execution Metrics for the query above:

{
	"timeStart": "2024-07-10T22:54:30.330Z",
	"timeEnd": "2024-07-10T22:54:31.064Z",

	"durationMs": 734,
	"vertipaqJobCpuTimeMs": 219,
	"queryProcessingCpuTimeMs": 516,
	"totalCpuTimeMs": 734,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 66599,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 501
}

Notice the durationMS and approximatePeakMemConsumptionKB metrics, which tell you how long the query takes to run and how much memory it uses.

Now consider the following version of a report with a slicer for the County column and the county “Bath and North East Somerset” selected.

Here’s the DAX query for the table visual now:

DEFINE
	VAR __DS0FilterTable = 
		TREATAS({"BATH AND NORTH EAST SOMERSET"}, 'Property Transactions'[County])

	VAR __DS0Core = 
		SUMMARIZECOLUMNS(
			'Property Transactions'[County],
			'Property Transactions'[Postcode],
			__DS0FilterTable,
			"Count_Of_Sales", 'Property Transactions'[Count Of Sales],
			"Average_Price_Paid", 'Property Transactions'[Average Price Paid]
		)

	VAR __DS0PrimaryWindowed = 
		TOPN(501, __DS0Core, 'Property Transactions'[County], 1, 'Property Transactions'[Postcode], 1)

EVALUATE
	__DS0PrimaryWindowed

ORDER BY
	'Property Transactions'[County], 'Property Transactions'[Postcode]

As you would expect, this query now contains a filter on the county selected in the slicer. It also contains a TOPN filter but the interesting thing is that since there are more than 501 postcodes in the selected county, the query returns exactly the same rows as before. Of course you can’t now scroll down and see data for other counties than the one selected in the slicer but you can always select a different county in the slicer.

Here are the Execution Metrics for the new query:

{
	"timeStart": "2024-07-10T22:58:29.725Z",
	"timeEnd": "2024-07-10T22:58:29.741Z",

	"durationMs": 16,
	"vertipaqJobCpuTimeMs": 0,
	"queryProcessingCpuTimeMs": 16,
	"totalCpuTimeMs": 16,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 2564,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 501
}

Notice that both the duration and peak memory usage of the query are both much, much lower: duration has gone from 734ms to 16ms, while peak memory usage has gone from 66599KB to 2564KB. If you have more measures which are more complex and/or inefficiently written the difference could be much bigger.

Why is there such a big difference? Well if you look at the physical query plan generated for both queries you can see that before the TOPN filter is applied, the Vertipaq engine still has to spool the entire, unfiltered table. In the first query this unfiltered table has 538753 rows, which is why it’s relatively slow and memory hungry, whereas in the second query this table, with the County slicer, has only 1869 rows (the number of postcodes in the selected county). As a result slicing on County, even though it doesn’t affect which rows are returned after TOPN filter is applied, leads to a more efficient query. If you’re using DirectQuery mode something similar happens because, as I noted here, the TOPN filter can only be pushed back to the relational source in a few basic scenarios which means the SQL queries generated can return a very large number of rows and which can hit the Max Intermediate Row Set Count limit.

What can you learn from this? Table visuals that can display a large number of rows should be avoided. I’m not report design guru but I would go so far as to say that any table with a scrollbar on is a mistake: if your user needs to scroll down to see all the rows or scroll right to see all the columns, why not use a slicer to allow them to select the rows they want to see more easily or use field parameters to allow them to select the columns they want to see? Not only will this be better from a usability point of view, performance will be a lot better and memory usage will be lower. And yes, I know that your end users ask for tables with lots of rows and columns because that’s what they are used to seeing in Excel, but giving them what they want risks slow performance and memory errors. So they need to make a choice.

DAX Measures That Never Return Blank

Following on from my earlier post on the Query Memory Limit in Power BI, and as companion to last week’s post on how a DAX antipattern using Calculate() and Filter() can lead to excessive memory consumption by queries (and therefore lead to you hitting the Query Memory Limit), in this post I want to look at the effects of another DAX antipattern on performance and memory usage: measures that can never return a blank value.

Adding zero to the result returned by a measure

What do I mean by a measure that never returns blank? Well using the same model that I used in last week’s post, let’s say I have a simple measure that counts the rows in my fact table:

Count Of Sales = COUNTROWS('Property Transactions')

I can use this measure in a matrix visual with Property Type on columns and Postcode on rows, like so:

Here’s what Execution Metrics says about the DAX query for this visual:

{
	"timeStart": "2024-07-03T10:16:16.251Z",
	"timeEnd": "2024-07-03T10:16:19.345Z",

	"durationMs": 3094,
	"vertipaqJobCpuTimeMs": 188,
	"queryProcessingCpuTimeMs": 2656,
	"totalCpuTimeMs": 2844,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 179404,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 230
}

And here’s what DAX Studio’s Server Timings shows:

It’s not fast (there are a lot of Postcodes even though the query has a Topn N filter and only returns 230 rows – that’s a subject for another blog post though) but the thing to look at is the peak memory consumption which is 179404KB or 175MB and the fact that there is just one Storage Engine query.

Now let’s say your boss says she hates all that white space in the matrix and wants to see zeroes instead. The obvious way to fix this is to add a zero to the result of the count in the measure, like so:

Count Of Sales = COUNTROWS('Property Transactions')+0

It’s a minor change so what could go wrong? Here’s what Execution Metrics shows after making that change:

{
	"timeStart": "2024-07-03T10:22:01.343Z",
	"timeEnd": "2024-07-03T10:22:10.390Z",

	"durationMs": 9047,
	"vertipaqJobCpuTimeMs": 313,
	"queryProcessingCpuTimeMs": 8578,
	"totalCpuTimeMs": 8891,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 379432,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 612
}

And here are the Server Timings:

The query is now three times slower, has three Storage Engine queries, and uses 370MB of memory – twice as much as before! This increase in memory can easily push you over the Query Memory Limit and result in the “This visual has exceeded the available resources” error, as this real-life example shows.

Why does this change make such a big difference? Adding zero to the result of the count results in the creation of a “dense” measure, that’s to say a measure that never returns a blank value. The white space in the first visual was the result of the measure not returning any values, whereas in the second visual the measure is returning values for every cell in the matrix. What is a blank value? I strongly recommend you read Marco’s article here for a detailed introduction to this subject; blanks are somewhat similar to nulls in SQL but there are some very important differences, and in this case the thing to point out is that the expression BLANK()+0 returns 0 in DAX. As a result a measure which used to return a blank value in some cases now never returns a blank. This can be extremely bad for DAX performance and memory usage because the Vertipaq engine inside Power BI can do a lot of optimisations when it knows a measure will return blank in some circumstances. Nikola Illic has a great post here going into more detail about this.

Using FORMAT() in measures

There are a few other common ways you can run into the same problem. One is the use of the FORMAT() function to return a formatted string from a measure, for example:

Count Of Sales = FORMAT(COUNTROWS('Property Transactions'),"Standard")

Here’s what Execution Metrics shows for the visual above with the new version of the measure:

{
	"timeStart": "2024-07-04T09:48:43.655Z",
	"timeEnd": "2024-07-04T09:48:53.499Z",

	"durationMs": 9844,
	"vertipaqJobCpuTimeMs": 281,
	"queryProcessingCpuTimeMs": 9359,
	"totalCpuTimeMs": 9656,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 380480,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 612
}

As you can see, the duration and memory usage is very similar to the version of the measure above that added a zero to the result of the COUNT(): slow and memory hungry.

The FORMAT() function returns a text value that represents a formatted version of the value passed in; blank values are converted to empty strings, so again this new version of the measure can never return a blank value. My recommendation is to always try to avoid using FORMAT() in measures because of the impact it can have on performance. Instead, try to use format strings (for more examples see my posts here and here) or dynamic format strings (you should also read the SQLBI article on dynamic format strings to be aware of the implications of using them) wherever possible. It’s a shame that format strings don’t have built in support for formatting blank values; I’m told there are some good technical reasons why this hasn’t happened yet.

IFERROR() and DIVIDE()

Some other DAX functions can also trigger this performance issue. The IFERROR() or ISERROR() functions are one example, since they allow you to trap errors in DAX expressions and return a value instead. However I can say quite confidently that you should never, ever use IFERROR() or ISERROR() when writing DAX anyway and there is some guidance documentation to back me up on this.

Another example which is less obviously bad is the use of the third parameter of the DIVIDE() function. As you probably know, the DIVIDE() function allows you to handle division by zero and division by blank safely, and by default it will return a blank value when division by zero or division by blank is detected. However there is an optional third parameter which allows you to return a value instead of a blank when dividing by zero or blank, and this can also trigger the problem we’re looking at.

Consider the following measure:

Division Test = 
DIVIDE(
    1,
    COUNTROWS('Property Transactions')
)

Here it is used in our visual:

Here are the Execution Metrics:

{
	"timeStart": "2024-07-04T11:42:29.636Z",
	"timeEnd": "2024-07-04T11:42:32.386Z",

	"durationMs": 2750,
	"vertipaqJobCpuTimeMs": 234,
	"queryProcessingCpuTimeMs": 2516,
	"totalCpuTimeMs": 2750,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 210960,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 230
}

Now, here’s the same measure with the third parameter of DIVIDE() set:

Division Test = 
DIVIDE(
    1,
    COUNTROWS('Property Transactions'),
    0
)

And here are the Execution Metrics:

{
	"timeStart": "2024-07-04T11:44:24.997Z",
	"timeEnd": "2024-07-04T11:44:32.247Z",

	"durationMs": 7250,
	"vertipaqJobCpuTimeMs": 359,
	"queryProcessingCpuTimeMs": 6891,
	"totalCpuTimeMs": 7250,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 379436,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 612
}

Once again, the second version of the measure that never returns a blank is slower and uses more memory.

Summary

As you have seen, Power BI measures that can never return a blank value can be very bad for performance and query memory usage – so as a result, when you are writing DAX you should always be careful to avoid doing this.

Calculate(), Filter() And DAX Memory Usage

Following on from my last post on the Query Memory Limit in Power BI, in this post I want to look at one of the most common DAX antipatterns and its effect on query memory usage: filtering on a whole table, rather than an individual column, in the filter parameters of the Calculate() function. A lot has already been written on this particular antipattern from the point of view of query performance – for example see here and here – but it’s only with the recent addition of the Execution Metrics Profiler/Log Analytics event that you can see how bad it is for memory usage too.

Here’s a simple example. Using a semantic model based on the UK Land Registry’s Price Paid data, with two dimension tables (Date and Property Type) and a fact table called Property Transactions with just over a million rows:

…let’s say that you write a measure that counts the number of property transactions for detached properties, ie counting the rows in the Property Transactions table where the Property Type column contains the value “D”. Here’s a first attempt at that:

Detached Count V1 =
CALCULATE (
    COUNTROWS ( 'Property Transactions' ),
    FILTER ( 'Property Transactions', 'Property Transactions'[Property Type] = "D" )
)

Notice that this measure follows the antipattern of filtering on the whole Property Transactions table with the Filter() function just to filter on the Property Type column.

Here’s a DAX query that shows the results of this measure for all Postcodes. It returns around 153000 rows to show the memory impact of the way the measure is written.

EVALUATE
SUMMARIZECOLUMNS(
    'Property Transactions'[Postcode],
    "Detached Count", [Detached Count V1]
)

Here’s what the Execution Metrics event returns for this query:

{
	"timeStart": "2024-06-28T15:41:59.951Z",
	"timeEnd": "2024-06-28T15:42:00.388Z",

	"durationMs": 438,
	"vertipaqJobCpuTimeMs": 47,
	"queryProcessingCpuTimeMs": 391,
	"totalCpuTimeMs": 438,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 22246,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 152583
}

In this case the memory usage of the query, as given by the approximatePeakMemConsumptionKB metrci, is 22246KB or about 23MB.

Now consider this version of the measure:

Detached Count V2 =
CALCULATE (
    COUNTROWS ( 'Property Transactions' ),
    'Property Transactions'[Property Type] = "D"
)

Running the same DAX query as before but with this new measure you get the same results but with a much lower memory usage of 8734KB or 9MB:

{
	"timeStart": "2024-06-28T15:56:09.431Z",
	"timeEnd": "2024-06-28T15:56:09.602Z",

	"durationMs": 172,
	"vertipaqJobCpuTimeMs": 31,
	"queryProcessingCpuTimeMs": 125,
	"totalCpuTimeMs": 172,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 8734,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 152583
}

Query duration and CPU usage is reduced too, but as I said above this highlights how different DAX patterns can result in very different memory footprints. Filtering on just the column you want to filter, rather than the whole table, is a lot more memory efficient! If you’re getting the “This visual has exceeded the available resources error because you’ve hit the Query Memory Limit then it’s worth checking to see if you have used this antipattern in your measures and rewriting accordingly.

Footnote: it’s worth mentioning that two other variations on the rewritten measure, one using the Property Type column on the Property Type dimension table instead of the Property Type column on the fact table:

Detached Count V3 =
CALCULATE (
    COUNTROWS ( 'Property Transactions' ),
    'Property Type'[Property Type] = "D"
)

…and one that added the KeepFilters() function (which is commonly used in this type of measure):

Detached Count V4 =
CALCULATE (
    COUNTROWS ( 'Property Transactions' ),
    KEEPFILTERS ( 'Property Type'[Property Type] = "D" )
)

…both had the same memory usage as the V2 version of the measure, 9MB.

Power BI Semantic Model Memory Errors, Part 4: The Query Memory Limit

Continuing my series on Power BI memory errors (see part 1, part 2 and part 3), in this post I’ll look at the query memory limit which controls the amount of memory that an individual query can consume. This is a subject which I’ve talked about in a few blog posts in the past: hitting this limit is one of the reasons you’ll see the “This visual has exceeded the available resourceserror which I blogged about here and and here. There’s also some official documentation here which is pretty good.

As I mentioned in part 1 of this series, when you run a DAX query against a Power BI semantic model it will use memory. How much memory it uses will depend on your data, how you have modelled it, what data your query is requesting and how you have written any DAX calculations used by your query. For obvious reasons we at Microsoft can’t let queries use an infinite amount of memory in the Power BI Service so there is a limit – the query memory limit – on how much memory an individual query can use. This limit varies depending on whether you are using Shared (also known as Power BI Pro) or Premium/Fabric capacity, and by the size/SKU of the capacity you’re using. The different limits for each SKU are documented here.

While you can’t increase the query memory limit over the published thresholds, capacity admins can reduce the query memory limit in the admin portal by setting the “Query Memory Limit %” property on the capacity.

The default value of this property is 0, which means the maximum value for the capacity SKU you’re using will be applied; any other value will be interpreted as a percentage of that maximum value. Reducing this value can be a good way to stop your developers from using inefficient DAX in their reports and consuming too many resources on your capacity – it won’t directly reduce a query’s CU usage but DAX expressions that are very memory-intensive often use a lot of CUs too.

If the DAX query generated by a visual in a Power BI report hits the query memory limit you’ll see an error in your report. The first reaction many Power BI developers have when they hit the limit is to ask if there is a way to increase it – which you can only do by buying a larger capacity – but to be brutally honest, if you are hitting the query memory limit you have done something wrong and you need to fix your model, your DAX calculations or your report to reduce memory usage. Doing this is likely to improve report performance too. If you’re encountering the error in Power BI Desktop you can raise the limit but this is only possible in Desktop and if you do this you may end up getting the error again after you publish.

Here’s the error you’ll see in Power BI Desktop if you hit the query memory limit:

This visual has exceeded the available resources. Try filtering to decrease the amount of data displayed.

If you hit the query memory limit in a published report you’ll see this error message:

In this case you not only get the “Visual has exceeded the available resources” error but going to the details shows a more helpful message that tells you what the current query memory limit is:

Resource Governing: This query uses more memory than the configured limit. The query — or calculations referenced by it — might be too memory-intensive to run. Either simplify the query or its calculations, or if using Power BI Premium, you may reach out to your capacity administrator to see if they can increase the per-query memory limit. More details: consumed memory 1 MB, memory limit 1 MB. See https://go.microsoft.com/fwlink/?linkid=2159752 to learn more.

The error number associated with this error is 0xC13E0004 (-1052901372).

How do you know how much memory your query is using to check how near you are to the query memory limit? The new Execution Metrics event in Profiler and Log Analytics will tell you. If you find the event associated with the Query End event for the query (something I discussed here) the approximatePeakMemConsumptionKB metric gives the peak memory usage of the query reached while it was running, and it is this value that must not exceed the Query Memory Limit.

{
	"timeStart": "2024-06-21T16:24:16.608Z",
	"timeEnd": "2024-06-21T16:24:18.326Z",

	"durationMs": 1719,
	"vertipaqJobCpuTimeMs": 1078,
	"queryProcessingCpuTimeMs": 531,
	"totalCpuTimeMs": 1609,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 46662,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 502
}

If you can’t use Profiler or Log Analytics there’s no direct way of knowing how much memory is using. You can however set a custom memory limit in Power BI Desktop and keep changing it until you see, or don’t see, the query memory limit and therefore estimate how much memory your query is using.

How can you reduce the amount of memory that your queries use? That’s a question that’s too big to answer in any one blog post and this one is already long enough. In my next few posts I will look at some common causes of excessive memory usage and what you can do to fix them.

Diagnosing Power BI DirectQuery Connection Limit Performance Problems With Execution Metrics

A few months ago I blogged about the new limits available for the Maximum Connections Per Data Source property in Premium and why the number of connections that a DirectQuery semantic model can open to a data source is so important for report performance. At that time, however, there was no way for you to know whether the performance of your reports was being affected by a lack of available connections. The good news is that, with the announcement this week of the new Execution Metrics event in Log Analytics and Profiler, you can now see when this is happening.

To illustrate how to use Execution Metrics to see whether availability of connections is hurting performance, I created a Power BI semantic model with three tables in DirectQuery mode connected to SQL Server. Each table consisted of a single row and column and was bound to a SQL query that took 10 seconds to run (using the TSQL custom function I blogged about here).

I then built a report connected to this model containing three cards, each of which displayed the single value returned by each of these three tables. As you would expect, the DAX queries associated with each of these card visuals took 10 seconds to run when run in isolation.

I left the Max Connections Per Data Source property set to the default value of 10 and published the model and the report to the Power BI Service:

I then opened the report and let it render to make sure there were some connections open in Power BI’s connection pool, then re-ran the report while running a Profiler trace that recorded the Query Begin/End, DirectQuery Begin/End and the new Execution Metrics event.

As you might expect, the three DAX queries for the three cards were run in parallel and each query took around 10 seconds to run. Each DAX query generated a single SQL query and each SQL query also took around 10 seconds to run. Here’s what the Execution Metrics event returned for the first DAX query (the Execution Metrics for the other two DAX queries were more or less identical):

{
	"timeStart": "2024-05-17T10:39:53.833Z",
	"timeEnd": "2024-05-17T10:40:04.381Z",

	"durationMs": 10548,
	"datasourceConnectionThrottleTimeMs": 0,
	"directQueryConnectionTimeMs": 4,
	"directQueryExecutionTimeMs": 10105,
	"directQueryIterationTimeMs": 126,
	"directQueryTotalTimeMs": 10109,
	"queryProcessingCpuTimeMs": 0,
	"totalCpuTimeMs": 16,
	"executionDelayMs": 0,

	"approximatePeakMemConsumptionKB": 0,

	"directQueryTimeoutMs": 225000,
	"tabularConnectionTimeoutMs": 225000,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 1,
	"directQueryRequestCount": 1,
	"directQueryTotalRows": 1
}

The datasourceConnectionThrottleTimeMs metric is 0, which indicates that no time was spent waiting for a connection before the model could run the sole SQL query linked to this DAX query.

I then created a copy of the semantic model, changed the Maximum Connections Per Data Source property to 1, and published this new model and an identical report and ran a Profiler trace while running the report. Changing the Maximum Connections Per Data Source property to 1 meant that this new model could only have one connection open to SQL Server at any one time and therefore could only run one SQL query at a time.

Here’s what the Profiler trace looked like:

The first thing to note is that even though the three DAX queries were still run in parallel they now took 10, 21 and 33 seconds to run, as seen from the Duration column for each of the three Query End events. The SQL queries generated by each DAX query, however, still only took 10 seconds each, as shown from the Duration column for the three DirectQuery End events.

Here’s what the Execution Metrics event for the last DAX query to finish (the one that took 33 seconds) returned:

{
	"timeStart": "2024-05-17T10:12:19.436Z",
	"timeEnd": "2024-05-17T10:12:52.341Z",

	"durationMs": 32906,
	"datasourceConnectionThrottleTimeMs": 21896,
	"directQueryConnectionTimeMs": 21901,
	"directQueryExecutionTimeMs": 10531,
	"directQueryIterationTimeMs": 129,
	"directQueryTotalTimeMs": 32434,
	"queryProcessingCpuTimeMs": 0,
	"totalCpuTimeMs": 0,
	"executionDelayMs": 9,

	"approximatePeakMemConsumptionKB": 0,

	"directQueryTimeoutMs": 204000,
	"tabularConnectionTimeoutMs": 225000,

	"commandType": 27,
	"queryDialect": 3,
	"queryResultRows": 1,
	"directQueryRequestCount": 1,
	"directQueryTotalRows": 1
}

This clearly shows that out of the total query duration of 33 seconds, 22 seconds of that was spent waiting for a connection to become available, as indicated by the datasourceConnectionThrottleTimeMs value. This was because this DAX query had to wait for the SQL queries generated by the two other DAX queries to complete before it could get a connection back to the source. As for the other two DAX queries generated for this report, the query that took 10 seconds still had a datasourceConnectionThrottleTimeMs of 0 because it was the first query to run and there was a connection available for it to use, while the second query to run that took 22 seconds had a datasourceConnectionThrottleTimeMs of 11 seconds because it only had to wait for the first DAX query’s SQL query to run before it could use the connection.

What should you do if you have performance problems and can see that datasourceConnectionThrottleTimeMs is consistently high? Before anything else you need to tune your model and your data source (see here and here for some tips); the more SQL queries your model generates when a report is run, and the slower those queries are, the more likely you are to run out of connections. If that doesn’t work and you are using Pro/Shared or a capacity that is lower than an F64, then you will need buy an F64 capacity or greater (see the table here for the maximum number of DirectQuery connections supported by each SKU) all to allow for more than 10 connections back to your source. Once you have done that you will also need to set the Max Connections Per Data Source property in your model to something larger than 10. However, you also need to be aware that increasing the maximum number of connections can make performance worse if your data source cannot handle the number of SQL queries that Power BI is trying to run on it.

Overhead Of Getting Relationship Columns In Power BI DirectQuery Mode

Many Power BI connectors for relational databases, such as the SQL Server connector, have an advanced option to control whether relationship columns are returned or not. By default this option is on. Returning these relationship columns adds a small overhead to the time taken to open a connection to a data source and so, for Power BI DirectQuery semantic models, turning this option off can improve report performance slightly.

What are relationship columns? If you connect to the DimDate table in the Adventure Works DW 2017 sample database using Power Query, you’ll see then on the right-hand side of the table. The following M code:

let
Source = Sql.Database("localhost", "AdventureWorksDW2017"),
dbo_DimDate = Source{[Schema="dbo",Item="DimDate"]}[Data]
in
dbo_DimDate

…shows the relationship columns:

Whereas if you explicitly turn off the relationships by deselecting the “Including relationship columns” checkbox:

…you get the following M code with the CreateNavigationProperties property set to false:

let
Source = Sql.Database("localhost", "AdventureWorksDW2017", [CreateNavigationProperties=false]),
dbo_DimDate = Source{[Schema="dbo",Item="DimDate"]}[Data]
in
dbo_DimDate

…and you don’t see those extra columns.

How much overhead does fetching relationship columns add? It depends on the type of source you’re using, how many relationships are defined and how many tables there are in your model (because the calls to get this information are not made in parallel). It’s also, as far as I know, impossible to measure the overhead from any public telemetry such as a Profiler trace or to deduce it by looking at the calls made on the database side. The overhead only happens when Power BI opens a connection to a data source and the result is cached afterwards, so it will only be encountered occasionally and not for every query that is run against your data source. I can say that the overhead can be quite significant in some cases though and can be made worse by other factors such as a lack of available connections or network/gateway issues. Since I have never seen anyone actually use these relationship columns in a DirectQuery model – they are quite handy in Power Query in general though – you should always turn them off when using DirectQuery mode.

[Thanks to Curt Hagenlocher for the information in this post]

Measuring The Total Time Spent Querying Sources In Power BI DirectQuery Mode

If you’re tuning a DirectQuery semantic model in Power BI one of the most important things you need to measure is the total amount of time spent querying your data source(s). Now that the queries Power BI generates to get data from your source can be run in parallel it means you can’t just sum up the durations of the individual queries sent to get the end-to-end duration. The good news is that there are new traces event available in Log Analytics (though not in Profiler at the time of writing) which solves this problem.

The events have the OperationName ProgressReportBegin/ProgressReportEnd and the OperationDetailName ParallelSession. Here’s a simple Log Analytics query that you can use to see how this event works:

PowerBIDatasetsWorkspace
| where TimeGenerated > ago(10min)
| where OperationName in
("QueryBegin", "QueryEnd",
"DirectQueryBegin", "DirectQueryEnd",
"ProgressReportBegin", "ProgressReportEnd")
| project OperationName, OperationDetailName, EventText, TimeGenerated,
DurationMs,CpuTimeMs, DatasetMode, XmlaRequestId
| order by TimeGenerated asc

Here’s what this query returned for a single DAX query that generated multiple SQL queries (represented by DirectQueryBegin/End event pairs) against a relational data source:

Notice that there is just one ProgressReportBegin/End event pair per query; this is always the case, no matter how many fact tables or data sources are used, at least as far as I know. The ProgressReportBegin event for ParallelSession comes before the DirectQueryBegin/End event pairs and the associated End event comes after the final DirectQueryEnd event. The DurationMs column for the ProgressReportEnd event gives you the total duration in milliseconds of all the DirectQuery events. In this case there were six SQL queries sent to the source (and so six DirectQueryBegin/End event pairs) each of which took between 1-2 seconds. However, since all of these queries ran in parallel, the overall duration was still just over 2 seconds.