| Bug #87335 | queryTimeout dose not work in connector/J loadbalance mode | ||
|---|---|---|---|
| Submitted: | 7 Aug 2017 6:08 | Modified: | 7 Aug 2017 9:02 |
| Reporter: | Haixing Weng (OCA) | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | Connector / J | Severity: | S3 (Non-critical) |
| Version: | 5.1.40 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | jdbc, loadbalance, queryTimeout | ||
[7 Aug 2017 7:53]
Chiranjeevi Battula
Hello Haixing Weng, Thank you for the bug report and test case. I tried to reproduce the issue at my end using MySQL Connector / J 5.1.43 and MySQL 5.7.19 but not seeing any issues in connectTimeout and socketTimeout. Thanks, Chiranjeevi.
[7 Aug 2017 7:54]
Chiranjeevi Battula
mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 331 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 331 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 1 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 334 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 334 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 4 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 339 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 339 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 9 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 346 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 346 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 16 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.02 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 352 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 352 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 22 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+------------+--------------------+ | 26 | root | localhost:63161 | test | Sleep | 358 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 358 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | | 41 | root | localhost:63208 | test | Query | 28 | User sleep | SELECT SLEEP(3600) | +----+------+-----------------+------+---------+------+------------+--------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+------+-----------------+------+---------+------+----------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+----------+------------------+ | 26 | root | localhost:63161 | test | Sleep | 362 | | NULL | | 27 | root | localhost:63162 | test | Sleep | 362 | | NULL | | 34 | root | localhost:63176 | NULL | Query | 0 | starting | show processlist | +----+------+-----------------+------+---------+------+----------+------------------+ 3 rows in set (0.01 sec) mysql>
[7 Aug 2017 9:02]
Haixing Weng
Hi Chiranjeevi Battula: I have confirmed that it's all normal in jdbc with a new version 5.1.43.I think I've made a mistake. Thank you
Description: Interface setQueryTimeout does not work when called in loadbalance mode. It seems like that disconnect will only depends on socketTimeout, and what's worse， connector/J cannot kill query which timeout so that MySQL will continue handle the sql query. How to repeat: When we use jdbc connect a standalone mysql server, it can run normally when setQueryTimeout， for example: conn = DriverManager.getConnection("jdbc:mysql://172.21.101.91:50001/test?connectTimeout=30000&socketTimeout=30000&user=whx&password=123"); stmt = conn.createStatement(); stmt.setQueryTimeout(30); stmt.executeQuery("SELECT SLEEP(3600);"); After 30 seconds, connection will be closed by jdbc, jdbc will send a kill query to mysql, with a message like that(I dumped the network message): 0x00000000 (00000) 01000001 012c0000 02036465 66000000 .....,....def... 0x00000010 (00016) 16404073 65737369 6f6e2e74 785f7265 .@@session.tx_re 0x00000020 (00032) 61645f6f 6e6c7900 0c3f0001 00000008 ad_only..?...... 0x00000030 (00048) 80000000 00050000 03fe0000 02000200 ................ 0x00000040 (00064) 00040130 05000005 fe000002 00 ...0......... get packet from client, session:19, datalen:21. 0x00000000 (00000) 11000000 034b494c 4c205155 45525920 .....KILL QUERY 0x00000010 (00016) 36383931 34 68914 get packet from server, session:19, datalen:11. But things is query different in load balance mode: conn = DriverManager.getConnection("jdbc:mysql:loadbalance://172.21.101.91:50001,172.21.101.91:50002,172.21.101.91:50003/test?" + "user=whx&password=123&connectTimeout=40000&socketTimeout=40000"); stmt = conn.createStatement(); stmt.setQueryTimeout(30); stmt.executeQuery("SELECT SLEEP(3600);"); And you will find that: 1. setQueryTimeout does not work at all, the query will be timeout and session will be closed in 40 seconds(which is socketTimeout value)。 2. jdbc dose not kill timeout query when timeout,I dumped network message in 3 servers,and found no "Kill Query" message.(Interestingly，when detect timout, jdbc will establish a new session in a random mysql servers and close it immediately） mysql> show processlist; +-------+---------+---------------------+------+---------+------+------------+--------------------+ | Id | User | Host | db | Command | Time | State | Info | +-------+---------+---------------------+------+---------+------+------------+--------------------+ | 68880 | cup_dba | localhost | NULL | Query | 0 | init | show processlist | | 68917 | whx | 172.21.101.91:43519 | test | Query | 103 | User sleep | SELECT SLEEP(3600) | +-------+---------+---------------------+------+---------+------+------------+--------------------+ 2 rows in set (0.00 sec) Cannot kill query after timeout is a serious bug， it means that we cannot terminate a sql query which might consume computing resource so much. Suggested fix: Yet I have no idea about how to fix it.