ccl/changefeedccl: TestChangefeedSchemaChangeNoBackfill failed

[github-actions]

ccl/changefeedccl.TestChangefeedSchemaChangeNoBackfill failed on master @ f349e39173b84834a31d080bdc8ee0d7253d6e1b:

goroutine 124945 [select]:
github.com/cockroachdb/pebble/vfs.(*diskHealthCheckingFile).startTicker.func1()
	external/com_github_cockroachdb_pebble/vfs/disk_health.go:259 +0xb5
created by github.com/cockroachdb/pebble/vfs.(*diskHealthCheckingFile).startTicker in goroutine 124883
	external/com_github_cockroachdb_pebble/vfs/disk_health.go:254 +0x58

goroutine 125376 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0x19b155df8c10, 0x16a1)
	GOROOT/src/runtime/sema.go:617 +0x1b3
sync.(*Cond).Wait(0x6f66140?)
	GOROOT/src/sync/cond.go:71 +0x73
github.com/cockroachdb/cockroach/pkg/kv/kvserver/rangefeed.(*schedulerShard).processEvents(0x19b14ee1fb00, {0x8088870, 0x19b164267360})
	pkg/kv/kvserver/rangefeed/scheduler.go:476 +0x95
github.com/cockroachdb/cockroach/pkg/kv/kvserver/rangefeed.(*Scheduler).Start.func1({0x8088870, 0x19b164267360})
	pkg/kv/kvserver/rangefeed/scheduler.go:249 +0x150
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx.func1({0x8088870, 0x19b164267360})
	pkg/util/stop/stopper.go:447 +0x8a
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx in goroutine 125367
	pkg/util/stop/stopper.go:445 +0x125

goroutine 125389 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0x19b155df8710, 0x1966)
	GOROOT/src/runtime/sema.go:617 +0x1b3
sync.(*Cond).Wait(0x19b16fb63908?)
	GOROOT/src/sync/cond.go:71 +0x73
github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*raftSchedulerShard).worker(0x19b163b59c00, {0x8088870, 0x19b152fa90e0}, {0x80b9380, 0x19b16fb63908}, 0x19b14bb30008)
	pkg/kv/kvserver/scheduler.go:379 +0xe6
github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*raftScheduler).Start.func2({0x8088870, 0x19b152fa90e0}, 0x19b172a48540?)
	pkg/kv/kvserver/scheduler.go:314 +0xe9
created by github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*raftScheduler).Start in goroutine 125367
	pkg/kv/kvserver/scheduler.go:329 +0x27e

goroutine 125348 [chan receive, 13 minutes]:
github.com/cockroachdb/cockroach/pkg/server.configureGRPCGateway.func2({0x8088870, 0x19b152fa90e0})
	pkg/server/grpc_gateway.go:99 +0x45
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx.func1({0x8088870, 0x19b152fa90e0})
	pkg/util/stop/stopper.go:447 +0x8a
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTaskEx in goroutine 124883
	pkg/util/stop/stopper.go:445 +0x125

goroutine 125337 [select]:
google.golang.org/grpc/internal/transport.(*controlBuffer).get(0x19b18c29e5a0, 0x1)
	external/org_golang_google_grpc/internal/transport/controlbuf.go:418 +0x10f
google.golang.org/grpc/internal/transport.(*loopyWriter).run(0x19b163462e70)
	external/org_golang_google_grpc/internal/transport/controlbuf.go:552 +0x78
google.golang.org/grpc/internal/transport.newHTTP2Client.func6()
	external/org_golang_google_grpc/internal/transport/http2_client.go:451 +0x85
created by google.golang.org/grpc/internal/transport.newHTTP2Client in goroutine 125347
	external/org_golang_google_grpc/internal/transport/http2_client.go:449 +0x21d0

Parameters:

• attempt=1
• run=1
• shard=1

Help

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/cdc

This test on roachdash | Improve this report!

Jira issue: CRDB-63718

[KeithCh]

/investigate

[github-actions]

Investigation: TestChangefeedSchemaChangeNoBackfill

