Implementing Custom Query Diagnostics and Step-Level Profiling in Power Query M: Measuring Execution Time, Row Counts, and Bottleneck Detection for Complex Pipelines

Introduction

You've built a Power Query pipeline that worked beautifully in development — a few hundred rows, snappy response times, clean transformations. Then it hit production data. Now it takes four minutes to refresh, your users are filing tickets, and you're staring at a chain of 30 steps with no idea which one is strangling your performance. You've clicked through Query Diagnostics in the Power Query Editor, watched the waterfall chart blur past, and still can't pin down whether the slowdown is in your custom function, your multi-step join, or that Table.NestedJoin you added as an afterthought.

This is the gap that native tooling doesn't fully close. Power Query's built-in Query Diagnostics is a blunt instrument — it captures engine-level events but gives you limited visibility into your specific steps as authored logic. What you need is a systematic, M-native approach to instrumenting your own pipelines: custom diagnostics that tell you exactly how long each logical step takes, how many rows survive each filter, and where your data volume explodes or collapses unexpectedly.

By the end of this lesson, you'll be able to build reusable diagnostic harnesses directly in M, profile step-by-step execution, detect bottlenecks in joins, group operations, and custom function calls, interpret the results to make targeted optimizations, and know when to reach back for native tooling to fill the gaps. This is expert-level work, and it requires understanding how the M engine actually evaluates code — not just how to write it.

What you'll learn:

How M's lazy evaluation model affects profiling strategy and what that means for instrumenting steps
How to capture per-step execution time and row counts using DateTime.LocalNow() and wrapper functions
How to build a reusable diagnostic table that logs step metadata without polluting your production query
How to detect row explosion and row collapse patterns that signal join problems, fanout bugs, or over-filtering
How to interpret diagnostic output alongside Query Diagnostics traces to triangulate bottlenecks in complex pipelines

Prerequisites

You should be comfortable writing M code directly in the Advanced Editor, not just using the GUI. You should understand how let...in expressions work, be familiar with Table.AddColumn, List.Generate, and higher-order functions, and have used Power Query on real datasets with multiple transformation steps. Some exposure to Power Query's built-in Query Diagnostics feature is helpful but not required.

Understanding Why Standard Profiling Doesn't Work in M

Before writing a single line of diagnostic code, you need to understand something fundamental about the M engine: it is a lazy, functional evaluation engine. This isn't just trivia — it directly determines what profiling strategies are even possible.

In an imperative language like Python, code executes top to bottom. If you wrap a step with start = time.time() before and end = time.time() after, you get a genuine wall-clock measurement of that step's execution. In M, that approach fails in non-obvious ways.

M evaluates expressions on demand. When you write:

let
    Source = Sql.Database("server", "database"),
    FilteredRows = Table.SelectRows(Source, each [Region] = "West"),
    GroupedData = Table.Group(FilteredRows, {"SalesRep"}, {{"Total", each List.Sum([Amount]), type number}})
in
    GroupedData

The engine doesn't execute Source, then FilteredRows, then GroupedData in sequence. It starts from GroupedData, sees it needs FilteredRows, sees that needs Source, and builds a query plan. Whether FilteredRows becomes a physical operation or gets folded into a single SQL query depends on the connector and the query folding optimizer.

This creates three problems for naive profiling:

Steps may not execute at all if they get folded into a downstream operation
The order of evaluation doesn't match the order of step definitions
DateTime.LocalNow() calls at different points in a single expression may return the same timestamp because the engine may evaluate them simultaneously or out of sequence

The implication is that you can't simply insert time-capture expressions between steps and expect meaningful results. You need to force evaluation at specific points and understand the difference between measuring M-layer execution versus measuring the full pipeline including data source operations.

Key insight: Real profiling in M requires forcing sequential evaluation by creating data dependencies between steps. If step B doesn't depend on step A, the engine has no obligation to evaluate A before B.

The Foundation: Forcing Sequential Evaluation

The mechanism for forcing evaluation order in M is data dependency. If you make step B consume output from step A, the engine must evaluate A first. This is the cornerstone of every profiling technique in this lesson.

Here's the simplest forced-dependency pattern:

let
    StartTime = DateTime.LocalNow(),
    Source = Sql.Database("server", "SalesDB"),
    // Force the engine to realize Source before recording start
    // by making StartTime part of a record that also references Source
    StepOneResult = Table.SelectRows(Source, each [Region] = "West"),
    // Capture count - this forces StepOneResult to fully evaluate
    StepOneCount = Table.RowCount(StepOneResult),
    // Now capture end time - StepOneCount creates the dependency chain
    StepOneEnd = DateTime.LocalNow(),
    StepOneMs = Duration.TotalSeconds(StepOneEnd - StartTime) * 1000
in
    StepOneMs

