ccl/changefeedccl: TestChangefeedTopicNames failed

[cockroach-teamcity]

ccl/changefeedccl.TestChangefeedTopicNames failed on release-25.4 @ 4188e69004009122ca2c687319561e9d835027a1:

=== RUN   TestChangefeedTopicNames
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestChangefeedTopicNames3714219866
    test_log_scope.go:82: use -show-logs to present logs inline
    changefeed_test.go:11303: -- test log scope end --
test logs left over in: outputs.zip/logTestChangefeedTopicNames3714219866
--- FAIL: TestChangefeedTopicNames (58.67s)
=== RUN   TestChangefeedTopicNames/pubsub
    helpers_test.go:1391: making server as secondary tenant
    helpers_test.go:1470: making pubsub feed factory
    helpers_test.go:1198: did not force enriched envelope for CREATE CHANGEFEED FOR "😆table_1", "table_2", "ta""ble_3", "table_4", "ta 	ble_5", "table͝_6", "table_7", "tab?l%ve_8", "table_9", "table_10", "table_11", "ta\nble_12", "tab͘le""_13", "table_14", "table%3a _15", "table_16", "tab%qle_17", "tabl%19e_18", "table_19", "table_20", "table_21", "table_22", "ta̾ble_23", "table_24", "table(_25", "ta*b'lE _26", "table_27", "ta%vble_28", "table_29", "ta%vble_30", "t͔able_31", "t%vable_32", "table_33", "table_34", "table'_35", "table&_36", "table_37", "t/able""_38", "t%vable_39", "tAb\nle_40", "table_41", "tabl e_42", "t%vable_43", "table_44", "table_45", "table_46", "%ptable_47", "table_48", "😒Ta-ble̙_49", "table_50", "table_51", "ta͡ble\\U0004F4A5_52", "table_53", "😱t	able_54", "table_55", "tablE_56", "table_57", "t͈a😱ble_58", "t able_59", "table_60", "tabl😧e_61", "t'able_62", "ta\\u173Abl{e_63", "table_64", "table_65", "tabl😎e_66", "table_67", "tab""le_68", "tabl̢e_69", "tabl😖e_70", "table_71", "T""able_72", "tablE_73", "table_74", "tab le_75", "tͦa🙂ble_76", ")table_77", "table_78", "%vta ble_79", "tabl̈́e_80", "table_81", "table_82", "table_83", "table_84", "tablE_85", "&tAble_86", "table_87", "t😨ablE_88", "table_89", "table_90", "table_91", "table_92", "ta😧ble_93", "table_94", "t abl e_95", "table_96", "table̛_97", "tab""l.e_98", "table_99", "table_100" because *changefeedccl.pubsubFeedFactory is not supported
    changefeed_test.go:11299: 
        	Error Trace:	pkg/ccl/changefeedccl/helpers_test.go:279
        	            				pkg/ccl/changefeedccl/helpers_test.go:498
        	            				pkg/ccl/changefeedccl/changefeed_test.go:11299
        	            				pkg/ccl/changefeedccl/helpers_test.go:1656
        	            				pkg/ccl/changefeedccl/helpers_test.go:1692
        	Error:      	Received unexpected error:
        	            	operation "withTimeout-1110476216059396097" timed out after 30s (given timeout 30s): stopping job due to TestFeed timeout
        	            	(1) operation "withTimeout-1110476216059396097" timed out after 30s (given timeout 30s)
        	            	Wraps: (2) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func3
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3046
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func1
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3035
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1700
        	            	Wraps: (3) stopping job due to TestFeed timeout
        	            	Error types: (1) *timeutil.TimeoutError (2) *withstack.withStack (3) *errutil.leafError
        	Test:       	TestChangefeedTopicNames/pubsub
--- FAIL: TestChangefeedTopicNames/pubsub (58.67s)

Parameters:

• attempt=1
• deadlock=true
• run=2
• shard=4

Help

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

/cc @cockroachdb/cdc

This test on roachdash | Improve this report!

Jira issue: CRDB-54858

[cockroach-teamcity]

ccl/changefeedccl.TestChangefeedTopicNames failed on release-25.4 @ a2df483559bb89c83e70d94d235db5fb6809e582:

=== RUN   TestChangefeedTopicNames
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestChangefeedTopicNames3515978583
    test_log_scope.go:82: use -show-logs to present logs inline
    changefeed_test.go:11303: -- test log scope end --
test logs left over in: outputs.zip/logTestChangefeedTopicNames3515978583
--- FAIL: TestChangefeedTopicNames (48.90s)
=== RUN   TestChangefeedTopicNames/pubsub
    helpers_test.go:1394: making server as system tenant
    helpers_test.go:1470: making pubsub feed factory
    changefeed_test.go:11299: 
        	Error Trace:	pkg/ccl/changefeedccl/helpers_test.go:279
        	            				pkg/ccl/changefeedccl/helpers_test.go:498
        	            				pkg/ccl/changefeedccl/changefeed_test.go:11299
        	            				pkg/ccl/changefeedccl/helpers_test.go:1656
        	            				pkg/ccl/changefeedccl/helpers_test.go:1692
        	Error:      	Received unexpected error:
        	            	operation "withTimeout-1110758031930654721" timed out after 30s (given timeout 30s): stopping job due to TestFeed timeout
        	            	(1) operation "withTimeout-1110758031930654721" timed out after 30s (given timeout 30s)
        	            	Wraps: (2) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func3
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3046
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func1
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3035
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1700
        	            	Wraps: (3) stopping job due to TestFeed timeout
        	            	Error types: (1) *timeutil.TimeoutError (2) *withstack.withStack (3) *errutil.leafError
        	Test:       	TestChangefeedTopicNames/pubsub
