MySQL Bugs: #67861: Connections lost/issue Federated and MySQL client

Bug #67861	Connections lost/issue Federated and MySQL client
Submitted:	10 Dec 2012 14:23	Modified:	13 Dec 2012 20:29
Reporter:	Erik Hoekstra	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Federated storage engine	Severity:	S2 (Serious)
Version:	5.6.8-rc1	OS:	Linux (el6)
Assigned to:		CPU Architecture:	Any
Tags:	federated, Got an error reading communication packets, Lost connection to MySQL server during query, mysql client, MySQL server has gone away

Description:
Our newest installation of 5.6.8-rc1 on el6 (centos) has issues with connections.

The mysql client doesn't reconnect as expected. Since the issue can be discribed as well for mysql client as for the federated connections, we think this could just as well be the same issue.

[root@.../]# mysql --help | grep 'reconnect'
reconnect                         TRUE

[root@.../]# cat /etc/my.cnf
[MYSQL]
disable-auto-rehash
default-character-set = utf8
...

@mysql client

mysql> show table status \G
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> show table status \G
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    17083871

The MySQL server has gone away is due to the inactive_timeout; the lost connection to MySQL server during query at first hand is the issue/bug?

For a Federated table this is quite the same; first call is a error (this time the Got an error reading communication packets ), second call ok. 

mysql> select * from views_1_F;
ERROR 1158 (08S01): Got an error reading communication packets
mysql> select * from views_1_F;
Empty set (0.00 sec)

The issues can be conbined as well :-\

mysql> select * from views_1_F;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> select * from views_1_F;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    17105645
Current database: kliks_tracking

ERROR 1158 (08S01): Got an error reading communication packets
mysql> select * from views_1_F;
Empty set (0.00 sec)

Federated connection strings are ok, structure etc as well.

How to repeat:
Install fresh el6 on centos (6)

Install fresh 5.6.8-rc1 on 2 different machines

Just tested 5.5.28 for mysql client (connect localhost); all ok, no issues on-before-reconnect

Tested 5.5.28 client to 5.6.8-rc1 server : no issues on-before-reconnect

Tested federated table from 5.5.28 to 5.6.8-rc1 : no issues

Issue solved in 5.6.9

Probably in the line of :

Connection ID (thread ID) values greater than 32 bits can occur on some systems (such as busy or long-running 64-bit systems), causing these problems:
 
■
 Connection IDs written to the general query log and slow query log were incorrect. This was true for logging to both files and tables. 

■
 The CONNECTION_ID() function could return a value with a data type too small for values larger than 32 bits. 

■
 The mysql_thread_id() and mysql_kill() C API functions did not handle ID values larger than 32 bits. This could result in killing the wrong thread; for example, if you invoked mysql_kill(mysql_thread_id()).
 

Connection IDs now are permitted to be 64-bit values when the server supports them (when built with 64-bit data types), which has these effects:
 
■
 Connection IDs are logged correctly to the general query log and slow query log.
 

Note 

This change involves a modification to the log tables, so after upgrading to this release, you must run mysql_upgrade and restart the server.
 
■
CONNECTION_ID() returns a data type appropriate for values larger than 32 bits. 

■
mysql_thread_id() is unchanged; the client/server protocal has only 4 bytes for the ID value. This function returns an incorrect (truncated) value for connection IDs larger than 32 bits and should be avoided. 

mysql_kill() still cannot handle values larger than 32 bits, but to guard against killing the wrong thread now returns an error in these cases:
 
◦
 If given an ID larger than 32 bits, mysql_kill() returns a CR_INVALID_CONN_HANDLE error. 

◦
 After the server's internal thread ID counter reaches a value larger than 32 bits, it returns an ER_DATA_OUT_OF_RANGE error for any mysql_kill() invocation and mysql_kill() fails.
 

To avoid problems with mysql_thread_id() and mysql_kill(), do not use them. To get the connection ID, execute a SELECT CONNECTION_ID() query and retrieve the result. To kill a thread, execute a KILL statement.
 

