起因:生产环境中的gps历史数据存放在gps数据库中,为了保持数据库的稳定和快速,需要将一年以前的gps历史数据删除,将数据库做完全备份的时候由于对备份后文件的估算错误,导致磁盘空间占满,虽然有naigos报警,但值班同事收到报警短信没有太在意,磁盘空间满了以后导致gps数据库写入故障,kill掉mysql后重启后,导致从服务器同步出现问题!
环境:
系统环境:CentOS release 5.5 64bit
数据库环境:mysql 5.1.50 ,innodb引擎 ,采用了分区表存储数据
数据库架构:mysql主从同步,架构图如下:
详细过程:
问题之----初步出现:
由于gps历史数据太多,数据达到了300多G,而网站业务需要的数据只需要调用最近一年的历史数据,因此一年以前的历史数据的存在会导致表的查询变慢,影响服务器的性能和稳定,因此需要对gps的历史数据一年以前的进行备份后删除,我的想法是:
1、 先对gps库进行全库备份
2、 编写perl脚本去查询出所有含有一年以前的车辆和数据,然后采用select * into outfile的方式对每辆车的数据进行备份后删除
因为用du -sh gps目录查看到总数据量为303G,因此我推算采用mysqldump备份出来的全备文件应该在320G左右,当时服务器还有385G的空间,因此没有意识到会把磁盘空间占满,再说了有naigos实时报警,如果磁盘空间使用超过80%就会报警短信到值班同事的手机上,因此没太在意。于是在晚上10点以后使用如下命令进行备份
nohup mysqldump -uroot -ppassword --single-transaction --flush-logs --master-data=2 gps > gps_`date -d "today" +%Y-%m-%d-%H-%M-%S`.sql &
就睡觉去了,结果早上8点多的时候收到报警gps不上数据了!赶紧登录到服务器上查看,发现磁盘空间已经被沾满,清除了一些日志以后释放出几十G的空间,然后再查看数据库中的数据写入情况,发现还是有问题,于是自己建了一张表,测试写入数据,等待了一会超时了,无法写入!于是执行重启mysql的操作: ,等了几分钟,还是不见动静,只能查询出mysqld的id,采用kill -9的形式杀死,然后执行/etc/rc.d/init.d/mysqld start的方式启动。启动OK了!再查看服务器也能正常写入数据了!看来mysqldump备份出来的文件会比du -sh看到的大好多,要记着这个教训,询问值班同事是否收到磁盘空间报警的短信,答曰:收到好多,想着磁盘报警不重要就直接忽略了!晕倒。差点害死人了!
问题之----深入探索:
以为已经没有问题了,过了10分钟左右,手机就收到mysql从服务器同步错误的报警,登录到从服务器上使用如下命令查看,限于篇幅,下面只显示重要信息,将其他信息去掉了!
root@(none) 09:56>show slave status\G;
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Log_File: mysql-bin.000593
Read_Master_Log_Pos: 581672913
Relay_Log_File: localhost-relay-bin.000002
Relay_Log_Pos: 251
Relay_Master_Log_File: mysql-bin.000593
Last_Errno: 1594
Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
Skip_Counter: 0
Exec_Master_Log_Pos: 550066696
Relay_Log_Space: 31606627
Last_SQL_Errno: 1594
Last_SQL_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
显然是由于刚才将mysqld进程杀死导致读取主服务器端日志错误。以前曾经遇到过类似的问题,直接指定Exec_Master_Log_Pos最后制定的位置,重新同步应该就ok了,于是执行:
stop slave
change master to master_host='192.168.100.130',master_user='replication',master_password='password',master_log_file='mysql-bin.000593', master_log_pos=550066696;
start slave
再用show slave status还是报同样的错误,没办法,只得到主服务器上去跟踪master_log_pos=550066696附近到底有什么问题导致不能正确同步,登录到主服务器查看:
mysqlbinlog | grep -A10 550066696
COMMIT/*!*/;
# at 550066696
ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 56902, event_type: 2
原来是这个错误,这个是mysql-bin.000593最后的日志记录,主上mysql重启后又重新生成了一个新的日志mysql-bin.000594,于是通过命令
mysqlbinlog mysql-bin.000594 | less
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#111122 9:27:49 server id 1 end_log_pos 106 Start: binlog v 4, server v 5.1.50-log created 111122 9:27:49 at startup
问题之----完美解决:
找到第一个位置为4然后执行如下命令:
stop slave;
change master to master_host='192.168.100.130',master_user='replication',master_password='password',master_log_file='mysql-bin.000594', master_log_pos=4;
start slave;
OK了,天下太平了!哈哈哈!
经验总结:
mysqldump备份出来的文件会比du -sh看到的大比较多,因此在用mysqldump进行打数据库备份的时候需要考虑磁盘空间的因素!另外一个教训就是对收到的报警要重视,提高职业素质!坚持运维24小时最快响应的原则!