search

cockroachdb / cockroach

CockroachDB — the cloud native, distributed SQL database designed for high availability, effortless scale, and control over data placement.
https://www.cockroachlabs.com
Other
30.16k stars 3.82k forks source link

pkg/sql/logictest/tests/cockroach-go-testserver-24.2/cockroach-go-testserver-24_2_test: TestLogic_mixed_version_timeseries_range failed #135830

Closed github-actions[bot] closed 1 day ago

github-actions[bot] commented 1 day ago

pkg/sql/logictest/tests/cockroach-go-testserver-24.2/cockroach-go-testserver-24_2_test.TestLogic_mixed_version_timeseries_range failed on master @ c06be5f6f64400bc790ae5f71bf09f1ecf2d4caf:

=== RUN   TestLogic_mixed_version_timeseries_range
    test_log_scope.go:165: test logs captured to: outputs.zip/logTestLogic_mixed_version_timeseries_range4286853930
    test_log_scope.go:76: use -show-logs to present logs inline
    logic.go:1434: 
        :0: error while processing
    logic.go:1434: cockroach-go testserver WaitForInit failed: init did not finish for node 0
    panic.go:626: -- test log scope end --
test logs left over in: outputs.zip/logTestLogic_mixed_version_timeseries_range4286853930
--- FAIL: TestLogic_mixed_version_timeseries_range (193.83s)

Parameters:

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/sql-foundations

This test on roachdash | Improve this report!

Jira issue: CRDB-44744

rafiss commented 1 day ago

Looks like hardware issues

