案例分析：mysqlbinlog|mysql GTID事务报错匿名事务的错误

时间：2022-01-14 01:04:53

报错展示

大概报错是这样的

[root@mgr3 bin]# /opt/my_mysql/bin/mysqlbinlog -vv /opt/bin/log_bin.000001bak --start-position=677|/opt/my_mysql/bin/mysql
ERROR 1782 (HY000) at line 23: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.

根据这个报错，最直观的解释是解析到的是匿名事务，而mysqld开启了GTID，也就不能执行了，但是经过检查binlog的事务全部是GTID事务，而mysqld也是开启了gtid的，按理来说不应该报这个错。

原因和原理

实际上这个问题的原因很简单就是--start-position=677 并不是一个事务的开始，至少不是gtid event的开头的pos，那么这种情况下这个事务就变为了匿名事务。要分析这个原理我们需要知道mysqlbinlog|mysql是如何读取解析和执行gtid event的。

mysqlbinlog对gtid event的解析

mysqlbinlog 调用的Log_event::read_log_event，进行gtid event的读取，这和SQL线程实际是一样的，来进行gtid event的读取和解析，如下，

dump_multiple_logs
 ->dump_single_log
   ->dump_local_log_entries
     ->Log_event::read_log_event
       ->Log_event::read_log_event
         ->Gtid_log_event::Gtid_log_event

解析完成后当然就是将gtid event的信息打印出来，如下，

dump_multiple_logs
 ->dump_single_log
   ->dump_local_log_entries
     ->process_event
       ->Gtid_log_event::print

实际上最后打印的结果就是

/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'e8eb8ce3-2ccb-11eb-832e-000c29621fc8:4'/*!*/;

以及last_committed, sequence_number等信息。

mysqld的执行gtid event相关内容

当SET @@SESSION.GTID_NEXT通过mysql传递到服务端mysqld过后实际执行的是

sql_set_variables
 ->set_var::update
   ->sys_var::update
     ->Sys_var_gtid_next::session_update
       ->set_gtid_next

实际上在函数set_gtid_next就会进行如下处理：

  • AUTOMATIC_GROUP

也就是我们常见的SET SESSION GTID_NEXT = AUTOMATIC，则会在事务提交的时候自动生成gtid

  • ANONYMOUS_GROUP

这个显然就是我们SQL线程或者mysqlbinlog|mysql解析binlog的时候一个事务是匿名的，这种情况下还会有额外的判断如下

    if (get_gtid_mode(GTID_MODE_LOCK_SID) == GTID_MODE_ON)
    {
      my_error(ER_CANT_SET_GTID_NEXT_TO_ANONYMOUS_WHEN_GTID_MODE_IS_ON, MYF(0));
      goto err;
    }

也就是如果本服务器开启了gtid则不允许出现匿名的gtid事务，报错

@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
  • GTID_GROUP

也就是正常的指定了gtid，通常也是SQL线程或者mysqlbinlog|mysql解析binlog的时候一个事务是正常的gtid事务，当然你也可以手动设置一个事务的gtid，比如跳事务的时候。那么也需要额外的判断如下

      if (get_gtid_mode(GTID_MODE_LOCK_SID) == GTID_MODE_OFF)
      {
        my_error(ER_CANT_SET_GTID_NEXT_TO_GTID_WHEN_GTID_MODE_IS_OFF, MYF(0));
        goto err;
      }

也就是本服务器如果关闭了gtid则不允许指定gtid的事务执行，报错

@@SESSION.GTID_NEXT cannot be set to UUID:NUMBER when @@GLOBAL.GTID_MODE = OFF.

同时接下来的逻辑还会判定是否这个事务已经在本服务器执行了，不管是否这行过这里都会设置事务的gtid为指定的gtid，而如果本gtid在服务器本服务器执行过了，则会通过函数gtid_pre_statement_checks进行跳过事务处理。 实际上mysqlbinlog|mysql执行binlog和SQL线程有很大的共同点，这里gtid event也是先读取解析然后执行的，只是这里读取解析由mysqlbinlog完成，而执行是由mysqld进行的。

那么回到问题，如果指定pos的时候执行错了没有指定到gtid event为事务的开始，那么就会导致这个事务是匿名事务，因为根本就没有SET @@SESSION.GTID_NEXT语句传给mysqld，如下注释：

    Ensure that we hold anonymous ownership before executing any
    statement, if gtid_next=anonymous or not_yet_determined. 

显然mysqld开启了gtid模式，而事务是匿名的当然也就报错了。

关于mysqlbinlog的--skip-gtids模式

显然如果mysqld执行过的事务，想再去通过mysqlbinlog|mysql去执行是行不通的，因为gtid能够起到过滤的功能，也就是函数gtid_pre_statement_checks进行跳过事务处理。 那么如果非要执行的话就需要将事务的gtid信息去掉，也就是指定--skip-gtids模式，但是事务的gtid信息一旦去掉就变为了匿名的事务，这个时候就需要要额外的处理。mysqlbinlog的做法是，在解析到FORMAT_DESCRIPTION event的时候在末尾加上一个SET @@SESSION.GTID_NEXT='AUTOMATIC'，如下，

    if (print_event_info->skip_gtids)
      my_b_printf(head, "/*!50616 SET @@SESSION.GTID_NEXT='AUTOMATIC'*/%s\n",
                  print_event_info->delimiter);

这样binlog的事务即便没有gtid信息，也会在提交的事务自动生成gtid。在解析出来的binlog中有如下显示：

# at 4
#230321 11:16:58 server id 333900  end_log_pos 123      Start: binlog v 4, server v 5.7.22-22-debug-log created 230321 11:16:58 at startup
ROLLBACK/*!*/;
BINLOG '
qiEZZA9MGAUAdwAAAHsAAAAAAAQANS43LjIyLTIyLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAACqIRlkEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
ALs/ev8=
'/*!*/;
/*!50616 SET @@SESSION.GTID_NEXT='AUTOMATIC'*//*!*/; 

而具体的mysqlbinlog具体跳过动作可以参考函数shall_skip_gtids。

相关文章