cockroachdb / cockroachdb/cockroach

kvcoord: some batch options are unsafe with EndTxn

Open
#153,446 1 comment 0 reactions 0 assignees View on GitHub
branch-master C-bug P-3 T-kv
Dominant language
Go
Stars
32.5k
Forks
4.1k
PR merge metrics
PR metrics pending

Description

**Preface**

This was discovered when attempting to add batch header option mutation to KVNemsis. Like the other bugs filed as a result of that work, the impact is believed to be minimal because SQL does not produce batches that will encounter this error.

This is similar to #153397 but I think merits its own issue since it could theoretically lead to a lost write (bug again, not in production use today.)

**Description**

A transaction with pipelined writes may be erroneously committed if its batch uses MaxSpanRequestKeys or TargetBytes.

Because (1) the batch header options MaxSpanRequestKeys and TargetBytes can result in DistSender short-circuiting the execution of a batch and (2) that short-circuiting is inconsistently handled (see #153397) we can see batches where we do not issue all QueryIntent requests required to verify previously pipelined writes. This can lead to an erroneously committed transaction:

We saw such a case via KVNemesis:

```
kvnemesis.go:173: committed snapshot txn missing write at seq s62: [w]/Table/100/"659656eedc5d9337":missing->v62@s62 [w]/Table/100/"c719c775ff0fe94e":1757662751.070336000,0->v63@s63 [w]/Table/100/"1bc6317b95a6b280":1757662751.070336000,0->v64@s64 [r]/Table/100/"c719c775ff0fe94e":[1757662751.070336000,0, )->v63
```

The transaction in question is:

```go
db0.Txn(ctx, func(ctx context.Context, txn *kv.Txn) error {
txn.SetIsoLevel(isolation.Snapshot)
txn.SetUserPriority(roachpb.UserPriority(0.001000))
txn.SetBufferedWritesEnabled(false)
txn.GetForUpdateGuaranteedDurability(ctx, tk(7320133828236645175)) // @1757662751.070336000,0 (, )
txn.ScanForUpdate(ctx, tk(5422888094137907567), tk(18069584446866127956), 0) // @1757662751.070336000,0 (/Table/100/"6baebe0079237474":v22, /Table/100/"738f224f668a7636":v60, /Table/100/"85994f683924bb4a":v47, /Table/100/"a03
541e4771dca06":v57, )
txn.Put(ctx, tk(7320133828236645175), sv(62)) // @1757662751.070336000,0
txn.Get(ctx, tk(11544205669340924422)) // @1757662751.070336000,0 (v57, )
txn.PutMustAcquireExclusiveLock(ctx, tk(14346717397569759566), sv(63)) // @1757662751.070336000,0
txn.GetForShareSkipLockedGuaranteedDurability(ctx, tk(5426538601602214216)) // @1757662751.070336000,0 (, )
txn.GetForShareSkipLocked(ctx, tk(7707117419943955649)) // @1757662751.070336000,0 (, )
txn.GetForShareSkipLocked(ctx, tk(9365137183136069873)) // @1757662751.070336000,0 (, )
txn.PutMustAcquireExclusiveLock(ctx, tk(2001341491274232448), sv(64)) // @1757662751.070336000,0
txn.GetForUpdateSkipLocked(ctx, tk(7147794234375549945)) // @1757662751.070336000,0 (, )
b := &kv.Batch{}
b.ReverseScanForUpdateGuaranteedDurability(tk(7262337075901438241), tk(16232295212695831014)) // (/Table/100/"c719c775ff0fe94e":v63, )
b.Get(tk(912017241287378728)) // (, )
b.Header.TargetBytes = 1 // MutateBatchHeaderOperation
txn.CommitInBatch(ctx, b) // @1757662751.070336000,0
return nil
})
```

When we add additional logging, we can see that the final EndTxn batch had a number of QueryIntents added to it:

```
QueryIntent [/Table/100/"659656eedc5d9337"],
QueryIntent [/Table/100/"c719c775ff0fe94e"],
ReverseScan(Exclusive,Replicated) [/Table/100/"64c90117d0411921",/Table/100/"e144b27e5a0241e6"),
Get [/Table/100/"0ca822d94ff74728"],
QueryIntent [/Table/100/"1bc6317b95a6b280"],
EndTxn(commit) [/Table/100/"659656eedc5d9337"], [txn: cac37bc7], [max_span_request_keys: 0], [target_bytes: 1]
```

But, then, the top-level splitting (`splitBatchAndCheckForRefreshSpans`) in DidstSender, split this into two batches:

```
QueryIntent [/Table/100/"659656eedc5d9337"],
QueryIntent [/Table/100/"c719c775ff0fe94e"],
ReverseScan(Exclusive,Replicated) [/Table/100/"64c90117d0411921",/Table/100/"e144b27e5a0241e6"),
[txn: cac37bc7], [max_span_request_keys: 0], [target_bytes: 1]
```
and

```
Get [/Table/100/"0ca822d94ff74728"],
QueryIntent [/Table/100/"1bc6317b95a6b280"],
EndTxn(commit) [/Table/100/"659656eedc5d9337"],
[txn: cac37bc7], [max_span_request_keys: 0], [target_bytes: 1]
```

Note that because of #153397, the consumption of target_bytes by the first of these splits is ignored by the second. The first chunk is then further split by range (`divideAndSendBatchToRanges`) and send it multiple batches, starting with:

```
QueryIntent [/Table/100/"c719c775ff0fe94e"],
ReverseScan(Exclusive,Replicated) [/Table/100/"72db1307ad0e1f9e",/Table/100/"e144b27e5a0241e6"),
[txn: cac37bc7], [max_span_request_keys: 0], [target_bytes: 1]
```

The reverse scan return 1 row, consuming the target_bytes quota, and thus we never issue `QueryIntent [/Table/100/"659656eedc5d9337"]` which would have been issued subsequently if the quota had not been consumed.

Then the second top-level split is processed, regardless of the TargetBytes consumption, so we fully process the second batch:

```
Get [/Table/100/"0ca822d94ff74728"],
QueryIntent [/Table/100/"1bc6317b95a6b280"],
EndTxn(commit) [/Table/100/"659656eedc5d9337"],
[txn: cac37bc7], [max_span_request_keys: 0], [target_bytes: 1]
```

Further node that the presence of a Get and ReverseScan in the final batch means we aren't eligible for parallel commit.

Thus, the `EndTxn` _assumes_ that all previous writes were verified. The EndTxn creates an implicitly committed transaction (this log message calls it a parallel commit, but it was not actually a parallel commit, all InFlightWrites were removed from the EndTxn request because of the presence of the read requests):

```
7.177ms 1.621ms event:kv/kvclient/kvcoord/txn_interceptor_committer.go:221 [n1,txn=cac37bc7] parallel commit attempt for transaction "unnamed" meta={id=cac37bc7 key=/Table/100/"659656eedc5d9337" iso=Snapshot pri=0.00000000 epo=0 ts=1757662751.070336000,0 min=1757662751.070336000,0 seq=4} lock=true stat=COMMITTED rts=1757662751.070336000,0 gul=1757662751.080336000,0 obs={n1@1757662751.070336000,0 n2@1757662751.071177000,1 n3@1757662751.070543000,0} int=1 resulted in explicit commit
```

In this case, this committed transaction is incorrect because the skipped query intent had failed to replicate (because of a KVNemesis-injected failure).

Aside: While investigating this bug, I also noted that the transaction pipeliner doesn't actually verify that all of the ResolveIntent requests found an intent. Rather it assume all ResolveIntent requests will be processed and return an error if the intent is missing. I was very concerned about this, but as far as I can tell, this alone can't cause an issue at the moment.

Jira issue: CRDB-54424

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.