Investigated failure: #169932
Failure SHA: f349e39173b84834a31d080bdc8ee0d7253d6e1b
EngFlow invocation: 0e4c6670-d456-4cbc-9f43-e4fd3de36121
Confidence: high

What This Test Does

TestChangefeedSchemaChangeNoBackfill verifies that certain schema changes (add column, rename column, alter default, drop NOT NULL, add/drop constraints, add index) do not trigger changefeed backfills. It creates a changefeed on a table, performs a DDL operation, inserts a row, and asserts the changefeed emits the expected payloads. The test runs across multiple sink types; this failure occurred on the pulsar sink.

Where the Failure Occurs

The test timed out after 15 minutes. The alter_default subtest was stuck at changefeed_test.go:2950 executing:

ALTER TABLE alter_default ALTER COLUMN b SET DEFAULT 'after'

This DDL statement hung for ~6 minutes until the test's 15-minute timeout was hit. The preceding drop_not_null subtest also exhibited the same problem, taking 446.71 seconds (7m25s) but eventually passing.

Analysis

Hypothesis: Schema change blocked by descriptor lease held by the changefeed (likely cause, high confidence)

The goroutine dump shows the schema change job (job 1173452210536546305) stuck in CheckTwoVersionInvariant — an infinite retry loop that waits for all old-version leases on the modified descriptor to expire before committing. The changefeed job (1173452210462392321) holds a lease on the old version of descriptor 115 (alter_default) and continues running (receiving resolved timestamps every 3 seconds), but does not release its lease.

The default descriptor lease duration is 5 minutes (DefaultDescriptorLeaseDuration = 5 * time.Minute), and this test does not override it. The sequence of events:

1. 18:39:04 — drop_not_null subtest's schema change job starts. It enters CheckTwoVersionInvariant waiting for changefeed's lease on the old descriptor version to expire.
2. 18:46:29 — After ~7m25s (5 min lease duration + jitter + retry overhead), the old lease expires and the drop_not_null schema change completes. The subtest passes with 446.71s duration.
3. 18:46:35 — alter_default subtest starts. A changefeed is created on alter_default table (descriptor 115, version 1). The ALTER TABLE DDL triggers a new schema change job.
4. 18:46:35 — The schema change job enters CheckTwoVersionInvariant, waiting for the changefeed's lease on descriptor 115 version 1 to expire.
5. 18:52:29 — After ~6 minutes of waiting (still within the 5-min lease + jitter window), the test's 15-minute timeout fires, killing the process before the lease can expire.

The root cause is that the test's 15-minute timeout is insufficient when the descriptor lease duration is 5 minutes and multiple subtests each trigger schema changes that must wait for lease expiry. The drop_not_null subtest consumed ~7.5 minutes, leaving only ~6 minutes for the remaining subtests — not enough for alter_default to also wait through a full lease expiry cycle.

This is a pre-existing slow-test issue that surfaces when the pulsar sink type is selected (as opposed to sinkless or table feeds which may have different execution characteristics), combined with the standard 5-minute descriptor lease duration. The other sink types (sinkless, kafka, etc.) likely complete faster or handle lease release differently.

Why doesn't the changefeed release its lease proactively? The changefeed acquires a lease on the table descriptor during its operation. The CheckTwoVersionInvariant code path (used by the new declarative schema changer) does not notify the changefeed to release its lease — it simply polls CountLeases in a retry loop. The lease only expires after the 5-minute lease duration elapses.

Related Issues and PRs

• #101142 — Prior TestChangefeedSchemaChangeNoBackfill failure (closed 2023-04-11). Different root cause: Google PubSub credentials missing. Not related.
• #169331 — sql: enforce statement_timeout on pre-commit two-version wait. This PR made CheckTwoVersionInvariant respect statement_timeout, but this test doesn't set one, so it doesn't help here.
• #169268 — catalog/lease: fix missing observer notifications on rangefeed updates. Recent lease fix, but focused on observer notifications, not lease expiry timing.

Timeline

