環境：雙M-M架構，其中一臺B因為磁碟損壞，伺服器異常重啟。重啟之後B上面的資料庫正常執行，當時A 庫報如下錯誤：

Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position

root@rac1 # my 3306

Entry Port ==== 3306

Welcome to the MySQL monitor. Commands end with ; or \g.

Your MySQL connection id is 1612406693

Server version: 5.1.40-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

root@127.0.0.1 : (none) 20:55:50> show slave status \G

*************************** 1. row ***************************

Slave_IO_State:

Master_Host: 10.250.7.3

Master_User: replicator

Master_Port: 3306

Connect_Retry: 60

Master_Log_File: mysql-bin.000143

Read_Master_Log_Pos: 664526789

Relay_Log_File: slave-relay.000339

Relay_Log_Pos: 251

Relay_Master_Log_File: mysql-bin.000143

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: 664526789

Relay_Log_Space: 445

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'

Last_SQL_Errno: 0

Last_SQL_Error:

1 row in set (0.00 sec)

root@127.0.0.1 : (none) 20:55:52> exit

Bye

檢視A庫的error log日誌發現

root@rac1 # tail -f /home/mysql/data/mysql/master-error.log

120611 19:32:35 [Warning] Aborted connection 1341365540 to db: 'unconnected' user: 'replicator' host: '10.250.7.3' (Got timeout writing communication packets)

120611 20:31:28 [ERROR] Error reading packet from server: Client requested master to start replication from impossible position ( server_errno=1236)

120611 20:31:28 [ERROR] Slave I/O: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position', Error_code: 1236

120611 20:31:28 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000143', position 664526789

120611 20:39:27 [Note] Error reading relay log event: slave SQL thread was killed

120611 20:39:38 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000143' at position 664526789, relay log '/home/mysql/data/mysql/slave-relay.000339' position: 251

120611 20:39:38 [Note] Slave I/O thread: connected to master 'replicator@10.250.7.3:3306',replication started in log 'mysql-bin.000143' at position 664526789

120611 20:39:38 [ERROR] Error reading packet from server: Client requested master to start replication from impossible position ( server_errno=1236) 上面的位置錯誤

120611 20:39:38 [ERROR] Slave I/O: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position', Error_code: 1236

120611 20:39:38 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000143', position 664526789

Slave_IO_Running執行緒終止。仔細看上面的報錯資訊，說slave程式試圖從mysql-bin.000143日誌的 position 664526789開始啟動恢復，但是該日誌中是沒有此position。

根據主庫A 上的錯誤資訊

120611 20:39:38 [Note] Slave I/O thread: connected to master 'replicator@10.250.7.3:3306',replication started in log 'mysql-bin.000143' at position 664526789

到從庫B 上檢視其bin log記錄

root@rac2 # mysqlbinlog mysql-bin.000143 > log_20120611.sql

root@rac2 #

root@rac2 # tail -f log_20120611.sql

SET TIMESTAMP=1339414288/*!*/;

insert into vm_monitor_20120611(time_stamp,name,group_id,user_id,cpu,memory,rx,tx,flow_volume,bandwidth, read_iops, write_iops, gmt_create) values(1339414287,'VM-3157068F','977','21',10.0304,12288,14533,31178,45711,1524,221.4,9.66667,'2012-06-11,19:31:28')

/*!*/;

# at 664521543 <===最後的日誌記錄位置明顯小於 A 報錯資訊中的 664526789 所以才報錯說“impossible position” 因為本來就沒有嘛

#120611 19:31:28 server id 2 end_log_pos 664521570 Xid = 546104615

COMMIT/*!*/;

DELIMITER ;

# End of log file

ROLLBACK /* added by mysqlbinlog */;

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

回到主庫A 上面進行重新指定應用日誌的位置,檢視master.info資訊，從這裡也可以看出 io thread 進行恢復的起始位置為不合理的664526789

root@rac1 #

root@rac1 # more master.info

15

mysql-bin.000143

664526789

10.250.7.3

replicator

xxxxxxxx

3306

60

0

root@rac1 # my 3306

Entry Port ==== 3306

Welcome to the MySQL monitor. Commands end with ; or \g.

Your MySQL connection id is 1612460302

Server version: 5.1.40-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

root@127.0.0.1 : (none) 21:11:51> stop slave;

Query OK, 0 rows affected (0.00 sec)

這裡可以指定mysql-bin.000144 的第一個post 也可以指定 mysql-bin.000143的664521543位置！

root@127.0.0.1 : (none) 21:12:27> CHANGE MASTER TO MASTER_HOST='10.250.7.3',

-> MASTER_USER ='replicator',

-> MASTER_PASSWORD ='xxxxx',

-> MASTER_LOG_FILE ='mysql-bin.000144',

-> MASTER_LOG_POS =4,

-> master_port =3306;

Query OK, 0 rows affected (0.16 sec)

root@127.0.0.1 : (none) 21:13:32> start slave;

Query OK, 0 rows affected (0.00 sec)

root@127.0.0.1 : (none) 21:13:38>

root@127.0.0.1 : (none) 21:13:38> show slave status \G

*************************** 1. row ***************************

Slave_IO_State: Waiting for master to send event

Master_Host: 10.250.7.3

Master_User: replicator

Master_Port: 3306

Connect_Retry: 60

Master_Log_File: mysql-bin.000144

Read_Master_Log_Pos: 148515312

Relay_Log_File: slave-relay.000002