MySQL案例09:Last_IO_Error: Got fatal error 1236 from master when reading data from binary log
剛處理完“挖礦”事件，在做最后一個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 的日志丟失。
浙公網安備 33010602011771號