(Bug #19806, Bug #11745768, Bug #65715, Bug #14236124, Bug #44728, Bug #11753308)

Issue solved

Probably in the line of:

Connection ID (thread ID) values greater than 32 bits can occur on some systems (such as busy or long-running 64-bit systems), causing these problems:
 
■
 Connection IDs written to the general query log and slow query log were incorrect. This was true for logging to both files and tables. 

■
 The CONNECTION_ID() function could return a value with a data type too small for values larger than 32 bits. 

■
 The mysql_thread_id() and mysql_kill() C API functions did not handle ID values larger than 32 bits. This could result in killing the wrong thread; for example, if you invoked mysql_kill(mysql_thread_id()).
 

Connection IDs now are permitted to be 64-bit values when the server supports them (when built with 64-bit data types), which has these effects:
 
■
 Connection IDs are logged correctly to the general query log and slow query log.
 

Note 

This change involves a modification to the log tables, so after upgrading to this release, you must run mysql_upgrade and restart the server.
 
■
CONNECTION_ID() returns a data type appropriate for values larger than 32 bits. 

■
mysql_thread_id() is unchanged; the client/server protocal has only 4 bytes for the ID value. This function returns an incorrect (truncated) value for connection IDs larger than 32 bits and should be avoided. 

mysql_kill() still cannot handle values larger than 32 bits, but to guard against killing the wrong thread now returns an error in these cases:
 
◦
 If given an ID larger than 32 bits, mysql_kill() returns a CR_INVALID_CONN_HANDLE error. 

◦
 After the server's internal thread ID counter reaches a value larger than 32 bits, it returns an ER_DATA_OUT_OF_RANGE error for any mysql_kill() invocation and mysql_kill() fails.
 

To avoid problems with mysql_thread_id() and mysql_kill(), do not use them. To get the connection ID, execute a SELECT CONNECTION_ID() query and retrieve the result. To kill a thread, execute a KILL statement.
 

(Bug #19806, Bug #11745768, Bug #65715, Bug #14236124, Bug #44728, Bug #11753308)

For federated tables the issue is still there

mysql> show table status;
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+--------------------------------------------+
| Name      | Engine    | Version | Row_format | Rows  | Avg_row_length | Data_length | Max_data_length  | Index_length | Data_free | Auto_increment | Create_time         | Update_time         | Check_time          | Collation         | Checksum   | Create_options | Comment                                    |
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+--------------------------------------------+
| error     | MyISAM    |      10 | Dynamic    | 19670 |            155 |     3057164 |  281474976710655 |      2840576 |         0 |           NULL | 2011-02-08 12:44:09 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci | 1212143160 | checksum=1     |                                            |
| views_0   | MyISAM    |      10 | Fixed      |     0 |              0 |           0 | 6473924464345087 |         1024 |         0 |              1 | 2011-10-14 13:01:01 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci |          0 | checksum=1     |                                            |
| views_0_F | FEDERATED |      10 |            |  NULL |              0 |           0 |                0 |            0 |         0 |           NULL | NULL                | NULL                | NULL                | latin1_swedish_ci |       NULL |                | Got an error reading communication packets |
| views_1   | MyISAM    |      10 | Fixed      |     0 |              0 |           0 | 6473924464345087 |         1024 |         0 |              1 | 2011-10-14 12:01:01 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci |          0 | checksum=1     |                                            |
| views_1_F | FEDERATED |      10 |            |  NULL |              0 |           0 |                0 |            0 |         0 |           NULL | NULL                | NULL                | NULL                | latin1_swedish_ci |       NULL |                | Got an error reading communication packets |
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+--------------------------------------------+
5 rows in set, 2 warnings (0.01 sec)

mysql> show warnings;
+---------+------+--------------------------------------------+
| Level   | Code | Message                                    |
+---------+------+--------------------------------------------+
| Warning | 1158 | Got an error reading communication packets |
| Warning | 1158 | Got an error reading communication packets |
+---------+------+--------------------------------------------+
2 rows in set (0.00 sec)

mysql> show table status;
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+---------+
| Name      | Engine    | Version | Row_format | Rows  | Avg_row_length | Data_length | Max_data_length  | Index_length | Data_free | Auto_increment | Create_time         | Update_time         | Check_time          | Collation         | Checksum   | Create_options | Comment |
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+---------+
| error     | MyISAM    |      10 | Dynamic    | 19670 |            155 |     3057164 |  281474976710655 |      2840576 |         0 |           NULL | 2011-02-08 12:44:09 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci | 1212143160 | checksum=1     |         |
| views_0   | MyISAM    |      10 | Fixed      |     0 |              0 |           0 | 6473924464345087 |         1024 |         0 |              1 | 2011-10-14 13:01:01 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci |          0 | checksum=1     |         |
| views_0_F | FEDERATED |      10 | Fixed      |     0 |              0 |           0 |                0 |            0 |         0 |              0 | NULL                | 1970-01-01 01:33:32 | NULL                | latin1_swedish_ci |       NULL |                |         |
| views_1   | MyISAM    |      10 | Fixed      |     0 |              0 |           0 | 6473924464345087 |         1024 |         0 |              1 | 2011-10-14 12:01:01 | 2012-11-29 17:08:29 | 2012-11-30 11:40:48 | latin1_swedish_ci |          0 | checksum=1     |         |
| views_1_F | FEDERATED |      10 | Fixed      |     0 |              0 |           0 |                0 |            0 |         0 |              0 | NULL                | 1970-01-01 01:33:32 | NULL                | latin1_swedish_ci |       NULL |                |         |
+-----------+-----------+---------+------------+-------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+------------+----------------+---------+
5 rows in set (0.00 sec)

mysql>

Federated issue hangs on wait_timeout on destination server

Bug #14874

Thank you for the report.

I agree: this is more likely duplicate of Bug #14874

Whenever a query is issued against a federated table,  a single/multiple [ depends on Number = table_open_cache_instances] will be created from the DB instance hosting the federated table to the DB instance hosting the main table. If those single/mutiple connection on the DB instance hosting main table expires because of [wait_timeout,connect_timeout] or if those gets terminated manually , any new queries on federated table will result in "ERROR 1158 (08S01) at line 1: Got an error reading communication packets" on the DB instance hosting the federated table. 
Reason   : Flushing of the federated table does not happen properly from the table_open_cache_instances , 
Solution : To avoid this, the temporary solution is to manually/forcefully flush only those federated tables once before every [wait_timeout,connect_timeout] seconds. In our case we put the flush command in event_scheduler since the number of federated tables were very less and we knew exactly which federated tables were rarely getting queried with gap of more than [wait_timeout,connect_timeout] seconds. This used to affect even our MEB backup when it used execute "flush tables with READ lock". 

flush table <federated_table_name>; -- executed every 4 hours 

Since then, after putting the manual flush of federated tables with a frequence less than [wait_timeout,connect_timeout] , this issue has not showed up. Hope this helps.

Thanks
Prasad