由于主库的主机192.168.1.1宕机,再次启来后,从库192.168.71.1连接主库发现报错. Slave_IO_Running: No 

root@192.168.71.1:~# mysql -uroot -p --socket=/opt/mysql/3399/3399.sock 
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 452723
Server version: 5.0.51a-24+lenny2 (Debian)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show slave status\G;
*************************** 1. row ***************************
             Slave_IO_State: 
                Master_Host: 192.168.1.1
                Master_User: repl
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: 99.000302
        Read_Master_Log_Pos: 165112917
             Relay_Log_File: 3399-relay-bin.000013
              Relay_Log_Pos: 165113047
      Relay_Master_Log_File: 99.000302
           Slave_IO_Running: No
          Slave_SQL_Running: Yes
            Replicate_Do_DB: 
        Replicate_Ignore_DB: mysql
         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: 165112917
            Relay_Log_Space: 165113047
            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
1 row in set (0.00 sec)


查看错误日志

mysql@192.168.71.1:/opt/mysql/3399$ cat 192.168.71.1.err
140115  1:51:01 [ERROR] Error reading packet from server: Client requested master to start replication from impossible position ( server_errno=1236)
140115  1:51:01 [ERROR] Got fatal error 1236: 'Client requested master to start replication from impossible position' from master when reading data from binary log
140115  1:51:01 [Note] Slave I/O thread exiting, read up to log '99.000302', position 165112917


根据错误位置,查找主库上log ‘99.000302’ 对应的位置 165112917

root@192.168.1.1:mysql.bin# mysqlbinlog 99.000302 > /tmp/test
root@192.168.1.1:mysql# tail -n 10 /tmp/test 
#140115  0:50:25 server id 1176  end_log_pos 165111351 	Query	thread_id=111	exec_time=0	error_code=0
SET TIMESTAMP=1389718225/*!*/;
INSERT INTO user_info_db_86.region_info_table_56 (userid, region, gameflag) VALUES (563625686, 0, 2) ON DUPLICATE KEY UPDATE gameflag = (gameflag | 2)/*!*/;
# at 165111351
#140115  0:50:25 server id 1176  end_log_pos 165111378 	Xid = 17877752
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

结果发现主库上位置最后是165111351 比165112917要小. 也就是从库同步找的位置比主库要大,故同步不成功


为什么会这样,这是因为这个在sync_binlog=0的情况,很容易出现。


sync_binlog=0,当事务提交之后,MySQL不做fsync之类的磁盘同步指令刷新binlog_cache中的信息到磁盘,而让系统自行决定什么时候来做同步,或者cache满了之后才同步到磁盘。

sync_binlog=n,当每进行n次事务提交之后,MySQL将进行一次fsync之类的磁盘同步指令来将binlog_cache中的数据强制写入磁盘。

在MySQL中系统默认的设置是sync_binlog=0,也就是不做任何强制性的磁盘刷新指令,这时候的性能是最好的,但是风险也是最大的。因为一旦系统Crash,在binlog_cache中的所有binlog信息都会被丢失。而当设置为“1”的时候,是最安全但是性能损耗最大的设置。因为当设置为1的时候,即使系统Crash,也最多丢失binlog_cache中未完成的一个事务,对实际数据没有任何实质性影响。从以往经验和相关测试来看,对于高并发事务的系统来说,“sync_binlog”设置为0和设置为1的系统写入性能差距可能高达5倍甚至更多。


这里由于mysql是默认配置所以该报错原因是: sync_binlog=0时 ,master binlog文件的flush log buffer(这个buffer是由于binlog文件的os buffer)  到disk是依赖于OS本身的,但Slave IO 线程在读取master dump 线程的位置,一般是直接读取log buffer的,这个位置,可能远远大于binlog文件实际大小。 所以当主机宕机后,binlog buffer未刷盘,当Master主机再次启动后,此时从库的binlog pos 165112917  已经比实际的binlog位置大小165111351


解决方法:

直接做change master to到当下一个binlog。

CHANGE MASTER TO
  MASTER_HOST='192.168.1.1',
  MASTER_USER='repl',
  MASTER_PASSWORD='replpass',
  MASTER_PORT=3306,
  MASTER_LOG_FILE='99.000303',
  MASTER_LOG_POS=98;