• MySQL多线程备份工具mydumper 之 RDS外部实例迁移平台


    此文已由作者温正湖授权网易云社区发布。

    欢迎访问网易云社区,了解更多网易技术产品运营经验。


    1、Format_description_event问题:

    BINLOG '
    kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW
    kTXkUyAKAAAALQAAAOgEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck'/*!*/;

    假设以上是使用 ../mysql/bin/mysqlbinlog -v --start-position=1094  mysql-bin.000036生成的一个BINLOG,类型为 DELETE_ROW_LOG_EVENT。内容如下:

    ### DELETE FROM `test`.`t3`### WHERE###  
     @1=1### DELETE FROM `test`.`t3`### WHERE### 
       @1=2

    mysql客户端,单独执行这个binlog无法达到删除t3中 (1), (2)这两行的目的。报错如下:

    mysql> BINLOG '
    kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW
    kTXkUyAKAAAALQAAAOgEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck'/*!*/;
    ERROR 1609 (HY000): The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
    mysql>

    DBA刚开始误以为是个mysql bug。其实不然。

    错误提示需要先执行format description BINLOG,即需要先执行Format_description_event,该binlog用于描述接下来要执行的BINLOG的版本等信息,如下:

    # at 4#140808 10:26:53 server id 10  end_log_pos 121 CRC32 0x5731b21e Start: binlog v 4, server v 5.6.19-log created 140808 10:26:53# Warning: this binlog is either in use or was not closed properly.BINLOG '
    bTXkUw8KAAAAdQAAAHkAAAABAAQANS42LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXQAEGggAAAAICAgCAAAACgoKGRkADQEe
    sjFX'/*!*/;

    该BINLOG位于每个binlog文件偏移位置4开始。

    似乎是合理的,在mysql-5.5.30版本中,DBA第二次执行原来的DELETE_ROW_LOG_EVENT时,却能够执行成功。这似乎不合理。其实第二次执行也不应该成功,这是mysql-5.5.30的一个bug

    链接为:https://bugs.launchpad.net/percona-server/+bug/966148

    在mysql 5.6.19验证了下,该bug已经修复:

    mysql> BINLOG 'kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW 
    kTXkUx4KAAAALQAAACcEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck
    '/*!*/;
    ERROR 1609 (HY000): The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
    mysql> BINLOG 'kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW 
    kTXkUx4KAAAALQAAACcEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck
    '/*!*/;
    ERROR 1609 (HY000): The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
    mysql> 
    mysql> BINLOG 'kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW 
    kTXkUx4KAAAALQAAACcEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck
    '/*!*/;
    ERROR 1609 (HY000): The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
    mysql>

    即不管执行多少次同一个BINLOG,都无法成功。除非先执行了Format_description_event:

    mysql> BINLOG '                                                                                                                                       
        '> bTXkUw8KAAAAdQAAAHkAAAABAAQANS42LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA    '> AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXQAEGggAAAAICAgCAAAACgoKGRkADQEe
        '> sjFX    '> '/*!*/;  //这是一个Format_description_eventQuery OK, 0 rows affected (0.00 sec)
    
    mysql> BINLOG '    '> kTXkUxMKAAAALQAAAPoDAAAAAEgAAAAAAAEABHRlc3QAAnQzAAEDAAFS1mTW
        '> kTXkUx4KAAAALQAAACcEAAAAAEgAAAAAAAEAAgAB//4BAAAA/gIAAAC52uck
        '> '/*!*/;
    Query OK, 0 rows affected (0.00 sec)


    2、执行binlog时“0 rows affected”问题

    这样就成功得将对应的t3中对应的(1),(2)删掉。但问题也来了,为什么执行完显示 “Query OK, 0 rows affected (0.00 sec)”。这个让人很费解。

    “0 rows affected” 这个问题,也是有DBA提出来了,他们在使用mysqlbinlog -B 进行flashback操作时,执行过程一直是“Query OK, 0 rows affected (0.00 sec)”,怀疑

    flashback功能出了问题。其实是因为执行BINLOG直接调用存储引擎的相关接口,跟常规的sql语句执行走的代码路径不完全相同,所以rows affected没有得到正确统计。

    继续回到Format_description_event问题上,需要注意的是,在一次客户端连接期间,只需执行一次Format_description_event即可。这个也是好理解的。


    3、flashback功能需要与-v配合使用问题

    不过mysql的flashback工具确实存在一个问题,就是在flashback update 操作时,需要-v和-B一起作用才能够成功。这是因为:

    Rows_log_event::exchange_update_rows在进行set和where内容调换时,需要计算这两段内容的长度,该功能由Rows_log_event::print_verbose_one_row完成,

    该函数会根据表定义table_def (td)来获取表中每个field的length,并通过binlog中的记录获取set和where中那几个field是NULL的。

    而td是从Table_map_log_event中获取的,且只有在-v时才会生成td:

    if (print_event_info->verbose)
      {
    
        Rows_log_event *ev= NULL;
        Log_event_type et= (Log_event_type) ptr[EVENT_TYPE_OFFSET];    if (checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF &&
            checksum_alg != BINLOG_CHECKSUM_ALG_OFF)
          size-= BINLOG_CHECKSUM_LEN; // checksum is displayed through the header
        
        switch(et)
        {    case TABLE_MAP_EVENT:
        {
          Table_map_log_event *map; 
          map= new Table_map_log_event((const char*) ptr, size, 
                                       glob_description_event);
          print_event_info->m_table_map.set_table(map->get_table_id(), map);break;
        }

    通过set_table(map->get_table_id(), map)来将对应的map( td从这里来map->create_table_def() )放入table的哈希表中;

    所以,不加-v进行update操作的flashback解析时,由于无法通过map= print_event_info->m_table_map.get_table(m_table_id)来获取map进而获取td。

    导致无法知道表定义,从而无法进行set和where长度的计算并进行内容调换。

    为了修复这个bug,修改如下:

    if (is_flashback) //Flashback
      {
        uint32 fb_size = size;if (checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF &&
     checksum_alg != BINLOG_CHECKSUM_ALG_OFF)
    fb_size-= BINLOG_CHECKSUM_LEN; // checksum is displayed through the header
        switch (ptr[EVENT_TYPE_OFFSET]) { //add TABLE_MAP_EVENT, as UPDATE_ROWS_EVENT need to get_table from map
     case TABLE_MAP_EVENT:
     {
    Table_map_log_event *map; 
    map= new Table_map_log_event((const char*) ptr, fb_size, 
    glob_description_event);
    print_event_info->m_table_map.set_table(map->get_table_id(), map);break;
     }      case WRITE_ROWS_EVENT:
            ptr[EVENT_TYPE_OFFSET]= DELETE_ROWS_EVENT;        break;
    ....  if (print_event_info->verbose)
      {
        Rows_log_event *ev= NULL;
        Log_event_type et= (Log_event_type) ptr[EVENT_TYPE_OFFSET];    if (checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF &&
            checksum_alg != BINLOG_CHECKSUM_ALG_OFF)
          size-= BINLOG_CHECKSUM_LEN; // checksum is displayed through the header
        
        switch(et)
        {    case TABLE_MAP_EVENT:
        { //if flashback, map has already set into hash above
     if (!is_flashback) 
     {
          Table_map_log_event *map; 
          map= new Table_map_log_event((const char*) ptr, size, 
                                       glob_description_event);
          print_event_info->m_table_map.set_table(map->get_table_id(), map);
     } break;
        }


    4、mysqlbinlog解析relay log报“unknown table”问题

    组内的小伙伴在做基于relay-log进行的数据库实例故障恢复时,发现mysqlbinlog的又一个bug,社区之前也已提及,如下:http://bugs.mysql.com/bug.php?id=60964。大意是在使用mysqlbinlog解析高可用数据库实例从库的relay log时,提示“### Row event for unknown table #16#”,简单分析可知该提示是说DML操作(UPDATE/INSERT/DELETE)所需的table map找不到了,而table map可以将table id(上述的16)跟表定义建立关联。没有table map当然就无法解析DML操作。

    那么table map真的不见了吗?其实不然,只是table map位于上一个relay log文件而已。那么,既然mysqlbinlog能够同时解析多个文件,能不能将上一个文件跟当前文件一起解析,这样应该就不会报这个错误了吧。我刚开始也是这么认为的,还跟小伙伴争了,结果应了那句:“没有调查就没有发言权”。小伙伴可是试验过了,结果还是无法解析。个人觉得这不合理啊。

      

    为此,看了mysqlbinlog的代码,很快就找到了问题所在,下面进行简单分析

    1、mysqlbinlog用一个for循环来处理一个或多个binlog文件,如下:

    // main loop:
     for (save_stop_position= stop_position, stop_position= ~(my_off_t)0 ; (--argc >= 0) ; ) 
     { 
     if (argc == 0) // last log, --stop-position applies stop_position= save_stop_position; 
     if ((retval= dump_log_entries(*argv++)) != OK_CONTINUE) 
         break; 
         
    // For next log, --start-position does not apply 
    start_position= BIN_LOG_HEADER_SIZE; 
    }

    这个循环代码很是简练,以至于刚开始看代码的还是,根本不知道是什么意思。其实,循环中argc表示有几个binlog文件需要解析,*argv表示具体的文件名称。start-position和stop_position处理得也很奇妙,在此不细说。


     2、有以上的铺垫可以知道,dump_log_entries函数是用来处理每个binlog文件的。

    /**
      High-level function for dumping a named binlog.
      This function calls dump_remote_log_entries() or
      dump_local_log_entries() to do the job.
      @param[in] logname Name of input binlog.
      @retval ERROR_STOP An error occurred - the program should terminate.
      @retval OK_CONTINUE No error, the program should continue.
      @retval OK_STOP No error, but the end of the specified range of
      events to process has been reached and the program should terminate.
    */static Exit_status dump_log_entries(const char* logname)
    {
      Exit_status rc;
      PRINT_EVENT_INFO print_event_info;  if (!print_event_info.init_ok())    return ERROR_STOP;  if (!only_event_info)
      {  /*
         Set safe delimiter, to dump things
         like CREATE PROCEDURE safely
      */
      fprintf(result_file, "DELIMITER /*!*/;
    ");
      strmov(print_event_info.delimiter, "/*!*/;");
      }
      
      print_event_info.verbose= short_form ? 0 : verbose;
      rc= (remote_opt ? dump_remote_log_entries(&print_event_info, logname) :
           dump_local_log_entries(&print_event_info, logname));  if (!only_event_info)
      {  if (!flashback_opt)
      {  /* Set delimiter back to semicolon */
        fprintf(result_file, "DELIMITER ;
    ");
        strmov(print_event_info.delimiter, ";");
      }
      }  return rc;
    }

    根据解析的binlog是否为远程的,又分为dump_remote_log_entries和dump_local_log_entries,我们主要用了dump_local_log_entries,进入函数后我们会发现,mysqlbinlog使用Log_event::read_log_event(file, glob_description_event)和process_event(print_event_info, ev, old_off, logname)两个函数来读取、构建和解析每个binlog。我们应该关注的是print_event_info,这个是控制整个解析过程的关键对象。比如说,如果binlog的类型是TABLE_MAP_EVENT (这个就是问题所在,保存table map的地方),那么在解析时,会将table id和具体的表定义联系起来。并记录到print_event_info中。process_event在处理WRITE_ROWS_EVENT/UPDATE_ROWS_EVENT/DELETE_ROWS_EVENT(对应前述的DML操作)时,由于event中仅记录所操作的表的table id,所以就需要借助print_event_info来获取对应的映射关系。跨relay log的事务在使用mysqlbinlog进行解析时出错的原因就在于,print_event_info是在dump_log_entries中定义的。在完成一个binlog文件的解析后会自动销毁掉,无法继承给下一个待解析的binlog文件。

    所以,解决问题的办法很简单,将PRINT_EVENT_INFO print_event_info定义提取出来,设为mysqlbinlog的全局变量即可解决问题。

    之前有小伙伴提问,为什么不把表定义直接记录到DML操作中,答案是显而易见的,如果每个DML的binlog都记录表定义,一是没有必要,二是太浪费存储空间了。


    网易云免费体验馆,0成本体验20+款云产品! 

    更多网易技术、产品、运营经验分享请点击


    相关文章:
    【推荐】 一次活动引发的血案

  • 相关阅读:
    react脚手架
    快速创建一个node后台管理系统
    vue脚手架结构及vue-router路由配置
    Spring 事务管理-只记录xml部分
    Spring-aspectJ
    Maven 自定义Maven插件
    JVM
    JVM
    Spring
    Digester
  • 原文地址:https://www.cnblogs.com/zyfd/p/9810505.html
Copyright © 2020-2023  润新知