sysbench read_write场景6002

【 使用环境 】测试环境
【 OB or 其他组件 】OB
【 使用版本 】

mysql> select version();
+------------------------------+
| version()                    |
+------------------------------+
| 5.7.25-OceanBase_CE-v4.3.5.5 |
+------------------------------+
1 row in set (0.01 sec)

【问题描述】

在 sysbench 的 read_write 场景压测中,未指定 --rand-type=uniform 参数时,会频繁复现 6002(Transaction rollbacked)错误,但该问题在 MySQL、TiDB 的压测中(天级别长时间压测)均未出现。出于对潜在风险的担忧,想知道该错误的根本原因。

该问题已在多个 OceanBase 版本中出现(暂不确定是否覆盖所有版本),此前曾咨询原厂技术人员并在社区发帖求助,但未获得最终结论。社区内也有多个同类问题反馈,普遍建议通过添加 --rand-type=uniform 参数规避,但核心原因始终不明确。本次测试 4.3.5.5 版本时,该问题再次复现,特此跟进。

这是上次的发的贴:4.0bp2版本sysbench压测write场景异常退出

报错如下:

FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
[ 1s ] thds: 100 tps: 32.91 qps: 2175.13 (r/w/o: 1801.14/212.43/161.56) lat (ms,95%): 669.89 err/s: 3.99 reconn/s: 0.00
[ 2s ] thds: 100 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
[ 3s ] thds: 100 tps: 4.99 qps: 24.95 (r/w/o: 0.00/19.96/4.99) lat (ms,95%): 2449.36 err/s: 3.99 reconn/s: 0.00
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked
[ 4s ] thds: 100 tps: 18.01 qps: 82.06 (r/w/o: 0.00/64.05/18.01) lat (ms,95%): 3773.42 err/s: 6.00 reconn/s: 0.00
FATAL: mysql_drv_query() returned error 6002 (Transaction rollbacked) for query 'BEGIN'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:405: SQL error, errno = 6002, state = '40000': Transaction rollbacked

【复现路径】

sysbench --db-driver=mysql --threads=100 --time=6000000 --mysql-host=xxx --mysql-port=2883 --mysql-user='xxxx' --mysql-password='xxxx' --report-interval=1 --tables=1 /usr/share/sysbench/ol
tp_read_write.lua run

【附件及日志】

OB_LOG_ob_db01_4_10.112.20.4_20260116150632_20260116153632.zip (2.6 KB)
obdiag_transaction_rollback_20260116152927.tar.gz (7.0 KB)

其中OB_log日志是通过
SELECT trace_id,sql_id,tx_id,ret_code,trans_status FROM GV$OB_SQL_AUDIT
WHERE ret_code = ‘-6002’ ORDER BY request_time desc
查出的trace_id为YB420A701404-0006485517B5A934-0-0,在OCP是查到并下载的日志。

obdiag的日志是通过以下命令查到的:
obdiag rca run --scene=transaction_rollback

【部分结论】

  1. 和obproxy无关:因为是否经过obproxy,都能复现。
1 个赞

Transaction rollbacked错误是死锁导致的
–rand-type=uniform 参数目的是减少锁冲突或者增加sysbench参数:–mysql-ignore-errors=1062,1213,6002 。

我明白, 也知道怎么跳过这个错。我想知道为什么会死锁,OB是兼容MYSQL的,那MYSQL为什么不报错。

ob在进行写入操作时,会加行锁
可以通过select * from __all_virtual_deadlock_event_history order by create_time desc limit 10;查询下锁进行分析

还有进行压测时候qps是一样的吗

select * from __all_virtual_deadlock_event_history order by create_time desc limit 10