0/cockroach.stderr:103:I241120 16:26:39.443612 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 68  slow non-blocking raft commit: commit-wait 751.173964ms sem 240ns
0/cockroach.stderr:110:I241120 16:26:41.318741 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 75  slow non-blocking raft commit: commit-wait 629.483368ms sem 390ns
0/cockroach.stderr:111:W241120 16:26:41.319115 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 76  slow heartbeat took 1.333203923s; err=<nil>
0/cockroach.stderr:112:I241120 16:26:42.004005 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 77  slow non-blocking raft commit: commit-wait 534.037022ms sem 570ns
0/cockroach.stderr:118:I241120 16:26:43.879519 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 83  slow non-blocking raft commit: commit-wait 552.450497ms wal-rot 713.50192ms sem 380ns
0/cockroach.stderr:119:I241120 16:26:44.266793 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 84  slow non-blocking raft commit: commit-wait 387.190727ms sem 170ns
0/cockroach.stderr:124:W241120 16:26:46.260058 485 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 89  Merge [/System/tsd/‹cr.node.rpc.method.querytxn.recv›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-count›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-sum›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-avg›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-max›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p99.999›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p99.99›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p99.9›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p99›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p90›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p75›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.callbacks.pending_duration-p50›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.granter.io_tokens_exhausted_duration.kv›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_queue_length.elastic-stores.bulk-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-count›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-sum›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-avg›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-max›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-p99.999›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.elastic-cpu-p99.99›/‹10s›/2024-11-20T16:00:00Z/‹1›],... 2790 skipped ..., Merge [/System/tsd/‹cr.store.kv.rangefeed.scheduler.system.latency-p90›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.kv.rangefeed.scheduler.system.latency-p75›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.kv.rangefeed.scheduler.system.latency-p50›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.admission.raft.paused_replicas_dropped_msgs›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.raft.entrycache.accesses›/‹10s›/2024-11-20T16:00:00Z/‹1›] has held latch for 3650434202 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:128:W241120 16:26:46.261254 475 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 93  ConditionalPut [/System/NodeLiveness/1], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/1], [txn: 3744c5d3], [can-forward-ts] has held latch for 3648392594 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:131:W241120 16:26:46.262269 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 96  slow heartbeat took 4.149706899s; err=result is ambiguous: after 3.65s of attempting command: context deadline exceeded
0/cockroach.stderr:144:W241120 16:26:47.524540 668 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 103  slow heartbeat took 1.264088562s; err=<nil>
0/cockroach.stderr:145:I241120 16:26:47.524821 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 104  slow non-blocking raft commit: commit-wait 1.263376262s sem 220ns
0/cockroach.stderr:146:I241120 16:26:47.524874 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r5/1:‹/{Systemtse-Table/0}›,raft] 105  slow non-blocking raft commit: commit-wait 190ns sem 511ns
0/cockroach.stderr:147:I241120 16:26:47.524891 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›,raft] 106  slow non-blocking raft commit: commit-wait 60ns sem 209ns
0/cockroach.stderr:148:I241120 16:26:47.524913 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›,raft] 107  slow non-blocking raft commit: commit-wait 80ns sem 190ns
0/cockroach.stderr:149:I241120 16:26:47.524926 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 108  slow non-blocking raft commit: commit-wait 170ns sem 570ns
0/cockroach.stderr:150:I241120 16:26:47.524938 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r25/1:‹/Table/2{2-3}›,raft] 109  slow non-blocking raft commit: commit-wait 170ns sem 590ns
0/cockroach.stderr:151:W241120 16:26:47.525041 489 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 110  Increment [/System‹/›‹"store-idgen›‹"›] has held latch for 3257563902 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:152:I241120 16:26:48.319889 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 111  slow non-blocking raft commit: commit-wait 794.921296ms sem 260ns
0/cockroach.stderr:153:W241120 16:26:48.957997 707 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 112  slow heartbeat took 2.696275338s; err=heartbeat failed on epoch increment
0/cockroach.stderr:155:I241120 16:26:48.958343 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r5/1:‹/{Systemtse-Table/0}›,raft] 114  slow non-blocking raft commit: commit-wait 638.37077ms sem 180ns
0/cockroach.stderr:161:W241120 16:26:49.262532 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 120  slow heartbeat took 3.00013753s; err=disk write failed while updating node liveness: interrupted during singleflight ‹engine sync:0›: context deadline exceeded
0/cockroach.stderr:170:I241120 16:26:50.065421 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›,raft] 123  slow non-blocking raft commit: commit-wait 1.106570059s sem 100ns
0/cockroach.stderr:176:I241120 16:26:51.084081 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 129  slow non-blocking raft commit: commit-wait 1.018011099s sem 190ns
0/cockroach.stderr:177:W241120 16:26:51.085663 751 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 130  slow heartbeat took 2.76542667s; err=<nil>
0/cockroach.stderr:178:W241120 16:26:51.086207 766 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r25/1:‹/Table/2{2-3}›] 131  slow heartbeat took 2.12738552s; err=<nil>
0/cockroach.stderr:179:W241120 16:26:51.086412 767 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 132  slow heartbeat took 1.893429002s; err=<nil>
0/cockroach.stderr:180:W241120 16:26:52.263357 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 133  slow heartbeat took 3.000641031s; err=disk write failed while updating node liveness: interrupted during singleflight ‹engine sync:0›: context deadline exceeded
0/cockroach.stderr:189:I241120 16:26:52.326384 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 136  slow non-blocking raft commit: commit-wait 1.240551136s sem 410ns
0/cockroach.stderr:190:W241120 16:26:52.326623 795 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›] 137  slow heartbeat took 2.260683457s; err=<nil>
0/cockroach.stderr:200:W241120 16:26:53.392923 775 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›] 147  slow heartbeat took 3.326877773s; err=<nil>
0/cockroach.stderr:201:I241120 16:26:53.393279 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›,raft] 148  slow non-blocking raft commit: commit-wait 1.065112765s sem 310ns
0/cockroach.stderr:204:I241120 16:26:54.159130 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 151  slow non-blocking raft commit: commit-wait 562.879386ms wal-rot 232.436837ms sem 469ns
0/cockroach.stderr:208:W241120 16:26:54.481628 776 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r5/1:‹/{Systemtse-Table/0}›] 155  slow heartbeat took 4.288870913s; err=<nil>
0/cockroach.stderr:209:I241120 16:26:54.481832 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 156  slow non-blocking raft commit: commit-wait 322.405472ms sem 730ns
0/cockroach.stderr:211:I241120 16:26:55.138387 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r9/1:‹/Table/{5-6}›,raft] 158  slow non-blocking raft commit: commit-wait 331.893799ms sem 60ns
0/cockroach.stderr:212:W241120 16:26:55.264488 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 159  slow heartbeat took 3.000764323s; err=result is ambiguous: after 0.13s of attempting command: context deadline exceeded
0/cockroach.stderr:226:I241120 16:26:56.614442 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r21/1:‹/Table/1{8-9}›,raft] 167  slow non-blocking raft commit: commit-wait 621.651275ms sem 240ns
0/cockroach.stderr:229:W241120 16:26:58.255045 1370 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 170  slow heartbeat took 2.876679997s; err=<nil>
0/cockroach.stderr:230:I241120 16:26:58.255673 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 171  slow non-blocking raft commit: commit-wait 1.641169288s sem 350ns
0/cockroach.stderr:265:W241120 16:27:00.112852 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 177  slow heartbeat took 3.000542766s; err=context deadline exceeded
0/cockroach.stderr:273:I241120 16:27:00.149913 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 179  slow non-blocking raft commit: commit-wait 1.893988159s sem 610ns
0/cockroach.stderr:274:I241120 16:27:01.710539 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 180  slow non-blocking raft commit: commit-wait 1.560550317s sem 260ns
0/cockroach.stderr:275:W241120 16:27:01.710770 1391 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r7/1:‹/Table/{3-4}›] 181  slow heartbeat took 6.332364776s; err=heartbeat failed on epoch increment
0/cockroach.stderr:277:W241120 16:27:01.710997 476 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 183  ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 45d1a2ae], [can-forward-ts] has held latch for 3455637259 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:278:W241120 16:27:01.714102 478 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 184  HeartbeatTxn [/Local/Range/System/tsd/‹RangeDescriptor›], [txn: a094e3bb] has held latch for 3417392790 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:279:W241120 16:27:03.113124 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 185  slow heartbeat took 3.000118983s; err=context deadline exceeded
0/cockroach.stderr:287:I241120 16:27:03.700453 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 187  slow non-blocking raft commit: commit-wait 1.989805451s sem 230ns
0/cockroach.stderr:291:W241120 16:27:06.444372 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 191  slow heartbeat took 3.000512917s; err=context deadline exceeded
0/cockroach.stderr:299:W241120 16:27:06.939214 1392 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r27/1:‹/Table/2{4-5}›] 193  slow heartbeat took 11.560752534s; err=heartbeat failed on epoch increment
0/cockroach.stderr:300:I241120 16:27:06.939272 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 194  slow non-blocking raft commit: commit-wait 3.238710118s sem 190ns
0/cockroach.stderr:301:W241120 16:27:07.947926 476 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 197  HeartbeatTxn [/System/NodeLiveness/2], [txn: 5ca43bed] has held latch for 6236154739 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:304:W241120 16:27:08.242702 1393 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r9/1:‹/Table/{5-6}›] 198  slow heartbeat took 12.864072629s; err=heartbeat failed on epoch increment
0/cockroach.stderr:305:I241120 16:27:08.652006 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r14/1:‹/Table/1{1-2}›,raft] 199  slow non-blocking raft commit: commit-wait 704.145298ms sem 410ns
0/cockroach.stderr:306:W241120 16:27:08.681694 1372 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r12/1:‹/Table/{8-9}›] 200  slow heartbeat took 13.303036044s; err=heartbeat failed on epoch increment
0/cockroach.stderr:312:W241120 16:27:09.236964 1607 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 206  slow heartbeat took 7.044014928s; err=<nil>
0/cockroach.stderr:313:W241120 16:27:09.237134 1613 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r5/1:‹/{Systemtse-Table/0}›] 207  slow heartbeat took 6.785785316s; err=<nil>
0/cockroach.stderr:314:W241120 16:27:09.237245 1617 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›] 208  slow heartbeat took 6.5393436s; err=<nil>
0/cockroach.stderr:315:W241120 16:27:09.237324 1621 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›] 209  slow heartbeat took 6.538419688s; err=<nil>
0/cockroach.stderr:316:W241120 16:27:09.237386 1651 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 210  slow heartbeat took 5.536640429s; err=<nil>
0/cockroach.stderr:317:W241120 16:27:09.237448 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 211  slow heartbeat took 2.792975698s; err=<nil>
0/cockroach.stderr:319:I241120 16:27:10.559697 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 213  slow non-blocking raft commit: commit-wait 859.848299ms sem 220ns
0/cockroach.stderr:320:W241120 16:27:10.560072 1869 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r14/1:‹/Table/1{1-2}›] 214  slow heartbeat took 1.836772828s; err=<nil>
0/cockroach.stderr:321:I241120 16:27:11.487843 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 215  slow non-blocking raft commit: commit-wait 928.07036ms sem 480ns
0/cockroach.stderr:324:W241120 16:27:13.561206 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 218  slow heartbeat took 3.000921341s; err=context deadline exceeded
0/cockroach.stderr:333:W241120 16:27:16.562083 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 221  slow heartbeat took 3.000743066s; err=context deadline exceeded
0/cockroach.stderr:341:I241120 16:27:16.697187 2089 3@pebble/event.go:776 ⋮ [n1,s1,pebble] 223  disk slowness detected: syncdata on file 000007.log has been ongoing for 5.2s
0/cockroach.stderr:342:I241120 16:27:16.856271 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 224  slow non-blocking raft commit: commit-wait 5.368375941s sem 170ns
0/cockroach.stderr:343:W241120 16:27:16.856546 1870 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r13/1:‹/Table/{9-11}›] 225  slow heartbeat took 8.133138058s; err=heartbeat failed on epoch increment
0/cockroach.stderr:347:I241120 16:27:18.479889 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 229  slow non-blocking raft commit: commit-wait 1.623530543s sem 260ns
0/cockroach.stderr:350:W241120 16:27:18.833748 484 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 232  TruncateLog [/System/tsd] has held latch for 8273522403 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:352:W241120 16:27:18.833968 475 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 234  ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 8e30c40d], [can-forward-ts] has held latch for 6599744229 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:354:W241120 16:27:18.835241 479 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 236  ConditionalPut [/System/StatusNode/1] has held latch for 8273123923 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:358:W241120 16:27:18.836353 1557 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,raftlog,s1,r4/1:‹/System{/tsd-tse}›] 240  slow replica RPC: have been waiting 10.52s (0 attempts) for RPC TruncateLog [/System/tsd] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.TruncateLogResponse›
0/cockroach.stderr:366:W241120 16:27:19.663283 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 248  slow heartbeat took 3.00083719s; err=context deadline exceeded
0/cockroach.stderr:380:I241120 16:27:20.060425 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 256  slow non-blocking raft commit: commit-wait 1.226644921s wal-rot 3.137477528s sem 740ns
0/cockroach.stderr:381:W241120 16:27:20.865013 1871 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r6/1:‹/Table/{0-3}›] 257  slow heartbeat took 12.013486548s; err=heartbeat failed on epoch increment
0/cockroach.stderr:382:I241120 16:27:20.865206 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 258  slow non-blocking raft commit: commit-wait 804.705778ms sem 300ns
0/cockroach.stderr:383:I241120 16:27:20.865254 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 259  slow non-blocking raft commit: commit-wait 240ns sem 420ns
0/cockroach.stderr:384:I241120 16:27:20.865275 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r14/1:‹/Table/1{1-2}›,raft] 260  slow non-blocking raft commit: commit-wait 140ns sem 130ns
0/cockroach.stderr:385:I241120 16:27:20.865287 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 261  slow non-blocking raft commit: commit-wait 180ns sem 120ns
0/cockroach.stderr:386:I241120 16:27:20.865318 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 262  slow non-blocking raft commit: commit-wait 170ns sem 140ns
0/cockroach.stderr:387:I241120 16:27:20.865365 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 263  slow non-blocking raft commit: commit-wait 70ns sem 100ns
0/cockroach.stderr:389:W241120 16:27:21.602609 1851 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r15/1:‹/Table/1{2-3}›] 265  slow heartbeat took 12.409094107s; err=heartbeat failed on epoch increment
0/cockroach.stderr:390:I241120 16:27:21.638336 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 266  slow non-blocking raft commit: commit-wait 772.289163ms sem 160ns
0/cockroach.stderr:394:W241120 16:27:21.719358 2022 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 270  slow heartbeat took 7.026550021s; err=<nil>
0/cockroach.stderr:395:W241120 16:27:21.719543 2023 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 271  slow heartbeat took 7.026658142s; err=<nil>
0/cockroach.stderr:396:W241120 16:27:21.719623 2036 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›] 272  slow heartbeat took 7.019550729s; err=<nil>
0/cockroach.stderr:397:W241120 16:27:21.719672 2038 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›] 273  slow heartbeat took 7.018594985s; err=<nil>
0/cockroach.stderr:398:W241120 16:27:21.719784 2087 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r7/1:‹/Table/{3-4}›] 274  slow heartbeat took 5.266782739s; err=<nil>
0/cockroach.stderr:399:W241120 16:27:21.719851 2257 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r14/1:‹/Table/1{1-2}›] 275  slow heartbeat took 2.526962443s; err=<nil>
0/cockroach.stderr:400:W241120 16:27:21.719928 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 276  slow heartbeat took 2.056463845s; err=<nil>
0/cockroach.stderr:402:I241120 16:27:22.759412 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 278  slow non-blocking raft commit: commit-wait 678.608437ms sem 390ns
0/cockroach.stderr:403:W241120 16:27:22.759840 2378 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r16/1:‹/Table/1{3-4}›] 279  slow heartbeat took 1.120544301s; err=<nil>
0/cockroach.stderr:404:W241120 16:27:22.764014 1666 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1] 280  slow replica RPC: have been waiting 14.51s (0 attempts) for RPC PushTxn(PUSH_TOUCH,00000000->a094e3bb) [/Local/Range/System/tsd/‹RangeDescriptor›] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.PushTxnResponse›
0/cockroach.stderr:405:I241120 16:27:23.386703 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 281  slow non-blocking raft commit: commit-wait 627.201093ms sem 480ns
0/cockroach.stderr:407:W241120 16:27:23.758244 2383 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›] 283  slow heartbeat took 2.06183813s; err=<nil>
0/cockroach.stderr:409:I241120 16:27:24.319654 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 285  slow non-blocking raft commit: commit-wait 561.426881ms sem 380ns
0/cockroach.stderr:411:W241120 16:27:25.760139 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 287  slow heartbeat took 3.00073347s; err=context deadline exceeded
0/cockroach.stderr:419:W241120 16:27:25.772772 2384 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›] 289  slow heartbeat took 4.076224395s; err=<nil>
0/cockroach.stderr:420:I241120 16:27:25.773026 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›,raft] 290  slow non-blocking raft commit: commit-wait 1.453279735s sem 110ns
0/cockroach.stderr:421:I241120 16:27:26.896783 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 291  slow non-blocking raft commit: commit-wait 1.046896084s sem 260ns
0/cockroach.stderr:424:I241120 16:27:27.751557 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 294  slow non-blocking raft commit: commit-wait 854.697099ms sem 490ns
0/cockroach.stderr:425:I241120 16:27:28.490965 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 295  slow non-blocking raft commit: commit-wait 739.313697ms sem 300ns
0/cockroach.stderr:427:W241120 16:27:28.492460 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 297  slow heartbeat took 2.732172571s; err=<nil>
0/cockroach.stderr:432:I241120 16:27:29.485174 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r18/1:‹/Table/1{5-6}›,raft] 302  slow non-blocking raft commit: commit-wait 993.359846ms sem 210ns
0/cockroach.stderr:433:W241120 16:27:29.485115 2597 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›] 303  slow heartbeat took 1.791955494s; err=<nil>
0/cockroach.stderr:436:I241120 16:27:30.604209 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 306  slow non-blocking raft commit: commit-wait 1.118910103s sem 390ns
0/cockroach.stderr:437:W241120 16:27:31.553000 2610 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›] 307  slow heartbeat took 3.859830144s; err=<nil>
0/cockroach.stderr:438:I241120 16:27:31.553262 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›,raft] 308  slow non-blocking raft commit: commit-wait 949.005768ms sem 160ns
0/cockroach.stderr:441:W241120 16:27:31.813750 2596 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 311  slow heartbeat took 4.12057725s; err=heartbeat failed on epoch increment
0/cockroach.stderr:444:W241120 16:27:32.486299 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 314  slow heartbeat took 3.000762498s; err=context deadline exceeded
0/cockroach.stderr:452:I241120 16:27:32.526416 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r18/1:‹/Table/1{5-6}›,raft] 316  slow non-blocking raft commit: commit-wait 972.629567ms sem 250ns
0/cockroach.stderr:455:W241120 16:27:33.170478 482 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 319  Merge [/System/tsd/‹cr.node.rpc.method.delete.recv›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.granter.io_tokens_bypassed.kv›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.requested.sql-root-start›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.elastic_tokens_unaccounted›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_queue_length.kv-stores.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.admitted.elastic-stores.bulk-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_queue_length.sql-leaf-start.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.regular_tokens_unaccounted›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.rpc.streams.mux_rangefeed.active›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.errored.sql-sql-response›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.requested.sql-sql-response.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.errored.sql-sql-response.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.elastic_tokens_deducted›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.elastic_requests_admitted›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_token_dispatch.remote_elastic›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.requested.sql-kv-response.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.admitted.elastic-cpu.bulk-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.raft.transport.sent›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.rpc.method.deleterange.recv›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.rpc.method.adminmerge.recv›/‹10s›/2024-11-20T16:00:00Z/‹3›],... 2794 skipped ..., Merge [/System/tsd/‹cr.store.raft.process.applycommitted.latency-p90›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.raft.process.applycommitted.latency-p75›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.raft.process.applycommitted.latency-p50›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.queue.tsmaintenance.process.success›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.queue.gc.info.transactionspangcaborted›/‹10s›/2024-11-20T16:00:00Z/‹3›] has held latch for 4312568877 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:463:I241120 16:27:35.349501 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 327  slow non-blocking raft commit: commit-wait 2.176931064s wal-rot 1.461461674s sem 860ns
0/cockroach.stderr:464:W241120 16:27:35.487412 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 328  slow heartbeat took 3.000948316s; err=context deadline exceeded
0/cockroach.stderr:473:I241120 16:27:36.941661 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 331  slow non-blocking raft commit: commit-wait 1.592106101s sem 250ns
0/cockroach.stderr:474:I241120 16:27:36.941722 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 332  slow non-blocking raft commit: commit-wait 190ns sem 450ns
0/cockroach.stderr:475:I241120 16:27:36.941751 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 333  slow non-blocking raft commit: commit-wait 170ns sem 670ns
0/cockroach.stderr:476:W241120 16:27:36.941807 2598 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 334  slow heartbeat took 9.248624777s; err=heartbeat failed on epoch increment
0/cockroach.stderr:477:W241120 16:27:36.941986 475 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 335  ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: db59af92], [can-forward-ts] has held latch for 4144296332 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:480:I241120 16:27:37.822877 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 338  slow non-blocking raft commit: commit-wait 881.102575ms sem 471ns
0/cockroach.stderr:481:W241120 16:27:38.300133 2612 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r13/1:‹/Table/{9-11}›] 339  slow heartbeat took 10.547533364s; err=heartbeat failed on epoch increment
0/cockroach.stderr:482:W241120 16:27:38.488451 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 340  slow heartbeat took 3.000815564s; err=context deadline exceeded
0/cockroach.stderr:490:I241120 16:27:38.880880 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r19/1:‹/Table/1{6-7}›,raft] 342  slow non-blocking raft commit: commit-wait 582.014439ms sem 429ns
0/cockroach.stderr:499:I241120 16:27:39.497884 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r19/1:‹/Table/1{6-7}›,raft] 347  slow non-blocking raft commit: commit-wait 616.668783ms sem 520ns
0/cockroach.stderr:502:W241120 16:27:39.875215 2785 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›] 350  slow heartbeat took 7.682206269s; err=<nil>
0/cockroach.stderr:503:W241120 16:27:39.875877 2807 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r9/1:‹/Table/{5-6}›] 351  slow heartbeat took 7.419759563s; err=<nil>
0/cockroach.stderr:504:W241120 16:27:39.876086 2818 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r10/1:‹/Table/{6-7}›] 352  slow heartbeat took 7.172577695s; err=<nil>
0/cockroach.stderr:505:W241120 16:27:39.876248 2820 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r50/1:‹/Table/4{7-8}›] 353  slow heartbeat took 7.171265668s; err=<nil>
0/cockroach.stderr:506:W241120 16:27:39.876416 2826 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›] 354  slow heartbeat took 6.703843409s; err=<nil>
0/cockroach.stderr:507:W241120 16:27:39.876539 2850 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r16/1:‹/Table/1{3-4}›] 355  slow heartbeat took 6.700950395s; err=<nil>
0/cockroach.stderr:508:W241120 16:27:39.876642 2851 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›] 356  slow heartbeat took 6.701004815s; err=<nil>
0/cockroach.stderr:509:W241120 16:27:39.876722 2845 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r18/1:‹/Table/1{5-6}›] 357  slow heartbeat took 6.683594496s; err=<nil>
0/cockroach.stderr:510:W241120 16:27:39.876800 2985 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›] 358  slow heartbeat took 2.934422373s; err=<nil>
0/cockroach.stderr:511:W241120 16:27:40.810948 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 359  slow heartbeat took 2.322370838s; err=<nil>
0/cockroach.stderr:512:I241120 16:27:40.811084 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r17/1:‹/Table/1{4-5}›,raft] 360  slow non-blocking raft commit: commit-wait 634.691858ms sem 190ns
0/cockroach.stderr:514:W241120 16:27:44.277845 3033 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r13/1:‹/Table/{9-11}›] 362  slow heartbeat took 5.747108661s; err=<nil>
0/cockroach.stderr:515:I241120 16:27:44.278104 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 363  slow non-blocking raft commit: commit-wait 3.092586319s sem 171ns
0/cockroach.stderr:516:W241120 16:27:44.278275 484 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 364  HeartbeatTxn [/Table/39/2/‹"\x80"›/‹"\x01\x01\x80\xa9\x90}\xe7\xf7\fFV\x88y\x14\x98\a\xbd\xda0"›/‹0›], [txn: 98dfc426] has held latch for 3462309670 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:517:W241120 16:27:44.278343 476 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 365  ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: aeff0fdd], [can-forward-ts] has held latch for 3465928051 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:518:W241120 16:27:44.278487 477 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r16/1:‹/Table/1{3-4}›,raft] 366  ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹0›], ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹2›/‹1›], ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹3›/‹1›], ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹4›/‹1›], ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹5›/‹1›], ConditionalPut [/Table/13/1/‹2024-11-20T16:27:28.49294Z›/‹1022524298215817217›/‹6›/‹1›] has held latch for 3462679642 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:519:W241120 16:27:44.278609 484 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r3/1:‹/System/{NodeLive…-tsd}›,raft] 367  ConditionalPut [/System/StatusNode/3] has held latch for 3463128475 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:521:W241120 16:27:44.286219 477 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r4/1:‹/System{/tsd-tse}›,raft] 369  Merge [/System/tsd/‹cr.node.liveness.livenodes›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.errored.sql-sql-response›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.kvadmission.flow_handle.streams_connected›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.tenant.consumption.write_requests›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.batch_responses.cross_region.bytes›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.node-id›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.gossip.connections.outgoing›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.admitted.sql-sql-response.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.elastic_cpu.max_available_nanos›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.elastic_tokens_unaccounted›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.kv.prober.write.attempts›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.granter.io_tokens_available.kv›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.admitted.kv-stores.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.requested.elastic-cpu.bulk-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-count›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-sum›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-avg›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-max›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-p99.999›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.node.admission.wait_durations.kv-stores-p99.99›/‹10s›/2024-11-20T16:00:00Z/‹1›],... 2824 skipped ..., Merge [/System/tsd/‹cr.store.raft.rcvd.prop›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.queue.gc.info.transactionspangcaborted›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.kv.tenant_rate_limit.write_batches_admitted›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.rebalancing.state.imbalanced_overfull_options_exhausted›/‹10s›/2024-11-20T16:00:00Z/‹1›], Merge [/System/tsd/‹cr.store.capacity›/‹10s›/2024-11-20T16:00:00Z/‹1›] has held latch for 3473133135 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:524:I241120 16:27:45.942833 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 372  slow non-blocking raft commit: commit-wait 1.66462354s sem 260ns
0/cockroach.stderr:525:W241120 16:27:45.943198 491 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 373  EndTxn(commit) [/Table/39/2/‹"\x80"›/‹"\x01\x01\x804 \v\xb5\xc1\x91O\x8d\xb5\xaa\xd9.\xd5:ݐ"›/‹0›], [txn: 8c0cb6e4] has held latch for 4757426519 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:529:W241120 16:27:47.278219 531 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,liveness-hb] 377  slow heartbeat took 3.000390762s; err=context deadline exceeded
0/cockroach.stderr:538:W241120 16:27:48.119278 3046 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r8/1:‹/Table/{4-5}›] 380  slow heartbeat took 9.358294498s; err=heartbeat failed on epoch increment
0/cockroach.stderr:540:I241120 16:27:48.119382 496 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n1,s1,r13/1:‹/Table/{9-11}›,raft] 381  slow non-blocking raft commit: commit-wait 2.176456759s sem 210ns
0/cockroach.stderr:541:W241120 16:27:48.474958 475 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 383  EndTxn(commit change-replicas) [/Local/Range/System/NodeLiveness/‹RangeDescriptor›], [txn: 147d2e6d] has held latch for 4194219930 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:542:W241120 16:27:48.475347 492 kv/kvserver/spanlatch/manager.go:654 ⋮ [T1,Vsystem,n1,s1,r42/1:‹/Table/{39-40}›,raft] 384  EndTxn(commit) [/Table/39/2/‹"\x80"›/‹"\x01\x01\x80\xa9\x90}\xe7\xf7\fFV\x88y\x14\x98\a\xbd\xda0"›/‹0›], [txn: 98dfc426] has held latch for 4196390304 ns. Some possible causes are slow disk reads, slow raft replication, and expensive request processing.
0/cockroach.stderr:545:W241120 16:27:48.491295 3066 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n1,s1,r19/1:‹/Table/1{6-7}›] 387  slow heartbeat took 8.992658366s; err=heartbeat failed on epoch increment
1/cockroach.stderr:150:W241120 16:26:54.809527 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 115  slow heartbeat took 1.463161781s; err=<nil>
1/cockroach.stderr:153:W241120 16:26:59.348859 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 118  slow heartbeat took 3.001784753s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 15cd27d9], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
1/cockroach.stderr:161:W241120 16:27:01.712400 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 120  slow heartbeat took 1.947176774s; err=<nil>
1/cockroach.stderr:166:W241120 16:27:06.700718 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 125  slow heartbeat took 3.000693383s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 7564bb1e], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
1/cockroach.stderr:174:W241120 16:27:08.653142 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 127  slow heartbeat took 1.952213449s; err=<nil>
1/cockroach.stderr:208:W241120 16:27:14.347665 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 132  slow heartbeat took 3.000875686s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 8e30c40d], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
1/cockroach.stderr:218:W241120 16:27:17.349707 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 136  slow heartbeat took 3.001288368s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 626570b9], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
1/cockroach.stderr:227:W241120 16:27:18.845484 746 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n2,ts-poll] 139  slow replica RPC: have been waiting 10.90s (0 attempts) for RPC Merge [/System/tsd/‹cr.node.spanconfig.kvsubscriber.update_behind_nanos›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.admission.requested.sql-kv-response.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.admission.errored.sql-sql-response.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.admission.admitted.sql-root-start.locking-normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.rpc.method.linkexternalsstable.recv›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.rpc.streams.mux_rangefeed.active›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-count›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-sum›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-avg›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-max›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p99.999›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p99.99›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p99.9›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p99›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p90›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p75›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.gossip.callbacks.processing_duration-p50›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.tenant.consumption.read_bytes›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.rpc.method.requestlease.recv›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.node.rpc.method.subsume.recv›/‹10s›/2024-11-20T16:00:00Z/‹2›],... 2794 skipped ..., Merge [/System/tsd/‹cr.store.kv.allocator.load_based_lease_transfers.should_transfer›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.store.storage.iterator.internal.seeks›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.store.txnrecovery.successes.committed›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.store.replicas.reserved›/‹10s›/2024-11-20T16:00:00Z/‹2›], Merge [/System/tsd/‹cr.store.range.raftleadertransfers›/‹10s›/2024-11-20T16:00:00Z/‹2›] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, ... 2794 skipped ..., *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse›
1/cockroach.stderr:232:I241120 16:27:20.060260 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:{-},raft] 144  slow non-blocking raft commit: commit-wait 923.716936ms sem 320ns
1/cockroach.stderr:235:W241120 16:27:20.351345 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 146  slow heartbeat took 3.001252836s; err=aborted in DistSender: result is ambiguous: context deadline exceeded
1/cockroach.stderr:268:W241120 16:27:25.852769 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 174  slow heartbeat took 2.50624106s; err=<nil>
1/cockroach.stderr:276:I241120 16:27:27.585060 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 182  slow non-blocking raft commit: commit-wait 1.827426838s wal-rot 914.035605ms sem 530ns
1/cockroach.stderr:290:W241120 16:27:31.046026 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 196  slow heartbeat took 3.001899313s; err=context deadline exceeded
1/cockroach.stderr:303:I241120 16:27:32.134929 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 203  slow non-blocking raft commit: commit-wait 3.468208909s sem 351ns
1/cockroach.stderr:304:I241120 16:27:32.797297 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 204  slow non-blocking raft commit: commit-wait 662.21814ms sem 1.04µs
1/cockroach.stderr:308:W241120 16:27:34.047328 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 208  slow heartbeat took 3.001100277s; err=result is ambiguous: after 1.25s of attempting command: context deadline exceeded
1/cockroach.stderr:317:I241120 16:27:35.165813 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 211  slow non-blocking raft commit: commit-wait 1.97468762s sem 711ns
1/cockroach.stderr:318:W241120 16:27:36.943853 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 212  slow heartbeat took 2.896194299s; err=<nil>
1/cockroach.stderr:319:I241120 16:27:37.942388 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 213  slow non-blocking raft commit: commit-wait 2.590837567s sem 650ns
1/cockroach.stderr:321:W241120 16:27:39.498425 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 215  slow heartbeat took 1.199596139s; err=<nil>
1/cockroach.stderr:322:I241120 16:27:40.641327 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 216  slow non-blocking raft commit: commit-wait 764.569288ms sem 370ns
1/cockroach.stderr:323:I241120 16:27:41.565970 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 217  slow non-blocking raft commit: commit-wait 750.790366ms sem 650ns
1/cockroach.stderr:324:W241120 16:27:42.875901 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 218  slow heartbeat took 3.001103513s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/2], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/2], [txn: 32f269ee], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
1/cockroach.stderr:334:I241120 16:27:44.276272 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 222  slow non-blocking raft commit: commit-wait 2.710227346s sem 630ns
1/cockroach.stderr:337:W241120 16:27:45.453013 748 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n2,liveness-hb] 225  slow heartbeat took 2.576764967s; err=<nil>
1/cockroach.stderr:338:I241120 16:27:45.453243 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 226  slow non-blocking raft commit: commit-wait 1.17679375s sem 730ns
1/cockroach.stderr:339:I241120 16:27:47.415395 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 227  slow non-blocking raft commit: commit-wait 1.9620938s sem 530ns
1/cockroach.stderr:342:W241120 16:27:48.479930 808 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n2] 230  slow replica RPC: have been waiting 11.54s (0 attempts) for RPC EndTxn(commit) [/Table/39/2/‹"\x80"›/‹"\x01\x01\x80\x8eoѪ\aoJ]\xa7\xf4]\xceI\xa5o?"›/‹0›], [txn: e5c3f44b] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.EndTxnResponse›
1/cockroach.stderr:355:I241120 16:27:48.556114 670 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n2,s2,r4/2:‹/System{/tsd-tse}›,raft] 243  slow non-blocking raft commit: commit-wait 974.912322ms sem 250ns
2/cockroach.stderr:141:W241120 16:26:59.900523 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 106  slow heartbeat took 3.000855553s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 45d1a2ae], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:149:W241120 16:27:01.712064 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 108  slow heartbeat took 1.811307335s; err=<nil>
2/cockroach.stderr:154:W241120 16:27:06.701458 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 113  slow heartbeat took 3.001435305s; err=aborted in DistSender: result is ambiguous: context deadline exceeded
2/cockroach.stderr:162:W241120 16:27:08.653148 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 115  slow heartbeat took 1.951518077s; err=<nil>
2/cockroach.stderr:164:W241120 16:27:10.560446 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 117  slow heartbeat took 1.660846837s; err=<nil>
2/cockroach.stderr:197:W241120 16:27:14.901089 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 121  slow heartbeat took 3.001102308s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 2798d488], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:208:W241120 16:27:17.902074 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 126  slow heartbeat took 3.000756882s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: acba83b1], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:221:W241120 16:27:18.848616 556 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n3,ts-poll] 133  slow replica RPC: have been waiting 10.89s (0 attempts) for RPC Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-count›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-sum›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-avg›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-max›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p99.999›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p99.99›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p99.9›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p99›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p90›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p75›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.wait_durations.sql-root-start-p50›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_controller.elastic_tokens_available›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.errored.sql-kv-response.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.admitted.sql-sql-response.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.scheduler_latency_listener.p99_nanos›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.requested.sql-kv-response›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.kvadmission.flow_token_dispatch.remote_regular›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.admitted.elastic-stores›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.admitted.elastic-stores.ttl-low-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.node.admission.errored.sql-leaf-start.normal-pri›/‹10s›/2024-11-20T16:00:00Z/‹3›],... 2794 skipped ..., Merge [/System/tsd/‹cr.store.queue.tsmaintenance.process.failure›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.txnwaitqueue.pusher.slow›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.kv.tenant_rate_limit.write_requests_admitted›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.replicas.leaders›/‹10s›/2024-11-20T16:00:00Z/‹3›], Merge [/System/tsd/‹cr.store.storage.keys.tombstone.count›/‹10s›/2024-11-20T16:00:00Z/‹3›] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, ... 2794 skipped ..., *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse, *kvpb.MergeResponse›
2/cockroach.stderr:227:W241120 16:27:20.869435 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 139  slow heartbeat took 2.967148136s; err=heartbeat failed on epoch increment
2/cockroach.stderr:235:W241120 16:27:25.853313 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 147  slow heartbeat took 1.953343086s; err=<nil>
2/cockroach.stderr:237:W241120 16:27:28.493298 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 149  slow heartbeat took 1.593669986s; err=<nil>
2/cockroach.stderr:239:I241120 16:27:32.526446 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:{-},raft] 151  slow non-blocking raft commit: commit-wait 712.800917ms sem 350ns
2/cockroach.stderr:240:W241120 16:27:32.901111 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 152  slow heartbeat took 3.001348052s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: c95394d5], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:260:W241120 16:27:38.299593 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 166  slow heartbeat took 2.399615014s; err=<nil>
2/cockroach.stderr:267:I241120 16:27:39.992421 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 173  slow non-blocking raft commit: commit-wait 642.921471ms sem 450ns
2/cockroach.stderr:272:I241120 16:27:40.971106 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 178  slow non-blocking raft commit: commit-wait 555.790808ms sem 1.18µs
2/cockroach.stderr:276:I241120 16:27:41.710161 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 182  slow non-blocking raft commit: commit-wait 738.956391ms sem 630ns
2/cockroach.stderr:281:W241120 16:27:42.644592 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 187  slow heartbeat took 3.000947715s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: aeff0fdd], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:295:I241120 16:27:44.587726 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 195  slow non-blocking raft commit: commit-wait 893.108158ms sem 591ns
2/cockroach.stderr:298:I241120 16:27:45.452239 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 198  slow non-blocking raft commit: commit-wait 864.426008ms sem 910ns
2/cockroach.stderr:299:W241120 16:27:45.646204 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 199  slow heartbeat took 3.001208753s; err=result is ambiguous: context done during DistSender.Send: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 05385ccd], [can-forward-ts]› RPC error: grpc: ‹context deadline exceeded› [code 4/DeadlineExceeded]
2/cockroach.stderr:309:I241120 16:27:46.548165 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 203  slow non-blocking raft commit: commit-wait 902.168244ms sem 690ns
2/cockroach.stderr:313:I241120 16:27:47.360567 484 kv/kvserver/replica_raft.go:1616 ⋮ [T1,Vsystem,n3,s3,r2/2:‹/System/NodeLiveness{-Max}›,raft] 207  slow non-blocking raft commit: commit-wait 812.320696ms sem 649ns
2/cockroach.stderr:330:W241120 16:27:48.647630 558 kv/kvserver/liveness/liveness.go:758 ⋮ [T1,Vsystem,n3,liveness-hb] 224  slow heartbeat took 3.001209362s; err=result is ambiguous: error=ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 263b4874], [can-forward-ts]› RPC error: grpc: ‹error reading from server: read tcp 127.0.0.1:51234->127.0.0.1:46343: read: connection reset by peer› [code 14/Unavailable] [exhausted] (last error: ‹failed to send RPC›: sending to all replicas failed; last error: ba: ‹ConditionalPut [/System/NodeLiveness/3], EndTxn(commit modified-span (node-liveness)) [/System/NodeLiveness/3], [txn: 263b4874], [can-forward-ts]› RPC error: grpc: ‹error reading from server: read tcp 127.0.0.1:51234->127.0.0.1:46343: read: connection reset by peer› [code 14/Unavailable])