Reasons for Significant Speed Fluctuations Between Statements Updating the Same Table

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: 更新同一张表的语句间速度浮动很大的原因

| username: Qiuchi

[TiDB Version] 6.5
When using an auto-increment primary key to update the same table, sometimes it takes 1ms per row, and sometimes it takes 10ms per row, with no other load on the database during this period.
When it takes 1ms, the disk IO usage is below 10%, and when it takes 10ms, the related kv IO usage increases to 90%. How can I identify the cause of this phenomenon?

In the execution plans, the 1ms one has a lock mark on the point get, while the 10ms one does not.

# 1ms
	id            	task	estRows	operator info                                      	actRows	execution info                                                                                                                                                                                                                                                                                  	memory 	disk
	Update_6      	root	0      	N/A                                                	0      	time:504µs, loops:1, lock_keys: {time:384.3µs, region:1, keys:1, slowest_rpc: {total: 0.000s, region_id: 2110830, store: 10.120.33.66:20160, tikv_wall_time: 129.2µs, scan_detail: {get_snapshot_time: 8.78µs, rocksdb: {block: {cache_hit_count: 9}}}, }, lock_rpc:364.748µs, rpc_count:1}	8.85 KB	N/A
	└─Point_Get_10	root	1      	table:cr_customer_position, handle:8033706093, lock	1      	time:405.5µs, loops:2                                                                                                                                                                                                                                                                          	N/A    	N/A

# 10ms
	id           	task	estRows	operator info                                	actRows	execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         	memory 	disk
	Update_4     	root	0      	N/A                                          	0      	time:880.2µs, loops:1, commit_txn: {prewrite:14ms, slowest_prewrite_rpc: {total: 0.014s, region_id: 1911628, store: 10.120.33.66:20160, tikv_wall_time: 13.6ms, scan_detail: {get_snapshot_time: 20.4µs, rocksdb: {block: {cache_hit_count: 15, read_count: 2, read_byte: 4.76 MB, read_time: 4.87ms}}}, write_detail: {store_batch_wait: 142.5µs, propose_send_wait: 0s, persist_log: {total: 2.69ms, write_leader_wait: 72ns, sync_log: 2.61ms, write_memtable: 16.5µs}, commit_log: 2.78ms, apply_batch_wait: 22.3µs, apply: {total:88.1µs, mutex_lock: 0s, write_leader_wait: 0s, write_wal: 22.3µs, write_memtable: 13.3µs}}}, region_num:3, write_keys:5, write_byte:752}	8.86 KB	N/A
	└─Point_Get_6	root	1      	table:cr_customer_position, handle:8032919450	1      	time:721.6µs, loops:2, Get:{num_rpc:1, total_time:688.6µs}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           	N/A    	N/A

The table has an auto-increment primary key, 4 secondary indexes, 50 fields, and 4 fields are updated during the update.


| username: Running | Original post link

Is it a single TiKV node? Could it be that the disk IO performance of each node is different, or is there jitter during the data partitioning process?

| username: Qiuchi | Original post link

There are six KVs, and the ones with high IO are three of them. Is it related to region distribution? The disk capacity and performance of each node are the same.

Not exactly, all KV IOs will increase, but three of them increase more significantly.

| username: tidb菜鸟一只 | Original post link

Take a look at the corresponding SQL on the dashboard page to see where it is slow?

| username: Qiuchi | Original post link

1ms seems to have incomplete statistics for some reason, and what’s strange is that for the 10ms one, its actRows=2, but that field is a primary key and should only have one row. The number of cumulative retries is also high.

This is the 1ms one

This is the 10ms one

| username: Holland | Original post link

Check if there are any write hotspots. Auto-increment primary keys can easily cause write hotspots, so you can change it to auto_random.
See if this document helps: TiDB 热点问题处理 | PingCAP 文档中心

| username: Qiuchi | Original post link

It doesn’t seem to be due to writing hotspots. I updated the problem description, and their execution plans look quite different.

| username: wzf0072 | Original post link

10ms: region_num:3, write_keys:5, write_byte:752
1ms: I didn’t see the corresponding data. Could it be that the data didn’t change before and after the modification?

| username: wzf0072 | Original post link

Sorry, I can’t translate the content from the image. Please provide the text you need translated.

| username: h5n1 | Original post link

The disk performance doesn’t seem very high, and any changes in IO affect Prewrite.

| username: Qiuchi | Original post link

This indeed updates the data.

| username: Qiuchi | Original post link

That’s true, but why is there such a big difference in IO for the same operation?

| username: wzf0072 | Original post link

At 1ms, it only locked, while the 10ms execution plan includes the time taken for the prewrite phase in the 2PC transaction commit stage, which is 14ms.

| username: wzf0072 | Original post link

The image is not visible. Please provide the text you need translated.

| username: Qiuchi | Original post link

The 2PC write for the former SQL should be at the client commit, right? But why does the latter cause an increase in IO?

| username: wzf0072 | Original post link

The IO peak lasted for several minutes, so it is highly unlikely that it was caused by these two updates.

| username: Qiuchi | Original post link

This is the same SQL running continuously, with approximately 6 million records needing to be updated.

| username: wzf0072 | Original post link

If the updates are on the same table, monitor the growth in the number of regions for that table on each TiKV node to see if it is proportional to the IO load.

| username: Qiuchi | Original post link

The IO load ratio is indeed concentrated on three KV nodes, but this is not the main issue. I suspect that even if the regions are evenly distributed across all KVs, my storage IO will still be maxed out. Now, after turning off auto-commit, the IO remains below 20% during the same operations, and there is no significant IO spike during commits. So, the main thing I want to know now is what is causing this. If both scenarios involve disk write operations, why is the cost of disk writes much higher with auto-commit?

| username: wzf0072 | Original post link

This is somewhat similar to your issue.

Why is the cost of automatic commit to disk much higher?
Commit has a cost.