1背景

最近在使用 BenchmarkSQL[1] 工具對(duì) MySQL 進(jìn)行性能測(cè)試的過(guò)程中，遇到一個(gè)比較有意思的問(wèn)題，Share 給大家。

BenchmarkSQL 是一款經(jīng)典的開源數(shù)據(jù)庫(kù)測(cè)試工具，內(nèi)含了TPC-C測(cè)試腳本，可支持 Oracle、MySQL、PostgreSQL、SQL Server以及一些國(guó)產(chǎn)數(shù)據(jù)庫(kù)的基準(zhǔn)測(cè)試。

2問(wèn)題描述

如下圖，在使用 BenchmarkSQL（版本為 5.0）壓測(cè)一段時(shí)間后，會(huì)出現(xiàn)卡住的現(xiàn)象，即 tpm TOTAL 的值不再發(fā)生變化，但通過(guò) top 命令觀測(cè)到 MySQL 當(dāng)前的壓力還是很大。

登錄 MySQL，通過(guò) information_schema.innodb_trx 表可以看到，MySQL 一直在重復(fù)執(zhí)行這兩個(gè) SQL：

mysql> select * from information_schema.innodb_trx\G
*************************** 1. row ***************************
                    trx_id: 685907
                 trx_state: RUNNING
               trx_started: 2024-05-28 11:14:21
     trx_requested_lock_id: NULL
          trx_wait_started: NULL
                trx_weight: 2
       trx_mysql_thread_id: 157
                 trx_query: SELECT no_o_id FROM bmsql_new_order WHERE no_w_id = 1 AND no_d_id = 1 ORDER BY no_o_id ASC
       trx_operation_state: NULL
         trx_tables_in_use: 0
         trx_tables_locked: 1
          trx_lock_structs: 2
     trx_lock_memory_bytes: 1128
           trx_rows_locked: 1
         trx_rows_modified: 0
   trx_concurrency_tickets: 0
       trx_isolation_level: REPEATABLE READ
         trx_unique_checks: 1
    trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 0
          trx_is_read_only: 0
trx_autocommit_non_locking: 0
       trx_schedule_weight: NULL
1 row in set (0.00 sec)
mysql> select * from information_schema.innodb_trx\G
*************************** 1. row ***************************
                    trx_id: 685907
                 trx_state: RUNNING
               trx_started: 2024-05-28 11:14:21
     trx_requested_lock_id: NULL
          trx_wait_started: NULL
                trx_weight: 2
       trx_mysql_thread_id: 157
                 trx_query: DELETE FROM bmsql_new_order WHERE no_w_id = 1 AND no_d_id = 1 AND no_o_id = 2102
       trx_operation_state: NULL
         trx_tables_in_use: 1
         trx_tables_locked: 1
          trx_lock_structs: 2
     trx_lock_memory_bytes: 1128
           trx_rows_locked: 1
         trx_rows_modified: 0
   trx_concurrency_tickets: 0
       trx_isolation_level: REPEATABLE READ
         trx_unique_checks: 1
    trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 0
          trx_is_read_only: 0
trx_autocommit_non_locking: 0
       trx_schedule_weight: NULL
1 row in set (0.00 sec)

多次執(zhí)行 show master status\G 也可以看到 GTID 不再發(fā)生變化。為了更好的分析，打開 MySQL 的 general log 后重新壓測(cè)抓取 SQL：

可以看到確實(shí)出現(xiàn)了重復(fù) DELETE FROM 和 SELECT 的情況，再往前多看幾個(gè)事務(wù)，你會(huì)發(fā)現(xiàn)前幾個(gè)事務(wù)均對(duì) 2102 這條記錄進(jìn)行了 DELETE 的操作。

3源碼探索

為什么會(huì)有這種類似死循環(huán)的情況出現(xiàn)呢？懷著探索精神，我們一起去看看 BenchmarkSQL 的源代碼。

• 首先下載對(duì)應(yīng)的源碼包，通過(guò) for 循環(huán)找出 SQL 文件對(duì)應(yīng)的代碼文件。

