is this a bug?

MySQL & MariaDB Other MySQL® Questions
1

i have met a replication error:

the slave server crashed
when it started again,
I execute the command: “show slave status”

*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: xx.xx.xx.xx
Master_User: repl
Master_Port: xxxx
Connect_Retry: 60
Master_Log_File: mysql-bin.000858
Read_Master_Log_Pos: 379908871
Relay_Log_File: relay-bin.000620
Relay_Log_Pos: 724847546
Relay_Master_Log_File: mysql-bin.000806
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 ‘1544846670’ for key ‘PRIMARY’’ on query. Default database: ‘xxxxxx_databasename’. Query: 'INSERT INTO xxx_tabname (…) VALUES ( 1165305, 17120165, 10, 100301, 81003010003, 2005, 1005, 50, 0, NULL, ‘2013-04-28 18:24:48’, ‘2013-07-28 23:59:59’, 1000, 1000, NULL, 1000, NULL, NULL, 0, NULL,
Skip_Counter: 0
Exec_Master_Log_Pos: 724847400
Relay_Log_Space: 56238889769
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 ‘1544846670’ for key ‘PRIMARY’’ on query. Default database: ‘xxxxxx_databasename’. Query: 'INSERT INTO xxx_tabname (…) VALUES ( 1165305, 17120165, 10, 100301, 81003010003, 2005, 1005, 50, 0, NULL, ‘2013-04-28 18:24:48’, ‘2013-07-28 23:59:59’, 1000, 1000, NULL, 1000, NULL, NULL, 0, NULL,
Replicate_Ignore_Server_Ids:
Master_Server_Id: 4
1 row in set (0.00 sec)

but i found that the slave did not contain a row that the id = 1544846670;

then I executed ‘start slave’
and show slave status again:
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: xx.xx.xx.xx
Master_User: repl
Master_Port: xxxx
Connect_Retry: 60
Master_Log_File: mysql-bin.000858
Read_Master_Log_Pos: 379935147
Relay_Log_File: relay-bin.000620
Relay_Log_Pos: 724847546
Relay_Master_Log_File: mysql-bin.000806
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 ‘1544846671’ for key ‘PRIMARY’’ on query. Default database: ‘xxxxxx_databasename’. Query: 'INSERT INTO xxx_tabname (…) VALUES ( 1165306, 14765802804742, 10, 100301, 81003010003, 2005, 1000, 50, 0, NULL, ‘2013-04-28 17:45:12’, ‘2014-04-27 23:59:59’, 6000, 5000, NULL, 5000, NULL, NULL, 0, N
Skip_Counter: 0
Exec_Master_Log_Pos: 724847400
Relay_Log_Space: 56238916045
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 ‘1544846671’ for key ‘PRIMARY’’ on query. Default database: ‘dxxxxxx_databasename’. Query: 'INSERT INTO xxx_tabname (…) VALUES ( 1165306, 14765802804742, 10, 100301, 81003010003, 2005, 1000, 50, 0, NULL, ‘2013-04-28 17:45:12’, ‘2014-04-27 23:59:59’, 6000, 5000, NULL, 5000, NULL, NULL, 0, N
Replicate_Ignore_Server_Ids:
Master_Server_Id: 4
1 row in set (0.00 sec)

the error record became the next one;
but I did nothing else! except the “start slave” command
then I found that the record(id=‘1544846671’) didnot exist too.

Now the slave had been recreated.

mysql-error.log:

141211 18:56:11 [ERROR] Slave SQL: Error ‘Duplicate entry ‘1544846670’ for key ‘PRIMARY’’ on query. Default database: ‘xxxx_databasename’. Query: 'INSERT INTO tabname (…) VALUES ( 1165305, 17120165, 10, 100301, 81003010003, 2005, 1005, 50, 0, NULL, ‘2013-04-28 18:24:48’, ‘2013-07-28 23:59:59’, 1000, 1000, NULL, 1000, NULL, NULL,
141211 18:56:11 [Warning] Slave: Duplicate entry ‘1544846670’ for key ‘PRIMARY’ Error_code: 1062
141211 18:56:11 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with “SLAVE START”. We stopped at log ‘mysql-bin.000806’ position 724847400
141212 9:35:01 [Note] Slave SQL thread initialized, starting replication in log ‘mysql-bin.000806’ at position 724847400, relay log ‘/var/lib/mysql/relay-bin.000620’ position: 724847546
141212 9:35:01 [ERROR] Slave SQL: Error ‘Duplicate entry ‘1544846671’ for key ‘PRIMARY’’ on query. Default database: ‘xxxx_databasename’. Query: 'INSERT INTO tabname (…) VALUES ( 1165306, 14765802804742, 10, 100301, 81003010003, 2005, 1000, 50, 0, NULL, ‘2013-04-28 17:45:12’, ‘2014-04-27 23:59:59’, 6000, 5000, NULL, 5000, NULL, N
141212 9:35:01 [Warning] Slave: Duplicate entry ‘1544846671’ for key ‘PRIMARY’ Error_code: 1062
141212 9:35:01 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with “SLAVE START”. We stopped at log ‘mysql-bin.000806’ position 724847400
141212 9:35:56 [Note] Slave SQL thread initialized, starting replication in log ‘mysql-bin.000806’ at position 724847400, relay log ‘/var/lib/mysql/relay-bin.000620’ position: 724847546
141212 9:35:56 [ERROR] Slave SQL: Error ‘Duplicate entry ‘1544846672’ for key ‘PRIMARY’’ on query. Default database: ‘xxxx_databasename’. Query: 'INSERT INTO tabname (…) VALUES ( 1165306, 36659631, 10, 100301, 81003010003, 2005, 1000, 50, 0, NULL, ‘2013-04-28 17:45:15’, ‘2014-04-27 23:59:59’, 6000, 5000, NULL, 5000, NULL, NULL,
141212 9:35:56 [Warning] Slave: Duplicate entry ‘1544846672’ for key ‘PRIMARY’ Error_code: 1062
141212 9:35:56 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with “SLAVE START”. We stopped at log ‘mysql-bin.000806’ position 724847400

2

Server version: 5.5.35-rel33.0-log Percona Server with XtraDB (GPL), Release rel33.0, Revision 611

3

This is surprising. The INSERT statement is truncated, does it include the PK value or is the PK an auto_increment column? If you check the rows in the slave for PK 1544846670, 1544846671, are those the rows inserted by the statements that once failed? Can you run SHOW CREATE TABLE on both master and slave? Also SELECT FROM WHERE pk_column > 1544846672;

4
5

The fact that auto_increment number increased and a different row showed in the SHOW SLAVE STATUS suggested that the previous row was inserted, but you didn’t see the row in the table. Is there any trigger defined or other jobs that might interfere? I’d suggest to track queries:

show slave status\G
select * from where pk_col > 1544846671;
set global general_log = 1;
stop slave;
start slave;
show slave status\G
select * from where pk_col > 1544846671;
$ cat /path/to/datadir/hostname.log

To stop capturing general queries:

set global general_log = 0;
stop slave;
start slave;

6

Thank you for reply, but I am sure there is no trigger or other jobs ,
the database had been recreated with xtrabackup., and the slave returns to normal. I think it maybe a bug.