release-26.2: kv/kvserver: TestRaftTracing failed

kv/kvserver.TestRaftTracing [failed](https://mesolite.cluster.engflow.com/invocations/default/6d224f4a-a98d-4875-a45d-230663ac2976?testReportRun=7&testReportShard=45&testReportAttempt=1#targets-Ly9wa2cva3Yva3ZzZXJ2ZXI6a3ZzZXJ2ZXJfdGVzdA==) on release-26.2 @ [218e00e3c31063ed087426fad63fe213be39b1ac](https://github.com/cockroachdb/cockroach/commits/218e00e3c31063ed087426fad63fe213be39b1ac):

```
| github.com/cockroachdb/cockroach/pkg/testutils.RunValues[...].func1
| pkg/testutils/subtest.go:23
| testing.tRunner
| GOROOT/src/testing/testing.go:1934
| runtime.goexit
| src/runtime/asm_amd64.s:1693
Wraps: (2) unable to find regexp 6 ("(?ms)ack-ing replication success to the client") in remaining string:
|
| [5863-5864]
| 1.605ms 0.984ms event:kv/kvserver/replica_raft.go:1284 [n1,s1,r83/1:/{Table/Max-Max}] applied entries [5863-5864]
| 1.614ms 0.009ms event:kv/kvserver/replica_raft.go:1284 [n1,s1,r83/1:/{Table/Max-Max}] unregistered log index 5864 from tracing
| 0.629ms -0.985ms === operation:local proposal gid:13914 _verbose:1 node:1 store:1 range:83/1:/{Table/Max-Max} raft:
| 1.546ms 0.917ms event:kv/kvserver/app_batch.go:120 [n1,s1,r83/1:/{Table/Max-Max},raft] applying command
| 1.582ms 0.036ms event:kv/kvserver/replica_application_state_machine.go:189 [n1,s1,r83/1:/{Table/Max-Max},raft] LocalResult (reply: (err: ), *kvpb.PutResponse, #encountered intents: 0, #acquired locks: 0, #resolved locks: 0 #updated txns: 0 #end txns: 0, PopulateBarrierResponse:false RepopulateSubsumeResponse:false GossipFirstRange:false MaybeGossipSystemConfig:false MaybeGossipSystemConfigIfHaveFailure:false MaybeAddToSplitQueue:false MaybeGossipNodeLiveness:
|
|
| after having matched:
|
| 0.000ms 0.000ms === operation:test gid:12462 _verbose:1
| 0.000ms 0.000ms [executeWriteBatch: {count: 1, duration 2ms}]
| 0.000ms 0.000ms [raft trace: {count: 1, duration 1ms}]
| 0.000ms 0.000ms [local proposal: {count: 1, duration 957µs}]
| 0.036ms 0.036ms event:kv/kvserver/store_send.go:158 [n1,s1] executing Put [/Table/Max]
| 0.049ms 0.012ms event:kv/kvserver/replica_send.go:199 [n1,s1,r83/1:/{Table/Max-Max}] read-write path
| 0.059ms 0.011ms event:kv/kvserver/concurrency/concurrency_manager.go:304 [n1,s1,r83/1:/{Table/Max-Max}] sequencing request
| 0.067ms 0.007ms event:kv/kvserver/concurrency/concurrency_manager.go:385 [n1,s1,r83/1:/{Table/Max-Max}] acquiring latches
| 0.077ms 0.010ms event:kv/kvserver/concurrency/concurrency_manager.go:429 [n1,s1,r83/1:/{Table/Max-Max}] scanning lock table for conflicting locks
| 0.079ms 0.002ms === operation:executeWriteBatch gid:12462 _verbose:1 node:1 store:1 range:83/1:/{Table/Max-Max}
| 0.079ms 0.000ms [raft trace: {count: 1, duration 1ms}]
| 0.079ms 0.000ms [local proposal: {count: 1, duration 957µs}]
| 0.092ms 0.013ms event:kv/kvserver/replica_write.go:180 [n1,s1,r83/1:/{Table/Max-Max}] applied timestamp cache
| 0.101ms 0.009ms event:kv/kvserver/replica_write.go:447 [n1,s1,r83/1:/{Table/Max-Max}] executing read-write batch
| 0.234ms 0.133ms event:kv/kvserver/replica_evaluate.go:580 [n1,s1,r83/1:/{Table/Max-Max}] evaluated Put command header: value: > expect_exclusion_since:<> , txn= : resp=header:<> , err=
| 0.247ms 0.012ms event:kv/kvserver/replica_proposal.go:1050 [n1,s1,r83/1:/{Table/Max-Max}] need consensus on write batch with op count=1
| 0.260ms 0.013ms event:kv/kvserver/replica_raft.go:133 [n1,s1,r83/1:/{Table/Max-Max}] evaluated request
| 0.271ms 0.011ms event:kv/kvserver/replica_raft.go:188 [n1,s1,r83/1:/{Table/Max-Max}] proposing command to write 0 new keys, 1 new values, 0 new intents, write batch size=48 bytes
| 0.281ms 0.010ms event:kv/kvserver/replica_raft.go:300 [n1,s1,r83/1:/{Table/Max-Max}] acquiring proposal quota (198 bytes)
| 0.294ms 0.013ms event:kv/kvserver/replica_raft.go:489 [n1,s1,r83/1:/{Table/Max-Max}] submitting proposal to proposal buffer
| 0.319ms 0.026ms event:kv/kvserver/replica_proposal_buf.go:561 [n1,s1,r83/1:/{Table/Max-Max}] flushing proposal to Raft
| 0.323ms 0.004ms === operation:raft trace gid:13926 _verbose:1 node:1 store:1 range:83/1:/{Table/Max-Max}
| 0.342ms 0.019ms event:kv/kvserver/replica_proposal_buf.go:1135 [n1,s1,r83/1:/{Table/Max-Max}] registering local trace i5864/10a6.34fc
| 0.366ms 0.024ms event:kv/kvserver/replica_raft.go:1991 [n1,s1,r83/1:/{Table/Max-Max}] 1->2 MsgApp Term:6 Log:6/5862 Entries:[5863-5864]
| 0.387ms 0.021ms event:kv/kvserver/replica_raft.go:1991 [n1,s1,r83/1:/{Table/Max-Max}] 1->3 MsgApp Term:6 Log:6/5862 Entries:[5863-5864]
| 0.401ms 0.014ms event:kv/kvserver/replica_raft.go:1218 [n1,s1,r83/1:/{Table/Max-Max}] appended entries [5863-5864] at leader term 6
| 0.430ms 0.029ms event:kv/kvserver/replica_raft.go:1970 [n1,s1,r83/1:/{Table/Max-Max}] synced log storage write at mark {Term:6 Index:5864}
| 0.595ms 0.165ms event:kv/kvserver/replica_raft.go:678 [n1,s1,r83/1:/{Table/Max-Max}] 3->1 MsgAppResp Term:6 Index:5864
| 0.621ms 0.026ms event:kv/kvserver/replica_raft.go:1086 [n1,s1,r83/1:/{Table/Max-Max}] applying entries
Error types: (1) *withstack.withStack (2) *errutil.leafError
Test: TestRaftTracing/lease-type=LeaseLeader
--- FAIL: TestRaftTracing/lease-type=LeaseLeader (1.73s)
```

Parameters:
- attempt=1
- run=7
- shard=45
Help

See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)

/cc @cockroachdb/kv-triage

[This test on roachdash](https://roachdash.crdb.dev/?filter=status:open%20t:.*TestRaftTracing.*&sort=title+created&display=lastcommented+project) | [Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/bazci/githubpost/issues)

Jira issue: CRDB-63986