Mysql slave 同步錯誤解決
分析解決
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. 錯誤仍存在,如下
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','913151000777430','xxx',now(),null,null,null,0,0)'
至此看來,雖然找到問題原因必須解決以上這個問題。 進一步了解mysql 同步機制及bin log, 原理:slave 獲取master的binlog, 並執行,執行報錯說明數據庫已有這條記錄,可能原因是日志中的position不准確,只能從binlog入手分析,
binlog查看參考: MySQL的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,每條記錄包含1個數據庫操作。
在bin log 中,很容易找到出錯的語句,現在問題是:找到slave SQL線程執行到哪個position. 這裡只能采用最笨的辦法,根據sql 語句,查看slave庫中的數據,如:
Query | 1 | 504873619 | replace into content_preference(userId,contentId,playRecordId,status,createTime)
values (587658,15308,1544691,0,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.00 sec)
mysql> CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000274',MASTER_LOG_POS=504873114;
Query OK, 0 rows affected (1.98 sec)
mysql> start slave;
Query OK, 0 rows affected (0.00 sec)
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Queueing master event to the relay log
Master_Host: 172.17.128.15
Master_User: xxx
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000274
Read_Master_Log_Pos: 693913486
Relay_Log_File: app3-relay-bin.000002
Relay_Log_Pos: 1819098
Relay_Master_Log_File: mysql-bin.000274
Slave_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工作監控。