The critical element here is StepOneCount. Calling Table.RowCount forces the engine to fully materialize StepOneResult — it cannot lazily defer this. Without that forced materialization, StepOneEnd might be captured before any data actually flows.

But this simple pattern has a flaw: it only gives you cumulative time, not per-step time, and it doesn't scale to 20-step pipelines. Let's build something more rigorous.

Building a Step-Level Diagnostic Harness

The Core Timing Function

We'll build a reusable wrapper function that takes a table expression, forces evaluation, and returns a record containing the result plus timing metadata.

// Save this as a named query: fn_ProfileStep
let
    fn_ProfileStep = (stepName as text, tableExpression as table, previousEndTime as nullable datetime) as record =>
    let
        StartTime = if previousEndTime = null then DateTime.LocalNow() else previousEndTime,
        // Force full materialization of the table
        RowCount = Table.RowCount(tableExpression),
        EndTime = DateTime.LocalNow(),
        ElapsedMs = Duration.TotalMilliseconds(EndTime - StartTime),
        ColumnCount = List.Count(Table.ColumnNames(tableExpression))
    in
        [
            StepName = stepName,
            StartTime = StartTime,
            EndTime = EndTime,
            ElapsedMs = ElapsedMs,
            RowCount = RowCount,
            ColumnCount = ColumnCount,
            Result = tableExpression
        ]
in
    fn_ProfileStep

Notice what this function does:

It accepts the table expression already computed — the M engine evaluates the argument before passing it in
It forces row count evaluation, which ensures the table is materialized
It accepts a previousEndTime parameter so you can chain steps: the "start" of step N is the "end" of step N-1, giving you true delta timing

The Result field in the returned record carries the actual table forward so you can extract it in the next step.

Using the Harness in a Real Pipeline

Let's apply this to a realistic scenario: a sales analytics pipeline that joins orders to customers, filters by date, calculates rep performance, and applies business rules.

let
    // ── Step 0: Pipeline start ─────────────────────────────────
    PipelineStart = DateTime.LocalNow(),

    // ── Step 1: Load Orders ────────────────────────────────────
    RawOrders = Sql.Database("PROD-SQL-01", "SalesDB", 
                    [Query = "SELECT * FROM dbo.Orders"]),
    P1 = fn_ProfileStep("Load Orders", RawOrders, PipelineStart),

    // ── Step 2: Filter to current year ────────────────────────
    FilteredOrders = Table.SelectRows(P1[Result], 
                        each Date.Year([OrderDate]) = Date.Year(DateTime.LocalNow())),
    P2 = fn_ProfileStep("Filter Current Year", FilteredOrders, P1[EndTime]),

    // ── Step 3: Load Customers ─────────────────────────────────
    Customers = Sql.Database("PROD-SQL-01", "SalesDB",
                    [Query = "SELECT CustomerID, CustomerName, Region, Tier FROM dbo.Customers"]),
    P3 = fn_ProfileStep("Load Customers", Customers, P2[EndTime]),

    // ── Step 4: Join Orders to Customers ──────────────────────
    JoinedData = Table.NestedJoin(
                    P2[Result], {"CustomerID"},
                    P3[Result], {"CustomerID"},
                    "CustomerDetail", JoinKind.Left),
    P4 = fn_ProfileStep("Nested Join", JoinedData, P3[EndTime]),

    // ── Step 5: Expand join columns ───────────────────────────
    Expanded = Table.ExpandTableColumn(P4[Result], "CustomerDetail",
                    {"CustomerName", "Region", "Tier"}),
    P5 = fn_ProfileStep("Expand Join", Expanded, P4[EndTime]),

    // ── Step 6: Group by Rep and Region ───────────────────────
    Grouped = Table.Group(P5[Result], {"SalesRep", "Region"}, {
                {"TotalRevenue", each List.Sum([Amount]), type number},
                {"OrderCount", each Table.RowCount(_), type number},
                {"AvgOrderValue", each List.Average([Amount]), type number}
              }),
    P6 = fn_ProfileStep("Group By Rep/Region", Grouped, P5[EndTime]),

    // ── Step 7: Apply Tier Logic ───────────────────────────────
    WithTier = Table.AddColumn(P6[Result], "PerformanceTier",
                   each if [TotalRevenue] > 500000 then "Platinum"
                        else if [TotalRevenue] > 250000 then "Gold"
                        else if [TotalRevenue] > 100000 then "Silver"
                        else "Bronze", type text),
    P7 = fn_ProfileStep("Apply Performance Tier", WithTier, P6[EndTime]),

    // ── Assemble Diagnostic Table ──────────────────────────────
    DiagnosticLog = Table.FromRecords({
        Record.RemoveFields(P1, {"Result"}),
        Record.RemoveFields(P2, {"Result"}),
        Record.RemoveFields(P3, {"Result"}),
        Record.RemoveFields(P4, {"Result"}),
        Record.RemoveFields(P5, {"Result"}),
        Record.RemoveFields(P6, {"Result"}),
        Record.RemoveFields(P7, {"Result"})
    }),

    // ── Add Cumulative and Delta Columns ──────────────────────
    PipelineEnd = DateTime.LocalNow(),
    WithCumulative = Table.AddColumn(DiagnosticLog, "CumulativeMs",
                        each Duration.TotalMilliseconds(
                            [EndTime] - PipelineStart)),
    WithPct = Table.AddColumn(WithCumulative, "PctOfTotal",
                  each Number.Round([ElapsedMs] / 
                      List.Sum(DiagnosticLog[ElapsedMs]) * 100, 1)),

    // ── Final Output: switch between diagnostic and result ─────
    FinalResult = P7[Result]

