roachtest: clearrange/checks=false failed

[cockroach-teamcity]

SHA: https://github.com/cockroachdb/cockroach/commits/e6348bb4abbfd117424c382ce5ab42e8abbe88f0

Parameters:

To repro, try:

# Don't forget to check out a clean suitable branch and experiment with the
# stress invocation until the desired results present themselves. For example,
# using stress instead of stressrace and passing the '-p' stressflag which
# controls concurrency.
./scripts/gceworker.sh start && ./scripts/gceworker.sh mosh
cd ~/go/src/github.com/cockroachdb/cockroach && \
make stressrace TESTS=clearrange/checks=false PKG=roachtest TESTTIMEOUT=5m STRESSFLAGS='-maxtime 20m -timeout 10m' 2>&1 | tee /tmp/stress.log

Failed test: https://teamcity.cockroachdb.com/viewLog.html?buildId=974325&tab=buildLog

The test failed on release-2.1:
	test.go:1002: test timed out (11h48m14.582497452s)
	test.go:606,cluster.go:1453,clearrange.go:187,clearrange.go:34: context canceled

[tbg]

A very tight loop of this:

I181019 07:47:26.066510 823 storage/store.go:3819 [n1,s1,r10772/2:/Table/53/1/3087{5835-9107}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066513 593 storage/store.go:3819 [n1,s1,r16965/2:/Table/53/1/4409{0694-3966}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066519 823 storage/store.go:3819 [n1,s1,r11443/2:/Table/53/1/3097{4825-8097}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066522 593 storage/store.go:3819 [n1,s1,r6906/1:/Table/53/1/2073{3596-6651}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066528 823 storage/store.go:3819 [n1,s1,r20502/1:/Table/53/1/554{77267-80539}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066537 593 storage/store.go:3819 [n1,s1,r9406/2:/Table/53/1/2683{6704-9976}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066541 823 storage/store.go:3819 [n1,s1,r11034/2:/Table/53/1/3092{0006-3278}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066352 535 storage/store.go:3819 [n1,s1,r4228/2:/Table/53/1/155{09246-12519}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066553 593 storage/store.go:3819 [n1,s1,r9756/2:/Table/53/1/268{89298-92570}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066555 823 storage/store.go:3819 [n1,s1,r11037/2:/Table/53/1/3092{3278-6550}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066357 528 storage/store.go:3819 [n1,s1,r10345/2:/Table/53/1/2697{5214-8486}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066573 535 storage/store.go:3819 [n1,s1,r11898/4:/Table/53/1/402{57416-60688}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066575 823 storage/store.go:3819 [n1,s1,r16391/4:/Table/53/1/44{797408-800680}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066576 528 storage/store.go:3819 [n1,s1,r10515/2:/Table/53/1/2699{5783-8226}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066587 535 storage/store.go:3819 [n1,s1,r18931/3:/Table/53/1/556{79762-83034}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066589 823 storage/store.go:3819 [n1,s1,r20034/1:/Table/53/1/554{07145-10417}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066592 528 storage/store.go:3819 [n1,s1,r18834/3:/Table/53/1/6087{2982-6254}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066599 823 storage/store.go:3819 [n1,s1,r6906/1:/Table/53/1/2073{3596-6651}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066600 535 storage/store.go:3819 [n1,s1,r18834/3:/Table/53/1/6087{2982-6254}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066605 528 storage/store.go:3819 [n1,s1,r18784/1:/Table/53/1/5956{2727-5999}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066615 535 storage/store.go:3819 [n1,s1,r8990/4:/Table/53/1/2716{3617-6889}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066621 528 storage/store.go:3800 [n1,s1,r18931/3:/Table/53/1/556{79762-83034}] added to replica GC queue (peer suggestion)
I181019 07:47:26.066626 593 storage/store.go:3819 [n1,s1,r18784/1:/Table/53/1/5956{2727-5999}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066633 528 storage/store.go:3819 [n1,s1,r8990/4:/Table/53/1/2716{3617-6889}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066640 593 storage/store.go:3819 [n1,s1,r17214/2:/Table/53/1/45793{118-270}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066654 528 storage/store.go:3819 [n1,s1,r9406/2:/Table/53/1/2683{6704-9976}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066664 593 storage/store.go:3819 [n1,s1,r10345/2:/Table/53/1/2697{5214-8486}] added to replica GC queue (contacted deleted peer)
I181019 07:47:26.066668 528 storage/store.go:3819 [n1,s1,r18928/3:/Table/53/1/608{89419-92691}] added to replica GC queue (contacted deleted peer)

individual rangeIDs repeat all the time.

At the *very* least, this log message way too spammy.

The test log never shows this message:

https://github.com/cockroachdb/cockroach/blob/70e2654f42619d6c8bd19c4164d3a3c630e8f3a1/pkg/cmd/roachtest/clearrange.go#L136

But it does show the monitor running, so we must've gotten stuck enabling the merge queue (it's enabled anyway) or setting its interval to zero.

I wonder if this could be another symptom of #31570, but I wouldn't know how. Anyway, the logs are near useless because they rotated away anything that might've given a clue as to the original cause. I'll send a PR to remove this logging.

[benesch]

Fixed by #31570.