cockroachdb / cockroachdb/cockroach
upgrade/upgrades: TestAlterInsightsTablesSchemaMigration failed
- Dominant language
- Go
- Stars
- 32.5k
- Forks
- 4.1k
- PR merge metrics
- PR metrics pending
Description
upgrade/upgrades.TestAlterInsightsTablesSchemaMigration [failed](https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_Ci_TestsAwsLinuxArm64_UnitTests/21425247?buildTab=log) with [artifacts](https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_Ci_TestsAwsLinuxArm64_UnitTests/21425247?buildTab=artifacts#/) on master @ [bf7ff3792d256ab4bfab5d07bdaa2d9f586d8b83](https://github.com/cockroachdb/cockroach/commits/bf7ff3792d256ab4bfab5d07bdaa2d9f586d8b83):
```
I260715 20:46:54.940946 8711 server/license/vcpu_audit.go:280 [T1,Vsystem,n1] 1743 vcpu audit writer stopped
W260715 20:46:54.940975 8654 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=table-stats-cache,mux_n=1,gen=2] 1744 error closing mux rangefeed client: context canceled
I260715 20:46:54.941021 8639 sql/stats/automatic_stats.go:857 [T1,Vsystem,n1] 1745 quiescing stats garbage collector
W260715 20:46:54.941049 8330 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010663949369345,rangefeed=sql-watcher-zones-rangefeed,mux_n=1,gen=2] 1746 error closing mux rangefeed client: context canceled
W260715 20:46:54.941055 8327 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010663949369345,rangefeed=sql-watcher-descriptor-rangefeed,mux_n=1,gen=2] 1747 error closing mux rangefeed client: context canceled
W260715 20:46:54.941091 8324 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010663949369345,rangefeed=sql-watcher-protected-ts-records-rangefeed,mux_n=1,gen=2] 1748 error closing mux rangefeed client: context canceled
I260715 20:46:54.941130 7887 jobs/registry.go:1651 [T1,Vsystem,n1,job=1193010663949369345] 1749 AUTO SPAN CONFIG RECONCILIATION job 1193010663949369345: stepping through state succeeded
W260715 20:46:54.941312 7777 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=system-config-cache,mux_n=1,gen=2] 1750 error closing mux rangefeed client: context canceled
W260715 20:46:54.941332 7389 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=spanconfig-subscriber,mux_n=1,gen=2] 1751 error closing mux rangefeed client: context canceled
W260715 20:46:54.941385 7326 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=sql_instances,mux_n=1,gen=2] 1752 error closing mux rangefeed client: context canceled
W260715 20:46:54.941417 7606 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=settings-watcher,mux_n=1,gen=2] 1753 error closing mux rangefeed client: context canceled
W260715 20:46:54.941435 7354 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=lease,mux_n=1,gen=2] 1754 error closing mux rangefeed client: context canceled
I260715 20:46:54.941590 6601 server/start_listen.go:114 [T1,Vsystem,n1] 1755 server shutting down: instructing cmux to stop accepting
W260715 20:46:54.944937 3028 server/server_sql.go:1875 [T1,Vsystem,n1] 1756 server shutdown without a prior graceful drain
I260715 20:46:54.945071 3028 server/server_controller.go:380 [T1,Vsystem,n1] 1757 server controller shutting down
I260715 20:46:54.945088 3028 server/server_controller.go:389 [T1,Vsystem,n1] 1758 waiting for tenant servers to report stopped
I260715 20:46:55.001347 3028 testutils/testcluster/testcluster.go:189 [-] 1759 TestCluster quiescing nodes
I260715 20:46:55.001566 5793 sql/stats/automatic_stats.go:857 [T1,Vsystem,n1] 1760 quiescing stats garbage collector
I260715 20:46:55.001594 19097 jobs/registry.go:1651 [T1,Vsystem,n1,job=100] 1761 KEY VISUALIZER job 100: stepping through state succeeded
W260715 20:46:55.001774 5248 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010661510578177,rangefeed=sql-watcher-protected-ts-records-rangefeed,mux_n=1,gen=2] 1762 error closing mux rangefeed client: context canceled
W260715 20:46:55.001897 5321 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010661510578177,rangefeed=sql-watcher-zones-rangefeed,mux_n=1,gen=2] 1763 error closing mux rangefeed client: context canceled
I260715 20:46:55.001939 813 server/start_listen.go:114 [T1,Vsystem,n1] 1764 server shutting down: instructing cmux to stop accepting
W260715 20:46:55.001969 5387 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=AUTO SPAN CONFIG RECONCILIATION id=1193010661510578177,rangefeed=sql-watcher-descriptor-rangefeed,mux_n=1,gen=2] 1765 error closing mux rangefeed client: context canceled
I260715 20:46:55.001960 18913 jobs/registry.go:1651 [T1,Vsystem,n1,job=103] 1766 AUTO UPDATE SQL ACTIVITY job 103: stepping through state succeeded
I260715 20:46:55.002007 4958 jobs/registry.go:1651 [T1,Vsystem,n1,job=1193010661510578177] 1767 AUTO SPAN CONFIG RECONCILIATION job 1193010661510578177: stepping through state succeeded
W260715 20:46:55.002492 19358 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,job=POLL JOBS STATS id=101,rangefeed=cluster-metrics-watcher,mux_n=1,gen=2] 1768 error closing mux rangefeed client: context canceled
W260715 20:46:55.002752 19221 jobs/adopt.go:563 [T1,Vsystem,n1] 1769 could not clear job claim: clear-job-claim: node unavailable; try another peer
W260715 20:46:55.002755 19255 jobs/adopt.go:563 [T1,Vsystem,n1] 1770 could not clear job claim: clear-job-claim: node unavailable; try another peer
W260715 20:46:55.002819 4906 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=settings-watcher,mux_n=1,gen=2] 1771 error closing mux rangefeed client: context canceled
W260715 20:46:55.002824 4921 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=spanconfig-subscriber,mux_n=1,gen=2] 1772 error closing mux rangefeed client: context canceled
W260715 20:46:55.002888 6068 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=statement-hints-watcher,mux_n=1,gen=2] 1773 error closing mux rangefeed client: context canceled
W260715 20:46:55.002949 5960 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=tenant-entry-watcher,mux_n=1,gen=2] 1774 error closing mux rangefeed client: context canceled
W260715 20:46:55.003004 5804 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=tenant-boundaries-watcher,mux_n=1,gen=2] 1775 error closing mux rangefeed client: context canceled
W260715 20:46:55.003010 5653 1@server/license/vcpu_audit.go:181 [-] 1776 failed to write vcpu audit record: node=1 period=2026-07-15T20:00:00Z: write-vcpu-audit-record: node unavailable; try another peer
I260715 20:46:55.003045 5653 server/license/vcpu_audit.go:280 [T1,Vsystem,n1] 1777 vcpu audit writer stopped
W260715 20:46:55.003188 4416 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=sql_instances,mux_n=1,gen=2] 1778 error closing mux rangefeed client: context canceled
W260715 20:46:55.003219 19194 jobs/adopt.go:563 [T1,Vsystem,n1] 1779 could not clear job claim: clear-job-claim: node unavailable; try another peer
W260715 20:46:55.003295 5776 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=table-stats-cache,mux_n=1,gen=2] 1780 error closing mux rangefeed client: context canceled
W260715 20:46:55.003295 4438 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=lease,mux_n=1,gen=2] 1781 error closing mux rangefeed client: context canceled
W260715 20:46:55.003369 5963 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=tenant-settings-watcher,mux_n=1,gen=2] 1782 error closing mux rangefeed client: context canceled
I260715 20:46:55.003395 5791 sql/stats/automatic_stats.go:766 [T1,Vsystem,n1] 1784 quiescing auto stats refresher
I260715 20:46:55.003408 5792 sql/stats/automatic_stats.go:804 [T1,Vsystem,n1] 1785 quiescing auto stats misestimates refresher
W260715 20:46:55.003432 4344 sql/sqlliveness/slinstance/slinstance.go:337 [T1,Vsystem,n1] 1786 exiting heartbeat loop
W260715 20:46:55.003465 4344 sql/sqlliveness/slinstance/slinstance.go:324 [T1,Vsystem,n1] 1787 exiting heartbeat loop with error: node unavailable; try another peer
E260715 20:46:55.003483 4344 server/server_sql.go:544 [T1,Vsystem,n1] 1788 failed to run update of instance with new session ID: node unavailable; try another peer
W260715 20:46:55.003371 5092 15@kv/kvclient/kvcoord/dist_sender_mux_rangefeed.go:417 [T1,Vsystem,n1,rangefeed=system-config-cache,mux_n=1,gen=2] 1783 error closing mux rangefeed client: context canceled
W260715 20:46:55.145151 3028 server/server_sql.go:1875 [T1,Vsystem,n1] 1789 server shutdown without a prior graceful drain
I260715 20:46:55.145296 3028 server/server_controller.go:380 [T1,Vsystem,n1] 1790 server controller shutting down
I260715 20:46:55.145317 3028 server/server_controller.go:389 [T1,Vsystem,n1] 1791 waiting for tenant servers to report stopped
--- FAIL: TestAlterInsightsTablesSchemaMigration (54.79s)
```
Help
See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)
/cc @cockroachlabs/release-eng @cockroachlabs/release-eng
[This test on roachdash](https://roachdash.crdb.dev/?filter=status:open%20t:.*TestAlterInsightsTablesSchemaMigration.*&sort=title+created&display=lastcommented+project) | [Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/bazci/githubpost/issues)
Jira issue: CRDB-65837
Contributor guide
Research direction
Start with the linked TeamCity failure log and artifacts for upgrade/upgrades.TestAlterInsightsTablesSchemaMigration, then locate that test and investigate the schema migration it exercises. The report shows shutdown-related log lines but not the original failure cause, so identify the relevant failing assertion or error first. Done when the failure is understood and the test passes reliably.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- databases
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Mostly clear
- Newbie friendliness
- 46/100