Some time ago I wrote the following post on how to work out how long your M query takes to execute in Power Query:
http://blog.crossjoin.co.uk/2014/11/17/timing-power-query-queries/
While it’s still relevant for Power Query and now of course Power BI (and it also illustrates some interesting facts about query execution), recently I had an interesting discussion with Colin Banfield in the comments section of that post that led to us finding an easier way of measuring query execution times.
In M, the DateTime.LocalNow() function returns the current system date and time at the time the function is called – which means that you could call it multiple times in the same query and get different results. There’s also the DateTime.FixedLocalNow() function which also returns the system date and time; the difference between the two is, as the documentation says:
This value is fixed and will not change with successive calls, unlike DateTime.LocalNow, which may return different values over the course of execution of an expression.
The question here is, though, what time does DateTimeFixedLocalNow() actually return? I asked on the Power Query forum here and Ehren from the Power Query dev team revealed that it returns the system date and time at the point when the query begins.
This means that it can be used to simply the original method I used to find query execution. Here’s a query that uses Function.InvokeAfter() to create a delay of 5 seconds during query execution and returns the difference between the values returned by DateTime.LocalNow() and DateTime.FixedLocalNow():
[sourcecode language=”text” padlinenumbers=”true”]
let
SomeFunction = ()=> DateTime.LocalNow(),
InvokeAfter5Secs =
Function.InvokeAfter(SomeFunction, #duration(0,0,0,5)),
Output =
Duration.ToText(InvokeAfter5Secs – DateTime.FixedLocalNow())
in
Output
[/sourcecode]
If you’re using this on a real query I strongly recommend you read my original post carefully and make sure that all of the steps in your query are executed, but does make things a little bit easier.
Wow, I will try it for tuning M codes.
I found that DateTime.FixedLocalNow() evaluates to the same value for all tables that are being refreshed at the same time, even if they have their own separate calls to DateTime.FixedLocalNow() and even if the queries are completely independent from each other. The only time that this didn’t hold true was when I first loaded the tables to the Data Model. I actually prefer to use DateTime.LocalNow() instead because it will evaluate as needed for each query.
For context, I am using the technique from your previous blog post to add a “Refresh Duration” column to all of my tables in the Data Model so that I can use them in measures and reports about the tables themselves. Since the column contains only 1 distinct value for each table, the column does not take up much space.