[TiKV] Latency Tracing

[nate-double-u]

TiKV is an open-source, distributed, and transactional key-value database. TiKV is widely used in many mission-critical scenarios that require request latency to be below a single millisecond level, so knowing where the latency has consumed is important. This project is going to let TiKV has the ability to observe the latency composition and diagnose slow requests. CPU-bound requests in TiKV, such as coprocessor requests, are executed at the requested granularity, which is relatively convenient to trace. However, for IO-bound requests in TiKV, such as prewrite requests, batch processing has been introduced to improve IO throughput, which will bring some challenges to trace since it's a scenario not covered by most tracing frameworks. Also, we need to fetch statistics from RocksDB, the storage engine powering TiKV, to provide further tracing details for IO-bound requests.

Mentor(s): Zhenchi (@zhongzc), breeswish (@breeswish)

https://github.com/cncf/mentoring/blob/main/summerofcode/2022.md#latency-tracing

[shota-kizawa]

@hzxuzhonghu @breeswish (and other experts)

Hi! My name is Shota. I'm preparing to apply for the GSoC. There are a few confirmations and requests.

1. Goal of this issue
   I recognized that the goal of this issue is to be able to see TiKV trace graphs, slow query logs, etc. from the Jaeger UI and Datadog dashboard when the TiUP or TiDB Operator trace switch is turned on.To achieve it, we will implement features to send reports to Jaeger or datadog by using minitrace-rust.
   For each query (trace id), we will collect the following information

   • Counts of parses, executions, and fetches
   • CPU time and elapsed time (latency)
   • Number of rows processed
   • Each commit and rollback
   • Summary of wait events for each SQL statement
   • Row operations showing the actual execution plan for each SQL statement
   • Number of physical reads, physical writes, and elapsed time for each row operation

   Please advise me if I make a mistake or have anything to add.

2. status of this issue
   I interpreted that most of the design & policy making finished, but implementation is not yet complete.
   (I saw this PR .)
   Please point out if my interpretation is wrong. Also, if you have any advice, please let me know.

3. what I need to research
   List any uncertainties as you make policy decisions and design the project.

If you have any other resources that would be helpful for implementation, please share them with me.

[zhongzc]

TiKV relies on the Multi-Raft provided by Raftstore for data replicating and strong consistency, and RocksDB for persistence. Upper-level callers usually treat these lower-level modules as black boxes and expect them to work as expected. But when a problem arises, it is difficult to quickly and accurately pinpoint the cause if we lack relevant diagnostic data. These low-level modules are the cornerstones of TiKV, and we want to enrich the diagnostic information to help us better diagnose problems and better optimize the performance of TiKV.

The goal here is to enable these low-level engines to provide trace information for individual calls. For example, when we invoke put of RocksDB, the internal execution may include these operations: write WAL, write memtable, wait for mutex, access file system, etc. We care about when these operations happen and how long they take so that we can better investigate the cause when the execution time is abnormal.

To achieve this goal, we can split the task into the following subtasks:

1. How the module generates trace data during execution
2. What structure to place trace data in
3. How to return trace data to the caller

You can choose to start your research with one of Raftstore and RocksDB. If Raftstore is your choice, I recommend focusing on the call chain of RaftCommand. This article can be used as a reference. If it's RocksDB, a deep dive into the call chain of put can be your starting point.