Bug #24571 replication seems to generate an invalid insert command
Submitted: 24 Nov 2006 12:07 Modified: 28 Nov 2006 9:30
Reporter: Mark Zealey Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server Severity:S4 (Feature request)
Version:5.0.27 OS:
Assigned to: CPU Architecture:Any

[24 Nov 2006 12:07] Mark Zealey
Description:
I took a master snapshot of a database a couple of days ago (it was recently upgraded from mysql3, but we havn't had any other problems with it). After about 2 days, I created a slave server and initalized it with the copied data (as the manual says). It's got through quite a lot of the replication process, but is then stuck, saying the following:

| Slave_IO_State                   | Master_Host   | Master_User | Master_Port | Connect_Retry | Master_Log_File  | Read_Master_Log_Pos | Relay_Log_File                 | Relay_Log_Pos | Relay_Master_Log_File | Slave_IO_Running | Slave_SQL_Running | Replicate_Do_DB | Replicate_Ignore_DB | Replicate_Do_Table | Replicate_Ignore_Table | Replicate_Wild_Do_Table | Replicate_Wild_Ignore_Table | Last_Errno | Last_Error                                                                                                                                                                                                                                                                                                                                                                                                          | Skip_Counter | Exec_Master_Log_Pos | Relay_Log_Space | Until_Condition | Until_Log_File | Until_Log_Pos | Master_SSL_Allowed | Master_SSL_CA_File | Master_SSL_CA_Path | Master_SSL_Cert | Master_SSL_Cipher | Master_SSL_Key | Seconds_Behind_Master |
+----------------------------------+---------------+-------------+-------------+---------------+------------------+---------------------+--------------------------------+---------------+-----------------------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-----------------------------+------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+--------------------+-----------------+-------------------+----------------+-----------------------+
| Waiting for master to send event | XXX | repl        |        3306 |            30 | mysql-bin.012703 |             9693785 | cust-mysql02a-relay-bin.008019 |           235 | mysql-bin.004006      | Yes              | No                |                 |                     |                    |                        |                         |                             |       1064 | Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '= 0
                WHERE session_id = 'f1d2242bbff50451c4f1897221a31d6f'
                        AND session_ip =' at line 1' on query. Default database: 'davefussell2'. Query: 'INSERT INTO nuke_admin = 0
                WHERE session_id = 'f1d2242bbff50451c4f1897221a31d6f'
                        AND session_ip = 'XXX'ยท' |            0 |                  98 |       540071161 | None            |                |             0 | No                 |                    |                    |                 |                   |                |                  NULL |

On the master, having a look at this binlog file:

[root@webdb2 mysql]#  mysqlbinlog logs/mysql-bin.004006
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
# at 4
#061122  5:51:13 server id 1  end_log_pos 98    Start: binlog v 4, server v 5.0.27-standard-log created 061122  5:51:13
# at 98
#061122  5:51:13 server id 1  end_log_pos 408   Query   thread_id=16061 exec_time=0     error_code=0
use davefussell2;
SET TIMESTAMP=1164174673;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1;
SET @@session.sql_mode=0;
/*!\C latin1 */;
SET @@session.character_set_client=48,@@session.collation_connection=48,@@session.collation_server=48;
INSERT INTO nuke_bbsessions
                        (session_id, session_user_id, session_start, session_time, session_ip, session_page, session_logged_in)
                        VALUES ('8285f0fc8dcf032810773274566c4170', '1', '1164174673', '1164174673', 'XXX', '19', '0');
# at 408
#061122  5:51:13 server id 1  end_log_pos 451   Rotate to mysql-bin.004007  pos: 4
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Thus, it seems that the replication process on the slave is generating an invalid SQL command for that insert statement ?

Any ideas how to fix this problem and get the replication online again?

Thanks,

Mark

How to repeat:
see description.
[24 Nov 2006 13:05] Valeriy Kravchuk
Thank you for a problem report. Please, describe your upgrade procedure. Have you perfromed dump and restore, as recommended?

I also noted that you gave different binary log quote from mentioned in that error message. In any case, please, send the results of SHOW CREATE TABLE and SHOW TABLE STATUS for that nuke_bbsessions table from master and slave.
[24 Nov 2006 13:42] Roeland Mertens
I did the upgrade. We did do a dump & restore.

on the master:

mysql> show create table nuke_bbsessions\G
*************************** 1. row ***************************
       Table: nuke_bbsessions
Create Table: CREATE TABLE `nuke_bbsessions` (
  `session_id` char(32) collate latin1_general_ci NOT NULL default '',
  `session_user_id` mediumint(8) NOT NULL default '0',
  `session_start` int(11) NOT NULL default '0',
  `session_time` int(11) NOT NULL default '0',
  `session_ip` char(8) collate latin1_general_ci NOT NULL default '0',
  `session_page` int(11) NOT NULL default '0',
  `session_logged_in` tinyint(1) NOT NULL default '0',
  PRIMARY KEY  (`session_id`),
  KEY `session_user_id` (`session_user_id`),
  KEY `session_id_ip_user_id` (`session_id`,`session_ip`,`session_user_id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 COLLATE=latin1_general_ci
1 row in set (0.00 sec)

mysql> show table status where name = 'nuke_bbsessions'\G
*************************** 1. row ***************************
           Name: nuke_bbsessions
         Engine: MyISAM
        Version: 10
     Row_format: Fixed
           Rows: 14
 Avg_row_length: 57
    Data_length: 3762
Max_data_length: 16044073672507391
   Index_length: 12288
      Data_free: 2964
 Auto_increment: NULL
    Create_time: 2006-11-22 02:45:40
    Update_time: 2006-11-24 13:41:41
     Check_time: 2006-11-22 02:45:40
      Collation: latin1_general_ci
       Checksum: NULL
 Create_options: 
        Comment: 
1 row in set (0.00 sec)
[24 Nov 2006 14:26] Mark Zealey
We didn't do a dump and restore, but rather stopped mysql (or turned off write) and then used tar czf to take the slave copy.

If I'm not mistaken, the error in the SHOW SLAVE STATUS command said it was that binlog file, and I put the entire contents of that binlog file into my first message...

Database on the slave:

mysql> use davefussell2
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show create table nuke_bbsessions\G
*************************** 1. row ***************************
       Table: nuke_bbsessions
Create Table: CREATE TABLE `nuke_bbsessions` (
  `session_id` char(32) collate latin1_general_ci NOT NULL default '',
  `session_user_id` mediumint(8) NOT NULL default '0',
  `session_start` int(11) NOT NULL default '0',
  `session_time` int(11) NOT NULL default '0',
  `session_ip` char(8) collate latin1_general_ci NOT NULL default '0',
  `session_page` int(11) NOT NULL default '0',
  `session_logged_in` tinyint(1) NOT NULL default '0',
  PRIMARY KEY  (`session_id`),
  KEY `session_user_id` (`session_user_id`),
  KEY `session_id_ip_user_id` (`session_id`,`session_ip`,`session_user_id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 COLLATE=latin1_general_ci
1 row in set (0.00 sec)

mysql> show table status where name = 'nuke_bbsessions'\G
*************************** 1. row ***************************
           Name: nuke_bbsessions
         Engine: MyISAM
        Version: 10
     Row_format: Fixed
           Rows: 24
 Avg_row_length: 57
    Data_length: 1368
Max_data_length: 16044073672507391
   Index_length: 6144
      Data_free: 0
 Auto_increment: NULL
    Create_time: 2006-11-22 02:45:40
    Update_time: 2006-11-24 11:29:54
     Check_time: 2006-11-23 15:42:18
      Collation: latin1_general_ci
       Checksum: NULL
 Create_options:
        Comment:
1 row in set (0.00 sec)
[24 Nov 2006 14:40] Roeland Mertens
as clarification :

for the upgrade of MySQL we performed a dump and restore.
For the configuration of the replication we used the procedure described by Mark.
[27 Nov 2006 13:14] Mark Zealey
Looks like the problem was some faulty hardware during the transfer between the two boxes - when i copy the files manually and add them to the server it doesnt generate these errors...
[28 Nov 2006 7:36] Valeriy Kravchuk
Thank you for additional checks. So, I am closing this report as not a bug in MySQL for now.
[28 Nov 2006 9:30] Mark Zealey
Perhaps it would be possible in future to add some sort of checksumming to the binary log to ensure it was transmitted correctly? From what I've seen, the file itself seems pretty fragile...