涉及知识点
mysql 主同步 ,参考:
mysqlbin log查看,参考:MySQL的binlog日志
解决slave参考:
slave根据库失败库失败的原因,并根据binlog 修改position 手动同步
问题
客户反映报表缺乏近期数据。
分析解决
master 数据库提供服务,slave通过数据库作报表服务器mysqlbin log做主从同步。
从报告数据来看,从10/28到现在(11/18)之前的数据缺乏比较master、slave数据库主要表数据,发现:
10/28之后的slave缺乏库数据,一致性不同步。
查看slave mysql同步状态:
关注图中的黄色字段:
Slave_IO_Running: Yes
Slave_SQL_Running: No --- 表示sql如果过程不工作,问题就在这里。
粉色背景,Last_Error: ....
'Duplicate entry '1169595' for key 'PRIMARY'' on query. Default database: ''. Query: 'insert into user。。。
这个错误很简单,违反了主键的唯一约束。
2. mysql 错误日志 通过my.conf 确定出错误日志文件,vi 根据日志151028搜索以下内容:
10/28 1:28:55 mysql 异常关闭; 1:29 重启后,开始recovery。1:29:16s 后I/O errror; 1:30:19s SQL error,slave SQL thread aborted(停止工作)。
mysql还给出了解决方案:
Fix the problem,and restart the slave SQL thread with "SLAVE START". We stopped at log 'mysql-bin.000274' position 504869752
重启,告诉我sql 执行的binlog 文件设置position,重启slave. 错误仍然存在,如下
mysql> CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000274',MASTER_LOG_POS=504873114;
ERROR1198 (HY000): This operation cannot be performed witha running slave; run STOP SLAVE first
mysql>stop slave;
Query OK,0 rows affected (0.00sec)
mysql> CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000274',MASTER_LOG_POS=504873114;
Query OK,0 rows affected (1.98sec)
mysql>start slave;
Query OK,0 rows affected (0.00sec)
mysql>show slave status\G*************************** 1. row ***************************Slave_IO_State: Waitingfor master tosend event
Master_Host:172.17.128.15Master_User: cns
Master_Port:3306Connect_Retry:60Master_Log_File: mysql-bin.000281Read_Master_Log_Pos:361947072Relay_Log_File: app3-relay-bin.000002Relay_Log_Pos:253Relay_Master_Log_File: mysql-bin.000274Slave_IO_Running: Yes
Slave_SQL_Running: No
View Code
错误的原因仍然是
Last_SQL_Error: Error 'Duplicate entry '1169595' for key 'PRIMARY'' on query. Default database: ''. Query: 'insert into user (type,lang,ipAddr,activityStatus,extUserId,endpoint,createTime,email,userName,mobile,storageSize,tuner
)values ('normal','zh-xx','xxxx','active‘913150077430’xxx',now(),null,null,null,0,0)'
到目前为止,尽管发现问题的原因必须解决上述问题。进一步了解mysql 同步机制及bin log,原理:slave 获取master的binlog,并执行,执行错误表明数据库有此记录,可能是因为日志position不准确,只能从binlog入手分析,
以第二种方式查看这里:
mysql> show binlog events [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count];
选项解析:
IN 'log_name 指定要查询的binlog文件名(不指定是第一个binlog文件)
FROM pos 指定从哪里来pos起点开始检查(不指定是整个文件的第一个pos点开始算)
LIMIT [offset,] 偏移量(不指定为0)
row_count 查询总数(不指定就是所有行)
log_name,pos 已知错误日志,查询如下:
binlog 包括所有数据库操作sql,每个记录包含一个数据库操作。
在bin log 很容易找到错误的句子,现在的问题是:找到slave SQL哪个线程执行position. 这里只能用最笨的方法,根据sql 句子,查看slave库中的数据,如:
Query | 1 | 504873619 | replace into content_preference(userId,contentId,playRecordId,status,createTime)
values now())
此sql语句为向content_preference 插入记录,然后salve库中content_preference确定表中是否有id=587658,contentId=如果有15308的记录,则表示句话已经执行了。
一直往下搜索,最后发现没有执行。sql 记录,找到position。
至此,可以判断slave库中执行binlog 的position,重新设定slave库的binlog position ,启动slave,检查执行状态,running,见下:
mysql>stop slave;
Query OK,0 rows affected (0.00sec)
mysql> CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000274',MASTER_LOG_POS=504873114;
Query OK,0 rows affected (1.98sec)
mysql>start slave;
Query OK,0 rows affected (0.00sec)
mysql>show slave status\G*************************** 1. row ***************************Slave_IO_State: Queueing master eventto the relay logMaster_Host:172.17.128.15Master_User: xxx
Master_Port:3306Connect_Retry:60Master_Log_File: mysql-bin.000274Read_Master_Log_Pos:693913486Relay_Log_File: app3-relay-bin.000002Relay_Log_Pos:1819098Relay_Master_Log_File: mysql-bin.000274Slave_IO_Running: Yes
Slave_SQL_Running: Yes
在备份执行完毕后,报表导出数据正常,问题解决。
反思
mysql在11/28日重启,原因是当天线上服务出现异常,无法解决,重启了机器,当时没考虑到报表数据库也在此机器上,重启后也未检查数据库备份情况,直到用户使用才发现问题。
mysql意外重启,虽然在下次重启启动后,记录了异常信息,和备份的binlog 日志文件及位置。如果是正在执行binlog SQL,但此时mysql意外关闭,记录的position 较旧,导致下次启动时,
会有部分binlog 日志重复执行导致。 此问题,不能说是mysql bug,这种机制,可以保证slave数据不至于丢失,但需要人工找到posion,即可。
后续:
1. 对于机器重启情况, 可手动执行stop slave. 在正常关闭mysql, 重启后,手动start slave, 应该就可以正常同步。
2. 线上系统,重启一定要小心, 重启后监控相关模块是否启动,可以增加mysql slave工作监控。