1004	18314974427645523740	10.112.20.4	2882	2625	2026-01-19 09:26:13.559477	2	2	witness	normal	18444975287747321183	2026-01-19 09:26:12.213551	0	transaction	{txid:1211790}	{"INT":5047}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	18314974427645523740	10.112.20.4	2882	2622	2026-01-19 09:26:13.559477	1	2	victim	normal	18444975287747226359	2026-01-19 09:26:12.206340	0	transaction	{txid:1211834}	{"INT":5036}	current sql	UPDATE sbtest1 SET c=? WHERE id=?				
1004	4769169147018730319	10.112.20.4	2882	2564	2026-01-19 09:26:11.245582	3	3	witness	normal	18444975287747322240	2026-01-19 09:26:11.737580	0	transaction	{txid:1211739}	{"INT":5032}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	4769169147018730319	10.112.20.4	2882	2562	2026-01-19 09:26:11.245582	2	3	witness	normal	18444975287747322240	2026-01-19 09:26:11.686700	0	transaction	{txid:1211738}	{"INT":4989}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	17547506817280426076	10.112.20.4	2882	2560	2026-01-19 09:26:12.146793	2	2	witness	normal	18444975287747322240	2026-01-19 09:26:11.616260	0	transaction	{txid:1211730}	{"INT":4996}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	1353316535427706739	10.112.20.4	2882	2554	2026-01-19 09:26:11.367840	4	11	witness	normal	18444975287747322240	2026-01-19 09:26:09.594932	0	transaction	{txid:1211736}	{"INT":5002}	current sql	UPDATE sbtest1 SET c=? WHERE id=?				
1004	1353316535427706739	10.112.20.4	2882	2552	2026-01-19 09:26:11.367840	3	11	witness	normal	18444975287747322240	2026-01-19 09:26:09.592165	0	transaction	{txid:1211733}	{"INT":5043}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	1353316535427706739	10.112.20.4	2882	2548	2026-01-19 09:26:11.367840	1	11	victim	normal	18444975287747318012	2026-01-19 09:26:07.904987	0	transaction	{txid:1211813}	{"INT":5035}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	2301096200578682462	10.112.20.4	2882	2548	2026-01-19 09:26:09.562955	5	8	witness	normal	18444975287747318012	2026-01-19 09:26:07.904987	0	transaction	{txid:1211813}	{"INT":5035}	current sql	DELETE FROM sbtest1 WHERE id=?				
1004	1353316535427706739	10.112.20.4	2882	2541	2026-01-19 09:26:11.367840	9	11	witness	normal	18444975287747321183	2026-01-19 09:26:07.904738	0	transaction	{txid:1211769}	{"INT":5003}	current sql	UPDATE sbtest1 SET c=? WHERE id=?				

我没有太理解这句话的意思。 sysbench压测的时候日志有贴子里有,是不是你想要的?

压测时候mysql的qps和ob的qps一样么。正常情况下mysql也会有锁冲突

MYSQL、TIDB(多个版本)都没事。压测过很多次,因为之前有忘了你们哪位兄弟说MYSQL也一样,所以我有针对这个问题特意的对MySQL压过几次,实测是不会出现的。且连着压2、3天也不会出现。事物隔离级别RC、RR都试过,都不会有问题。

而且还有其他的部分MYSQL兼容的国产数据库也不会,因为他们POC压测不压根跳过报错和指定uniform。 我目前遇到这个问题的就只有OB。

其实我线下和你们不同的原厂兄弟也都聊过。有几种反馈:

  1. 有直接确认这个问题存在的,但也没有后文
  2. 也有说行为和mysql一样的,但也拿不出来证据(其实这个如果有的话,也很容易拿出证据,至少大家压测mysql肯定是要加uniform,或者网上会有一堆报错帖子)
  3. 还有说这是我的个案的(大多数). 但是社区有其他的贴子证明不是个案, 且你们官方也明确知道解决这个问题是要加uniform来解决,这就说明不是个案,你们还是有人很清楚这个事。

这个问题我发现的很早了(21年),之前因为没弄清楚这个问题一直不敢用OB,现在基于你们案例这么多,倒是不会担心出大问题。 但没弄清楚之前总归是不放心的。

这是又重新压的mysql,还没有报错。

+-----------------------+----------------+
| Variable_name         | Value          |
+-----------------------+----------------+
| transaction_isolation | READ-COMMITTED |
+-----------------------+----------------+

mysql> select version();
+-----------+
| version() |
+-----------+
| 8.0.43    |
+-----------+
1 row in set (0.00 sec)

sysbench --db-driver=mysql --threads=500 --time=30000000 --mysql-host=10.xxx --mysql-port=3306 --mysql-user='tpcc' --mysql-password='xxx' --report-interval=1 --tables=1 /usr/share/sysbench/oltp_read_write.lua run
[ 27813s ] thds: 500 tps: 578.51 qps: 12209.70 (r/w/o: 8634.57/2378.08/1197.05) lat (ms,95%): 1739.68 err/s: 40.04 reconn/s: 0.00
[ 27814s ] thds: 500 tps: 437.01 qps: 9494.16 (r/w/o: 6791.11/1786.03/917.02) lat (ms,95%): 1618.78 err/s: 41.00 reconn/s: 0.00
[ 27815s ] thds: 500 tps: 478.89 qps: 10012.65 (r/w/o: 7062.34/1963.54/986.77) lat (ms,95%): 1973.38 err/s: 29.99 reconn/s: 0.00

MYSQL一天后正常


[ 87797s ] thds: 500 tps: 451.72 qps: 9602.14 (r/w/o: 6842.82/1823.89/935.43) lat (ms,95%): 1836.24 err/s: 31.98 reconn/s: 0.00
[ 87798s ] thds: 500 tps: 298.17 qps: 6426.57 (r/w/o: 4583.55/1216.68/626.35) lat (ms,95%): 2120.76 err/s: 30.02 reconn/s: 0.00

