Bug #15302 LOAD DATA FROM MASTER -> Packets out of order (Found: 2, expected 1)
Submitted: 29 Nov 2005 4:37 Modified: 2 Feb 2006 14:02
Reporter: Timothy Smith Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:4.1.16 OS:Any (any)
Assigned to: Magnus Blåudd CPU Architecture:Any

[29 Nov 2005 4:37] Timothy Smith
Description:
Any LOAD DATA FROM MASTER command causes the next statement to give an error:

mysql> load data from master;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
Packets out of order (Found: 2, expected 1)
ERROR 2013 (HY000): Lost connection to MySQL server during query

The LOAD DATA FROM MASTER command does appear to be successful.  I do not yet know what the warning is from, though.

This was tested on a recent 4.1 build from BK.  The customer reported it on 4.1.15

How to repeat:
I start the slave with:

/bin/mysqld_safe --no-defaults --basedir=$PWD --datadir=$PWD/data
--tmpdir=$PWD/tmp --log-error=$PWD/data/log.err --socket=mysql.sock --port=33413 --server-id=33414 --skip-networking --report-host=slave41a --skip-slave-start --warnings=3 --skip-innodb &

I started mysqld with a fresh data directory (no tables outside the mysql database), and also with some basic MyISAM tables in place.

mysql> show slave status\G
*************************** 1. row ***************************
             Slave_IO_State:
                Master_Host: 127.0.0.1
                Master_User: tim
                Master_Port: 33413
              Connect_Retry: 60
            Master_Log_File: binlog.000001
        Read_Master_Log_Pos: 79
             Relay_Log_File: siva-relay-bin.000001
              Relay_Log_Pos: 4
      Relay_Master_Log_File: binlog.000001
           Slave_IO_Running: No
          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: 0
                 Last_Error:
               Skip_Counter: 0
        Exec_Master_Log_Pos: 79
            Relay_Log_Space: 4
            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
1 row in set (0.00 sec)

mysql> load data from master;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
Packets out of order (Found: 2, expected 1)
ERROR 2013 (HY000): Lost connection to MySQL server during query

No matter what statement is run after LOAD DATA, it gives the "Packets out of order" error and says it lost the connection to the server.

The master does not crash.  There are no messages in the error logs of either master or slave.

Note that LOAD TABLE test.t FROM MASTER does work OK.  And when I run LOAD DATA FROM MASTER, it does copy the data to the slave.

Suggested fix:
Use mysqldump, mysqlhotcopy, etc. instead of LOAD DATA FROM MASTER.
[3 Dec 2005 0:53] Timothy Smith
This does not happen on 4.1.14.  It seems to have been introduced in 4.1.15.

When using a standard binary (not debugging) the symptoms are somewhat different.

If I issue the statements one at a time, I get:

mysql> stop slave;
Query OK, 0 rows affected (0.00 sec)

mysql> load data from master;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
+-------+------+-----------------------------------------------+
| Level | Code | Message                                       |
+-------+------+-----------------------------------------------+
| Note  | 1007 | Can't create database 'test'; database exists |
+-------+------+-----------------------------------------------+
1 row in set (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: 127.0.0.1
                Master_User: tsmith
                Master_Port: 33000
              Connect_Retry: 60
            Master_Log_File: binlog.000005
        Read_Master_Log_Pos: 79
             Relay_Log_File: shell-relay-bin.000001
              Relay_Log_Pos: 44
      Relay_Master_Log_File: binlog.000005
           Slave_IO_Running: Yes
          Slave_SQL_Running: Yes
...

If I issue the statements all at once, then I get a "lost connection to server" error in the client, after the LOAD DATA command:

mysql> stop slave;
Query OK, 0 rows affected (0.00 sec)

mysql> load data from master; start slave; show slave status\G
Query OK, 0 rows affected, 1 warning (0.01 sec)

ERROR 2013 (HY000): Lost connection to MySQL server during query
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    7
Current database: test

*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 127.0.0.1
                Master_User: tsmith
                Master_Port: 33000
              Connect_Retry: 60
            Master_Log_File: binlog.000005
        Read_Master_Log_Pos: 79
             Relay_Log_File: shell-relay-bin.000001
              Relay_Log_Pos: 44
      Relay_Master_Log_File: binlog.000005
           Slave_IO_Running: Yes
          Slave_SQL_Running: Yes

That was all tested with 4.1.15 on Linux, using the mysql-standard-4.1.15*i686 binary.

Regards,

Timothy
[26 Jan 2006 10:09] Magnus Blåudd
Reproduced this with mysql-test-run. A small bug in mysqltest disregards the case where warnings are reported but no warnings are returned.

The below patch will make our existing test detect the problem.
===== mysqltest.c 1.189 vs edited =====
2969,2970c2969,2970
<         verbose_msg("Warning count is %u but didn't get any warnings\n",
<                     count);
---
>         die("Warning count is %u but didn't get any warnings\n",
>             count);
3449,3450c3449,3450
<         verbose_msg("Warning count is %u but didn't get any warnings\n",
<                     count);
---
>         die("Warning count is %u but didn't get any warnings\n",
>           count);

Now, on to the cause of the problem...
[26 Jan 2006 14:56] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/1676
[31 Jan 2006 11:47] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/1932
[1 Feb 2006 10:40] Magnus Blåudd
Pushed to 4.1.19, already present in 5.0 and up.

Fixes the problem when LOAD DATA FROM MASTER produces invalid warnings and "Packet out of order" when database already exists on slave.
[2 Feb 2006 14:02] Jon Stephens
Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.

If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information 
about accessing the source trees is available at
    http://www.mysql.com/doc/en/Installing_source_tree.html

Additional info:

Documented bugfix in 4.1.19 changelog. Closed.