fix(db-bigquery): poll query results until the configured timeout - #3010
Conversation
jswir
left a comment
There was a problem hiding this comment.
Pre-submission review notes (malloy-scoped). Overall this is a correct, well-diagnosed fix — I verified the mechanism claim (request-level vs job-level wait) against the @google-cloud/bigquery source, git history supports it (it implements the long-standing TODO left by the 2022 timeout commits rather than reverting them), and moving the abort-listener removal into an outer finally fixes a real latent bug where retries after the first were non-cancelable.
Inline comments below. The two worth addressing before merge:
- the poll loop widens worst-case abort latency, because "still running" is no longer bounded by the retry count (only by the deadline); and
- "still running" is detected only by a regex on the client's error string, which degrades silently back to the pre-fix behavior if that wording ever changes.
Both have a more robust alternative noted inline. The rest are nits (deadline tolerance, error actionability, '0' timeout handling, spread order, test coverage).
Two more, not inline:
- The TODO around line 346 (
confirm that resulting metadata has "jobComplete: true") is effectively resolved by this mechanism: the client throws precisely whenjobComplete === falseand atimeoutMsis requested (which this code always sends), so a non-throwing resolve implies it's true. Worth removing/updating. - Downstream consideration for the Malloy Publisher: its HTTP socket timeout is 10 min — equal to this connector's new default deadline. Under Publisher's default 5-min query-timeout wrapper this is moot, but if an operator raises that wrapper to let long BigQuery queries finish (the case this unblocks), the 10-min deadline races the 10-min socket timeout with zero margin. Worth choosing the connector default to sit under common downstream HTTP timeouts, or documenting the relationship.
|
@jswir Structured jobComplete signal (the regex concern). Switched getQueryResultsUntilComplete to the callback overload and now branch on apiResponse.jobComplete === false instead of matching the error string. isQueryStillRunningError is removed, so the silent-regression-on-message-drift path no longer exists. Verified against @google-cloud/bigquery@7.9.4 that the still-running callback carries jobComplete: false. Thanks for pointing at the callback form; it's a strictly better signal than the message. Abort latency. The abort signal is now threaded into getQueryResultsUntilComplete: checked at the top of each iteration, and pollQueryResults also races the signal so an in-flight poll settles immediately on abort rather than after the server-side wait. So the Publisher's AbortController now actually ends the call. Added an "abort fires mid-poll" test and an "already aborted" one, matching the coverage bar from #2760. Soft deadline / clamp. Each poll's timeoutMs is clamped to min(GET_QUERY_RESULTS_POLL_MS, remaining), so a short configured timeout fails fast and the overall deadline can't overshoot by a full poll. Test added. Spread order. timeoutMs is now applied after ...getQueryResultsOptions, so a caller can't override the poll interval. Unactionable error. On deadline exceeded it now throws a wrapped error naming the actual configured deadline and pointing at timeoutMs, instead of rethrowing the misleading last-poll ...120000ms string. '0' timeout. Added resolveTimeoutMs, which preserves an explicit '0' (fail-fast) and only falls back to the default on an unset/empty/non-numeric value. It's used for both the poll deadline and jobTimeoutMs so the two stay consistent. line-346 TODO (confirm ... jobComplete: true): removed. The new polling contract only returns once the job is complete, so it's guaranteed; left a one-line note in its place. Mixed-signal test. Added one that interleaves still-running and transient responses and asserts a still-running poll does not refill the 3-retry budget. Downstream 10-min race. Went with documenting rather than changing the default. TIMEOUT_MS is pre-existing and also bounds jobTimeoutMs, and this is a general-purpose connector that shouldn't hard-code a margin against one embedder's socket timeout. Added a comment at TIMEOUT_MS noting it should sit below any downstream HTTP/request timeout. The abort fix above also helps in practice: the Publisher's query-timeout wrapper now settles the call, so that wrapper (kept below the socket timeout) becomes the effective ceiling and the connector deadline is a backstop. Happy to lower the default instead if you'd prefer a built-in margin. |
|
Traced the polling rewrite against the Two small non-blocking things:
Optional: |
|
Thanks Sagar, addressed all of them. Whitespace timeoutMs: The guard is now configured.trim() === '', so a blank-but-not-empty value falls back to the default instead of coercing to 0 and failing every query. resolveTimeoutMs is now exported and directly unit-tested (unset / empty / whitespace / '0' / numeric / non-numeric). '0' behavior change: Agreed it's user-visible and intentional. I called it out explicitly in the PR description Notes: '0' is now preserved as fail-fast, where the previous Number(...) || TIMEOUT_MS treated it as falsy and fell back to the 10-minute default. Hermetic wiring coverage: Added bigquery_connection.unit.spec.ts, which drives runSQL against a stubbed job (no live BigQuery) and locks down the seam: that config.timeoutMs reaches the deadline ('0' fails fast before any poll; a whitespace value falls back and the query completes), and that a jobComplete: false response is polled rather than surfaced to the caller as empty data. |
|
Went through the diff against every other connector to check the "Scope" claim, and it holds up: Snowflake is the only other connector that does real client-side timeout work. Databricks and Trino/Presto delegate to their client libraries, Postgres/MySQL/DuckDB are synchronous, and the Publisher forwards over HTTP with a fixed axios timeout while currently dropping That makes Snowflake the reference point to align against, and the good news is this PR already matches it where it matters most: the same 10-minute default, and the same abort discipline (fail fast when the signal is already aborted, listener cancels the in-flight statement/job, settle promptly rather than waiting out the server). Two things to close out before merge, one of which is a divergence from that standard. 1.
|
|
Thanks @kylenesbit , Addressed in d75cd3d.
Also, thanks for independently verifying the scope claim against every connector, glad it holds up. |
Correct the BigQuery timeoutMs row: an unset, blank, non-numeric, or 0 value falls back to the 10-minute default, matching the connector change in malloydata/malloy#3010. Signed-off-by: Girish Jeswani <girish@credibledata.com>
|
Thanks @mtoy-googly-moogly for the review. Updated the BigQuery PR to match: 0 now falls back to the internal default. Since unset/blank/non-numeric/0 all resolve to the 10 min default, this drops the special-case helper entirely and is back to the original parse, just correctly wired through the new poll path. timeoutMs shadows to jobTimeoutMs and the client polls getQueryResults to the same deadline, totaling the wait across the ~200s-capped calls. Cancel on our own deadline. If we reach the client deadline and BigQuery's job-timeout error hasn't come back yet, we call job.cancel() before throwing, so the job doesn't keep running (and billing) past the point we stopped waiting. |
|
Going to close and re-open which should, accoridng to claude, run the new CI,. |
getQueryResults was called with a hardcoded 2-minute timeoutMs, so any query that took longer than ~2 minutes to finish failed with "The query did not complete before 120000ms" regardless of the connection's configured timeoutMs. Raising timeoutMs alone does not help: BigQuery caps a single getQueryResults call's server-side wait near 2 minutes and the client then throws while the job is still running fine. Add getQueryResultsUntilComplete, which polls getQueryResults until the job completes or the connection's configured timeoutMs elapses (the same knob that already bounds jobTimeoutMs; default TIMEOUT_MS = 10 min). The transient access-denied retry is preserved (bounded), and the abort listener is now removed in a finally wrapping the whole operation instead of after the first iteration. Unit-tested with a fake job and an injected clock. Signed-off-by: Girish Jeswani <girish@credibledata.com>
Comments only, no behavior change. Signed-off-by: Girish Jeswani <girish@credibledata.com>
- Detect "still running" via the callback overload's apiResponse.jobComplete instead of matching the client's error string. Removes isQueryStillRunningError and the silent-regression risk if the client's wording ever changes. - Thread the abort signal into the poll loop so a cancel settles the call promptly instead of waiting out the full deadline. - Clamp each poll's timeoutMs to the remaining deadline: short timeouts fail fast and the overall deadline is not overshot by a poll interval. - On deadline, throw an actionable error naming the timeout and the knob to raise. - Preserve an explicit timeoutMs of "0" via resolveTimeoutMs, used for both the poll deadline and jobTimeoutMs. - Apply timeoutMs after the caller's options so a caller cannot override it. - Remove the now-resolved "jobComplete: true" TODO; document that TIMEOUT_MS should sit below downstream HTTP/socket timeouts. - Tests: callback-based mock plus abort-mid-poll, already-aborted, clamp, and mixed still-running/transient coverage. Signed-off-by: Girish Jeswani <girish@credibledata.com>
…tests
Follow-up review (sagarswamirao):
- resolveTimeoutMs: treat a whitespace-only timeoutMs as unset. Number(' ')
is 0 (not NaN), so a blank-but-not-empty config value slipped past the
empty-string guard and produced a fail-fast 0ms deadline; guard on
trim() === '' instead.
- Export resolveTimeoutMs and unit-test it (unset/empty/whitespace/'0'/numeric/
non-numeric).
- Add a hermetic BigQueryConnection.runSQL test with a stubbed job, covering the
config.timeoutMs to deadline wiring and that a jobComplete:false response is
polled rather than surfaced as empty data.
The '0'-as-fail-fast behavior change is now noted in the PR description.
Signed-off-by: Girish Jeswani <girish@credibledata.com>
…wflake Per review (kylenesbit): a configured timeoutMs of 0 was fail-fast (the deadline was already blown, so every query threw before dispatch), the opposite of Snowflake where 0 disables the client-side limit. Same knob, same docs, opposite behavior. Align on Snowflake: a resolved 0 now means no client-side timeout. No poll deadline (poll until the job completes or the caller aborts), and jobTimeoutMs is omitted rather than sent as 0 so BigQuery applies its own default. resolveTimeoutMs is unchanged (still preserves 0 and treats blank/whitespace as unset); the disabled semantic is applied at the two call sites. Tests: the hermetic "0" case now asserts poll-through plus omitted jobTimeoutMs; added a positive-timeout case (jobTimeoutMs set) and reframed the whitespace guard to assert the default jobTimeoutMs. Signed-off-by: Girish Jeswani <girish@credibledata.com>
…adline an explicit timeoutMs of 0, like a blank or non-numeric value, now falls back to the 10-minute default rather than disabling the client-side timeout. The resolveTimeoutMs helper is removed and the resolved value is Number(timeoutMs) || TIMEOUT_MS. That one value shadows to the job's jobTimeoutMs and bounds the results poll. On reaching the client deadline the job is now cancelled before throwing, as a backstop for the case where BigQuery's own job timeout has not surfaced its error yet, so the job does not keep running (and billing) past the point we stopped waiting. Tests: the hermetic 0 case now asserts the default jobTimeoutMs while still polling through; the poll spec asserts the job is cancelled on the deadline and not on the happy path. Signed-off-by: Girish Jeswani <girish@credibledata.com>
…l interval
Per review: resolvedTimeoutMs used Number(timeoutMs) || TIMEOUT_MS, so a negative value passed through (Number('-5') is truthy), creating a job with jobTimeoutMs: -5 that blew the deadline on the first poll. Guard with Number(...) > 0 so zero and negative both fall back to the default, matching the doc comment.
Also floor the spacing between getQueryResults polls: BigQuery can return jobComplete:false sooner than the timeoutMs requested, which would busy-poll and hammer the API. Wait out only the shortfall below a 1s minimum (bounded by the remaining deadline, abortable), so a poll that already blocked adds no latency.
Tests: negative-timeoutMs falls back to the default; the poll floor waits only the shortfall and not when a poll already blocked; and a cancel around the inter-poll wait exits promptly without re-polling.
Signed-off-by: Girish Jeswani <girish@credibledata.com>
eb21301 to
2009f95
Compare
…lts callback The offline query-metadata spec stubbed getQueryResults with the promise overload, but the connector reads results via the callback overload and polls on apiResponse.jobComplete, so the mock must invoke the callback with jobComplete: true or runSQL never settles (the tests timed out at 100s in CI). Signed-off-by: Girish Jeswani <girish@credibledata.com>
getQueryResults is paginator-wrapped, and at the default autoPaginate the paginator hands the callback the error alone, dropping the apiResponse. The jobComplete check therefore never matched and every still-running poll was misread as a fetch error, so the loop exhausted its retry budget and threw instead of polling. Disabling autoPaginate for the poll restores the four-argument callback. It does not change what a completed fetch returns. The hermetic specs stub the callback, so they cannot catch this; add a live contract test that pins the shape against BigQuery itself.
The Snowflake connector resolved timeoutMs with 'options?.timeoutMs ?? TIMEOUT_MS', so an explicit 0 was kept and then read by the executor's 'timeoutMs ? setTimeout(cancel, timeoutMs) : undefined' as no timer, i.e. wait forever. A blank or non-numeric value parses to NaN and behaved the same. Resolve with '|| TIMEOUT_MS' so 0 and NaN fall back to the 10-minute default, matching the BigQuery change in malloydata#3010. Applied to timeoutMs and the sibling schemaSampleTimeoutMs. The per-statement client-side cancel is unchanged; on timeout the executor already cancels the running statement server-side. Adds snowflake_connection.unit.spec.ts asserting the resolution via a stubbed executor (0, unset, and NaN fall back; a positive value passes through). Signed-off-by: Girish Jeswani <girish@credibledata.com>
…ery (#3022) * fix(db-snowflake): resolve timeoutMs 0 to the default, matching BigQuery The Snowflake connector resolved timeoutMs with 'options?.timeoutMs ?? TIMEOUT_MS', so an explicit 0 was kept and then read by the executor's 'timeoutMs ? setTimeout(cancel, timeoutMs) : undefined' as no timer, i.e. wait forever. A blank or non-numeric value parses to NaN and behaved the same. Resolve with '|| TIMEOUT_MS' so 0 and NaN fall back to the 10-minute default, matching the BigQuery change in #3010. Applied to timeoutMs and the sibling schemaSampleTimeoutMs. The per-statement client-side cancel is unchanged; on timeout the executor already cancels the running statement server-side. Adds snowflake_connection.unit.spec.ts asserting the resolution via a stubbed executor (0, unset, and NaN fall back; a positive value passes through). Signed-off-by: Girish Jeswani <girish@credibledata.com> * fix(db-snowflake): fall back to the default on a non-positive timeoutMs Extend the 0-to-default resolution to negatives: a bare || let a negative through (it is truthy), and the executor would then schedule setTimeout(cancel, <negative>) and abort the statement almost immediately. Resolve with Number(...) > 0 so zero and negative both default, for timeoutMs and the sibling schemaSampleTimeoutMs. Adds a negative-timeoutMs unit test. Signed-off-by: Girish Jeswani <girish@credibledata.com> * test(db-snowflake): remove the timeout-resolution unit spec Signed-off-by: Girish Jeswani <girish@credibledata.com> --------- Signed-off-by: Girish Jeswani <girish@credibledata.com>
Run `npm run upgrade-malloy 0.0.427` to move every @malloydata/* pin from 0.0.426 to 0.0.427 across all packages and the root resolutions. malloy-explorer is left unchanged (0.0.427 is not published for it). The reason to adopt 0.0.427 is the BigQuery connector poll-timeout fix (malloydata/malloy#3010): the results poll now honors the connection's configured timeoutMs instead of giving up at a hardcoded ceiling of a few minutes. Long-running materializations (CTAS) need this to finish. DuckDB and pg build knobs already match the new release; lockfile relocked. typecheck:server and typecheck:sdk pass after regenerating API types. Signed-off-by: Girish Jeswani <girish@credibledata.com>
Summary
The BigQuery connector could not complete any query that ran longer than about
six minutes, regardless of configuration.
runSQL(viacreateBigQueryJobAndGetResults) fetched results withjob.getQueryResultsusing a hardcoded 2-minute
timeoutMs, wrapped in a fixed 3-retry loop. Eachcall waits ~2 minutes and throws
The query did not complete before 120000mswhile the job is still running fine; after 3 retries the loop gives up at
~6 minutes. The
120000msin the message is a single poll's window, not thereal ceiling. The connection's configured
timeoutMsnever reached this path(it only bounded
jobTimeoutMs), so no configuration could extend it.This resolves the long-standing TODO in
createBigQueryJobAndGetResults, whichalready called for exactly this: "extend the wait for results using a timeout
set by the user, and probably needs to loop to check for results."
Root cause
getQueryResultsis a request-level wait, not a job-level one. Per the BigQuerydocs a single call returns after at most ~200s regardless of the requested
timeoutMs, reportingjobComplete: falsewhile the job is still running; thedocumented pattern is to keep calling until
jobCompleteis true. The old codetreated the incomplete response as a failure and gave up after a fixed number of
retries.
Fix
The connection's configured
timeoutMsnow drives one resolved value thatbounds both the BigQuery job and the client-side wait, and
getQueryResultsispolled to completion instead of being retried a fixed number of times:
timeoutMsto the job'sjobTimeoutMsso BigQuery cancels a runawayjob server-side, and poll
getQueryResultsup to the same deadline on theclient, totaling the wait across calls (BigQuery returns each call after ~200s
regardless of the requested
timeoutMs).overload's
apiResponse.jobComplete === false, not a regex on the client'serror string, so it cannot silently regress if the wording changes.
jobTimeoutMsshould already be cancelling it, but this covers the case wherethat timeout error has not come back yet, so the job does not keep running
(and billing) after we have stopped waiting.
poll, so a cancel settles the call promptly (and cancels the job) instead of
waiting out the deadline.
min(GET_QUERY_RESULTS_POLL_MS, remaining), so shorttimeouts fail fast and the deadline is not overshot by a poll.
jobComplete: falsesoonerthan the per-poll wait we requested, the loop waits out only the shortfall
below a 1s floor (bounded by the remaining deadline) instead of busy-polling.
first fetch, replacing the old blanket 3-retries-on-everything.
timeoutMsresolves to a positive number or the default: unset, blank,non-numeric, zero, or negative all fall back to the 10-minute default; only a
positive value overrides it. A non-positive value must not reach the job, or
it would cancel on the first poll.
Scope
BigQuery-only, by design. Among the connectors only BigQuery hand-rolls result
polling: Snowflake passes its configured timeout through, Databricks and Trino
delegate polling to their client libraries, and Postgres/MySQL/DuckDB are
synchronous. This brings BigQuery in line with the others rather than adding a
shared abstraction. Per review, two follow-ups: aligning the Snowflake
connector's
0handling with this (open as #3022), and addinga
timeoutMssetting to Databricks.Tests
get_query_results_polling.spec.tsdrives the poll loop directly with ascripted fake job and an injected clock: immediate completion (with no cancel);
polling past "still running" until done; the minimum inter-poll spacing
(waiting only the shortfall when a poll returns early, and not waiting when a
poll already blocked at least the interval); per-poll clamp to the remaining
deadline; the actionable deadline error and that the job is cancelled on
give-up; bounded transient retry then rethrow; that a still-running poll does
not reset the transient-retry budget; and prompt exit on abort (mid-poll,
already-aborted, and around the inter-poll wait).
bigquery_connection.unit.spec.tsdrivesrunSQLagainst a stubbed job tolock the seam: a positive
timeoutMsis passed to the job asjobTimeoutMs;'0', a whitespace-only value, and a negative value all fall back to thedefault
jobTimeoutMs; and ajobComplete: falseresponse is polled ratherthan surfaced as empty data.
tsc,eslint, and the tests all pass.Notes
resolve to the 10-minute default; only a positive value overrides it. What
changes functionally is that the resolved timeout now actually bounds the
results wait (previously it only bounded
jobTimeoutMs, and the results fetchwas capped near six minutes by a fixed retry loop).
timeoutMsstill defaults to 10 minutes; running longer queries requiresraising it on the connection. When the connector runs behind an HTTP layer
(e.g. the Malloy Publisher), keep the connection
timeoutMsbelow that layer'ssocket/request timeout so a long query ends with the connector's clear error
rather than an opaque socket reset (documented at
TIMEOUT_MS).Checklist
malloydata.github.io/src/documentation/setup/config.malloynb(companion PR docs(config): clarify BigQuery timeoutMs semantics malloydata.github.io#336):
timeoutMsnow boundsthe results wait as well as the job, with the 10-minute default documented.