091127 21:50:21 [ERROR] Error reading packet from server: Client requested master to start replication
from impossible position ( server_errno=1236)
091127 21:50:21 [ERROR] Got fatal error 1236: 'Client requested master to start replication
from impossible position' from master when reading data from binary log
091127 21:50:21 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000535', position 193022771
Slave_IO_Running线程终止。仔细看上面的报错信息,说slave进程试图从mysql-bin.000535日志的 position 193022771开始启动恢复,但是该日志中是没有这个position的。
跑到A上通过mysqlbinlog查看该日志,发现最后一个有效position是193009460。而要求的193022771已经大于最后有效的position了。这个原因就搞不明白了,难道是因为A库异常关闭后导致A节点的binlog没有来得及刷到磁盘,而B节点slave已经恢复到前面去了?
$mysqlbinlog mysql-bin.000535 > 1.txt
$tail -n 7 1.txt
# at 193009460
#091127 20:50:21 server id 1 end_log_pos 193009487 Xid = 194299849
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
尝试将B节点change master到最后一个有效的position处,问题暂时得到解决:
change master to master_log_file='mysql-bin.000535', master_log_pos=193009460
网上搜索了一把,发现logzgh之前也碰到过同样的问题,版本是5.0.51。
=================================================================
转:http://denniswwh.itpub.net/post/15174/471080
今天几台MySQL服务器突然停电,重启后复制无法启动,总是报如下错误:
080922 10:29:01 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000778' at position 2874108, relay log '
./relay-bin.003287' position: 2874245
080922 10:29:01 [Note] Slave I/O thread: connected to master 'replication@192.168.0.10:3306', replication started in log 'mysql-b
in.000778' at position 2874108
080922 10:29:01 [ERROR] Error reading packet from server: Client requested master to start replication from impossible position ( se
rver_errno=1236)
080922 10:29:01 [ERROR] Got fatal error 1236: 'Client requested master to start replication from impossible position' from master wh
en reading data from binary log
为什么会报impossible position呢?打开mysql-bin.000778看看。
mysqlbinlog mysql-bin.000778 > log.sql
tail -f log.sql
# at 2871574
#080922 10:20:27 server id 2 end_log_pos 2871601 Xid = 2516638
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/
最后一个position是2871574,而 从库要从2874108开始,难怪报impossible position,难道是断电时有部分log在缓存中还没来得及写入binglog?无论如何先恢复再说吧
stop slave;
CHANGE MASTER TO
MASTER_LOG_FILE='mysql-bin.000778',
MASTER_LOG_POS=2871574;
start slave;
show slave statusG
同步正常。。
后来查看主库的启动日志中这样一段
InnoDB: Last MySQL binlog file position 0 2874108, file name ./mysql-bin.000778
080922 10:22:09 InnoDB: Started; log sequence number 6 2534366248
080922 10:22:09 [Note] Recovering after a crash using mysql-bin
080922 10:22:09 [Note] Starting crash recovery...
080922 10:22:09 [Note] Crash recovery finished.
080922 10:22:09 [Note] /usr/sbin/mysqld: ready for connections.
这里Last MySQL binlog file position 0 2874108也是错误的,这个信息到底是哪里来的呢?为什么会这样呢?不明白。
为了保证以后binglog及时写入,将主库 sync_binlog变量设置1。