in
    // Change to DiagnosticLog to inspect profiling, FinalResult for production
    FinalResult

This is a full instrumented pipeline. Let me explain several design decisions:

Why Record.RemoveFields(Px, {"Result"})? The Result field holds the entire table — including it in your diagnostic log record would cause the log table itself to embed nested tables, which creates confusing output and wastes memory. We strip it before assembling the log.

Why pass P1[EndTime] as the start of step 2? This chains the timing so each step's elapsed time is measured from the moment the previous step finished, not from some shared reference point. This gives you true per-step deltas.

The FinalResult vs DiagnosticLog switch: In production, your query returns FinalResult. During debugging, you swap to DiagnosticLog. This is a conscious design choice — one query, two modes. Some teams create a query parameter DiagnosticMode = true/false to control this programmatically.

Detecting Row Count Anomalies

Timing tells you where slowness lives. Row counts tell you why. The two most dangerous patterns in complex pipelines are row explosion (a join or expand dramatically multiplies your rows) and row collapse (a filter or aggregation drops rows you expected to keep).

Let's add row count anomaly detection to our diagnostic framework:

let
    // After building DiagnosticLog from the section above...
    
    WithRowDelta = Table.AddColumn(DiagnosticLog, "RowDelta",
                      (row) => 
                          let
                              CurrentIdx = List.PositionOf(
                                  Table.ToRows(DiagnosticLog), 
                                  Table.ToRows(Table.SelectRows(DiagnosticLog, 
                                      each [StepName] = row[StepName])){0}),
                              PrevRows = if CurrentIdx = 0 then row[RowCount]
                                         else DiagnosticLog[RowCount]{CurrentIdx - 1}
                          in
                              row[RowCount] - PrevRows,
                      type number),

    WithRowMultiplier = Table.AddColumn(WithRowDelta, "RowMultiplier",
                           (row) =>
                               let
                                   CurrentIdx = List.PositionOf(
                                       DiagnosticLog[StepName], row[StepName]),
                                   PrevRows = if CurrentIdx = 0 then row[RowCount]
                                              else DiagnosticLog[RowCount]{CurrentIdx - 1}
                               in
                                   if PrevRows = 0 then null
                                   else Number.Round(row[RowCount] / PrevRows, 3),
                           type number),

    WithAnomalyFlag = Table.AddColumn(WithRowMultiplier, "AnomalyFlag",
                         each if [RowMultiplier] > 2.0 then "ROW_EXPLOSION"
                              else if [RowMultiplier] < 0.1 and [RowCount] > 0 
                                   then "HEAVY_FILTER"
                              else if [RowCount] = 0 then "EMPTY_RESULT"
                              else "OK",
                         type text)
in
    WithAnomalyFlag

The RowMultiplier is the ratio of rows after a step versus before. A multiplier of 8.3 on your "Expand Join" step is a red flag — it means each order row matched 8+ customer records, which almost certainly indicates a missing or wrong join key. A multiplier of 0.002 on a filter step might mean your date filter is using the wrong column or the wrong year.

Warning: The List.PositionOf approach above works for diagnostic tables with moderate row counts (one row per step). Don't use this pattern on large data tables — it's O(n²). For the diagnostic log itself, where you have at most 30-40 rows, it's perfectly fine.

A More Elegant Row Tracking Approach

The positional approach above is correct but verbose. Here's a cleaner version using Table.AddIndexColumn and Table.Join:

let
    DiagnosticWithIndex = Table.AddIndexColumn(DiagnosticLog, "StepIndex", 0, 1),
    
    // Self-join to get previous row's count
    PreviousStep = Table.RenameColumns(
                       Table.SelectColumns(DiagnosticWithIndex, 
                           {"StepIndex", "RowCount"}),
                       {{"StepIndex", "PrevIndex"}, {"RowCount", "PrevRowCount"}}),
    
    WithPrevious = Table.NestedJoin(
                       DiagnosticWithIndex, {"StepIndex"},
                       Table.AddColumn(PreviousStep, "StepIndex", 
                           each [PrevIndex] + 1),
                       {"StepIndex"}, "PrevData", JoinKind.Left),
    
    Expanded = Table.ExpandTableColumn(WithPrevious, "PrevData", {"PrevRowCount"}),
    
    WithMultiplier = Table.AddColumn(Expanded, "RowMultiplier",
                        each if [PrevRowCount] = null or [PrevRowCount] = 0 
                             then 1.0
                             else Number.Round([RowCount] / [PrevRowCount], 3)),

    WithAnomalyFlag = Table.AddColumn(WithMultiplier, "AnomalyFlag",
                         each if [RowMultiplier] > 2.0 then "ROW_EXPLOSION"
                              else if [RowMultiplier] < 0.1 and [RowCount] > 0 
                                   then "HEAVY_FILTER"
                              else if [RowCount] = 0 then "EMPTY_RESULT"
                              else "OK")
