MySQL 并行复制从库更新的记录不存在实际却存在

程序员文章站 2022-06-24 21:51:03

并行复制从库更新的记录不存在实际却存在背景开了并行复制的半同步从库SQL 线程报1032错误，异步复制从库没有报错，偶尔会出现这种分析版本mysql 5.7.16 mysql show variables like '%slave_para%'; + + + | Variable_name ......

并行复制从库更新的记录不存在实际却存在

背景

开了并行复制的半同步从库SQL 线程报1032错误，异步复制从库没有报错，偶尔会出现这种

分析

2018-04-03T10:11:47.720156+08:00 16 [ERROR] Slave SQL for channel '': Worker 13 failed executing transaction 'a272bbcf-874f-11e7-a288-00505695b721:687871861' at master log mysql-bin.004119, end_log_pos 376471678; Could not execute Update_rows event on table anytxn.seq_xxxx; Can't find record in 'seq_xxxx', Error_code: 1032; handler error HA_ERR_END_OF_FILE; the event's master log mysql-bin.004119, end_log_pos 376471678, Error_code: 1032

2018-04-03T10:11:47.720230+08:00 2 [Warning] Slave SQL for channel '': ... The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to problems. In such cases you have to examine your data (see documentation for details). Error_code: 1756
2018-04-03T10:11:47.720959+08:00 2 [Note] Error reading relay log event for channel '': slave SQL thread was killed

3、从 SQL线程停止的position分析binlog发现

SET @@SESSION.GTID_NEXT= 'a272bbcf-874f-11e7-a288-00505695b721:687871861'/*!*/;
# at 376471694
#180403 10:11:47 server id 104073  end_log_pos 376471555 CRC32 0x1be91176   Query   thread_id=2086049   exec_time=0 error_code=0
SET TIMESTAMP=1522721507/*!*/;
BEGIN
/*!*/;
# at 376471768
#180403 10:11:47 server id 104073  end_log_pos 376471616 CRC32 0x10644d77   Table_map: `anytxn`.`seq_xxxx` mapped to number 301
# at 376471829
#180403 10:11:47 server id 104073  end_log_pos 376471678 CRC32 0x871a9787   Update_rows: table id 301 flags: STMT_END_F

### UPDATE `anytxn`.`seq_xxxx`
### WHERE
###   @1=7116088 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2=1 /* INT meta=0 nullable=0 is_null=0 */
### SET
###   @1=7116089 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2=1 /* INT meta=0 nullable=0 is_null=0 */
# at 376471891
#180403 10:11:47 server id 104073  end_log_pos 376471709 CRC32 0x9eb59238   Xid = 22247621418
COMMIT/*!*/;
# at 376471922
#180403 10:11:47 server id 104073  end_log_pos 376471774 CRC32 0xf7b6ad5d   GTID    last_committed=641254   sequence_number=641259
SET @@SESSION.GTID_NEXT= 'a272bbcf-874f-11e7-a288-00505695b721:687871862'/*!*/;
# at 376471987
#180403 10:11:47 server id 104073  end_log_pos 376471856 CRC32 0x6256de00   Query   thread_id=2085350   exec_time=0 error_code=0
SET TIMESTAMP=1522721507/*!*/;
BEGIN
/*!*/;
# at 376472069
#180403 10:11:47 server id 104073  end_log_pos 376471979 CRC32 0x6c329578   Table_map: `anytxn`.`bm_cc_customer_address_info` mapped to number 1569
# at 376472192
#180403 10:11:47 server id 104073  end_log_pos 376472162 CRC32 0x834cc8b9   Write_rows: table id 1569 flags: STMT_END_F


### INSERT INTO `anytxn`.`bm_xxxxxxxxxxxxxx`
### SET
###   @1=14480779 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='0000001002380654' /* STRING(96) meta=65120 nullable=0 is_null=0 */
###   @3='B001' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */
###   @4=NULL /* STRING(12) meta=65036 nullable=1 is_null=1 */
###   @5='10000010001202000000001' /* VARSTRING(96) meta=96 nullable=1 is_null=0 */
###   @6='B00' /* STRING(9) meta=65033 nullable=1 is_null=0 */
###   @7='xxxxxxxxxxx' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */
###   @8=NULL /* STRING(18) meta=65042 nullable=1 is_null=1 */
###   @9=NULL /* STRING(18) meta=65042 nullable=1 is_null=1 */
###   @10=NULL /* STRING(18) meta=65042 nullable=1 is_null=1 */

 mysql@ACSXFDB6.xwbank.com:/home/mysql>  mysqlbinlog -v -v --start-datetime='2018-04-03 10:11:45' --stop-datetime='2018-04-03 10:11:48'  /data/mysql/ACSXFDB6-relay-bin.005477 | grep last_comm | grep 10:11:47 | grep 641254
#180403 10:11:47 server id 104073  end_log_pos 376469618 CRC32 0xb6dc6cef   GTID    last_committed=641227   sequence_number=641254
#180403 10:11:47 server id 104073  end_log_pos 376471774 CRC32 0xf7b6ad5d   GTID    last_committed=641254   sequence_number=641259
#180403 10:11:47 server id 104073  end_log_pos 376472258 CRC32 0x27cf3013   GTID    last_committed=641254   sequence_number=641260

从上面信息可以看出，发生更新记录不存在是在更新anytxn.seq_xxxx表的标识为7116088 的记录
有两个并发提交的事务last_committed=641254 ，与发现更新的记录不存在的 687871861 事务还有提交的事务 sequence_number=641260（即insert另一张表的操作）

4、查看更新的记录不存在的表和相关记录

show create table seq_xxxx;
| seq_xxxx | CREATE TABLE seq_xxxx (
currentValue bigint(20) NOT NULL,
increment int(11) NOT NULL DEFAULT '1'

mysql> select * from seq_xxxx;
+--------------+-----------+
| currentValue | increment |
+--------------+-----------+
| 7116088 | 1 |
+--------------+-----------+
可以发现实际数据库中是存在该记录的

测试

mysql> select @@version;
+------------+
| @@version |
+------------+
| 5.7.19-log |
+------------+
1 row in set (0.00 sec)
mysql> show variables like '%para%';
+------------------------+---------------+
| Variable_name | Value |
+------------------------+---------------+
| slave_parallel_type | LOGICAL_CLOCK |
| slave_parallel_workers | 4 |
+------------------------+---------------+

sysbench /usr/share/sysbench/tests/include/oltp_legacy/oltp.lua --mysql-host=10.186.30.73 --mysql-socket=/opt/mysql/data/3307/mysqld.sock --mysql-port=3307  --db-driver=mysql  --mysql-db=test --mysql-user=admin --mysql-password=admin --table_size=100000 --tables=5 --threads=100 --time=120 --report-interval=5  run

有并发提交的事务，但没有模拟重现出更新的记录不存在，但在库中却存在的情况
MySQL 并行复制从库更新的记录不存在实际却存在

上一篇：贵州所有专科大学排名及录取分数线2021最新名单（2022年文科参考）

下一篇：翻译：delete语句(已提交到MariaDB官方手册)