mysql error日志大量打印，日志巨大

原创黄超 2021-08-23

1661

现象：mysql版本是5.7.26 企业版
mysql的error日志:

2021-04-14T23:00:55.725983Z 1842327 [Warning] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:207384205' at master log mysql-bin.000200, end_log_pos 361561314; Error executing row event: 'Deadlock found when trying to get lock; try restarting transaction', Error_code: 1213
2021-04-14T23:00:55.734483Z 1842327 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:207384205' at master log mysql-bin.000200, end_log_pos 361561660; Could not execute Query event. Detailed error: When @@SESSION.GTID_NEXT is set to a GTID, you must explicitly set it to a different value after a COMMIT or ROLLBACK. Please check GTID_NEXT variable manual page for detailed explanation. Current @@SESSION.GTID_NEXT is '3f6558f9-632b-11ea-a4d3-fa163e7c1636:207384205'.;, Error_code: 1837
2021-04-14T23:00:55.741502Z 1842327 [ERROR] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:207384205' at master log mysql-bin.000200, end_log_pos 361561824; Error executing XA PREPARE event: 'When @@SESSION.GTID_NEXT is set to a GTID, you must explicitly set it to a different value after a COMMIT or ROLLBACK. Please check GTID_NEXT variable manual page for detailed explanation. Current @@SESSION.GTID_NEXT is '3f6558f9-632b-11ea-a4d3-fa163e7c1636:207384205'.', Error_code: 1837
2021-04-14T23:00:55.741550Z 1842325 [Warning] Slave SQL for channel 'ccvv1': ... 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
2021-04-14T23:00:55.752161Z 1842325 [Note] Slave SQL thread for channel 'ccvv1' exiting, replication stopped in log 'mysql-bin.000200' at position 361520253  'mysql-bin.000200', position 376052731
2021-04-14T23:01:56.998327Z 1842030 [Note] Slave I/O thread killed while reading event for channel 'ccvv1'
2021-04-14T23:01:56.998352Z 1842030 [Note] Slave I/O thread exiting for channel 'ccvv1', read up to log 'mysql-bin.000200', position 376052731
2021-04-14T23:01:57.242254Z 2152187 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2021-04-14T23:01:57.261221Z 2152188 [Note] Slave SQL thread for channel 'ccvv1' initialized, starting replication in log 'FIRST' at position 0, relay log 'relay-bin-ccvv1.000001' position: 4
2021-04-14T23:01:57.294664Z 2152187 [Note] Slave I/O thread for channel 'ccvv1': connected to master 'rpl_user@10.1.1.6:3310',replication started in log 'FIRST' at position 4
2021-04-14T23:01:57.385640Z 2152189 [Note] Slave SQL for channel 'ccvv1': Worker 1 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925023' at master log mysql-bin.000200, end_log_pos 2184; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-1ECDBD945A9DEB618CF001000200D23A-0-2021-04-14 19:49:53' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 2184, Error_code: 1062
2021-04-14T23:01:57.391201Z 2152191 [Note] Slave SQL for channel 'ccvv1': Worker 3 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925029' at master log mysql-bin.000200, end_log_pos 7389; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '30-94E7DEC49D5A71EB9543t.schulzmartine-0-2021-04-14 19:49:56' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 7389, Error_code: 1062
2021-04-14T23:01:57.391218Z 2152192 [Note] Slave SQL for channel 'ccvv1': Worker 4 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925030' at master log mysql-bin.000200, end_log_pos 9413; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-7C8DF4945A9DEB618B7F01000100E039-0-2021-04-14 19:49:56' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 9413, Error_code: 1062
2021-04-14T23:01:57.392256Z 2152194 [Note] Slave SQL for channel 'ccvv1': Worker 6 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925032' at master log mysql-bin.000200, end_log_pos 10061; Could not execute Write_rows event on table bss_1234.p_tss; Duplicate entry '1517841786-2021-04-14 19:49:54' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 10061, Error_code: 1062
2021-04-14T23:01:57.392827Z 2152190 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925028' at master log mysql-bin.000200, end_log_pos 5399; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-B278D8945A9DEB61BF65010001001537-0-2021-04-14 19:49:56' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 5399, Error_code: 1062
2021-04-14T23:01:57.394427Z 2152190 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925034' at master log mysql-bin.000200, end_log_pos 10710; Could not execute Write_rows event on table bss_1234.p_tss; Duplicate entry '1517846580-2021-04-14 19:49:54' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 10710, Error_code: 1062
2021-04-14T23:01:57.396035Z 2152192 [Note] Slave SQL for channel 'ccvv1': Worker 4 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925040' at master log mysql-bin.000200, end_log_pos 15950; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-32172D955A9DEB618B7F01000100E039-0-2021-04-14 19:49:57' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 15950, Error_code: 1062
2021-04-14T23:01:57.396515Z 2152190 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925038' at master log mysql-bin.000200, end_log_pos 13630; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-34EE0D955A9DEB61BF65010001001537-0-2021-04-14 19:49:53' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 13630, Error_code: 1062
2021-04-14T23:01:57.401497Z 2152190 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925048' at master log mysql-bin.000200, end_log_pos 20058; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-70FD44955A9DEB61BF65010001001537-0-2021-04-14 19:49:57' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 20058, Error_code: 1062
2021-04-14T23:01:57.404568Z 2152191 [Note] Slave SQL for channel 'ccvv1': Worker 3 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925057' at master log mysql-bin.000200, end_log_pos 26161; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-CEB26D955A9DEB618B7F01000100E039-0-2021-04-14 19:49:54' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 26161, Error_code: 1062
2021-04-14T23:01:57.404606Z 2152192 [Note] Slave SQL for channel 'ccvv1': Worker 4 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925058' at master log mysql-bin.000200, end_log_pos 28174; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-1A7B77955A9DEB61BF65010001001537-0-2021-04-14 19:49:54' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 28174, Error_code: 1062
2021-04-14T23:01:57.404910Z 2152193 [Note] Slave SQL for channel 'ccvv1': Worker 5 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925059' at master log mysql-bin.000200, end_log_pos 30172; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-D24D7E955A9DEB61876A010000008F3A-0-2021-04-14 19:49:57' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 30172, Error_code: 1062
2021-04-14T23:01:57.405189Z 2152194 [Note] Slave SQL for channel 'ccvv1': Worker 6 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925060' at master log mysql-bin.000200, end_log_pos 32184; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-BC467D955A9DEB61B47D01000200213A-0-2021-04-14 19:49:54' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 32184, Error_code: 1062
2021-04-14T23:01:57.405611Z 2152190 [Note] Slave SQL for channel 'ccvv1': Worker 2 failed executing transaction '3f6558f9-632b-11ea-a4d3-fa163e7c1636:206925056' at master log mysql-bin.000200, end_log_pos 24170; Could not execute Write_rows event on table bss_1234.dd_log_3; Duplicate entry '20-76A05F955A9DEB618B7F01000100E039-0-2021-04-14 19:49:57' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000200, end_log_pos 24170, Error_code: 1062
复制

分析:
从库同步复制SQL thread遇到死锁，超时回滚事务，内存里面的gtid丢失，同步通道中断，重新拉起slave同步，同步从log mysql-bin.000200的头部重新拉数据，数据同步冲突打印日志。日志巨大，已经几十个G，还在打印。
查看atop日志，当时有mysqlbackup在全量备份，同时mysql在跑批量业务.

解决：
1.通过主库全量物理备份数据，到备库全量恢复，配置同步复制。
2.备份error日志，然后注空日志文件.
3.备份脚本上加上参数–no-locking，不进行全局锁表，不造成锁冲突。
4.调整备份时间，在业务低峰执行，减少影响。

mysql