MySQL案例09:Last_IO_Error: Got fatal error 1236 from master when reading data from binary log

Rangle發表於2018-08-03

剛處理完“挖礦”事件,在做最後一個MySQL NBU備份的時候,發現從庫有問題,好奇的是怎麼主從狀態異常沒有告警呢?先不管這麼多了,處理了這個問題再完善告警內容。

一、錯誤資訊

從庫show slave status \G看到的錯誤資訊如下:

Slave_IO_Running: No
Slave_SQL_Running: Yes
Last_IO_Errno: 1236
Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position; the first event 'mysql-bin.000081' at 480141113, the last event read from './mysql-bin.000081' at 4, the last byte read from './mysql-bin.000081' at 4.'

二、錯誤原因

這裡看到從庫的io_thread已經終止,錯誤編號是1236,具體是由於讀取主庫的binlog日誌位置(the first event 'mysql-bin.000081' at 480141113, the last event read from './mysql-bin.000081' at 4)不對導致主從失敗建立失敗。

三、解決方案

1.檢查從庫狀態以及讀取、執行的binlog資訊

mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: 
                  Master_Host: xx.xx.xx.xx
                  Master_User: username
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000081
          Read_Master_Log_Pos: 480141113
               Relay_Log_File: mysql9017-relay-bin.000163
                Relay_Log_Pos: 480141259
        Relay_Master_Log_File: mysql-bin.000081
             Slave_IO_Running: No
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 480141113
              Relay_Log_Space: 480141462
              Until_Condition: None
               Until_Log_File: 
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File: 
           Master_SSL_CA_Path: 
              Master_SSL_Cert: 
            Master_SSL_Cipher: 
               Master_SSL_Key: 
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 1236
                Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position; the first event 'mysql-bin.000081' at 480141113, the last event read from './mysql-bin.000081' at 4, the last byte read from './mysql-bin.000081' at 4.'
               Last_SQL_Errno: 0
               Last_SQL_Error: 
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 17
1 row in set (0.00 sec)

2.檢視主庫的binlog內容

[backup]# mysqlbinlog  mysql-bin.000081 >mysql-bin.log

看到主庫binlog日誌mysql-bin.000081最大的pos為480140557,但從庫要讀取的是'mysql-bin.000081' at 480141113,顯然從庫要讀的pos值比主庫本身存在的pos值大,導致讀取不到,進而失敗。

可通過下面語句檢視binlog的pos資訊和日誌內容
mysql> show binlog events in  'mysql-bin.000081' from 480140557 limit 10;       
Empty set (0.04 sec)
3.更改從庫的同步位置,完成資料重新同步

 主庫:

mysqlbinlog  mysql-bin.000082  |more

從庫:

change master to master_host='xx.xx.xx.xx',master_user='username',master_port=3306,master_password='password',master_log_file='mysql-bin.000082',master_log_pos=4;

start slave;

show slave status \G

主從同步正常

4.主庫引數改進

 導致這個原因很大程度上是由於主從在同步的過程中,主庫異常斷電,導致記憶體資料傳輸到從庫但沒有提交到binlog日誌,即主庫 sync_binlog設定可能有問題,在主庫檢查引數設定:

mysql> show global variables like '%sync_binlog%';                       
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| sync_binlog   | 0     |
+---------------+-------+
1 row in set (0.00 sec)

果然其值是 0,不主動同步binlog cache的資料到磁碟,而依賴作業系統本身不定期把檔案內容 flush 到磁碟。設為 1 最安全,在每個語句或事務後同步一次 binary log,即使在崩潰時也最多丟失一個語句或事務的日誌,但因此也最慢。這裡設定為0,斷電的情況下導致binlog cache資料丟失沒有寫入主庫的binlog,但binlog資訊已同步至從庫。這種情況容易導致主從資料不一致,所以即使恢復主從資料後,依舊要通過主從資料對比校驗資料的一致性。

mysql> set global sync_binlog=1;
Query OK, 0 rows affected (0.00 sec)

更改配置檔案my.cnf設定sync_binlog=1

5.主從資料校驗

 pt-table-checksum h=master_ipaddr,u=username,p='password',P=mysql_port --nocheck-binlog-format --recursion-method=hosts

pt-table-checksum h=master_ipaddr,u=username,p='password',P=mysql_port --nocheck-binlog-format --recursion-method=hosts  
Checking if all tables can be checksummed ...
Starting checksum ...
            TS ERRORS  DIFFS     ROWS  CHUNKS SKIPPED    TIME TABLE
08-03T17:49:29      0      0      595       1       0   0.186 user.hole

其中--recursion-method有幾種方式檢視從庫資訊,這裡採用的是hosts方式,需要在從庫加入如下引數,方可在主庫執行show slave hosts檢視從庫的資訊

report_host=slave_ip

 

report_port=slave_port

METHOD       USES
===========  =============================================
processlist  SHOW PROCESSLIST
hosts        SHOW SLAVE HOSTS
cluster      SHOW STATUS LIKE 'wsrep\_incoming\_addresses'
dsn=DSN      DSNs from a table
none         Do not find slaves

 

6.innodb_flush_log_at_trx_commit引數擴充套件

innodb_flush_log_at_trx_commit 引數指定了 InnoDB 在事務提交後的日誌寫入頻率。這麼說其實並不嚴謹,且看其不同取值的意義和表現。

    當 innodb_flush_log_at_trx_commit 取值為 0 的時候,log buffer 會 每秒寫入到日誌檔案並刷寫(flush)到磁碟。但每次事務提交不會有任何影響,也就是 log buffer 的刷寫操作和事務提交操作沒有關係。在這種情況下,MySQL效能最好,但如果 mysqld 程式崩潰,通常會導致最後 1s 的日誌丟失。
    當取值為 1 時,每次事務提交時,log buffer 會被寫入到日誌檔案並刷寫到磁碟。這也是預設值。這是最安全的配置,但由於每次事務都需要進行磁碟I/O,所以也最慢。
    當取值為 2 時,每次事務提交會寫入日誌檔案,但並不會立即刷寫到磁碟,日誌檔案會每秒刷寫一次到磁碟。這時如果 mysqld 程式崩潰,由於日誌已經寫入到系統快取,所以並不會丟失資料;在作業系統崩潰的情況下,通常會導致最後 1s 的日誌丟失。

 

相關文章