[root@lucky src]$ pwd
/root/packages/BenchmarkSQL-5.0/src

[root@lucky src]$ for dic in client  jdbc  LoadData  OSCollector
do
 echo $dic
 for file in `ls $dic`
 do
     echo $file && cat $dic/$file | grep -Ein 'bmsql_customer|grep bmsql_customer|bmsql_customer|bmsql_oorder|bmsql_new_order|bmsql_order_line|bmsql_stock|bmsql_item|bmsql_history'
 done
done

• 執(zhí)行以上命令，可以定位到事務(wù) SQL 的代碼在 ./client/jTPCCConnection.java 文件中，通過(guò)搜索 DELETE FROM bmsql_new_order 和 SELECT no_o_id FROM bmsql_new_order，找到對(duì)應(yīng)的 stmtDeliveryBGSelectOldestNewOrder 和 stmtDeliveryBGDeleteOldestNewOrder 關(guān)鍵字。

圖片

• 再次通過(guò)關(guān)鍵字 stmtDeliveryBGDeleteOldestNewOrder 搜索，最終可以定位到 ./BenchmarkSQL-5.0/src/client/jTPCCTData.java 的這部分代碼：

圖片

看到這部分注釋，也許你已經(jīng)知道了問(wèn)題所在，下面我們結(jié)合代碼、注釋和實(shí)驗(yàn)，來(lái)探究卡住的原因。

• 事務(wù)A：DELETE FROM bmsql_new_order WHERE no_w_id = 1 AND no_d_id = 1 AND no_o_id = 2102;
• 事務(wù)B：DELETE FROM bmsql_new_order WHERE no_w_id = 1 AND no_d_id = 1 AND no_o_id = 2102;執(zhí)行時(shí)被阻塞。
• 事務(wù)A：提交。
• 事務(wù)B：繼續(xù)執(zhí)行 DELETE 語(yǔ)句，但因?yàn)槭聞?wù)A已經(jīng)刪除了這行數(shù)據(jù)，故刪除的記錄數(shù)為 0。BenchmarkSQL 中使用了 JDBC 的 executeUpdate() 方法，該方法會(huì)返回一個(gè) INT 類型的值，即本次操作在數(shù)據(jù)庫(kù)中改變的行數(shù)。
• 結(jié)合代碼分析，在執(zhí)行 stmt2.executeUpdate() 后，rc=0，o_id=-1。又因?yàn)?o_id<0，故執(zhí)行了 continue，繼續(xù)下一個(gè) while 循環(huán)。

// 重點(diǎn)簡(jiǎn)要代碼
while (o_id < 0)
{
   rs = stmt1.executeQuery();
   rc = stmt2.executeUpdate();
   if (rc == 0)
   {
       o_id = -1;
   }
}

if (o_id < 0)
{
   continue;
}

6. 因?yàn)楫?dāng)前隔離級(jí)別配置為 REPEATABLE-READ 級(jí)別，故在同一事務(wù)中執(zhí)行 SELECT no_o_id FROM bmsql_new_order ...ASC 進(jìn)行排序后，查詢結(jié)果依舊為 no_o_id=2102 的數(shù)據(jù)，由此 rc 再次被賦值為 0，進(jìn)入到無(wú)限的 while 死循環(huán)中。

4場(chǎng)景實(shí)驗(yàn)

下面我們基于 REPEATABLE-READ 級(jí)別和 READ-COMMITTED 級(jí)別，進(jìn)行類似場(chǎng)景的實(shí)驗(yàn)。

1） REPEATABLE-READ 場(chǎng)景

2）READ-COMMITTED 場(chǎng)景

5總結(jié)

由此我們可以得出結(jié)論，因?yàn)?MySQL 配置的隔離級(jí)別是 REPEATABLE-READ，導(dǎo)致 BenchmarkSQL 出現(xiàn)了死循環(huán)的問(wèn)題，將其修改為 READ-COMMITTED 級(jí)別后，問(wèn)題得以解決。

參考資料

[1]benchmarksql: https://benchmarksql.readthedocs.io/en/latest/