BigQuery: silent jobRateLimitExceeded causes compile freeze on shard-heavy projects

[emilmar]

Discussed at dbt community Slack. Full HTTP/2 capture and follow-up experiment data in collapsed sections below.

Symptom

dbtf compile on a project with ~700 sharded source schemas (introspective queries against INFORMATION_SCHEMA) freezes after ~30 seconds. Nothing reaches dbt.log. The same workload finishes in 4 min 14 s under dbt-core 1.10.15 + dbt-bigquery 1.10.2 (Python).

Root cause: Go BigQuery SDK retries jobRateLimitExceeded for polling

googleapis/google-cloud-go:bigquery/bigquery.go warns explicitly against using jobRetryReasons for polling, then does it anyway in waitForQuery:

// These reasons are used exclusively for enqueuing jobs (jobs.insert and
// jobs.query). Using them for polling may cause unwanted retries until
// context deadline/cancellation/etc.
jobRetryReasons = []string{"backendError", "rateLimitExceeded", "jobRateLimitExceeded", "internalError"}

// bigquery/job.go::waitForQuery
backoff := gax.Backoff{Initial: 50 * time.Millisecond, Multiplier: 1.3, Max: 60 * time.Second}
err := internal.Retry(ctx, backoff, func() (stop bool, err error) {
    res, err = call.Do()
    if err != nil {
        return !retryableError(err, jobRetryReasons), err  // jobRateLimitExceeded => retry
    }
    ...
})

jobRateLimitExceeded was added to the list in google-cloud-go#9726 (2024-04-11); polling backoff tuned aggressive in #10555 (2024-07-17). The diagnostic captured 1,323 of these 400s in 2 minutes, all absorbed inside this loop.

A controlled probe injecting a synthetic *googleapi.Error at arrow-adbc's runQuery confirmed errors that reach that point propagate intact to stderr, dbt.log, and query_log.sql. The production silence is the SDK's retry loop, not arrow-adbc or the Rust adapter.

Ancillary: arrow-adbc HTTP/2 connection pool