• The drop_not_null subtest has likely always been slow with enterprise sink types (pulsar, kafka, etc.) when the lease duration is 5 minutes, but typically the total test time stays under 15 minutes.
• The combination of drop_not_null (~7m25s) + alter_default (needs ~5m+) exceeds the 15-minute test timeout, causing this failure.
• No specific recent commit appears to have caused this regression. It is likely a flaky timing issue that depends on the sink type selection and lease expiry jitter.

Detailed evidence and investigation notes

Log Excerpts

Schema change job for drop_notnull (descriptor 111) — waited ~7m25s:

I260507 18:39:04.550932  ... executing declarative schema change PostCommitNonRevertiblePhase stage 1 of 2
...
I260507 18:46:29.452356  ... executing declarative schema change PostCommitNonRevertiblePhase stage 1 of 2  [retried after ~7m25s]
I260507 18:46:29.499709  ... waiting for 1 leases to expire: desc=[{drop_notnull 111 2}]
I260507 18:46:29.513368  ... all leases have expired at ...
I260507 18:46:29.649595  ... waited for 1 [1173450733924909057] queued jobs to complete 7m25.145981362s

Schema change job for alter_default (descriptor 115) — stuck until timeout:

I260507 18:46:35.182663  ... executing declarative schema change PostCommitPhase stage 1 of 1 with 3 MutationType ops
[No further log entries — stuck in CheckTwoVersionInvariant until timeout at 18:52:29]

Goroutine dump showing the stuck schema change:

goroutine 334589 [select, "job":"NEW SCHEMA CHANGE id=1173452210536546305", "n":"1"]:
github.com/cockroachdb/cockroach/pkg/util/retry.(*Retry).Next(0x19b141717eb8)
    pkg/util/retry/retry.go:211
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs.CheckTwoVersionInvariant(...)
    pkg/sql/catalog/descs/txn.go:120
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).checkDescriptorTwoVersionInvariant(...)
    pkg/sql/conn_executor_exec.go:2437

Goroutine dump showing the test stuck on the DDL:

goroutine 334450 [IO wait, 5 minutes]:
...
github.com/lib/pq.(*conn).simpleExec(...)
    "ALTER TABLE alter_default ALTER COLUMN b SET DEFAULT 'after'"  [length 0x3c = 60 bytes]
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.TestChangefeedSchemaChangeNoBackfill.func1.10(...)
    pkg/ccl/changefeedccl/changefeed_test.go:2950

Metamorphic constants (from test.log):

initialized metamorphic constant "disable-catalog-leased-descriptors-threshold" with value 2
initialized metamorphic constant "kv.lease.expiration_leases_only.enabled" with value true

Code References

• changefeed_test.go:2944-2956 — The alter_default subtest
• txn.go:120 — CheckTwoVersionInvariant retry loop where the schema change is stuck
• lease.go:596-621 — WaitForOneVersion used by the old schema changer path
• config.go:62 — DefaultDescriptorLeaseDuration = 5 * time.Minute

Things Ruled Out

• Google PubSub credentials issue (ccl/changefeedccl: TestChangefeedSchemaChangeNoBackfill failed #101142): The prior failure was about missing PubSub credentials. This failure is a timeout, not a credentials error.
• Recent code changes: No relevant changes to the schema changer, lease manager, or changefeed test code between recent commits and the failure SHA that would explain a regression.
• Changefeed logic bug: The changefeed itself is functioning correctly (emitting resolved timestamps every 3 seconds). The issue is that it holds a descriptor lease that blocks the schema change.

Other Failure Occurrences

This is the first occurrence in the current issue thread. Historical issues with the same test name (#101142, #44475, #32433-32463) had different root causes (PubSub credentials, older infrastructure issues).

Potential Fixes

1. Override lease duration in this test — Set sql.catalog.descriptor_lease_duration to a shorter value (e.g., 10-30 seconds) for this test to prevent the 5-minute lease expiry wait.
2. Increase the test timeout — Increase from 15 minutes to accommodate multiple subtests each potentially waiting for lease expiry. However, this masks the underlying slowness.
3. Investigate whether changefeeds should proactively release descriptor leases — When a schema change is pending, the changefeed could be notified to release its old-version lease sooner.

Workflow run

---

Was this investigation helpful? Leave a 👍 or 👎 on this comment.