in
    WithAnomalyFlag

This produces a clean diagnostic table with columns: StepName, ElapsedMs, RowCount, PctOfTotal, RowMultiplier, AnomalyFlag. Load this table into your Power BI report or Excel worksheet and you have a runtime performance dashboard for your pipeline.

Profiling Custom Functions and Iterative Operations

Simple step timing is straightforward. The hard cases are custom functions applied row-by-row and nested table operations, which are often the real culprits in slow pipelines.

Detecting Per-Row Function Overhead

Consider a pipeline that calls a custom function to parse complex product codes:

// fn_ParseProductCode - a custom function that does text manipulation
let
    fn_ParseProductCode = (productCode as text) as record =>
    let
        Parts = Text.Split(productCode, "-"),
        CategoryCode = if List.Count(Parts) >= 1 then Parts{0} else "UNKNOWN",
        SKU = if List.Count(Parts) >= 2 then Parts{1} else "UNKNOWN",
        VariantCode = if List.Count(Parts) >= 3 then Parts{2} else null,
        // Simulate a more expensive lookup
        CategoryName = Record.FieldOrDefault(
            [A = "Apparel", B = "Books", C = "Electronics", D = "Digital", E = "Equipment"],
            CategoryCode, "Other")
    in
        [Category = CategoryName, SKU = SKU, Variant = VariantCode]
in
    fn_ParseProductCode

When you apply this to 500,000 rows with Table.AddColumn, you're calling this function 500,000 times in the M engine. The engine may or may not parallelize this — it depends on the host (Power BI Desktop vs. Power BI Service vs. Excel) and whether query folding is possible (it won't be for custom functions like this).

To profile the aggregate cost of a row-wise operation, wrap it the same way as any other step:

let
    // ... previous steps ...
    
    ParseStart = DateTime.LocalNow(),
    WithParsedCodes = Table.AddColumn(FilteredOrders, "ProductDetail",
                          each fn_ParseProductCode([ProductCode])),
    ParseForced = Table.RowCount(WithParsedCodes),  // Force evaluation
    ParseEnd = DateTime.LocalNow(),
    ParseMs = Duration.TotalMilliseconds(ParseEnd - ParseStart),
    
    // If ParseMs is > 30% of total pipeline time, your function needs optimization
    // Consider: replacing with Table.TransformColumns for bulk ops,
    // or rewriting as a single Text.Split + Record.FromList operation
    
    ExpandedCodes = Table.ExpandRecordColumn(WithParsedCodes, "ProductDetail",
                        {"Category", "SKU", "Variant"})
in
    ExpandedCodes

Performance insight: If your custom function shows high elapsed time, the first optimization to try is bulk replacement. Instead of Table.AddColumn(t, "X", each fn(row)), consider whether you can transform the entire column at once with Table.TransformColumns or extract the column as a list, process it with List.Transform, and add it back. The overhead per-call accumulates.

Sampling to Estimate Function Cost

For extremely expensive row-wise operations, you can estimate total cost with a sample:

let
    FullTable = /* your source */,
    TotalRows = Table.RowCount(FullTable),
    
    // Sample 1000 rows
    SampleSize = 1000,
    SampledTable = Table.FirstN(FullTable, SampleSize),
    
    SampleStart = DateTime.LocalNow(),
    SampleProcessed = Table.AddColumn(SampledTable, "Result",
                          each fn_ExpensiveOperation([InputColumn])),
    SampleForced = Table.RowCount(SampleProcessed),
    SampleEnd = DateTime.LocalNow(),
    
    SampleMs = Duration.TotalMilliseconds(SampleEnd - SampleStart),
    EstimatedTotalMs = Number.Round(SampleMs / SampleSize * TotalRows, 0),
    MsPerRow = Number.Round(SampleMs / SampleSize, 3),
    
    Estimate = [
        SampleSize = SampleSize,
        SampleMs = SampleMs,
        MsPerRow = MsPerRow,
        TotalRows = TotalRows,
        EstimatedTotalMs = EstimatedTotalMs,
        EstimatedTotalSeconds = Number.Round(EstimatedTotalMs / 1000, 1)
    ]
in
    Estimate

