roachtest: gossip/chaos/nodes=9 failed [needs #138904]

[cockroach-teamcity]

roachtest.gossip/chaos/nodes=9 failed with artifacts on master @ 5cc8013ada42f9ea03eda661a4f178c141f4f24d:

(gossip.go:81).2: gossip did not stabilize (dead node 7) in 26.8s
test artifacts and logs in: /artifacts/gossip/chaos/nodes=9/run_1

Parameters:

• ROACHTEST_arch=amd64
• ROACHTEST_cloud=azure
• ROACHTEST_coverageBuild=false
• ROACHTEST_cpu=4
• ROACHTEST_encrypted=false
• ROACHTEST_runtimeAssertionsBuild=false
• ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

Grafana is not yet available for azure clusters

/cc @cockroachdb/kv-triage

This test on roachdash | Improve this report!

Jira issue: CRDB-42194

[tbg]

Well - this is interesting. A story best told in a code-output interleaving:

/pkg/cmd/roachtest/tests/gossip.go#L122-L135

		waitForGossip := func(deadNode int) {
// 2024/09/14 08:06:29 gossip.go:123: test status: waiting for gossip to exclude dead node 7
			t.Status(fmt.Sprintf("waiting for gossip to exclude dead node %d", deadNode))
			start := timeutil.Now()
			for {
// 2024/09/14 08:06:29 gossip.go:126: checking if gossip excludes dead node 7 (0s)
				t.L().Printf("checking if gossip excludes dead node %d (%.0fs)\n",
					deadNode, timeutil.Since(start).Seconds())
// 2024/09/14 08:06:29 gossip.go:88: 1: checking gossip
// 2024/09/14 08:06:29 gossip.go:92: 1: gossip not ok (dead node 7 present) (0s)
				if gossipOK(start, deadNode) {
					return
				}
				const sleepDur = 1 * time.Second
// 2024/09/14 08:06:29 gossip.go:132: sleeping for 1s (0s)
				t.L().Printf("sleeping for %s (%.0fs)\n", sleepDur, timeutil.Since(start).Seconds())
				time.Sleep(sleepDur)
			}
		}

and then the next log line we see is:

2024/09/14 08:06:56 gossip.go:126: checking if gossip excludes dead node 7 (27s)

meaning somehow it took us 27 seconds to time.Sleep(time.Second) and jump to the beginning of the for loop. The subsequent call to gossipOK then fails, since it calls t.Fatal if it's been >= 20s:

2024/09/14 08:06:56 test_impl.go:423: test failure #1: full stack retained in failure_1.log: (gossip.go:81).2: gossip did not stabilize (dead node 7) in 26.8s

I'm having trouble believing that anything could've delayed this by 26s, however, maybe a time jump is to blame instead. Either way, I'll file this away as an infra flake.

[nvanbenschoten]

I raised this question with test-eng in https://cockroachlabs.slack.com/archives/C023S0V4YEB/p1729266529436189.

[blathers-crl]

cc @cockroachdb/test-eng

[DarrylWong]

We have #136783 to track reporting of live migrations and #138904 to track the TC runner being overloaded so going to close this issue out

[tbg]

I'll reopen this because until the problem is addressed, the test may fail again, potentially causing more effort to re-determine that all we need to do here is wait.

Will assign back to T-kv.