dbt-labs/arrow-adbc:go/adbc/driver/bigquery/connection.go::newClient L693 (commit d2808cf, pinned in dbt-fusion's Cargo.toml) calls bigquery.NewClient twice without option.WithHTTPClient, so each call builds its own *http.Transport. 82% of connections closed at maxStream=1. A local patch sharing one HTTP client per databaseImpl:

Metric	Baseline	Patched
HTTP 400 (jobRateLimitExceeded)	5,534	3,594 (−35%)
Highest maxStream on a single connection	25	1,967 (78×)
Compile completed within 120 s	no	no

Reduces request volume measurably but does not stop the freeze; the SDK still retries forever once quota saturates. Patch diff in the second collapsed section. Not proposing a PR here.

Workaround

dbt-core 1.10 (Python) finishes the same workload in 4 min 14 s.

Source pointers

• googleapis/google-cloud-go:bigquery/bigquery.go L254-266, bigquery/job.go L355-378
• dbt-labs/arrow-adbc:go/adbc/driver/bigquery/connection.go L693 (bigquery.NewClient at L710, L728); commit d2808cf
• dbt-labs/dbt-fusion:crates/dbt-adapter/src/{engine/mod.rs L103, engine/retry.rs L122, adapter/adapter_impl.rs L586}

Environment

dbt Fusion 2.0.0-preview.176, macOS arm64, OAuth (gcloud), no proxy. ~700 sharded source schemas.

HTTP/2 capture and observations

Setup

A single dbtf compile --select tag:stg_tripletex run instrumented with GODEBUG=http2debug=2 and a lsof connection-count probe, killed manually after ~2 minutes when forward progress stopped. Control: dbt compile under dbt-core 1.10.15 + dbt-bigquery 1.10.2 (Python) against the same target.

Capture summary

Artifact	Size	Notes
combined.log	330,121 lines	GODEBUG=http2debug=2 HTTP/2 trace + Rust-side stderr
dbt.log	7.96 MB	dbt progress log; stops at 11:57:14, ~30s after start
query_log.sql	212,872 lines	Every SQL submitted to BigQuery
conn_count.log	496 samples	lsof snapshot every 200ms

The compile was killed at ~11:58:51 (~2 minutes from start). dbt.log stops writing model-progress events at 11:57:14, but the HTTP/2 layer continues making real (non-PING) BigQuery requests for another 90 seconds.

HTTP/2 frame counts

Frame type	wrote	read
GOAWAY	0	0
RST_STREAM	0	0
HEADERS	3,335	3,797
DATA	1,568	6,341
SETTINGS	1,841	1,841
PING / PING-ACK	3,905	3,905
WINDOW_UPDATE	2,255	920

PING/PING-ACK exchanges continue successfully up to the moment of the kill; the HTTP/2 transport itself is healthy throughout.

Connection pool: maxStream distribution

Go's HTTP/2 transport logs maxStream=N (the highest stream ID opened on that connection during its lifetime) when closing each connection. For a healthy multiplexing client this is in the tens or hundreds. The 490 connections closed during the capture:

maxStream	connections
1	445
15	23
31	16
27	3
51, 33, 23, 213, 11	1 each

82% of connections served exactly one request. This is HTTP/1.1-style behavior over HTTP/2: full TLS handshake, full HTTP/2 SETTINGS exchange, one request, close.

Corroborating events:

• 540 × http2: Transport failed to get client conn for ...: http2: no cached connection was available
• 540 × Transport creating client conn (exact match).
• Bursts of up to 78 new connections per second.

HTTP response status distribution

Status	Count	%
200 (OK)	1,993	60%
400 (Bad Request)	1,323	40%
499 (cancelled from kill)	19	<1%

400 response body

1,312 of the 1,323 400 responses share an identical gzipped body (content-length=277):

{
  "error": {
    "code": 400,
    "message": "Job exceeded rate limits: Your user exceeded quota for rate INFORMATION_SCHEMA queries per user. For more information, see https://cloud.google.com/bigquery/docs/troubleshoot-quotas",
    "errors": [{
      "message": "Job exceeded rate limits: ...",
      "domain": "global",
      "reason": "jobRateLimitExceeded"
    }],
    "status": "INVALID_ARGUMENT"
  }
}

Workload volume

Metric	Count
Queries submitted	250
Distinct query_id values	232
Queries containing UNION ALL (shard-fanout introspections)	121
POST .../jobs (submissions on the wire)	298
GET .../queries/{id} (poll requests)	2,121

Each UNION ALL query fans out across ~91 sharded INFORMATION_SCHEMA.TABLES references. Aggregate poll rate observed at 76/sec.

Model-rendering progress at kill

Phase	Started	Finished
Rendering	1,185	843
Analyzing	828	827

296 models started rendering and never finished.

Control: dbt-core 1.10

Same project, same BigQuery target, dbt compile under dbt-core 1.10.15 + dbt-bigquery 1.10.2 (Python, 8 threads) completed in 4 min 14 s, 891 models, no errors.

Reproduction

LOGDIR="logs/diag-$(date +%Y%m%d-%H%M%S)"
mkdir -p "$LOGDIR"

# lsof connection probe (separate terminal)
while true; do
  count=$(lsof -nP -iTCP -sTCP:ESTABLISHED -c dbt 2>/dev/null | grep -c "443->")
  echo "$(date +%s.%N) $count" >> "$LOGDIR/conn_count.log"
  sleep 0.2
done &

# Instrumented compile
GODEBUG=http2debug=2 \
RUST_LOG=debug,reqwest=trace,hyper=debug \
  dbtf compile \
    --log-level trace --log-format-file json \
    --log-path "$LOGDIR" \
    > "$LOGDIR/combined.log" 2>&1

Decoding a 400 response body: extract data="..." from a DATA frame following :status="400", decode Go %q quoting, gunzip.

Experiment B and C raw data (probe + connection-pool patch validation)

Experiment B: drop-point probe

Method

Injected a synthetic, easily-greppable error at the topmost return path of arrow-adbc's runQuery. If the literal makes it to some artifact and not to others, the first artifact where it disappears is the drop point.

Patch:

--- a/go/adbc/driver/bigquery/record_reader.go
+++ b/go/adbc/driver/bigquery/record_reader.go
@@ -36,6 +36,7 @@ import (
 	"github.com/apache/arrow-go/v18/arrow/memory"
 	"golang.org/x/sync/errgroup"
+	"google.golang.org/api/googleapi"
 	"google.golang.org/api/iterator"

 func runQuery(...) (...) {
 	job, err := query.Run(ctx)
+	if err == nil {
+		err = &googleapi.Error{
+			Code:    400,
+			Message: "DROPPOINT_PROBE message body",
+			Errors:  []googleapi.ErrorItem{{Reason: "DROPPOINT_PROBE_REASON"}},
+		}
+	}
 	if err != nil {
 		return nil, -1, err
 	}

Note: dbtf compile --select <one_model> served the entire compile out of Fusion's Frontier schema cache, so runQuery was never called. Switched to dbtf show --inline "select 1 as DROPPOINT_TEST_QUERY" to force a real SQL statement through runQuery.

Result

The probe fired and surfaced fully end-to-end. User-visible stderr from the patched build:

error: dbt1000: Unknown: [BigQuery] googleapi: Error 400: DROPPOINT_PROBE message body
More details:
Reason: DROPPOINT_PROBE_REASON, Message:  (sqlstate: [0, 0, 0, 0, 0], vendor_code: -2147483648)

query_log.sql entry:

-- outcome: error
-- error message: Error { message: "[BigQuery] googleapi: Error 400: DROPPOINT_PROBE message body\nMore details:\nReason: DROPPOINT_PROBE_REASON, Message: \n", status: Unknown, vendor_code: -2147483648, sqlstate: [0, 0, 0, 0, 0], details: Some([]) }

Both the outer Message and the inner Errors[0].Reason reached every log artifact intact (dbt.log, combined.log stderr, query_log.sql). ADBC → Rust → log path drops nothing.

Conclusion: the drop is not in arrow-adbc, not in the FFI, not in Fusion's adbc_error_to_adapter_error, and not in the adapter's log emission. It is upstream of runQuery, inside the Google Go SDK's waitForQuery retry loop.

---

Experiment C: shared *http.Client patch (before/after metrics)

Patch

--- a/go/adbc/driver/bigquery/bigquery_database.go
+++ b/go/adbc/driver/bigquery/bigquery_database.go
@@ type databaseImpl struct {
 	tableID   string
+	httpClientOnce sync.Once
+	httpClient     *http.Client
+	httpClientErr  error
 }
+
+func (d *databaseImpl) ensureHTTPClient(ctx context.Context, authOptions []option.ClientOption) (*http.Client, error) {
+	d.httpClientOnce.Do(func() {
+		client, _, err := htransport.NewClient(ctx, authOptions...)
+		if err != nil {
+			d.httpClientErr = err; return
+		}
+		d.httpClient = client
+	})
+	return d.httpClient, d.httpClientErr
+}

 func (d *databaseImpl) Open(ctx context.Context) (adbc.Connection, error) {
 	conn := &connectionImpl{
 		...,
+		databaseRef: d,
 	}
 	err := conn.newClient(ctx)

-func (d *databaseImpl) Close() error { return nil }
+func (d *databaseImpl) Close() error {
+	if d.httpClient != nil { d.httpClient.CloseIdleConnections() }
+	return nil
+}

--- a/go/adbc/driver/bigquery/connection.go
+++ b/go/adbc/driver/bigquery/connection.go
@@ type connectionImpl struct {
 	clientStorageApiDisabled *bigquery.Client
+	databaseRef *databaseImpl
 }

 func (c *connectionImpl) newClient(ctx context.Context) error {
 	authOptions, err := c.authOptions(ctx)
 	...
-	storageReadClient, err := bigquery.NewClient(ctx, c.catalog, authOptions...)
+	httpClient, err := c.databaseRef.ensureHTTPClient(ctx, authOptions)
+	if err != nil { return err }
+	bqOptions := append(authOptions, option.WithHTTPClient(httpClient))
+	storageReadClient, err := bigquery.NewClient(ctx, c.catalog, bqOptions...)
 	...
 	err = storageReadClient.EnableStorageReadClient(ctx, authOptions...) // gRPC, not bqOptions
 	...
-	client, err := bigquery.NewClient(ctx, c.catalog, authOptions...)
+	client, err := bigquery.NewClient(ctx, c.catalog, bqOptions...)

EnableStorageReadClient deliberately receives plain authOptions because the Storage Read API is gRPC, and option.WithHTTPClient has no effect on a gRPC client. Mixing HTTP and gRPC client sharing is a separate concern.

Full before/after

Both runs: same 120-second dbtf compile --select tag:stg_tripletex workload, cold target/, default dev target.

Metric	Baseline (unpatched)	Patched (shared-HTTP-client)	Change
combined.log HTTP/2 trace size	47.3 MB	34.6 MB	−27%
HTTP 200 responses	2,372	2,186	−8%
HTTP 400 (jobRateLimitExceeded)	5,534	3,594	−35%
Closed connections at maxStream=1	701	475	−32%
Connections at maxStream=15	119	0	−100%
Highest maxStream on a single conn	25	1,967	78×
Peak concurrent connections (lsof)	2	1	half
Average concurrent connections	1.8	0.8	−56%
query_log.sql success queries	243	244	~same
query_log.sql error queries	127	0	−100%
Compile completed within 120 s?	no (killed)	no (killed)	unchanged

Three independent signals confirm the patch works:

1. HTTP/2 multiplexing engages. Baseline top maxStream was 25 across 822 closed connections. Patched has one connection carrying 1,967 streams. That is the multiplexing-actually-works signature.
2. Request volume drops. 35% fewer HTTP 400s in the same window means less pressure on the per-user INFORMATION_SCHEMA quota.
3. Auxiliary 1-second cancellations vanish. 127 baseline queries hit Job execution was cancelled: Job timed out after 1 sec, stopped. Patched had 0. Both runs had the job_execution_timeout_seconds: 1800000 profile workaround in place; the difference is not the profile, it is that the patched run spent less time on transport handshakes and more time inside actual BigQuery polls.

What the patch does NOT do

The compile still froze. The patch reduces the rate at which the system enters saturated-retry but does not stop google-cloud-go:bigquery/job.go::waitForQuery from retrying jobRateLimitExceeded internally. With the patch, fewer rate-limit responses come back per second; without an upstream change to that retry policy, the loop still fires forever once quota is saturated.

[hope-wat]

This was erroneously added to the Core-Working board by the github project automation

[serramatutu]

Small correction on the underlying cause:

The BigQuery SDK hardcodes retry/backoff parameters per request (source). That means each request is unaware of each other, and even if one request is backing off, a new request will still start by hammering the API before backing off. This combined with the fact that the SDK does not propagate the rate-limit error upwards means that dbt's backpressure mechanism does not slow down, and we get a storm of more requests that are not properly backed off.

The ideal solution is optionally disabiling retries/backoff in the Google SDK, and push it up to the driver level, so that we have one global backoff. This will require a change to the Google SDK.

[mishamsk]

@serramatutu why our back-pressure doesn’t kick in though? we guard connections, and a query sitting on retries should occupy the connection. I would expect backpressure to work, except for the fact that it may not be applied for metadata queries or dbt-state - when I worked on issues about threads this was a known “gap” to be closed…

back-pressure will/may not solve all scenarios, but theoretically if it is applied across the board and threads are set to a low value it should help until we get upstream driver change allowing us to handle rate limiting

@kczimm FYI

[serramatutu]

@mishamsk 2 things

[1]: I investigated a bit more and there is another issue that the Google SDK conflates some return codes and hangs indefinitely even if the job has been canceled due to rate limit (I think this is what the user was referring to initially in the issue body). I.e the statement stays parked there retrying even if it will never succeed until timeout. This has been fixed in the upstream ADBC Foundry driver but not in our fork. adbc-drivers/bigquery#55

[2]: I think our backpressure IS getting triggered, but it is based on a fixed number of connections (48 for BigQuery), so there's could always be 48 separate statements running on separate backoffs in parallel. Yes they will eventually finish but having separate backoffs means every time a new statement gets created and we're under rate-limit it will start off by wasting a lot of the rate-limit quota, which I think slows down healing.

Fixes

@xuliangs is working on porting us to the newer driver which should include the fix to [1]. dbt-labs/bigquery-adbc#1

Meanwhile I have a PR to use a global backoff across all statements to fix [2], which I'll also port to the new driver. dbt-labs/arrow-adbc#145

I marked this as blocked while the new driver is not out.

[mishamsk]

@serramatutu yeah, this all makes sense. However, if our back pressure applies to all queries (metadata included), then a customer setting --threads to a lower value (like 4) should be able to use that as a workaround until all of the fixes you've mentioned are in.

So I would work on back pressure gaps. I found my list of them: https://github.com/dbt-labs/fs/pull/10439#issuecomment-4523954216 - it is pretty concrete!

[mishamsk]

upd. full threads handling will come with https://github.com/dbt-labs/fs/pull/12037

[hope-wat]

Linked https://github.com/dbt-labs/fs/pull/12037 in Development -- we'll monitor and close this issue once that PR is pulled through.