ccl/changefeedccl: TestAvroSchemaNaming failed

[cockroach-teamcity]

ccl/changefeedccl.TestAvroSchemaNaming failed on master @ 7a924823002246b4fb02b54c3e71639d7a7a1e7c:

Fatal error:

panic: close of closed channel [recovered, repanicked]

Stack:

goroutine 253623 [running]:
testing.tRunner.func1.2({0x6c88dc0, 0x88dc530})
	GOROOT/src/testing/testing.go:1872 +0x237
testing.tRunner.func1()
	GOROOT/src/testing/testing.go:1875 +0x35b
panic({0x6c88dc0?, 0x88dc530?})
	GOROOT/src/runtime/panic.go:783 +0x132
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.(*jobFeed).Close(0xc01a861740)
	pkg/ccl/changefeedccl/testfeed_test.go:649 +0x239
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.(*kafkaFeed).Close(0xc01980c0c0)
	pkg/ccl/changefeedccl/testfeed_test.go:2188 +0x6b
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.closeFeed({0x89fcd00, 0xc0043fec40}, {0x892eaa0?, 0xc01980c0c0?})
	pkg/ccl/changefeedccl/helpers_test.go:1428 +0x2f
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.TestAvroSchemaNaming.func1(_, {0xc018ea8750, {0x7fa9060abcd8, 0xc019f3ce00}, {{0xd6f1c00, 0xd6f1c20, {0x1}}, {0xd6f1c00}, 0x0}, {{0x88f30a0, ...}, ...}}, ...)
	pkg/ccl/changefeedccl/encoder_test.go:740 +0xbbe
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.cdcTestNamed.func1(_, {{0xc018ea8750, {0x7fa9060abcd8, 0xc019f3ce00}, {{0xd6f1c00, 0xd6f1c20, {...}}, {0xd6f1c00}, 0x0}, {{0x88f30a0, ...}, ...}}, ...}, ...)
	pkg/ccl/changefeedccl/helpers_test.go:1794 +0x56
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.cdcTestNamedWithSystem.func1(0xc0043fec40)
	pkg/ccl/changefeedccl/helpers_test.go:1830 +0x293
testing.tRunner(0xc0043fec40, 0xc018f06ba0)
	GOROOT/src/testing/testing.go:1934 +0xea
created by testing.(*T).Run in goroutine 253618
	GOROOT/src/testing/testing.go:1997 +0x465

Log preceding fatal error

=== RUN   TestAvroSchemaNaming
    test_log_scope.go:172: test logs captured to: outputs.zip/logTestAvroSchemaNaming4221780520
    test_log_scope.go:82: use -show-logs to present logs inline
--- FAIL: TestAvroSchemaNaming (5.41s)

Parameters:

• attempt=1
• run=9
• shard=6

Help

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

/cc @cockroachdb/cdc

This test on roachdash | Improve this report!

Jira issue: CRDB-61240

[KeithCh]

/investigate

[github-actions]

Investigation: TestAvroSchemaNaming

Investigated failure: Issue body
Failure SHA: 7a924823002246b4fb02b54c3e71639d7a7a1e7c
Confidence: high

What This Test Does

TestAvroSchemaNaming verifies that Avro schema naming works correctly with various changefeed options (full table names, schema prefixes, split column families). It creates multiple Kafka changefeeds in sequence, each with different naming options, and asserts that the produced messages have the expected Avro schema subjects registered.

Where the Failure Occurs

The test panics with close of closed channel at testfeed_test.go:649, inside jobFeed.Close(). The panic occurs when Close() attempts to close the f.shutdown channel, but it has already been closed by a concurrent jobFailed() call.

Analysis

Hypothesis: TOCTOU race between jobFeed.Close() and stopFeedWhenDone / jobFailed() — Confidence: high

There is a race condition in jobFeed.Close() at testfeed_test.go:622-660. The sequence is:

1. assertPayloads → withTimeout → stopFeedWhenDone: When assertPayloads is called for a feed, it wraps the operation in withTimeout (helpers_test.go:480-494). If the timeout fires, stopFeedWhenDone calls jobFailed() (testfeed_test.go:3044-3047), which closes f.shutdown under the mutex.

2. defer closeFeed(...) → kafkaFeed.Close() → jobFeed.Close(): When the test function returns (either normally or due to a prior t.Fatal from the timeout), the deferred closeFeed calls run in reverse order. jobFeed.Close() first does a non-mutex-protected select check on f.shutdown (line 624). If the channel is not yet closed at this instant, it enters the default branch.

3. The race: Between the select check at line 624 and the close(f.shutdown) at lines 642 or 649, jobFailed() from another goroutine (the stopFeedWhenDone goroutine) can close f.shutdown first. When Close() then tries to close(f.shutdown), it panics with "close of closed channel".

The select check at line 624 is not synchronized with the mutex, so the check-then-act pattern is inherently racy. While jobFailed() correctly guards its close() with a mutex and a terminalErr check, Close() only acquires the mutex after checking the channel status and querying the job state, creating a window for the race.

