cockroachdb / cockroachdb/cockroach

gc: potential logical bug in MVCC GC

Open
#166,091 2 comments 0 reactions 0 assignees View on GitHub
A-kv A-kv-transactions branch-master C-bug P-3 T-kv
Dominant language
Go
Stars
32.5k
Forks
4.1k
PR merge metrics
PR metrics pending

Description

**Describe the problem**

This issue was discovered in a KVNemesis test with MVCC GC operations enabled. The core issue is an assertion failure during an MVCC GC run:

```
I260316 23:35:58.386265 25881 15@kv/kvserver/mvcc_gc_queue.go:605 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5824 attempt to delete range tombstone ‹"/Table/100/\"{52e982f2b9e020c3\"-7bece2728321e648\"}/1773704141.867478046,2"› hiding key at ‹/Table/100/"65608df5366d033b"/1773704135.146885382,15›
```

**To Reproduce**

After #165450 is merged, run the following test with many iterations (~100). This particular failure was caught in 3/100 runs.

```
func TestKVNemesisMVCCGCRepro(t *testing.T) {
defer leaktest.AfterTest(t)()
defer log.Scope(t).Close(t)
cfg := defaultTestConfiguration(5)
cfg.numSteps = 2000
cfg.seedOverride = 0
cfg.gcTTlSeconds = 5
cfg.testGeneratorConfig = func(cfg *GeneratorConfig) {
cfg.Ops.MvccGC.MvccGC = 5
}
cfg.testSettings = func(ctx context.Context, settings *cluster.Settings) {
gc.ClearRangeMinKeys.Override(ctx, &settings.SV, 1)
}
testKVNemesisImpl(t, cfg)
}
```

**Expected behavior**
This is a violation of the assertion in [pkg/storage/mvcc.go:7015-7020](https://github.com/cockroachdb/cockroach/blob/30a2971583c05285c5281df9da73c10190b4f0d9/pkg/storage/mvcc.go#L7015-L7020). The impact of the bug is low, as it only fails to perform GC and shouldn't produce any correctness issues.

**Additional data**

The relevant portion of the log is here:

```
I260316 23:35:58.362850 25881 15@kv/kvserver/mvcc_gc_queue.go:691 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5819 GC processing; score ‹queue=false with 0.03/fuzz(1.00)=0.03=valScaleScore(0.04)*deadFrac(0.94)+intentScore(0.00)›
I260316 23:35:58.362850 25881 15@kv/kvserver/mvcc_gc_queue.go:691 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5819 +‹likely last GC: never, 4.0 KiB non-live, curr. age 714 B*s, min exp. reduction: 0 B*s›; gcTimestamp=1773704153.377025712,2147483647, oldThreshold=1773689756.715150810,0, newThreshold=1773704148.377025712,2147483647
I260316 23:35:58.364876 5307 kv/kvnemesis/kvnemesis_test.go:171 ⋮ [-] 5820 inserting illegal lease index for /Table/100/‹"52e982f2b9e020c3"› (seen 2 times)
W260316 23:35:58.375585 40667 spanconfig/spanconfigstore/span_store.go:229 ⋮ [T1,Vsystem,n2,replicate,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5821 span config not found for ‹/Table/100/"52e982f2b9e020c3"›
I260316 23:35:58.381062 25881 15@kv/kvserver/mvcc_gc_queue.go:605 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5822 attempt to GC data ‹/Table/100/"64b85a3c9dd8e908"/1773704158.368946514,8› above threshold 1773704148.377025712,2147483647 with clear range
W260316 23:35:58.381115 25881 15@kv/kvserver/gc/gc.go:979 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5823 failed to GC keys with clear range: attempt to GC data ‹/Table/100/"64b85a3c9dd8e908"/1773704158.368946514,8› above threshold 1773704148.377025712,2147483647 with clear range
I260316 23:35:58.386265 25881 15@kv/kvserver/mvcc_gc_queue.go:605 ⋮ [T1,Vsystem,n2,s2,r113/4:/Table/100/‹"›{‹52e982›…-‹c0e009›…}] 5824 attempt to delete range tombstone ‹"/Table/100/\"{52e982f2b9e020c3\"-7bece2728321e648\"}/1773704141.867478046,2"› hiding key at ‹/Table/100/"65608df5366d033b"/1773704135.146885382,15›
```

First, in `gc.Run`, `processReplicatedKeyRange` is called to clear up any GC-able data, which fails because of the error `attempt to GC data ‹/Table/100/"64b85a3c9dd8e908"/1773704158.368946514,8› above threshold 1773704148.377025712,2147483647 with clear range`. I suspect the bug might be in this logic. That key shouldn’t have been selected to be GC-ed since it’s above the GC threshold.

This error is ignored, as explained by the comment in [/pkg/kv/kvserver/gc/gc.go:975](https://github.com/cockroachdb/cockroach/blob/b748e63fad1f9ea11f9c3bf239b4964dad6d62ff/pkg/kv/kvserver/gc/gc.go#L975).

> // Even though we are batching the GC process, it's
> // safe to continue because we bumped the GC
> // thresholds. We may leave some inconsistent history
> // behind, but nobody can read it.

Then GC calls `processReplicatedRangeTombstones` to GC range tombstones, which fails with the error `attempt to delete range tombstone ‹"/Table/100/\"{52e982f2b9e020c3\"-7bece2728321e648\"}/1773704141.867478046,2"› hiding key at ‹/Table/100/"65608df5366d033b"/1773704135.146885382,15›`, as the prior GC failed to delete some keys that are an invariant for this call.

**Environment:**
- CockroachDB version: 103dbfc10d54911b52a292ceeb379d99ac59b2b2
- Server OS: Linux
- Client app: KVNemesis

Jira issue: CRDB-61740

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.