--- FAIL: TestChangefeedTopicNames/pubsub (48.90s)

Parameters:

• attempt=1
• deadlock=true
• run=2
• shard=4

Help

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

Same failure on other branches

• ccl/changefeedccl: TestChangefeedTopicNames failed #154307 ccl/changefeedccl: TestChangefeedTopicNames failed [A-cdc C-test-failure O-robot T-cdc branch-master release-blocker]

This test on roachdash | Improve this report!

[cockroach-teamcity]

ccl/changefeedccl.TestChangefeedTopicNames failed on release-25.4 @ 5d6369861bd83d0693349ae940a39dd421506ab3:

=== RUN   TestChangefeedTopicNames
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestChangefeedTopicNames3058415009
    test_log_scope.go:82: use -show-logs to present logs inline
    changefeed_test.go:11303: -- test log scope end --
test logs left over in: outputs.zip/logTestChangefeedTopicNames3058415009
--- FAIL: TestChangefeedTopicNames (59.11s)
=== RUN   TestChangefeedTopicNames/pubsub
    helpers_test.go:1391: making server as secondary tenant
    helpers_test.go:1470: making pubsub feed factory
    helpers_test.go:1198: did not force enriched envelope for CREATE CHANGEFEED FOR "table_1", "table_2", "ta😶ble_3", "table_4", "tAble_5", "table_6", "ta̩ble_7", "😋table�_8", "😾table_9", " ta{ble_10", "tab%vle_11", "table_12", "table_13", "table😞_14", "tA😒ble_15", "😔table_16", "table_17", "table_18", "table_19", "ta\fB😴le_20", "table_21", "taBle͎_22", "tab'le _23", "table_24", "ta ble_25", "table_26", "tAble_27", "tAble_28", "table_29", "table_30", "table_31", "table_32", "tàble_33", "table'_34", "%ptable_35", "table_36", "table_37", "table_38", "table_39", "table_40", "table_41", "table_42", "ta bl{e _43", "tabl͗e_44", "table�_45", "table_46", "tab'le_47", "table_48", "table_49", "table_50", "table_51", "ta.ble_52", "table%v_53", "tabLe_54", "table_55", "table_56", "tab le_57", "tab/le _58", " table_59", "ta%16ble_60", "table _61", "table_62", "table_63", "t\\u2991abͅle_64", "tab'le_65", "table_66", "t'a😔bl e_67", "table_68", "table_69", "tab%vle_70", "table_71", "tab\\x6fle\\x76_72", "t.able_73", "table_74", "tab̿le_75", "t a%qble_76", "table\v_77", "table_78", "tabl\\U00069E18e_79", "ta%vble_80", "t%q😅able_81", "tabl%pe%p_82", "table_83", "table_84", "table͖_85", "tab le_86", "table_87", "ta ble_88", "table_89", "table_90", "table?_91", "table_92", "table_93", "tab le_94", "table_95", "tab\\U000DDF50le_96", "t able_97", "tab😝le_98", "table_99", "table_100" because *changefeedccl.pubsubFeedFactory is not supported
    changefeed_test.go:11299: 
        	Error Trace:	pkg/ccl/changefeedccl/helpers_test.go:279
        	            				pkg/ccl/changefeedccl/helpers_test.go:498
        	            				pkg/ccl/changefeedccl/changefeed_test.go:11299
        	            				pkg/ccl/changefeedccl/helpers_test.go:1656
        	            				pkg/ccl/changefeedccl/helpers_test.go:1692
        	Error:      	Received unexpected error:
        	            	operation "withTimeout-1111325728897990657" timed out after 30s (given timeout 30s): stopping job due to TestFeed timeout
        	            	(1) operation "withTimeout-1111325728897990657" timed out after 30s (given timeout 30s)
        	            	Wraps: (2) attached stack trace
        	            	  -- stack trace:
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func3
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3046
        	            	  | github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.stopFeedWhenDone.func1
        	            	  | 	pkg/ccl/changefeedccl/testfeed_test.go:3035
        	            	  | runtime.goexit
        	            	  | 	src/runtime/asm_amd64.s:1700
        	            	Wraps: (3) stopping job due to TestFeed timeout
        	            	Error types: (1) *timeutil.TimeoutError (2) *withstack.withStack (3) *errutil.leafError
        	Test:       	TestChangefeedTopicNames/pubsub
--- FAIL: TestChangefeedTopicNames/pubsub (59.10s)

Parameters:

• attempt=1
• deadlock=true
• run=1
• shard=4

Help

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

Same failure on other branches

• ccl/changefeedccl: TestChangefeedTopicNames failed #154307 ccl/changefeedccl: TestChangefeedTopicNames failed [A-cdc C-test-failure O-robot P-1 T-cdc branch-master release-blocker]

This test on roachdash | Improve this report!

[andyyang890]

git bisect points to adfa889, still investigating root cause

[andyyang890]

This test is timing out because of per-table PTS performance issues. The test creates a changefeed that watches 100 tables and when the change frontier receives the flushed frontier from the change aggregator, it processes each table's resolved span one at a time and decides to manage PTS after each span, which took 5s each when I was running this on my gceworker under deadlock. The test times then understandably times out (100*5s=500s).

The commit linked above exposed this issue because it increases the frequency of the change aggregator flushing progress to the change frontier and so a flush could happen before all the expected messages have been emitted.

Not a release blocker because per-table PTS has been disabled by default (and will be forcibly disabled once #154478 merges). Improving the performance of PTS is tracked in: #147788.

Edit: This failure actually exposes a separate bug in the resolved span frontier, which when fixed should also deflake this test: #154587