zoukankan      html  css  js  c++  java
  • MySQL Replication--开启GTID模式下匿名事务异常

    错误环境:

    OS: CentOS release 6.5 (Final)

    MySQL: MySQL 5.7.19

    主从参数配置:

    master_info_repository      = TABLE
    relay_log_info_repository   = TABLE
    gtid_mode		    = on
    enforce-gtid-consistency    = true
    log_slave_updates           = 1
    slave-parallel-workers      = 8
    slave-parallel-type         = LOGICAL_CLOCK
    slave_preserve_commit_order = 0

    错误描述:

    从库SQL进程异常停止(从库在此前刚因内存异常重启),报错内容为:

    Last_Errno: 1782
    Last_Error: Error executing row event: '@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.'

    出库执行位点:

    Relay_Master_Log_File: mysql-bin.001204
      Exec_Master_Log_Pos: 52454628
        Executed_Gtid_Set: 6b5be2cf-b1ad-11e7-aeb2-246e965aa709:1432389-825991260

    按照位点信息去主库上解析binlog

    /export/servers/mysql/bin/mysqlbinlog -vvv /export/data/mysql/data/mysql-bin.001204 --start_position=52454628 |more

    输出内容为:

    /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
    /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
    DELIMITER /*!*/;
    # at 4
    #190518  1:05:08 server id 60863  end_log_pos 123 CRC32 0x0545d99b 	Start: binlog v 4, server v 5.7.19-log created 190518  1:05:08
    BINLOG '
    xOneXA+/7QAAdwAAAHsAAAAAAAQANS43LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
    AZvZRQU=
    '/*!*/;
    # at 52454628
    #190518  2:56:10 server id 60863  end_log_pos 52455702 CRC32 0x24c5219e 	Update_rows: table id 27578 flags: STMT_END_F
    
    BINLOG '
    ygPfXB+/7QAAMgQAABZpIAMAALprAAAAAAEAAgBX/////////////////////////////6ABAyBw
    D8B8ALyAPfUdAAAAAAABMQwxMDAwMDAwMTc1NTmMAOWuieWwlOmbhSBBTkVSWUEg5pel5byP5ZWG
    6LaF5ZCM5qy+IOaHkuS6uuaymeWPkeixhuiii+aXoOWNsOWIm+aEj+aRh+aRh+akheS8kemXsuWM
    l+asp+amu+amu+exs+WNleS6uuWkmuWKn+iDveW4g+iJuuaymeWPkSDnj4rnkZrok50g5aSn5qy+
    ATCAAAAABROIATABMAQAaHpyegYxMzQxNzAJAOa1meaxn+ecgQExATABMAEwATABMAEwBDk4NzAB
    MAwAMTAwMDAwMDE3NTU5ATABMACZogdLxFzbUkQDMzAxEWdvb2RzSW5mb0Rvd25sb2FkEWdvb2Rz
    SW5mb0Rvd25sb2FkDAAxMDAwMDAwMTc1NTmAAAAAAAAAATABMAEwATCAAAAAAAAAATCAAAAAAAAA
    gAAAAAAAAIAAAAAAAACAAAAAAAAAgAAAAAAAAAEwAzY1MQEzAIAAAAKeAACAAAACXQAAgAAAAlgA
    AAEwATABMAABMD4AamZzL3QzMDM4Mi8yMzgvMjIwMzM3MzU1LzI4MzAzMi8zNjJjODZiNy81YmVi
    YjI5N05lMWE5MjZmYy5qcGcBADElzoqzagEAAAPnrrEAAIAAAAAAAACAAAAAAAAAoAEDIHAPwHwA
    vIA99R0AAAAAAAExDDEwMDAwMDAxNzU1OYwA5a6J5bCU6ZuFIEFORVJZQSDml6XlvI/llYbotoXl
    kIzmrL4g5oeS5Lq65rKZ5Y+R6LGG6KKL5peg5Y2w5Yib5oSP5pGH5pGH5qSF5LyR6Zey5YyX5qyn
    5qa75qa757Gz5Y2V5Lq65aSa5Yqf6IO95biD6Im65rKZ5Y+RIOePiueRmuiTnSDlpKfmrL4BMIAA
    AAAFE4gBMAEwBABoenJ6BjEzNDE3MAkA5rWZ5rGf55yBATEBMAEwATABMAEwATAEOTg3MAEwDAAx
    MDAwMDAwMTc1NTkBMAEwAJmiB0vEXN8DygMzMDERZ29vZHNJbmZvRG93bmxvYWQRZ29vZHNJbmZv
    RG93bmxvYWQMADEwMDAwMDAxNzU1OYAAAAAAAAABMAEwATABMIAAAAAAAAABMIAAAAAAAACAAAAA
    AAAAgAAAAAAAAIAAAAAAAACAAAAAAAAAATADNjUxATMAgAAAAp4AAIAAAAJdAACAAAACWAAAATAB
    MAEwAAEwPgBqZnMvdDMwMzgyLzIzOC8yMjAzMzczNTUvMjgzMDMyLzM2MmM4NmI3LzViZWJiMjk3
    TmUxYTkyNmZjLmpwZwEAMSOx2cNqAQAAA+eusQAAgAAAAAAAAIAAAAAAAACeIcUk
    '/*!*/;
    ### Row event for unknown table #27578# at 52455702
    #190518  2:56:10 server id 60863  end_log_pos 52455733 CRC32 0xb829837d 	Xid = 8647697161
    COMMIT/*!*/;
    # at 52455733
    #190518  2:56:10 server id 60863  end_log_pos 52455798 CRC32 0x02c73826 	GTID	last_committed=21489	sequence_number=21490 -rbr_only=yes
    /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
    SET @@SESSION.GTID_NEXT= '6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990109'/*!*/;
    # at 52455798
    #190518  2:56:10 server id 60863  end_log_pos 52455871 CRC32 0x1863b7ae 	Query	thread_id=7254910	exec_time=0	error_c
    ode=0
    SET TIMESTAMP=1558119370/*!*/;
    SET @@session.pseudo_thread_id=7254910/*!*/;
    SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
    SET @@session.sql_mode=1411383296/*!*/;
    SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
    /*!C utf8 *//*!*/;
    SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
    SET @@session.lc_time_names=0/*!*/;
    SET @@session.collation_database=DEFAULT/*!*/;
    BEGIN
    /*!*/;
    # at 52455871

    网上关于错误“Row event for unknown table”的资料较少,查到资料解释大意是在建立table map信息丢失导致。

    参考链接:

    https://bugs.mysql.com/bug.php?id=60964
    https://www.jianshu.com/p/4e28f09b3ce5

    从上面的解析结果发现,该事务设置GTID_NEXT,难道真的是匿名事务?

    通过指定时间段方式来解析:

    /export/servers/mysql/bin/mysqlbinlog -vvv /export/data/mysql/data/mysql-bin.001204 --start_datetime='2019-05-18 2:56:09' --stop_datetime='2019-05-18 2:56:11'

    解析结果包含如下信息:

    # at 52454142
    #190518  2:56:10 server id 60863  end_log_pos 52454173 CRC32 0xb0e1832b 	Xid = 8647697160
    COMMIT/*!*/;
    ### GTID为6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990107的事务提交
    # at 52454173
    #190518  2:56:10 server id 60863  end_log_pos 52454238 CRC32 0x83d1552a 	GTID	last_committed=21486	sequence_number=21489	rbr_only=yes
    /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
    ### GTID为6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108的事务开始
    SET @@SESSION.GTID_NEXT= '6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108'/*!*/;
    # at 52454238
    #190518  2:56:10 server id 60863  end_log_pos 52454314 CRC32 0xb78b3241 	Query	thread_id=7172612	exec_time=0	error_code=0
    SET TIMESTAMP=1558119370/*!*/;
    BEGIN
    /*!*/;
    # at 52454314
    #190518  2:56:10 server id 60863  end_log_pos 52454628 CRC32 0x643ab683 	Table_map: `report`.`bs_itembase` mapped to number 27578
    # at 52454628
    #190518  2:56:10 server id 60863  end_log_pos 52455702 CRC32 0x24c5219e 	Update_rows: table id 27578 flags: STMT_END_F
    
    BINLOG '
    ygPfXBO/7QAAOgEAAORkIAMAALprAAAAAAEABnJlcG9ydAALYnNfaXRlbWJhc2UAVwgPDw8PD/b2
    Dw8PDw8PDw8PDw8PDw8PDw8PDw8PDxIRDw8PDw8PD/YPDw8PDw8PD/YP9vb29g8P9g8PDw8PDw8P
    Afb29g8PDwEPDw8PDw8PDwgPARD29qKWAFoA3AUDAB4ADwQPBB4AAwCWACwBlgAAAwMAAwAeAB4A
    AwADAAMAAwADAJYAAwBYAgMAAwCWAAADAAB4ADwAPABYAgMAAwB4AA8EeAB4AHgAeAADAAMAAwAD
    AA8EAwAPBA8EDwQPBB4AHgAPBAMAAwADAB4AHgAeADwAPAAPBA8EDwQDAAMAAwADAHgA3AVYAiwB
    WALcBVgCPAABAA8EDwT+//8/////////H4O2OmQ=
    ygPfXB+/7QAAMgQAABZpIAMAALprAAAAAAEAAgBX/////////////////////////////6ABAyBw
    D8B8ALyAPfUdAAAAAAABMQwxMDAwMDAwMTc1NTmMAOWuieWwlOmbhSBBTkVSWUEg5pel5byP5ZWG
    6LaF5ZCM5qy+IOaHkuS6uuaymeWPkeixhuiii+aXoOWNsOWIm+aEj+aRh+aRh+akheS8kemXsuWM
    l+asp+amu+amu+exs+WNleS6uuWkmuWKn+iDveW4g+iJuuaymeWPkSDnj4rnkZrok50g5aSn5qy+
    ATCAAAAABROIATABMAQAaHpyegYxMzQxNzAJAOa1meaxn+ecgQExATABMAEwATABMAEwBDk4NzAB
    MAwAMTAwMDAwMDE3NTU5ATABMACZogdLxFzbUkQDMzAxEWdvb2RzSW5mb0Rvd25sb2FkEWdvb2Rz
    SW5mb0Rvd25sb2FkDAAxMDAwMDAwMTc1NTmAAAAAAAAAATABMAEwATCAAAAAAAAAATCAAAAAAAAA
    gAAAAAAAAIAAAAAAAACAAAAAAAAAgAAAAAAAAAEwAzY1MQEzAIAAAAKeAACAAAACXQAAgAAAAlgA
    AAEwATABMAABMD4AamZzL3QzMDM4Mi8yMzgvMjIwMzM3MzU1LzI4MzAzMi8zNjJjODZiNy81YmVi
    YjI5N05lMWE5MjZmYy5qcGcBADElzoqzagEAAAPnrrEAAIAAAAAAAACAAAAAAAAAoAEDIHAPwHwA
    vIA99R0AAAAAAAExDDEwMDAwMDAxNzU1OYwA5a6J5bCU6ZuFIEFORVJZQSDml6XlvI/llYbotoXl
    kIzmrL4g5oeS5Lq65rKZ5Y+R6LGG6KKL5peg5Y2w5Yib5oSP5pGH5pGH5qSF5LyR6Zey5YyX5qyn
    5qa75qa757Gz5Y2V5Lq65aSa5Yqf6IO95biD6Im65rKZ5Y+RIOePiueRmuiTnSDlpKfmrL4BMIAA
    AAAFE4gBMAEwBABoenJ6BjEzNDE3MAkA5rWZ5rGf55yBATEBMAEwATABMAEwATAEOTg3MAEwDAAx
    MDAwMDAwMTc1NTkBMAEwAJmiB0vEXN8DygMzMDERZ29vZHNJbmZvRG93bmxvYWQRZ29vZHNJbmZv
    RG93bmxvYWQMADEwMDAwMDAxNzU1OYAAAAAAAAABMAEwATABMIAAAAAAAAABMIAAAAAAAACAAAAA
    AAAAgAAAAAAAAIAAAAAAAACAAAAAAAAAATADNjUxATMAgAAAAp4AAIAAAAJdAACAAAACWAAAATAB
    MAEwAAEwPgBqZnMvdDMwMzgyLzIzOC8yMjAzMzczNTUvMjgzMDMyLzM2MmM4NmI3LzViZWJiMjk3
    TmUxYTkyNmZjLmpwZwEAMSOx2cNqAQAAA+eusQAAgAAAAAAAAIAAAAAAAACeIcUk
    '/*!*/;
    ### UPDATE `report`.`xxxx`
    ### WHERE
    ### 更新语句...
    
    # at 52455702
    #190518  2:56:10 server id 60863  end_log_pos 52455733 CRC32 0xb829837d 	Xid = 8647697161
    COMMIT/*!*/;
    ### GTID为6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108的事务提交
    # at 52455733
    #190518  2:56:10 server id 60863  end_log_pos 52455798 CRC32 0x02c73826 	GTID	last_committed=21489	sequence_number=21490	rbr_only=yes
    /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
    ### GTID为6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990109的事务开始
    SET @@SESSION.GTID_NEXT= '6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990109'/*!*/;
    # at 52455798
    #190518  2:56:10 server id 60863  end_log_pos 52455871 CRC32 0x1863b7ae 	Query	thread_id=7254910	exec_time=0	error_code=0
    SET TIMESTAMP=1558119370/*!*/;
    SET @@session.sql_mode=1411383296/*!*/;
    BEGIN
    /*!*/;
    # at 52455871
    #190518  2:56:10 server id 60863  end_log_pos 52455941 CRC32 0xb9e2e221 	Table_map: `dcomb`.`snapshot_position` mapped to number 30731
    # at 52455941
    #190518  2:56:10 server id 60863  end_log_pos 52456099 CRC32 0xea181383 	Update_rows: table id 30731 flags: STMT_END_F

    从上面解析内容可以发现事务中包含有GTID信息,但由于从库复制使用基于位点方式搭建,且从库开启多线程复制,因此Exec_Master_Log_Pos=52454628信息记录并不准确,而从该位置点开始应用BINLOG,没有执行该位点上面的内容(标黄部分):

    #190518  2:56:10 server id 60863  end_log_pos 52454238 CRC32 0x83d1552a  GTID last_committed=21486 sequence_number=21489 rbr_only=yes
    /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
    ### GTID为6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108的事务开始
    SET @@SESSION.GTID_NEXT= '6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108'/*!*/;
    # at 52454238
    #190518  2:56:10 server id 60863  end_log_pos 52454314 CRC32 0xb78b3241  Query thread_id=7172612 exec_time=0 error_code=0
    SET TIMESTAMP=1558119370/*!*/;
    BEGIN
    /*!*/;
    # at 52454314
    #190518  2:56:10 server id 60863  end_log_pos 52454628 CRC32 0x643ab683  Table_map: `report`.`bs_itembase` mapped to number 27578
    # at 52454628
    #190518  2:56:10 server id 60863  end_log_pos 52455702 CRC32 0x24c5219e  Update_rows: table id 27578 flags: STMT_END_F

    当执行到COMMIT时,由于没有设置GTID_NEXT,因此MySQL认为该事务未匿名事务,SQL线程异常停止。

    上面的情况是跳过"SET @@SESSION.GTID_NEXT" 和"BEGIN"两部分,而如果只跳过"SET @@SESSION.GTID_NEXT",则执行BEGIN时,会报如下错误:

    Last_Errno: 1782
    Last_Error: Error '@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.' on query. Default database: ''. Query: 'BEGIN'

    位于该错误位点的GTID为“6b5be2cf-b1ad-11e7-aeb2-246e965aa709:825990108”,而从库执行过的GTID为“6b5be2cf-b1ad-11e7-aeb2-246e965aa709:1432389-825991260”,由于缺少GTID_NEXT标识事务,从库无法判定该事务是否已在从库上执行,也就无法自动跳过该事务。

    由于参数relay_log_recovery默认值为OFF,从库服务器上未明确设置参数relay_log_recovery=ON,还需验证该参数对上述异常的影响,未完待续。

  • 相关阅读:
    centos7搭建ELK开源实时日志分析系统
    基于ELK的简单数据分析
    用ELK打造可视化集中式日志
    elk单台环境搭建
    用logstash,elasticSearch,kibana实现数据收集和统计分析工作
    用Kibana和logstash快速搭建实时日志查询、收集与分析系统
    elasticsearch按照配置时遇到的一些坑 [Failed to load settings from [elasticsearch.yml]]
    分布式搜索elasticsearch几个概念解析
    分布式搜索elasticsearch配置文件详解
    CENTOS安装ElasticSearch
  • 原文地址:https://www.cnblogs.com/gaogao67/p/10885858.html
Copyright © 2011-2022 走看看