This gives you a quick cost estimate before committing to the full operation. If EstimatedTotalSeconds is 180 seconds and your SLA is 30 seconds, you know right now that this approach is non-viable and you need a different strategy — before your users find out.

Integrating with Native Query Diagnostics

The M-level profiling we've built measures wall-clock time in the M engine. But Power Query's native Query Diagnostics (available in Power Query Editor under Tools → Start Diagnostics) captures a different layer: the query plan, connector requests, and data source roundtrips.

These two tools are complementary, not redundant. Here's how to use them together:

What Query Diagnostics Tells You (That M Profiling Doesn't)

Query Diagnostics captures events at the engine level with columns like Id, Query, Step, Category, Data Source Query, Row Count, Start Time, End Time, and Duration. The most valuable column is Data Source Query — it shows you the actual SQL (or OData query, or other source query) that was generated and sent to your data source.

If your step shows up in Query Diagnostics with a clean SQL query in that column, query folding is happening — the M engine pushed the work to your database. This is almost always good: your database's query optimizer is almost certainly faster than M's in-memory engine for that operation.

If a step shows up in Query Diagnostics with an empty Data Source Query column, that step is executing in M's engine. This means:

Query folding broke at or before this step
All subsequent steps will also execute in M's engine

Cross-Referencing Your Diagnostic Log with Native Diagnostics

Run your instrumented query with profiling enabled:

In Power Query Editor, go to Tools → Start Diagnostics
Refresh your query
Go to Tools → Stop Diagnostics
This creates two new queries: Diagnostics - Summary and Diagnostics - Detail

Then cross-reference:

// In a new query, load your M-profiling diagnostic log (from your instrumented query)
// and the native diagnostics detail table
let
    MProfilingLog = YourDiagnosticLogQuery,  // from your instrumented query
    NativeDiagnostics = #"Diagnostics - Detail",
    
    // Filter native diagnostics to your specific query
    RelevantNative = Table.SelectRows(NativeDiagnostics, 
                        each Text.Contains([Query], "YourQueryName")),
    
    // Find steps where folding broke
    FoldingBreaks = Table.SelectRows(RelevantNative,
                       each [Category] = "Data Access" and 
                            ([#"Data Source Query"] = "" or 
                             [#"Data Source Query"] = null)),
    
    // These step names map to your M profiling log
    BreakPoints = Table.SelectColumns(FoldingBreaks, {"Step", "Duration"}),
    
    // Join to find which of YOUR steps correspond to folding breaks
    Annotated = Table.NestedJoin(MProfilingLog, {"StepName"},
                    BreakPoints, {"Step"},
                    "FoldingInfo", JoinKind.Left),
    
    WithFoldingFlag = Table.AddColumn(
        Table.ExpandTableColumn(Annotated, "FoldingInfo", {"Duration"}, 
            {"NativeDuration"}),
        "QueryFolded",
        each [NativeDuration] = null,
        type logical)
in
    WithFoldingFlag

This merged view tells you which of your profiled steps are folding to the data source and which aren't. When you see a step with high ElapsedMs in your M profiling log and QueryFolded = false, that's your primary optimization target.

Important architectural note: Query folding can break for many reasons — using custom functions, certain Table.AddColumn patterns, type changes after certain operations, or using Table.Buffer. The step where folding breaks is called the "folding fence." Every M operation after the folding fence executes in the M engine. Finding and pushing your folding fence as far downstream as possible is often the single highest-leverage optimization in a Power Query pipeline.

Advanced Pattern: A Self-Contained Diagnostic Framework Query

For teams that run complex pipelines regularly, it's worth building a standalone diagnostic framework as a separate query that your production pipelines can reference. Here's a more complete implementation:

// Query Name: DiagnosticFramework
// Returns a record containing utility functions for pipeline profiling
let
    // Core timing record for a pipeline
    CreatePipelineTimer = () as record =>
        [
            StartTime = DateTime.LocalNow(),
            Steps = {}
        ],

    // Record a step result and timing
    RecordStep = (timer as record, stepName as text, 
                  result as table, prevEndTime as datetime) as record =>
        let
            StartTime = prevEndTime,
            RowCount = Table.RowCount(result),
            ColCount = List.Count(Table.ColumnNames(result)),
            EndTime = DateTime.LocalNow(),
            StepRecord = [
                StepName = stepName,
                StartTime = StartTime,
                EndTime = EndTime,
                ElapsedMs = Duration.TotalMilliseconds(EndTime - StartTime),
                RowCount = RowCount,
                ColumnCount = ColCount,
                Result = result
            ],
            UpdatedSteps = timer[Steps] & {StepRecord}
        in
            [
                StartTime = timer[StartTime],
                Steps = UpdatedSteps,
                LastEndTime = EndTime,
                LastResult = result
            ],

    // Build diagnostic table from completed timer
    BuildDiagnosticTable = (timer as record) as table =>
        let
            StepRecords = List.Transform(timer[Steps],
                             each Record.RemoveFields(_, {"Result"})),
            BaseTable = Table.FromRecords(StepRecords),
            TotalMs = List.Sum(BaseTable[ElapsedMs]),
            WithPct = Table.AddColumn(BaseTable, "PctOfTotal",
                          each Number.Round([ElapsedMs] / TotalMs * 100, 1),
                          type number),
            WithIndex = Table.AddIndexColumn(WithPct, "_idx", 0, 1),
            // Add row multiplier
            WithMultiplier = Table.AddColumn(WithIndex, "RowMultiplier",
                                (row) =>
                                    let
                                        idx = row[_idx],
                                        prevCount = if idx = 0 then row[RowCount]
                                                    else WithIndex[RowCount]{idx - 1}
                                    in
                                        if prevCount = 0 then null
                                        else Number.Round(row[RowCount] / prevCount, 3)),
            WithAnomaly = Table.AddColumn(WithMultiplier, "Status",
                             each if [RowCount] = 0 then "⚠ EMPTY"
                                  else if [RowMultiplier] <> null and [RowMultiplier] > 3.0 
                                       then "🔴 EXPLOSION"
                                  else if [RowMultiplier] <> null and [RowMultiplier] < 0.05 
                                       then "🟡 HEAVY FILTER"
                                  else if [PctOfTotal] > 40.0 then "🔴 BOTTLENECK"
                                  else if [PctOfTotal] > 20.0 then "🟡 WATCH"
                                  else "✅ OK"),
            Cleaned = Table.RemoveColumns(WithAnomaly, {"_idx"})
        in
            Cleaned,

    // Formatted summary text
    BuildSummaryText = (diagnosticTable as table) as text =>
        let
            BottlenecksExist = Table.RowCount(
                Table.SelectRows(diagnosticTable, 
                    each Text.Contains([Status], "BOTTLENECK") or 
                         Text.Contains([Status], "EXPLOSION"))) > 0,
            TotalMs = List.Sum(diagnosticTable[ElapsedMs]),
            TopStep = Table.SelectRows(diagnosticTable,
                          each [ElapsedMs] = List.Max(diagnosticTable[ElapsedMs])),
            TopStepName = TopStep[StepName]{0},
            TopStepMs = TopStep[ElapsedMs]{0}
        in
            "Pipeline total: " & Text.From(Number.Round(TotalMs / 1000, 2)) & "s | " &
            "Slowest step: " & TopStepName & " (" & Text.From(TopStepMs) & "ms) | " &
            (if BottlenecksExist then "⚠ BOTTLENECKS DETECTED" else "✅ No bottlenecks")

in
    [
        CreateTimer = CreatePipelineTimer,
        RecordStep = RecordStep,
        BuildTable = BuildDiagnosticTable,
        Summarize = BuildSummaryText
    ]

Using the framework in a production pipeline:

let
    Diag = DiagnosticFramework,
    Timer0 = Diag[CreateTimer](),

    // Step 1
    RawSales = Csv.Document(File.Contents("C:\Data\sales_2024.csv"),
                   [Delimiter=",", Columns=12, Encoding=1252, QuoteStyle=QuoteStyle.None]),
    Timer1 = Diag[RecordStep](Timer0, "Load Raw CSV", RawSales, Timer0[StartTime]),

    // Step 2
    TypedSales = Table.TransformColumnTypes(Timer1[LastResult], {
                     {"OrderDate", type date}, {"Amount", type number},
                     {"Quantity", Int64.Type}, {"CustomerID", type text}}),
    Timer2 = Diag[RecordStep](Timer1, "Apply Types", TypedSales, Timer1[LastEndTime]),

    // Step 3
    FilteredSales = Table.SelectRows(Timer2[LastResult],
                       each [Amount] > 0 and [OrderDate] >= #date(2024, 1, 1)),
    Timer3 = Diag[RecordStep](Timer2, "Filter Valid Sales", FilteredSales, Timer2[LastEndTime]),

    // Step 4
    ProductRef = Excel.Workbook(File.Contents("C:\Data\products.xlsx"), true),
    ProductTable = ProductRef{[Item="Products",Kind="Sheet"]}[Data],
    Timer4 = Diag[RecordStep](Timer3, "Load Product Reference", ProductTable, Timer3[LastEndTime]),

    // Step 5
    Joined = Table.NestedJoin(Timer3[LastResult], {"ProductID"},
                 Timer4[LastResult], {"ProductID"},
                 "ProductInfo", JoinKind.Left),
    Timer5 = Diag[RecordStep](Timer4, "Join Products", Joined, Timer4[LastEndTime]),

    // Step 6
    Expanded = Table.ExpandTableColumn(Timer5[LastResult], "ProductInfo",
                   {"ProductName", "Category", "UnitCost"}),
    Timer6 = Diag[RecordStep](Timer5, "Expand Product Info", Expanded, Timer5[LastEndTime]),

    // Diagnostic output
    DiagnosticTable = Diag[BuildTable](Timer6),
    Summary = Diag[Summarize](DiagnosticTable),

    // Your final result
    FinalResult = Timer6[LastResult]

in
    // Switch: DiagnosticTable | FinalResult
    DiagnosticTable

Reading the Diagnostic Output: A Decision Framework

Once you have diagnostic results, you need a systematic way to interpret them. Here's the decision logic:

High `PctOfTotal` + No Query Folding

Action: Investigate the folding fence. Can you move this operation earlier, before the point where folding breaks? Can you push the heavy work to the database with a native SQL query?

`ROW_EXPLOSION` on a Join Step

Action: Check your join keys for duplicates. A Table.NestedJoin on a non-unique key in the right table will fan out every left row by the number of matching right rows. Verify uniqueness with:

let
    DuplicateCheck = Table.SelectRows(
                         Table.AddColumn(
                             Table.Group(Customers, {"CustomerID"}, 
                                 {{"Count", each Table.RowCount(_), Int64.Type}}),
                             "IsDuplicate",
                             each [Count] > 1),
                         each [IsDuplicate] = true)
in
    DuplicateCheck

If this returns rows, you have duplicate keys and need to deduplicate before joining.

High `ElapsedMs` on `Table.Group`

Action: Grouping is O(n log n) in the best case. If you're grouping a large table with many aggregation functions that each iterate the subtable, you're doing multiple passes. Consider consolidating aggregations or using Table.Buffer strategically on the pre-grouped table to avoid re-pulling from source.

`HEAVY_FILTER` with Unexpected Row Count

Action: Your filter condition may be more restrictive than intended. Log a sample of the rows that didn't pass the filter:

let
    Rejections = Table.SelectRows(FullTable, each not (/* your filter condition */)),
    SampleRejections = Table.FirstN(Rejections, 100)
in
    SampleRejections

Hands-On Exercise

You'll build a fully instrumented pipeline for a multi-source analytical query and use the diagnostic output to identify and fix a deliberate bottleneck.

Scenario: You're building a daily pipeline that loads three months of transaction data from a SQL database, joins to a product catalog from SharePoint, applies a custom margin calculation, and groups by product category and region.

Setup: Create the following as separate queries in Power Query (you can use #table to simulate data sources without a live connection):

// Query: SimulatedTransactions
let
    RowCount = 50000,
    RandomSeed = List.Generate(
        () => [i = 0, val = 0.7],
        each [i] < RowCount,
        each [i = [i] + 1, val = Number.Mod([val] * 1664525 + 1013904223, 4294967296) / 4294967296],
        each [val]),
    Transactions = Table.FromColumns({
        List.Transform({1..RowCount}, each "TXN-" & Text.PadStart(Text.From(_), 8, "0")),
        List.Transform(RandomSeed, each "PROD-" & Text.From(Number.RoundDown(_ * 200) + 1)),
        List.Transform(RandomSeed, each Number.Round(_ * 5000 + 50, 2)),
        List.Transform(RandomSeed, each Number.Round(_ * 100 + 10, 2)),
        List.Transform(RandomSeed, each Date.AddDays(#date(2024, 1, 1), 
                           Number.RoundDown(_ * 90)))
    }, {"TransactionID", "ProductID", "Revenue", "Cost", "TransactionDate"})
in
    Transactions

// Query: SimulatedProducts  
let
    Products = #table(
        {"ProductID", "ProductName", "Category", "Region", "ListPrice"},
        List.Transform({1..200}, each {
            "PROD-" & Text.From(_),
            "Product " & Text.From(_),
            {"Electronics", "Apparel", "Books", "Food", "Tools"}{Number.Mod(_, 5)},
            {"North", "South", "East", "West"}{Number.Mod(_, 4)},
            Number.Round(100 + _ * 23.7, 2)
        })
    )
in
    Products

Your task:

Build an instrumented pipeline that:
- Loads transactions and products
- Filters transactions to Q1 2024 (January through March)
- Joins to product catalog
- Adds a margin calculation column: (Revenue - Cost) / Revenue
- Groups by Category and Region, summing revenue and averaging margin
Intentionally introduce a bottleneck by adding this deliberately inefficient step after the join:

// Intentionally slow: row-by-row lookup instead of a join
SlowLookup = Table.AddColumn(Joined, "PriceCategory",
                 each let
                          price = List.First(List.Select(
                              SimulatedProducts[ListPrice],
                              each _ = [ListPrice])),
                          cat = if price > 3000 then "Premium"
                                else if price > 1000 then "Standard"
                                else "Budget"
                      in cat)

Run your diagnostic framework and identify which step shows the highest PctOfTotal
Fix the bottleneck by replacing the slow lookup with a proper column transformation, re-run diagnostics, and measure the improvement
Examine the RowMultiplier on your join step — if it's not 1.0, investigate why

Common Mistakes & Troubleshooting

Mistake 1: Forgetting to Force Evaluation

The most common error is capturing DateTime.LocalNow() without forcing the preceding computation:

// WRONG: EndTime may be captured before data actually materializes
Step1 = Table.SelectRows(Source, each [Active] = true),
EndTime = DateTime.LocalNow()  // May fire before Step1 is evaluated

// CORRECT: Force evaluation with RowCount
Step1 = Table.SelectRows(Source, each [Active] = true),
Step1Count = Table.RowCount(Step1),  // Forces materialization
EndTime = DateTime.LocalNow()

Mistake 2: Using `Table.Buffer` for Timing Without Understanding the Side Effects

Table.Buffer forces full materialization of a table into memory, which seems useful for timing. But it has a critical side effect: it breaks query folding for all downstream operations on that buffered table. Using Table.Buffer to force timing will make your diagnostic measurements accurate while simultaneously crippling the query performance you're trying to measure. Use Table.RowCount instead — it forces evaluation without preventing folding.

Mistake 3: Profiling in a Single-Step Monolith

If your query is already written as a long let...in block with no intermediate variables, you cannot add profiling without refactoring. This is actually a good reason to write queries with meaningful intermediate step names — not just for profiling, but for maintainability. Each step name is a potential diagnostic probe point.

Mistake 4: Confusing M-Layer Time with Total Refresh Time

Your M profiling captures M-engine execution time. But total refresh time in Power BI includes the time to load data into the model (the Vertipaq engine import), relationship processing, and calculated column/measure computation. If your M profiling shows 30 seconds but the full refresh takes 8 minutes, the bottleneck is not in M — it's in the model layer.

Mistake 5: Not Accounting for Caching

If you run your instrumented query twice in quick succession in Power Query Editor, the second run may appear much faster due to data source result caching. Always test performance after clearing the cache (close and reopen the file, or use a new connection) or in an environment where caching doesn't apply (like Power BI Service scheduled refresh).

Troubleshooting: `DateTime.LocalNow()` Returns Identical Values

If multiple timing captures return the same timestamp, the M engine evaluated them simultaneously (possible in some parallel execution scenarios) or the operations completed faster than the timer resolution. Windows system timers have ~15ms resolution by default. For sub-millisecond operations, use a larger dataset for profiling or accept that the step is fast enough to ignore.

Troubleshooting: Diagnostic Log Shows Null Values

If ElapsedMs is null, check that your previousEndTime parameter was correctly passed between steps. A single null in the chain propagates forward. Add a null guard:

StartTime = if previousEndTime = null then DateTime.LocalNow() else previousEndTime

Summary & Next Steps

You now have a complete toolkit for instrumenting Power Query M pipelines at a professional level. Let's recap what you built and why it works:

The core mechanism is forced sequential evaluation via data dependency. By calling Table.RowCount() after each step, you create a mandatory evaluation checkpoint that allows accurate timing capture.

The diagnostic framework captures per-step elapsed time, row counts, column counts, and derives anomaly indicators (row explosion, heavy filter, bottlenecks by percentage of total time). This gives you both timing data and cardinality data — the two dimensions you need to understand pipeline behavior.

The integration with native Query Diagnostics lets you cross-reference M-level timing with query folding information, so you can distinguish between "this step is slow because M is doing the work" versus "this step is slow because the database query is slow."

The row multiplier pattern catches the silent killers: bad join keys that fan out your data and create downstream performance problems that seem mysterious until you see a 15x row multiplier on your join step.

Where to Go Next

Query Folding deep-dive: Study how to test for query folding programmatically using Value.Metadata and the folding indicators in Query Diagnostics. Learn which M functions break folding and how to restructure queries to preserve it.
Table.Buffer strategy: Learn when buffering is beneficial (preventing repeated source queries in complex joins) versus harmful (breaking folding). The decision rules are nuanced and depend heavily on your data source and query structure.
Custom connector performance: If you're using custom connectors built with the M SDK, the diagnostic techniques in this lesson apply directly to connector debugging — you can profile which connector functions are slow.
Parameter-driven diagnostic mode: Build a query parameter (DiagnosticsEnabled = true/false) that controls whether your pipeline returns the diagnostic table or the production result, making it safe to ship instrumented queries to production environments.
Alerting and logging: Export your diagnostic table to a historical log (append to a SharePoint list or Azure SQL table) to build a performance baseline and detect regressions over time. A query that ran in 45 seconds last Monday and now takes 180 seconds needs investigation — and you can't see that without historical data.

The discipline of instrumenting your own pipelines separates engineers who suspect where performance problems are from those who know. Build the habit, and your optimization work will always be targeted and evidence-based.

Implementing Custom Query Diagnostics and Step-Level Profiling in Power Query M