歡迎關注我的《深入理解MySQL主從原理 32講 》，如下：

![image.png](https://upload-images.jianshu.io/upload_images/7398834-0ffa3bdc078cddf4.png?imageMogr2/auto-orient/strip%7CimageView2/2/w/1240)
如果圖片不能顯示可檢視下面連結： 
https://www.jianshu.com/p/d636215d767f

###一、流程解析
```
start_slave
 ->start_slave_threads
   ->
     if (!mi->inited || !mi->rli->inited)//如果沒有初始化 
  {
    int error= (!mi->inited ? ER_SLAVE_MI_INIT_REPOSITORY :
                ER_SLAVE_RLI_INIT_REPOSITORY);
   
   ER_SLAVE_MI_INIT_REPOSITORY
   ER_SLAVE_RLI_INIT_REPOSITORY
   
   ->
     if (mi->is_auto_position() && (thread_mask & SLAVE_IO) &&
      get_gtid_mode(GTID_MODE_LOCK_NONE) == GTID_MODE_OFF)
      
      ER_CANT_USE_AUTO_POSITION_WITH_GTID_MODE_OFF eng 
      "The replication receiver thread%-.192s cannot start in 
      AUTO_POSITION mode: this server uses @@GLOBAL.GTID_MODE = OFF."
  -> 啟動IO 執行緒
       if (thread_mask & SLAVE_IO)
                   is_error= start_slave_thread(
                      #ifdef HAVE_PSI_INTERFACE
                                 key_thread_slave_io,
                      #endif
                                 handle_slave_io, lock_io, lock_cond_io,
                                 cond_io,
                                 &mi->slave_running, &mi->slave_run_id,
                                 mi);
                                 
     -> mysql_thread_create 建立執行緒 回撥函式handle_slave_io
       ->handle_slave_io
         ->初始化IO執行緒屬性 init_slave_thread
           進入狀態THD_STAGE_INFO(thd, stage_waiting_for_master_update);
         ->safe_connect 進行連線主庫
           ->connect_to_master 
            ->將引數slave_net_timeout設定為IO執行緒連線超時和IO執行緒讀取Event 超時            
              case MYSQL_OPT_CONNECT_TIMEOUT: //MYSQL_OPT_CONNECT_TIMEOUT
               mysql->options.connect_timeout= *(uint*) arg;
               break;
             case MYSQL_OPT_READ_TIMEOUT://MYSQL_OPT_READ_TIMEOUT
               mysql->options.read_timeout= *(uint*) arg;
               break;
            ->迴圈 實現連線和重新連線
              
            -> 根據使用者名稱、密碼、IP、埠建立連線
              mysql_real_connect(mysql, mi->host, user, password, 0, mi->port, 0, client_flag)
              
            ->如果連線失敗 迴圈重連 
              每次列印日誌
              mi->report(ERROR_LEVEL, last_errno,
               "error %s to master '%s@%s:%d'"
               " - retry-time: %d  retries: %lu",
               (reconnect ? "reconnecting" : "connecting"),
               mi->get_user(), mi->host, mi->port,
               mi->connect_retry, err_count + 1);
               
             if (++err_count == mi->retry_count)
              {
                slave_was_killed=1;
                break;
              }
              slave_sleep(thd, mi->connect_retry, io_slave_killed, mi); //睡眠時間
               
              每次睡眠時間為MASTER_CONNECT_RETRY設定的時間，預設60秒，迴圈次數由MASTER_RETRY_COUNT指定  
              預設86400次
         ->get_master_version_and_clock
           ->比較版本
           ->發起命令SELECT UNIX_TIMESTAMP() 獲取主庫時間
             mysql_real_query(mysql, STRING_WITH_LEN("SELECT UNIX_TIMESTAMP()
             計算差值用於延遲計算
             mi->clock_diff_with_master= (long) (time((time_t*) 0) - strtoul(master_row[0], 0, 10)); 
             也就是說差值計算是在start slave命令發起的時候進行計算的，後面如果修改slave的伺服器時間
             那麼延遲計算將出現問題
           ->發起命令SELECT @@GLOBAL.SERVER_ID 獲取主庫server id
             比較主庫的server id和本從庫是否相同，如果相同則報錯
             The slave I/O thread stops because master and slave have equal \           
             MySQL server ids; these ids must be different for replication to work (or \
             the --replicate-same-server-id option must be used on slave but this does \
             not always make sense; please check the manual before using it).
           ->發起命令SELECT @@GLOBAL.COLLATION_SERVER  
             如果主庫的這個值和備庫不一致將會報錯
             The slave I/O thread stops because master and slave have \                  
             different values for the COLLATION_SERVER global variable. The values must \
             be equal for the Statement-format replication to work
           ->發起命令SELECT @@GLOBAL.TIME_ZONE 老版本檢測
             比較主庫和從庫的時區，如果不一致
             The slave I/O thread stops because master and slave have \           
             different values for the TIME_ZONE global variable. The values must \
             be equal for the Statement-format replication to work
           ->發起命令SELECT @@GLOBAL.GTID_MODE  
             比較主庫和從庫的GTID MODE是否相容
                 if ((slave_gtid_mode == GTID_MODE_OFF &&                                                                
                      master_gtid_mode >= GTID_MODE_ON_PERMISSIVE) ||                 
                     (slave_gtid_mode == GTID_MODE_ON &&                              
                      master_gtid_mode <= GTID_MODE_OFF_PERMISSIVE))                  
                 {                                                                    
                   mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR,                      
                              "The replication receiver thread cannot start because " 
                              "the master has GTID_MODE = %.192s and this server has "
                              "GTID_MODE = %.192s.",                                  
                              get_gtid_mode_string(master_gtid_mode),                 
                              get_gtid_mode_string(slave_gtid_mode));                 
                   DBUG_RETURN(1);                                                    
                 }                                                                    
                 if (mi->is_auto_position() && master_gtid_mode != GTID_MODE_ON)      
                 {                                                                    
                   mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR,                      
                              "The replication receiver thread cannot start in "      
                              "AUTO_POSITION mode: the master has GTID_MODE = %.192s "
                              "instead of ON.",                                       
                              get_gtid_mode_string(master_gtid_mode));                
                   DBUG_RETURN(1);                                                    
                 }
           ->回到handle_slave_io
         ->get_master_uuid   獲取主句UUID 比較UUID
           發起命令SELECT @@GLOBAL.SERVER_UUID
           比較主庫和備庫的UUID如果相同報錯
           "The slave I/O thread stops because master and slave have equal "           
                         "MySQL server UUIDs; these UUIDs must be different for "                                                                          
                         "replication to work."   
         ->io_thread_init_commands
           SET @slave_uuid= '%s' 是什麼意思  
           
         ->register_slave_on_master 進行註冊    
           主庫呼叫register_slave進行註冊
           註冊完成後 show slave hosts就能查詢到了 主庫show slave會呼叫
           show_slave_hosts 函式        
         ->request_dump 傳送需要讀取的GTID或者位點資訊給主庫。
           如果是AUTO com_binlog_dump_gtid         
           - restirve_gtid+execute_gtid
            if (gtid_executed.add_gtid_set(mi->rli->get_gtid_set()) != RETURN_STATUS_OK ||
             gtid_executed.add_gtid_set(gtid_state->get_executed_gtids()) !=
             RETURN_STATUS_OK)
           - server_id
           
        主庫讀取
          (gdb) p gtid_string
            $17 = 0x7ffee400ef20 "010fde77-2075-11e9-ba07-5254009862c0:1,\ncb7ea36e-670f-11e9-b483-5254008138e4:1-16"
          (gdb) p name
          $18 = '\000' <repeats times="">, "\v\000\000\000\a\000\000\000\000\t\000\344\376\177\000\000\340\252U\354\377\177\000\000\242kL\001\000\000\000\000\002\000\000\000\000\000\000\000\346?\001\000\000\000\000\002\000\000\000\000\000\000\000\346?\001\000\000\000\000\300\252U\354\377\177\000\000L?\001\n\000\000\000ЪU\354\377\177\000\000L?\001\000\000\000\000\360\252U\354\377\177\000\000\240\343\221\001\000\000\000\000\000\253U\354\377\177\000\000\340\b\000\344\376\177\000\000\020\253U\354\377\177\000\000\"I\353\001\000\000\000\000\000\t\000\344\376\177\000\000\240\255U\354\377\177\000\000\060\253U\354\377\177\000\000\272~\356\000\000\000\000\000\v\000\000\000\005\000\000\000\240\255U\354\377\177\000\000\000\256U\354\377\177\000\000\246\323M\001\000\000\000\000\221\333/\002\000\000\000\000\030=\000\344\376\177", '\000' <repeats times="">, "\002\000\000\000\000\000\000\000\346?\001\000\000\000\000\016\202\036\002\000\000\000\000\250"...
        (gdb) p pos
         $19 = 4

不是AUTO
          - server_id
          - MASTER INFO 表的讀取位點
          - MASTER INFO 表的讀取binlog檔名
          
          主庫讀取 com_binlog_dump
            (gdb) p pos
           $1 = 3587
          (gdb) p packet + 10
           $3 = 0x7ffedc00a88b "binlog.000005"
          
          我們可以看到即便開啟了GTID不開啟AUTO也不會根據GTID來讀取。     
            
         ->迴圈讀取event
           進入狀態 stage_waiting_for_master_to_send_event
           
         ->將讀取的event寫入到 relay log
           進入狀態Queueing master event to the relay log 
           ->queue_event 讀取的event寫入到 relay log
             檢測GTID event的合法性
             Cannot replicate GTID-transaction when @@GLOBAL.GTID_MODE = OFF, at file %.512s, position %lld.
             Cannot replicate anonymous transaction when AUTO_POSITION = 1, at file %.512s, position %lld.
             Cannot replicate anonymous transaction when @@GLOBAL.GTID_MODE = ON, at file %.512s, position %lld.
            
             ->rli->relay_log.append_buffer 進行relay log寫入

->MYSQL_BIN_LOG::after_append_to_relay_log //進行寫入後處理
                ->flush_and_sync 函式根據relay log sync引數設定決定是否做sync操作 單位是event個數
                 ->MYSQL_BIN_LOG::sync_binlog_file 判斷是否進行刷盤 
                ->can_rotate 根據這個值決定是否計入Retrieved_Gtid_Set     邊界分析器
                ->進行relay log切換
             ->更改相關被變數
                 master 位置/master 檔案
                 增加容量log_space_total
             
               mi->set_master_log_pos(mi->get_master_log_pos() + inc_pos);//增加master 位置
               
               rli->relay_log.harvest_bytes_written(&rli->log_space_total);
          
               /*
                 If this event is GTID_LOG_EVENT we store its GTID to add to the
                 Retrieved_Gtid_Set later, when the last event of the transaction be
                 queued.
               */
               if (event_type == binary_log::GTID_LOG_EVENT)
               {
                 mi->set_last_gtid_queued(gtid); 
               } 
         ->flush_master_info(mi, FALSE)
          ->Rpl_info_table::do_flush_info 
            透過引數sync_master設定決定多少個event 進行寫table 
            
            handler->set_sync_period(sync_masterinfo_period);
            if (!(force || (sync_period &&                                                                                                             
                  ++(sync_counter) >= sync_period)))//如果沒有達到 sync的次數(sync_master_info 或者 sync_relay_log_info次數 不做flush  不寫表 直接返回)
                DBUG_RETURN(0);//但是relay_log_info依賴於是否是table模式如果是table模式則會在commit的時候做相應的flush Slave_worker::flush_info        
```                
                
###二、證明sync_master_info單位是Event

設定sync_master_info=1

主庫做一個大事務，觀察slave_master_info表如下：
```         
mysql> select * from  slave_master_info  \G;                  
*************************** 1. row ***************************
       Number_of_lines: 25                                    
       Master_log_name: binlog.000002                         
        Master_log_pos: 1222540           
```

主庫執行：
```      
/mysqldata/mysql3340/bin/mysqlbinlog binlog.000002   --base64-output='decode-rows'|grep  -C 10 -E  "BEGIN|COMMIT" 
```      
主庫event 可以看到在中間        
```      
BEGIN                                                                                                                                         
/*!*/;                                                                                                                    
# at 992468                                                                                                               
#190519 13:07:26 server id 413340  end_log_pos 992520 CRC32 0x5d85ea03  Table_map: `testmts`.`testio` mapped to number 111
# at 992520                                                                                                               
#190519 13:07:26 server id 413340  end_log_pos 1000735 CRC32 0xfceb6697         Write_rows: table id 111                  
# at 1000735                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 1008950 CRC32 0x0ca6515c         Write_rows: table id 111                  
# at 1008950                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 1017165 CRC32 0x21d7b17d         Write_rows: table id 111                  
# at 1017165                                                                                                              
--                                                                                                                        
# at 2939475                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 2947690 CRC32 0xcb553fab         Write_rows: table id 111                  
# at 2947690                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 2955905 CRC32 0xd42382c9         Write_rows: table id 111                  
# at 2955905                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 2964120 CRC32 0xe516b98a         Write_rows: table id 111                  
# at 2964120                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 2967035 CRC32 0x9cbfbc0a         Write_rows: table id 111 flags: STMT_END_F
# at 2967035                                                                                                              
#190519 13:07:26 server id 413340  end_log_pos 2967066 CRC32 0xb907da17         Xid = 45                                  
COMMIT/*!*/;                                                                                                              
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;                                                    
DELIMITER ;                                                                                                               
# End of log file                                                                                                         
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;                                                                      
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;                                                                             
You have mail in /var/spool/mail/root            
```

###三、測試AUTO_POSITION=1和POSTION模式下MysqlD異常重啟的恢復過程

下面是 recover_relay_log=0 的情況 POS和GTID AUTO_POSITION=1不同的處理。

斷點
```
Master_info::set_master_log_pos 設定master info io thread 讀取主庫的binlog pos
Relay_log_info::set_group_relay_log_pos 設定relay info sql thread 從庫讀取relay pos的位置 
```
- GTID 
AUTO_POSITION binlog recover_relay_log=0的情況下：
DUMP執行緒會重新傳送最後一個事務給從庫，從庫使用Crash前的Relay_Log_Pos進行讀取。relay log可能出現不完整的事務。這種情況會觸發回滾機制。單執行緒會在GTID event 中回滾，MTS會由協調執行緒呼叫coord_handle_partial_binlogged_transaction回滾

```
change master to 
master_host='192.168.99.41',
master_user='repl',
master_password='gelc123',
master_port=3340,
AUTO_POSITION=1;
start slave; 
```

主庫：

```
# at 912
#190519 21:22:16 server id 413340  end_log_pos 977 CRC32 0x5840ca71     GTID    last_committed=1        sequence_number=2       rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'cb7ea36e-670f-11e9-b483-5254008138e4:2'/*!*/;
# at 977
#190519 21:22:16 server id 413340  end_log_pos 1052 CRC32 0xcd8345de    Query   thread_id=3     exec_time=13    error_code=0
SET TIMESTAMP=1558272136/*!*/;
BEGIN
/*!*/;
# at 1052
#190519 21:22:16 server id 413340  end_log_pos 1104 CRC32 0x782391dd    Table_map: `testmts`.`testgp` mapped to number 108
# at 1104
#190519 21:22:16 server id 413340  end_log_pos 9319 CRC32 0x8de0fbdd    Write_rows: table id 108
# at 9319
#190519 21:22:16 server id 413340  end_log_pos 17534 CRC32 0xae798162   Write_rows: table id 108
# at 17534
#190519 21:22:16 server id 413340  end_log_pos 25749 CRC32 0x683b9e95   Write_rows: table id 108
# at 25749
--
# at 477574
#190519 21:22:16 server id 413340  end_log_pos 485789 CRC32 0x44e99850  Write_rows: table id 108
# at 485789
#190519 21:22:16 server id 413340  end_log_pos 494004 CRC32 0x280300fd  Write_rows: table id 108
# at 494004
#190519 21:22:16 server id 413340  end_log_pos 502219 CRC32 0x075c8ff8  Write_rows: table id 108
# at 502219
#190519 21:22:16 server id 413340  end_log_pos 503274 CRC32 0x08c3f96c  Write_rows: table id 108 flags: STMT_END_F
# at 503274
#190519 21:22:16 server id 413340  end_log_pos 503305 CRC32 0x3b6dd31c  Xid = 26
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
```
```
mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: Queueing master event to the relay log
                  Master_Host: 192.168.99.41
                  Master_User: repl
                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 165404
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 1119
        Relay_Master_Log_File: binlog.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
```            
crash 後              
```
mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: 
                  Master_Host: 192.168.99.41
                  Master_User: repl
                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 190049
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 1119
        Relay_Master_Log_File: binlog.000001
```        
不完整的事物日誌如下：
```        
# at 1119
#190519 21:22:16 server id 413340  end_log_pos 977 CRC32 0x5840ca71     GTID    last_committed=1        sequence_number=2       rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'cb7ea36e-670f-11e9-b483-5254008138e4:2'/*!*/;
# at 1184
#190519 21:22:16 server id 413340  end_log_pos 1052 CRC32 0xcd8345de    Query   thread_id=3     exec_time=13    error_code=0
SET TIMESTAMP=1558272136/*!*/;
BEGIN
/*!*/;
# at 1259
#190519 21:22:16 server id 413340  end_log_pos 1104 CRC32 0x782391dd    Table_map: `testmts`.`testgp` mapped to number 108
# at 1311
#190519 21:22:16 server id 413340  end_log_pos 9319 CRC32 0x8de0fbdd    Write_rows: table id 108
# at 9526
#190519 21:22:16 server id 413340  end_log_pos 17534 CRC32 0xae798162   Write_rows: table id 108
# at 17741
#190519 21:22:16 server id 413340  end_log_pos 25749 CRC32 0x683b9e95   Write_rows: table id 108
# at 25956
WARNING: The range of printed events ends with a row event or a table map event that does not have 
the STMT_END_F flag set. This might be because the last statement was not fully written to the log, 
or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement.
 The event(s) from the partial statement have not been written to output.
```

啟動後 IO_THREAD
```   
mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.99.41
                  Master_User: repl
                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 503305
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 1119
        Relay_Master_Log_File: binlog.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: No            
```                 
              
啟動IO TRHEAD後 重新傳輸了，但是老的沒有完全傳輸完成的日誌還在relay log
新的日誌已經有了 ，老的也還在。

```       
# at 445
#190519 21:22:16 server id 413340  end_log_pos 977 CRC32 0x5840ca71     GTID    last_committed=1        sequence_number=2       rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'cb7ea36e-670f-11e9-b483-5254008138e4:2'/*!*/;
# at 510
#190519 21:22:16 server id 413340  end_log_pos 1052 CRC32 0xcd8345de    Query   thread_id=3     exec_time=13    error_code=0
SET TIMESTAMP=1558272136/*!*/;
SET @@session.pseudo_thread_id=3/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=83,@@session.collation_connection=83,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 585
#190519 21:22:16 server id 413340  end_log_pos 1104 CRC32 0x782391dd    Table_map: `testmts`.`testgp` mapped to number 108
# at 637
#190519 21:22:16 server id 413340  end_log_pos 9319 CRC32 0x8de0fbdd    Write_rows: table id 108
# at 8852
#190519 21:22:16 server id 413340  end_log_pos 17534 CRC32 0xae798162   Write_rows: table id 108
# at 17067
#190519 21:22:16 server id 413340  end_log_pos 25749 CRC32 0x683b9e95   Write_rows: table id 108 (以上本來已經傳輸了)
# at 25282
--
# at 477107
#190519 21:22:16 server id 413340  end_log_pos 485789 CRC32 0x44e99850  Write_rows: table id 108
# at 485322
#190519 21:22:16 server id 413340  end_log_pos 494004 CRC32 0x280300fd  Write_rows: table id 108
# at 493537
#190519 21:22:16 server id 413340  end_log_pos 502219 CRC32 0x075c8ff8  Write_rows: table id 108
# at 501752
#190519 21:22:16 server id 413340  end_log_pos 503274 CRC32 0x08c3f96c  Write_rows: table id 108 flags: STMT_END_F
# at 502807
#190519 21:22:16 server id 413340  end_log_pos 503305 CRC32 0x3b6dd31c  Xid = 26
COMMIT/*!*/;
```

- POSITION
在 recover_relay_log=0的情況下從庫會從Read_Master_Log_Pos的位置接著拉取replay log，一旦Read_Master_Log_Pos和replay log出現問題那麼將會導致從庫異常。主庫只需要從Relay_Log_Pos的位置應用即可。因此引數
- sync_relay_log=1
- sync_master_info=1
是必須的。

```
change master to 
master_host='192.168.99.41',
master_user='repl',
master_password='gelc123',
master_port=3340,
MASTER_LOG_FILE='binlog.000001',
MASTER_LOG_POS=154;
start slave; 
```
```
mysql> show slave status \G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.99.41
                  Master_User: repl
                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 912
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 1075
        Relay_Master_Log_File: binlog.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
```

寫入途中：
```
mysql> show slave status \G;
*************************** 1. row ***************************
               Slave_IO_State: Queueing master event to the relay log
                  Master_Host: 192.168.99.41
                  Master_User: repl
                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 124329
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 1075
        Relay_Master_Log_File: binlog.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
  ```

主庫binlog：
```            
BEGIN
/*!*/;
# at 1052
#190519 16:43:43 server id 413340  end_log_pos 1104 CRC32 0x1b959719    Table_map: `testmts`.`testgp` mapped to number 108
# at 1104
#190519 16:43:43 server id 413340  end_log_pos 9319 CRC32 0x98ff5e73    Write_rows: table id 108
# at 9319
#190519 16:43:43 server id 413340  end_log_pos 17534 CRC32 0xbb6624cc   Write_rows: table id 108
# at 17534
#190519 16:43:43 server id 413340  end_log_pos 25749 CRC32 0x7d243b3b   Write_rows: table id 108
# at 25749
--
# at 477574
#190519 16:43:43 server id 413340  end_log_pos 485789 CRC32 0x51f63dfe  Write_rows: table id 108
# at 485789
#190519 16:43:43 server id 413340  end_log_pos 494004 CRC32 0x3d1ca553  Write_rows: table id 108
# at 494004
#190519 16:43:43 server id 413340  end_log_pos 502219 CRC32 0x12432a56  Write_rows: table id 108
# at 502219
#190519 16:43:43 server id 413340  end_log_pos 503274 CRC32 0x4373f461  Write_rows: table id 108 flags: STMT_END_F
# at 503274
#190519 16:43:43 server id 413340  end_log_pos 503305 CRC32 0xe33a6266  Xid = 60
COMMIT/*!*/;
```

Crash啟動後日志如下：

```
# at 321652
#190519 16:43:43 server id 413340  end_log_pos 329704 CRC32 0xbf87ced1  Write_rows: table id 108
# at 329867
#190519 16:43:43 server id 413340  end_log_pos 337919 CRC32 0x2f3bd840  Write_rows: table id 108
# at 338082
#190519 16:43:43 server id 413340  end_log_pos 346134 CRC32 0xe317c093  Write_rows: table id 108
# at 346297
#190519 16:43:43 server id 413340  end_log_pos 354349 CRC32 0x81e3ea0d  Write_rows: table id 108
# at 354512
#190519 16:43:43 server id 413340  end_log_pos 362564 CRC32 0x7f51fc3a  Write_rows: table id 108
# at 362727
#190519 16:25:17 server id 953340  end_log_pos 362770 CRC32 0xb6611a85  Rotate to relay.000003  pos: 4
WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
ROLLBACK /* added by mysqlbinlog */ /*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

[root@gp1 log]# /mysqldata/mysql3340/bin/mysqlbinlog  --base64-output='decode-rows' relay.000003
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#190519 16:25:17 server id 953340  end_log_pos 123 CRC32 0xe6fd01bf     Start: binlog v 4, server v 5.7.22-22-debug-log created 190519 16:25:17
# This Format_description_event appears in a relay log and was generated by the slave thread.
# at 123
#190519 16:25:17 server id 953340  end_log_pos 154 CRC32 0xde5482b5     Previous-GTIDs
# [empty]
# at 154
#700101  8:00:00 server id 413340  end_log_pos 0 CRC32 0x86e86060       Rotate to binlog.000001  pos: 362564
# at 198
#190519 16:42:31 server id 413340  end_log_pos 0 CRC32 0x5361aca0       Start: binlog v 4, server v 5.7.22-22-debug-log created 190519 16:42:31
# at 317
#190519 16:43:43 server id 413340  end_log_pos 370779 CRC32 0x8b7abae8  Write_rows: table id 108
# at 8532
#190519 16:43:43 server id 413340  end_log_pos 378994 CRC32 0x28e1279c  Write_rows: table id 108
# at 16747
#190519 16:43:43 server id 413340  end_log_pos 387209 CRC32 0x278d98ed  Write_rows: table id 108
# at 24962
#190519 16:43:43 server id 413340  end_log_pos 395424 CRC32 0x85d21655  Write_rows: table id 108
# at 33177
#190519 16:43:43 server id 413340  end_log_pos 403639 CRC32 0x156e00c4  Write_rows: table id 108
# at 41392
#190519 16:43:43 server id 413340  end_log_pos 411854 CRC32 0xed83b3ac  Write_rows: table id 108
# at 49607
#190519 16:43:43 server id 413340  end_log_pos 420069 CRC32 0x465939b4  Write_rows: table id 108
# at 57822
#190519 16:43:43 server id 413340  end_log_pos 428284 CRC32 0xaab146d2  Write_rows: table id 108
# at 66037
#190519 16:43:43 server id 413340  end_log_pos 436499 CRC32 0x97f1428f  Write_rows: table id 108
WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
[root@gp1 log]# /mysqldata/mysql3340/bin/mysqlbinlog  --base64-output='decode-rows' relay.000005
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#190519 16:31:57 server id 953340  end_log_pos 123 CRC32 0xecc598ac     Start: binlog v 4, server v 5.7.22-22-debug-log created 190519 16:31:57
# This Format_description_event appears in a relay log and was generated by the slave thread.
# at 123
#190519 16:31:57 server id 953340  end_log_pos 154 CRC32 0x21c8a43a     Previous-GTIDs
# [empty]
# at 154
#700101  8:00:00 server id 413340  end_log_pos 0 CRC32 0xeed34528       Rotate to binlog.000001  pos: 428284
# at 198
#190519 16:42:31 server id 413340  end_log_pos 0 CRC32 0x5361aca0       Start: binlog v 4, server v 5.7.22-22-debug-log created 190519 16:42:31
# at 317
#190519 16:43:43 server id 413340  end_log_pos 436499 CRC32 0x97f1428f  Write_rows: table id 108
# at 8532
#190519 16:43:43 server id 413340  end_log_pos 444714 CRC32 0xfd447f7d  Write_rows: table id 108
# at 16747
#190519 16:43:43 server id 413340  end_log_pos 452929 CRC32 0xc4c67bff  Write_rows: table id 108
# at 24962
#190519 16:43:43 server id 413340  end_log_pos 461144 CRC32 0x6dbd096a  Write_rows: table id 108
# at 33177
#190519 16:43:43 server id 413340  end_log_pos 469359 CRC32 0xb42d58b6  Write_rows: table id 108
# at 41392
#190519 16:43:43 server id 413340  end_log_pos 477574 CRC32 0x7a2e502d  Write_rows: table id 108
# at 49607
#190519 16:43:43 server id 413340  end_log_pos 485789 CRC32 0x51f63dfe  Write_rows: table id 108
# at 57822
#190519 16:43:43 server id 413340  end_log_pos 494004 CRC32 0x3d1ca553  Write_rows: table id 108
# at 66037
#190519 16:43:43 server id 413340  end_log_pos 502219 CRC32 0x12432a56  Write_rows: table id 108
# at 74252
#190519 16:43:43 server id 413340  end_log_pos 503274 CRC32 0x4373f461  Write_rows: table id 108 flags: STMT_END_F
# at 75307
#190519 16:43:43 server id 413340  end_log_pos 503305 CRC32 0xe33a6266  Xid = 60
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
```

從 end_log_pos 可以看到他們湊成了一個完整的事務日誌。</repeats></repeats>

二十二：從庫的IO執行緒（筆記）

相關文章