Last_Errno: 1062，Last_Error: Error 'Duplicate entry '...' for key 'PRIMARY'' on query.的詳細分析過程 線上環境我從來沒有碰到過1062的問題，測試環境開發環境不停的出現類似問題，以往為了趕時間都是skip或者直接重新做，這會有時間，就好好去查查問題所在。
1 從庫報錯信息：
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: xxxx0402.china.online.ea.com
Master_User: replication
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000154
Read_Master_Log_Pos: 56680675
Relay_Log_File: mysql-relay-bin.000455
Relay_Log_Pos: 33013454
Relay_Master_Log_File: mysql-bin.000152
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1062
Last_Error: Error 'Duplicate entry '250.1.1-rding-changelogs/myIDENTITY/250/xxxx.xml' for key 'PRIMARY'' on query. Default database: 'identity'. Query: 'INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom SQL', '', '4ac9fbf5222bc344362ccdecbc072', '250.1.1', 'changelogs/myIDENTITY/250/xxxx.xml')'
Skip_Counter: 0
Exec_Master_Log_Pos: 33013308
Relay_Log_Space: 33020134
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
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1062
Last_SQL_Error: Error 'Duplicate entry '250.1.1-rding-changelogs/myIDENTITY/250/xxxx.xml' for key 'PRIMARY'' on query. Default database: 'identity'. Query: 'INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom SQL', '', '4ac9fbf5222bc344362ccdecbc072', '250.1.1', 'changelogs/myIDENTITY/250/xxxx.xml')'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
1 row in set (0.00 sec)
2 看表結構
mysql> show create table DATABASECHANGELOG;
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| DATABASECHANGELOG | CREATE TABLE `databasechangelog` (
`ID` varchar(63) NOT NULL,
`AUTHOR` varchar(63) NOT NULL,
`FILENAME` varchar(200) NOT NULL,
`DATEEXECUTED` datetime NOT NULL,
`MD5SUM` varchar(32) DEFAULT NULL,
`DESCRIPTION` varchar(255) DEFAULT NULL,
`COMMENTS` varchar(255) DEFAULT NULL,
`TAG` varchar(255) DEFAULT NULL,
`xxxx` varchar(10) DEFAULT NULL,
PRIMARY KEY (`ID`,`AUTHOR`,`FILENAME`) 坑爹的表設計結構，不是我喜歡的風格
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
3 看已經存在的數據
mysql> select * from DATABASECHANGELOG where AUTHOR ='rding';
+---------+--------+-----------------------------------------+---------------------+----------------------------------+-------------+------------------------------------------+------+-----------+
| ID | AUTHOR | FILENAME | DATEEXECUTED | MD5SUM | DESCRIPTION | COMMENTS | TAG | xxxx |
+---------+--------+-----------------------------------------+---------------------+----------------------------------+-------------+------------------------------------------+------+-----------+
| 250.1.1 | rding | changelogs/myIDENTITY/250/xxxx.xml | 2013-08-12 20:41:22 | 4ac9fbf5222bc344362ccdecbc072 | Custom SQL | | NULL | 1.9.3 |
| 250.1.2 | rding | changelogs/myIDENTITY/250/xxxx.xml | 2013-08-12 20:41:22 | 8463e1cf4ba029e3ace675d3e69a71d2 | Custom SQL | Create new table for email change record | NULL | 1.9.3 |
+---------+--------+-----------------------------------------+---------------------+----------------------------------+-------------+------------------------------------------+------+-----------+
2 rows in set (0.00 sec)
4 看binlog，在Relay_Master_Log_File: mysql-bin.000152，去主庫找這個binlog解析出來
解析
[root@xxxx0402 tmp]# mysqlbinlog mysql-bin.000152 > a152.log
搜索包含'rding'字符串的語句，因為這個是主鍵字段之一，所以檢索起來應該比較容易。
[root@xxxx0402 tmp]# grep a152.log 'rding' > rd.log
grep: rding: No such file or directory
[root@xxxx0402 tmp]# grep 'rding' a152.log > rd.log
[root@xxxx0402 tmp]# ll
[root@xxxx0402 tmp]# more rd.log
INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom
SQL', '', '4ac9fbf5222bc344362ccdecbc072', '250.1.1', 'changelogs/myIDENTITY/250/xxxx.xml')
INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom
SQL', 'Create new table for email change record', '8463e1cf4ba029e3ace675d3e69a71d2', '250.1.2', 'changelogs/myIDENTITY/250/xxxx.xml')
主庫上面只有一條insert sql語句。
5 再去看從庫的relay log日志Relay_Log_File: mysql-relay-bin.000455
[root@eanshlt2mydbc004db002 data]# cp mysql-relay-bin.000455 /tmp
[root@eanshlt2mydbc004db002 data]# cd /tmp
[root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-relay-bin.000455 > relay.log
[root@eanshlt2mydbc004db002 tmp]#
[root@eanshlt2mydbc004db002 tmp]# grep 'rding' relay.log > rd.log
[root@eanshlt2mydbc004db002 tmp]# more rd.log
INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom
SQL', '', '4ac9fbf5222bc344362ccdecbc072', '250.1.1', 'changelogs/myIDENTITY/250/xxxx.xml')
INSERT INTO `DATABASECHANGELOG` (`DATEEXECUTED`, `AUTHOR`, `xxxx`, `DESCRIPTION`, `COMMENTS`, `MD5SUM`, `ID`, `FILENAME`) VALUES (NOW(), 'rding', '1.9.3', 'Custom
SQL', 'Create new table for email change record', '8463e1cf4ba029e3ace675d3e69a71d2', '250.1.2', 'changelogs/myIDENTITY/250/xxxx.xml')
奇怪了，2邊的都是一樣子的。這個錯誤怎麼判斷？ 6 去看下主從關於這個數據記錄的錄入時間。
從庫上面：
mysql> select * from DATABASECHANGELOG where AUTHOR='rding' and ID='250.1.1' and FILENAME='changelogs/myIDENTITY/250/xxxx.xml'\G;
*************************** 1. row ***************************
ID: 250.1.1
AUTHOR: rding
FILENAME: changelogs/myIDENTITY/250/xxxx.xml
DATEEXECUTED: 2013-08-12 20:41:22
MD5SUM: 4ac9fbf5222bc344362ccdecbc072
DESCRIPTION: Custom SQL
COMMENTS:
TAG: NULL
xxxx: 1.9.3
1 row in set (0.00 sec)
ERROR:
No query specified
mysql>
主庫上面 ：
mysql> select * from DATABASECHANGELOG where AUTHOR='rding' and ID='250.1.1' and FILENAME='changelogs/myIDENTITY/250/xxxx.xml'\G;
*************************** 1. row ***************************
ID: 250.1.1
AUTHOR: rding
FILENAME: changelogs/myIDENTITY/250/xxxx.xml
DATEEXECUTED: 2013-08-12 19:54:29
MD5SUM: 4ac9fbf5222bc344362ccdecbc072
DESCRIPTION: Custom SQL
COMMENTS:
TAG: NULL
xxxx: 1.9.3
1 row in set (0.02 sec)
ERROR:
No query specified
mysql>
看DATEEXECUTED時間字段都是8月12日錄入的，可惜我的db server由於磁盤有限，只保存了近期的binlog，而且現在主庫上面最早的binlog就是出錯的那個mysql-bin.000152 7 最後一招，去看從庫的binlog，看是否近期有人insert了這條記錄
[root@eanshlt2mydbc004db002 data]# cp mysql-bin.004* /tmp/ [root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-bin.004268 > 1.log [root@eanshlt2mydbc004db002 tmp]# grep 'rding' 1.log > rd1.log [root@eanshlt2mydbc004db002 tmp]# ll rd1.log -rw-r--r-- 1 root root 0 Sep 3 17:47 rd1.log
空的，第一個日志沒有錄入操作
[root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-bin.004269 > 2.log [root@eanshlt2mydbc004db002 tmp]# grep 'rding' 2.log > rd2.log [root@eanshlt2mydbc004db002 tmp]# ll rd2.log -rw-r--r-- 1 root root 0 Sep 3 17:48 rd2.log [root@eanshlt2mydbc004db002 tmp]#
空的，第二個日志沒有錄入操作
[root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-bin.004270 > 3.log [root@eanshlt2mydbc004db002 tmp]# grep 'rding' 3.log > rd3.log [root@eanshlt2mydbc004db002 tmp]# ll rd3.log -rw-r--r-- 1 root root 0 Sep 3 17:49 rd3.log [root@eanshlt2mydbc004db002 tmp]#
空的，第三個日志沒有錄入操作
[root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-bin.004271 > 4.log ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 438, event_type: 2 [root@eanshlt2mydbc004db002 tmp]# grep 'rding' 4.log > rd4.log [root@eanshlt2mydbc004db002 tmp]# ll rd4.log -rw-r--r-- 1 root root 0 Sep 3 17:50 rd4.log
空的，第四個日志沒有錄入操作 這裡解析報錯了，解決方案，記錄在如此
[root@eanshlt2mydbc004db002 tmp]# mysqlbinlog mysql-bin.004272 > 5.log [root@eanshlt2mydbc004db002 tmp]# grep 'rding' 5.log > rd5.log [root@eanshlt2mydbc004db002 tmp]# ll rd5.log -rw-r--r-- 1 root root 0 Sep 3 18:07 rd5.log [root@eanshlt2mydbc004db002 tmp]#
空的，第五個日志沒有錄入操作 解析了從庫的5個日志，都沒有看到這條紀律的insert操作，問題到此卡住了，原因何在？這邊開發的兄弟們已經在催了，我只要skip之後從庫重新做了。
mysql> stop slave;
set global sql_slave_skip_counter=1;
start slave;
show slave status\G
Query OK, 0 rows affected (0.09 sec)
mysql> set global sql_slave_skip_counter=1;
Query OK, 0 rows affected (0.00 sec)
mysql> start slave;
Query OK, 0 rows affected (0.00 sec)
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: xxxx0402.china.online.ea.com
Master_User: replication
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000184
Read_Master_Log_Pos: 27865900
Relay_Log_File: mysql-relay-bin.000495
Relay_Log_Pos: 253
Relay_Master_Log_File: mysql-bin.000171
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
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: 107
Relay_Log_Space: 8000
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: 3434734
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
1 row in set (0.11 sec)
mysql>
