High apply wait tail latency

[Connor1996]

As you can see, the append log duration and apply log duration is 100ms at most, whereas, the apply wait duration is quite high reaching 5s. Indeed, it was a write hotspot at the time.

The write flow of append and apply should be nearly the same. As no slow in raft append process, raft apply wait shouldn't be that large.

[Connor1996]

It turns out the io flow difference between raft-engine and kvdb. As raft-engine performs lz4 compression on write while kvdb doesn't enable wal compression, the size after compression would be quite small if the data of high rate of repetition

[LykxSassinator]

Wait for enhancements in the later work.

[tonyxuqqi]

cc @v01dstar After rocksdb is upgraded and WAL compression is supported, this issue should be mitigated.

[mzygQAQ]

@tonyxuqqi @Connor1996 May I ask, what are the possible reasons for high apply wait? I have a TikV cluster here, and the applyWaitDuration P99 can reach 3-5 seconds, but the applyDuration not slow, (1-2ms P99)  The number of threads in the apply pool is 4, and I have checked their CPU consumption, which is approximately 20% per thread. The machine level CPU idle is also very high.  I am unable to identify the cause and make improvements. I checked the code and found that the apply wait duration measures the time a Committed Entry spends in the Apply BatchSystem (pending in the queue), but I don't know why it's so slow. Can you help me, thanks !

[LykxSassinator]

There are several clues for u to do the further investigation:

• Write conflicts on fetching mutex in Rocksdb are frequent. Check the perf metrics of Rocksdb.write in TiKV-Details / Raft Propose / Perf Context Duration to see whether the duration on apply-xxx is high. If these metrics are high, u can check whether there are too many flushes or too many ingestion of sst files caused by applying snapshots.
• Heavy writes. Check the memory usage of raftstore.raft-entry in the Server / Memory Trace panel to see whether there are too many writes in a short time.
• Busy on loading evicted raft entries from Disk. Check the metrics Raft Entry Cache Evicts in the Server / Memory Trace panel, and do the double check on the RaftEngine / Operation panel. If there are too many loading operations, u will see it on the read_entry label.

[mzygQAQ]

@LykxSassinator In my scenario, apply is fast, but apply_wait is high. it think that apply_wait be the time it stays in the queue? Shouldn't it involve the Rocksdb Mutex and load entry eviced what you mentioned?

[LykxSassinator]

@guoxiangCN Pls check the others mentioned above.

[LykxSassinator]

https://github.com/tikv/tikv/pull/17408 is made to mitigate the issue where apply wait latency is high when merging numerous small regions.