roachperf: regression in kv on 2023/03/10 - multiple benchmarks

[smg260]

Significant drop on or around March 10th.

Affects multiple kv0 and kv95

Jira issue: CRDB-25340

[blathers-crl]

cc @cockroachdb/test-eng

[smg260]

Bisection results using kv0/enc=false/nodes=1:

2023-03-14T14:06:32Z   Bisecting regression in [kv0/enc=false/nodes=1] using commit range [4dc9e98d8cc (known good),d4a584e49f0 (known bad)]
2023-03-14T14:06:32Z   Thresholds [good >= 10643, bad <= 6599]
2023-03-14T14:23:01Z   [6f444d4f841] median ops/s: [9397]. User marked as good. Threshold updated.
2023-03-14T14:34:05Z   [eb0ba1123bf] median ops/s: [7182]. User marked as bad. Threshold updated.
2023-03-14T14:46:44Z   [25ecce9c598] median ops/s: [9756]. Auto marked as good.
2023-03-14T15:00:14Z   [e4ceb499e9b] median ops/s: [10248]. Auto marked as good.
2023-03-14T15:15:13Z   [42be60f296a] median ops/s: [10066]. Auto marked as good.
2023-03-14T15:45:18Z   [5705e7c358f] median ops/s: [9302]. User marked as good. Threshold updated.
2023-03-14T15:58:48Z   [86a5852c253] median ops/s: [6200]. Auto marked as bad.
2023-03-14T15:58:48Z   Bisection complete. Suspect commit:
commit 86a5852c2531428a493231f26786c886327f30e3
Author: Nathan VanBenschoten <[email protected]>
Date:   Sun Mar 5 15:46:20 2023 -0500

    kv: async resolve unreplicated locks on other ranges after one-phase commit

    Fixes #94400.

    This commit fixes async lock resolution on external ranges after a transaction
    exercises the one-phase commit fast-path. Before the change, the 1PC fast-path
    was failing to handle the case where a transaction had acquired locks on ranges
    other than the range with the transaction record. As a result, these locks were
    not asynchronously but eagerly cleaned up. Conflicting transactions that
    encountered these locks would then wait 50ms before pushing the lock holder,
    finding it to be committed, and removing the locks themselves.

    It's fairly rare for a transaction to acquire locks on multiple ranges but then
    still be able to perform a 1PC commit. Regardless, we should handle such cases.

    Release note (bug fix): Fixed a bug where transactions that performed a SELECT
    FOR UPDATE across multiple ranges but never performed writes could fail to
    eagerly clean up their locks after commit. Future transactions that encountered
    these abandoned locks could be delayed for 50ms before unlocking them.

#98044

[erikgrinaker]

@nvanbenschoten ^

[nvanbenschoten]

Thanks @smg260 for determining the cause of the regression. I can see it in microbenchmarks as well:

$ benchdiff --new=86a5852c2531428a493231f26786c886327f30e3 --post-checkout='dev generate go' --run='BenchmarkKV/Insert/Native' ./pkg/sql/tests
test binaries already exist for '2d87998'; skipping build
test binaries already exist for '86a5852'; skipping build

  pkg=1/1 iter=10/10 cockroachdb/cockroach/pkg/sql/tests \

name                            old time/op    new time/op    delta
KV/Insert/Native/rows=10-30        201µs ± 2%     221µs ± 2%   +9.98%  (p=0.000 n=10+10)
KV/Insert/Native/rows=100-30       601µs ± 1%     677µs ± 1%  +12.69%  (p=0.000 n=10+10)
KV/Insert/Native/rows=1-30         150µs ± 3%     171µs ± 2%  +13.80%  (p=0.000 n=10+10)
KV/Insert/Native/rows=10000-30    38.1ms ± 3%    44.4ms ± 3%  +16.67%  (p=0.000 n=10+10)
KV/Insert/Native/rows=1000-30     3.82ms ± 3%    4.49ms ± 2%  +17.62%  (p=0.000 n=10+10)

name                            old alloc/op   new alloc/op   delta
KV/Insert/Native/rows=1-30        18.4kB ± 1%    23.7kB ± 1%  +28.88%  (p=0.000 n=9+10)
KV/Insert/Native/rows=10-30       43.8kB ± 1%    66.3kB ± 1%  +51.59%  (p=0.000 n=10+9)
KV/Insert/Native/rows=10000-30    35.0MB ± 2%    55.3MB ± 1%  +58.11%  (p=0.000 n=10+10)
KV/Insert/Native/rows=100-30       292kB ± 1%     485kB ± 1%  +66.28%  (p=0.000 n=9+9)
KV/Insert/Native/rows=1000-30     2.80MB ± 1%    4.81MB ± 1%  +71.85%  (p=0.000 n=10+10)

name                            old allocs/op  new allocs/op  delta
KV/Insert/Native/rows=1-30           144 ± 1%       194 ± 1%  +35.28%  (p=0.000 n=8+10)
KV/Insert/Native/rows=10-30          302 ± 1%       418 ± 1%  +38.37%  (p=0.000 n=10+9)
KV/Insert/Native/rows=100-30       1.66k ± 1%     2.40k ± 0%  +44.34%  (p=0.000 n=9+9)
KV/Insert/Native/rows=10000-30      148k ± 0%      215k ± 0%  +45.15%  (p=0.000 n=9+10)
KV/Insert/Native/rows=1000-30      15.0k ± 0%     21.9k ± 0%  +46.14%  (p=0.000 n=10+10)

[nvanbenschoten]

This looks to be due to a misunderstanding of how kvserverbase.IntersectSpan works. The utility does not attempt to handle point keys correctly. Instead, it considers all point keys to be outside of the descriptor's key range, even if they are contained by the descriptor's range:

cockroach/pkg/kv/kvserver/kvserverbase/base.go

Lines 189 to 196 in a79338a

	func IntersectSpan(
	span roachpb.Span, desc *roachpb.RangeDescriptor,
	) (middle *roachpb.Span, outside []roachpb.Span) {
	start, end := desc.StartKey.AsRawKey(), desc.EndKey.AsRawKey()
	if len(span.EndKey) == 0 {
	outside = append(outside, span)
	return
	}

As a result, 1PC txns were launching async intent resolution tasks for local point lock spans.

The following diff resolves the regression:

diff --git a/pkg/kv/kvserver/kvserverbase/base.go b/pkg/kv/kvserver/kvserverbase/base.go
index 09ed15547ae..338b12d1b6c 100644
--- a/pkg/kv/kvserver/kvserverbase/base.go
+++ b/pkg/kv/kvserver/kvserverbase/base.go
@@ -164,6 +164,9 @@ func IntersectSpan(
 ) (middle *roachpb.Span, outside []roachpb.Span) {
        start, end := desc.StartKey.AsRawKey(), desc.EndKey.AsRawKey()
        if len(span.EndKey) == 0 {
+               if ContainsKey(desc, span.Key) {
+                       return &span, nil
+               }
                outside = append(outside, span)
                return
        }

The non-1PC EndTxn path also uses this utility function, but only for ranged intent spans.

[blathers-crl]

Hi @nvanbenschoten, please add branch-* labels to identify which branch(es) this release-blocker affects.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}