Why this test is susceptible: The test creates 5 separate changefeeds sequentially (lines 648-738 of encoder_test.go), each with defer closeFeed(...). If any assertPayloads call times out (as noted in issue #150537 — the test has known transient errors), the timeout fires jobFailed(), and then the deferred closeFeed calls run, hitting the race.

Suggested fix: In jobFeed.Close(), after acquiring the mutex at lines 639/646, check f.mu.terminalErr != nil before calling close(f.shutdown). This mirrors the guard already present in jobFailed() (lines 468-470). Alternatively, replace the initial select check with a mutex-protected check of f.mu.terminalErr.

Related Issues and PRs

• #165814 — Same test, same close of closed channel panic, on release-26.1 branch. Same root cause.
• #150537 — Known transient errors in TestAvroSchemaNaming (referenced in a TODO comment at encoder_test.go:742). These transient errors may trigger the timeout path that leads to the race.
• #147071 (closed) — Previous TestAvroSchemaNaming failure, but with a different failure mode: withTimeout timeouts (30s) rather than the close of closed channel panic. A comment noted it was "most likely a flake" and linked to #146179 as a possible shared cause (test infra issue where messages were emitted but not read by the test feed reader).

Timeline

• The jobFeed.Close() method was written in 2021 (4f5313e5) with the initial select-based shutdown check.
• The "succeeded"/"failed" state handling with close(f.shutdown) was added in 2022 (d0fd09c3, b91b7294) — this is when the race was introduced, since these paths close the channel without first checking if it was already closed by jobFailed().
• The stopFeedWhenDone mechanism (which calls jobFailed() on timeout) predates the 2022 changes. The combination of both closing f.shutdown creates the race window.

Detailed evidence and investigation notes

Log Excerpts

From the issue body:

panic: close of closed channel [recovered, repanicked]

goroutine 253623 [running]:
testing.tRunner.func1.2({0x6c88dc0, 0x88dc530})
	GOROOT/src/testing/testing.go:1872 +0x237
testing.tRunner.func1()
	GOROOT/src/testing/testing.go:1875 +0x35b
panic({0x6c88dc0?, 0x88dc530?})
	GOROOT/src/runtime/panic.go:783 +0x132
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.(*jobFeed).Close(0xc01a861740)
	pkg/ccl/changefeedccl/testfeed_test.go:649 +0x239
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.(*kafkaFeed).Close(0xc01980c0c0)
	pkg/ccl/changefeedccl/testfeed_test.go:2188 +0x6b
github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.closeFeed(...)
	pkg/ccl/changefeedccl/helpers_test.go:1428 +0x2f

The panic is at line 649: close(f.shutdown) inside the status == "failed" branch of Close().

Code References

The race in jobFeed.Close() (testfeed_test.go:622-660):

func (f *jobFeed) Close() error {
	select {
	case <-f.shutdown:
	// Already failed/or failing.      ← (1) non-atomic check
	default:
		// ...
		if status == string(jobs.StateFailed) {
			f.mu.Lock()
			defer f.mu.Unlock()
			f.mu.terminalErr = errors.New("changefeed failed")
			close(f.shutdown)           // ← (3) PANIC if jobFailed() closed it between (1) and here
			return nil
		}
	}
	return nil
}

The safe version in jobFailed() (testfeed_test.go:460-474):

func (f *jobFeed) jobFailed(err error) {
	f.mu.Lock()
	defer f.mu.Unlock()
	if f.mu.terminalErr != nil {      // ← properly checks before closing
		return
	}
	f.mu.terminalErr = err
	close(f.shutdown)                  // ← (2) concurrent close from timeout
}

Things Ruled Out

• Specific test logic bug: The panic is in test infrastructure (jobFeed.Close()), not in the changefeed logic itself.
• Recent regression: The race condition has existed since 2022. It's a latent bug that manifests intermittently when timing aligns.
• Single-goroutine issue: This requires concurrent execution — the stopFeedWhenDone goroutine must call jobFailed() in a narrow window during Close(). This explains why it's intermittent.

Other Failure Occurrences

• Issue ccl/changefeedccl: TestAvroSchemaNaming failed #165169 (this issue): panic: close of closed channel at testfeed_test.go:649 on master.
• Issue ccl/changefeedccl: TestAvroSchemaNaming failed #165814: Identical panic, identical stack trace, on release-26.1. Same root cause.
• Issue ccl/changefeedccl: TestAvroSchemaNaming failed #147071 (closed): Different failure mode — 30s timeout in assertPayloads rather than a panic. This represents the other outcome of the same underlying flakiness (changefeed sometimes doesn't produce messages in time), but without the race triggering.

Tooling Feedback

• EngFlow artifact download for the specific shard (shard 6) did not contain TestAvroSchemaNaming output. The shard/run numbering in the issue URL (testReportRun=9&testReportShard=6) may not directly correspond to the artifact shard number. A mapping between EngFlow test report runs and artifact shards would be helpful.
• EngFlow web UI required authentication (returned 303), so direct URL fetching was not possible.

---

Workflow run

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