MYSQL两天后正常

[ 170515s ] thds: 500 tps: 409.06 qps: 8864.19 (r/w/o: 6314.85/1691.23/858.12) lat (ms,95%): 1973.38 err/s: 40.01 reconn/s: 0.00
[ 170516s ] thds: 500 tps: 431.96 qps: 9182.10 (r/w/o: 6535.36/1744.83/901.91) lat (ms,95%): 2238.47 err/s: 37.00 reconn/s: 0.00
[ 170517s ] thds: 500 tps: 398.83 qps: 8487.38 (r/w/o: 6038.43/1625.31/823.65) lat (ms,95%): 2198.52 err/s: 26.99 reconn/s: 0.00
[ 255014s ] thds: 500 tps: 393.04 qps: 8436.88 (r/w/o: 6017.63/1600.17/819.09) lat (ms,95%): 2778.39 err/s: 32.00 reconn/s: 0.00
[ 255015s ] thds: 500 tps: 477.08 qps: 10130.68 (r/w/o: 7201.20/1934.32/995.17) lat (ms,95%): 2120.76 err/s: 40.01 reconn/s: 0.00

[ 453757s ] thds: 500 tps: 360.04 qps: 7693.75 (r/w/o: 5455.53/1487.15/751.07) lat (ms,95%): 2082.91 err/s: 30.00 reconn/s: 0.00
[ 453758s ] thds: 500 tps: 403.75 qps: 8700.52 (r/w/o: 6189.51/1669.70/841.31) lat (ms,95%): 2198.52 err/s: 34.81 reconn/s: 0.00

报错遇到6002情况,多少数据集?表的数量、每个表的函数,并发数,租户的规格这几个信息麻烦提供一下

涨知识

为了排除其他的干扰。专门为这个测试建议的一个租户

  1. 只有一个额外的database :sbtest
  2. 只有一张表:sbtest1 (多张表也能出现,出现的概率会低,1张表很空易出现,且方便排查问题)
  3. 并发:100。 (并发量越大越容易复现问题,从并发5开始就很容易复现,到10开始就要压就会出现)
sysbench --db-driver=mysql --threads=100 --time=6000000 --mysql-host=xxx --mysql-port=2883 --mysql-user='xxxx' --mysql-password='xxxx' --report-interval=1 --tables=1 /usr/share/sysbench/ol
tp_read_write.lua run

  1. 数据量:(少和多都能复现)
mysql> select count(*) from sbtest1;
+----------+
| count(*) |
+----------+
|    10000 |
+----------+
1 row in set (0.01 sec)

mysql> select count(*) from sbtest1;
+------------+
| count(*)   |
+------------+
| 1963180220 |
+------------+
1 row in set (2 min 20.91 sec)

  1. 没有其他的函数,整个租户就这一张表,还是sysbench给创建的
  2. sysbench版本:1.0.20
  3. 和obproxy无关 :已经验证,是否直连都能复现。
  4. zone当前优先级:zone1; zone2,zone3 。 (已经验证无关,随机或固定到某个zone,都会出现)
  5. 当前租户规格(6C20G) (和租户规格无关,扩大到12C40G也能复现)
  6. unit_num:1 (无关,扩到2也能复现)
  7. 和社区版无关(企业版也可以复现)

涨知识

这个问题,与跟数据集小有一定关系 数据集大uniform更随机些产生锁冲突几率小些。ob与mysql死锁检测上行为存在差异,不影响业务使用的
具体原因如下图所示 328事务持有5002行锁,5019行被其他事务占锁。326事务持有5019行锁,5035行被其他事务占锁。


推荐你使用sysbench1.1版本以上压测试试

  1. 官网能不能出一个针对这个锁机制差异的理论介绍?
  2. "不影响业务使用”这个结论我大概相信,但我无法通过专业理论让别人也相信这个结论。

3.数据量变大,也一样报错,很容易。

mysql> select count(*) from sbtest1;
+------------+
| count(*)   |
+------------+
| 1963180220 |
+------------+

  1. 升级sysbench版本对这个问题的本质没有意义。我不是为了解决报错,而是要弄清楚为什么和mysql的行为有差异。升级版本即使不报错,也和加Uniform一样,只是跳过这个问题。

分析

observer sysbench和mysql表现不同的原因是 ob 与 mysql在发生死锁之后的行为不兼容,ob需要手动执行rollback才能开启新的事务否则会报-6002,而mysql在新的begin语句到来时会自动新开启一个事务。导致了在sysbench下表现不同。也有其他客户遇到相同的问题。
ob从3.x死锁检测功能有已来都是这个表现,近期暂无兼容的计划。