If you write ETL procedures in Snowflake but don't have ACCOUNT_USAGE
access, you've probably had this exact conversation: someone says a load
job got slower, you can look at one query's profile if you already know
which query, but QUERY_HISTORY gives you zero help connecting a CALL
to the statements it ran internally. There's no PARENT_QUERY_ID. No
ROOT_QUERY_ID. TRANSACTION_ID doesn't match between parent and
child. QUERY_TAG is empty unless the caller happens to set it.
So when a 7-statement procedure regresses, "which of the 7 got slower,
and why" is a manual, undocumented process that lives in whoever's head
has done it before. I got tired of doing it by hand, so I spent a few
weeks building three SQL procedures that do it for me. This post is
about the interesting part: how the attribution actually works, since
Snowflake genuinely doesn't expose it and I couldn't find anyone else
who'd written this up.
The gap
ACCOUNT_USAGE.QUERY_HISTORY has about 85 columns. I went through all
of them looking for anything that links a CALL to its child
statements. Here's what doesn't work, in case it saves someone else the
time:
-
TRANSACTION_ID- differs per child statement, doesn't match the parentCALLrow (which is usually0/null). -
QUERY_TAG- empty unless the calling session sets it explicitly. Not usable generically, since a tool like this doesn't control the customer's session. -
CHILD_QUERIES_WAIT_TIME- this one's interesting. It exists on the parentCALLrow, and its mere existence proves Snowflake tracks the parent/child relationship internally. It just doesn't expose the child query IDs, only an aggregate wait-time duration. So close.
The workaround: session ID + timestamp containment
No FK column exists, but the data needed to reconstruct the relationship
does: SESSION_ID, START_TIME, END_TIME, TOTAL_ELAPSED_TIME.
The core idea: a child statement belongs to whichever same-session query
has the tightest enclosing time window. Concretely, for any statement,
find every same-session query whose window fully contains it
(candidate.START_TIME <= child.START_TIME AND candidate.END_TIME >=), then pick the one with the minimum
child.END_TIME
TOTAL_ELAPSED_TIME among those candidates. A nested window is always
shorter than any window that contains it, so "shortest containing
window" and "nearest enclosing window" are the same thing - no separate
tree-walk needed, and no need to pre-filter candidates to
QUERY_TYPE = 'CALL' either, since single-session serial execution means
unrelated sibling queries in the same session can never overlap at all.
-- simplified shape of the correlation, not the full procedure
SELECT
child.query_id,
(
SELECT candidate.query_id
FROM query_history candidate
WHERE candidate.session_id = child.session_id
AND candidate.start_time <= child.start_time
AND candidate.end_time >= child.end_time
AND candidate.query_id != child.query_id
ORDER BY candidate.total_elapsed_time ASC
LIMIT 1
) AS parent_query_id
FROM query_history child
That's the whole trick. Everything else is bookkeeping.
Where I expected this to break, and it didn't
I didn't trust "timestamp containment" until I'd tried to break it on
purpose. Three cases:
-
Nested procs (proc A calls proc B calls a statement). The
grandchild's window can fit inside both the inner and outer
CALLwindows simultaneously. This is exactly why "any containing window" isn't enough and it has to be the tightest one - confirmed against a realOUTER_PROC -> INNER_PROC -> tablecall tree. -
Concurrent sessions - same user, two worksheets, running the same
procedure at genuinely overlapping wall-clock times. Filtering to the
exact
SESSION_IDof the parentCALLcleanly isolates its own children even when a second session runs the identical procedure at the same moment, becauseSESSION_IDis per-connection, not per-user. -
Rapid back-to-back
CALLs submitted as a single batch in one session. Still executed serially with clean, non-overlapping windows. No interleaving to worry about.
I also forced real warehouse contention (MAX_CONCURRENCY_LEVEL = 1,
two concurrent sessions) to check the attribution still holds when
execution windows genuinely overlap under queuing pressure, not just
when they're clean and sequential. It did: the queued statement still
attributed to the right parent, and the flag for warehouse queuing (see
below) fired correctly on the queued child, not the parent.
What it's wrapped into
Three procedures, matching the manual workflow instead of one black-box
call:
| Procedure | Does |
|---|---|
DIAGNOSE_PROCEDURE(proc_name, lookback_hours) |
Bulk scan: reconstructs the call tree for recent runs and flags statements for regression vs. their own history, poor pruning, spilling, non-sargable predicates, duplicate table scans, VARCHAR/NUMBER join-key mismatches, and warehouse queuing |
GET_STATEMENT_PROFILE(query_id) |
Per-operator drill-down for one flagged statement, via GET_QUERY_OPERATOR_STATS()
|
EXPLAIN_WITH_CORTEX(query_id) |
Opt-in AI second opinion via Snowflake Cortex (AI_COMPLETE), in-account, no external LLM call |
None of them specify EXECUTE AS, so they run as owner's rights by
Snowflake's default: install once with ACCOUNT_USAGE access, then
GRANT USAGE on the procedures to anyone who needs to call them without
ever giving them ACCOUNT_USAGE themselves.
What it doesn't do (yet)
Procedures only, not views. View definitions get inlined into the query
plan, so mapping a slow operator back to which view (and which part of
it) caused it is a genuinely harder problem, and I decided to ship the
procedure case well rather than both cases half-done.
The regex-based flags (duplicate-scan detection, join-type mismatch) are
text pattern matching, not a real parser, so they miss CTEs, subqueries,
and multi-condition joins. They catch the common case, not everything.
Repo
MIT licensed, three SQL files, nothing to install beyond pasting SQL
into your own account: https://github.com/TracepointData/QueryTrace
Curious if anyone else has fought this exact problem, and if so how you
solved the attribution piece.
Top comments (0)