Bug #30668 | connection pooling failures | ||
---|---|---|---|
Submitted: | 28 Aug 2007 13:03 | Modified: | 5 Sep 2007 15:57 |
Reporter: | simon elliston ball | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Proxy | Severity: | S3 (Non-critical) |
Version: | 0.6.0 trunk | OS: | Any |
Assigned to: | Jan Kneschke | CPU Architecture: | Any |
[28 Aug 2007 13:03]
simon elliston ball
[28 Aug 2007 15:27]
simon elliston ball
Some more info about reproducing this bug: I have some databases setup db1...db10 and users user1...user10, each db contains a table called test: CREATE TABLE `test` ( `id` int(11) NOT NULL auto_increment, `data` varchar(255) default NULL, PRIMARY KEY (`id`) ) The queries executed, with lua debug, are: user1@db1 SELECT * FROM test; [connect_server] [1].connected_clients = 0 [1].idling_connections = 0 [1].type = 1 [1].state = 0 [1] open new connection [connect_server] [1].connected_clients = 1 [1].idling_connections = 0 [1].type = 1 [1].state = 1 [1] open new connection [disconnect_client] [read_query] current backend = 0 client default db = client username = user1 sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : false network-mysqld.c.1223: (store init-db) COM_INIT_DB: db1 [read_query] current backend = 0 client default db = db1 client username = user1 query = EXPLAIN SELECT * FROM test sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client] user1@db1 SELECT * FROM test; [connect_server] [1].connected_clients = 0 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [2].connected_clients = 0 [2].idling_connections = 0 [2].type = 2 [2].state = 0 [2] open new connection [connect_server] [1].connected_clients = 0 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [2].connected_clients = 1 [2].idling_connections = 0 [2].type = 2 [2].state = 1 [2] open new connection [disconnect_client] [read_query] current backend = 0 client default db = client username = user1 sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : false network-mysqld.c.1223: (store init-db) COM_INIT_DB: db1 [read_query] current backend = 0 client default db = db1 client username = user1 query = EXPLAIN SELECT * FROM test server default db: client default db: db1 syncronizing sending to backend : sqldb1.cromwells.co.uk:3306 is_slave : true server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : true network-mysqld.c.1223: (store init-db) COM_INIT_DB: db1 [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb1.cromwells.co.uk:3306 is_slave : true server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client] user2@db2 SELECT * FROM test; [connect_server] [1].connected_clients = 0 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [3].connected_clients = 0 [3].idling_connections = 0 [3].type = 2 [3].state = 0 [3] open new connection [read_query] current backend = 0 client default db = client username = user2 network-conn-pool.c.75: no pool-entry for user2 found sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false (read_query) /usr/local/share/mysql-proxy/rw-splitting.lua:289: attempt to index local 's' (a nil value) network-mysqld-proxy.c.2815: I have no server backend, closing connection network-mysqld.c.1161: plugin_call(CON_STATE_READ_QUERY) failed [disconnect_client] [connect_server] [1].connected_clients = 0 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [3].connected_clients = 0 [3].idling_connections = 1 [3].type = 2 [3].state = 1 opening new connection on: 1 [read_query] current backend = 0 client default db = client username = user2 sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: server username : user2 in_trans : false in_calc_found : false COM_QUERY : false network-mysqld.c.1223: (store init-db) COM_INIT_DB: db2 [read_query] current backend = 0 client default db = db2 client username = user2 query = EXPLAIN SELECT * FROM test network-conn-pool.c.75: no pool-entry for user2 found (read_query) /usr/local/share/mysql-proxy/rw-splitting.lua:276: attempt to index local 's' (a nil value) network-mysqld-proxy.c.2815: I have no server backend, closing connection network-mysqld.c.1161: plugin_call(CON_STATE_READ_QUERY) failed [disconnect_client]
[30 Aug 2007 10:12]
simon elliston ball
With the latest trunk (rev 197) I seem to be having problems with the connected_clients field on the backend not being reduced properly, consequently the connect scripts do not work, leading to user not found in pool messages. The first backend will just grow more and more connections, while the read query will eventually fail with a lost connection error 2013 because it will try to use the second backend, which has never received a connection for the client's user due to the fact that there is never more than one idling connection on the main backend. See log below using rw-splitting.lua from r197. The queries were generated from a simple php client which was just requested repeatedly. Note the ever increasing [1].connected_clients = 1 [connect_server] [1].connected_clients = 1 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [1].address = sqldb.example.com:3306 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [2].address = sqldb1.example.com:3306 opening new connection on: 1 [read_query] current backend = 1 client default db = client username = user1 sending to backend : sqldb.example.com:3306 is_slave : false server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : false [read_query_result] releasing backend : 1 [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb1.example.com:3306 is_slave : true server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query_result] releasing backend : 2 [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client] [connect_server] [1].connected_clients = 2 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [1].address = sqldb.example.com:3306 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [2].address = sqldb1.example.com:3306 opening new connection on: 1 [read_query] current backend = 1 client default db = client username = user1 sending to backend : sqldb.example.com:3306 is_slave : false server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : false [read_query_result] releasing backend : 1 [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb1.example.com:3306 is_slave : true server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query_result] releasing backend : 2 [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client] [connect_server] [1].connected_clients = 3 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [1].address = sqldb.example.com:3306 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [2].address = sqldb1.example.com:3306 opening new connection on: 1 [read_query] current backend = 1 client default db = client username = user1 sending to backend : sqldb.example.com:3306 is_slave : false server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : false [read_query_result] releasing backend : 1 [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb1.example.com:3306 is_slave : true server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query_result] releasing backend : 2 [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client] [connect_server] [1].connected_clients = 4 [1].idling_connections = 1 [1].type = 1 [1].state = 1 [1].address = sqldb.example.com:3306 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [2].address = sqldb1.example.com:3306 opening new connection on: 1 [read_query] current backend = 1 client default db = client username = user1 sending to backend : sqldb.example.com:3306 is_slave : false server default db: server username : user1 in_trans : false in_calc_found : false COM_QUERY : false [read_query_result] releasing backend : 1 [read_query] current backend = 0 client default db = db1 client username = user1 query = SELECT * FROM test sending to backend : sqldb1.example.com:3306 is_slave : true server default db: db1 server username : user1 in_trans : false in_calc_found : false COM_QUERY : true [read_query_result] releasing backend : 2 [read_query] current backend = 0 client default db = db1 client username = user1 [disconnect_client]
[31 Aug 2007 16:33]
simon elliston ball
I think I may have tracked down the source of this problem. When the connect_server script checks for least_idle_connections, and assigns a discovered index to the proxy.connections.backend_ndx userdata field, the function network-mysqld-proxy.c:proxy_connection_set gets called. This will lead to a proxy_connection_pool_swap, which will increment the connected_clients field of the backend. However, the end of the function will then allow a connect to continue on the backend, leading to network-mysqld-proxy.c:NETWORK_MYSQLD_PLUGIN_PROTO(proxy_connect_server) also increasing the backends connection count. The read_auth successfully decrements on of these, but not the other, which means you will have a spare connection which always remains a 'connected' part of the pool and is not available either to queries, or to the disconnect client hook. A transcript of the lua debug, with some extra debug inserted into network-mysqld-proxy.c shows the problem, and where the decrement is not happening. The backend index in the debug from the c code is incremented to match the lua indexes for clarity. [connect_server] [1].connected_clients = 0 [1].idling_connections = 4 [1].type = 1 [1].state = 1 [1].address = sqldb.cromwells.co.uk:3306 [2].connected_clients = 0 [2].idling_connections = 1 [2].type = 2 [2].state = 1 [2].address = sqldb1.cromwells.co.uk:3306 [3].connected_clients = 0 [3].idling_connections = 1 [3].type = 2 [3].state = 1 [3].address = sqldb.cromwells.co.uk:3306 Least idle connections on : 2 backend is 0 network-mysqld-proxy.c:634: proxy_connection_pool_swap: Connected clients increased on 2 to 1 network-mysqld-proxy.c:576: proxy_connection_pool_add_connection: Connected clients reduced on 2 to 0 network-mysqld-proxy.c:3624: proxy_connect_server: Connected client increased on 1 to 1 [read_auth_result] backend : 1 network-mysqld-proxy.c:576: proxy_connection_pool_add_connection: Connected clients reduced on 1 to 0 [read_query] current backend = 0 client default db = client username = test cmd = COM_INIT_DB schema = db1 network-mysqld-proxy.c:634: proxy_connection_pool_swap: Connected clients increased on 1 to 1 running an init db : c= s= setting to db1 sending to backend : sqldb.cromwells.co.uk:3306 is_slave : false server default db: server username : test in_trans : false in_calc_found : false COM_QUERY : false [read_query_result] inj.id : 1 inj.query : db1 (read_query_result) releasing backend 1 network-mysqld-proxy.c:576: proxy_connection_pool_add_connection: Connected clients reduced on 1 to 0 [read_query] current backend = 0 client default db = db1 client username = test cmd = COM_QUERY query = SELECT * FROM test network-mysqld-proxy.c:634: proxy_connection_pool_swap: Connected clients increased on 2 to 1 sending to backend : sqldb1.cromwells.co.uk:3306 is_slave : true server default db: db1 server username : test in_trans : false in_calc_found : false COM_QUERY : true [read_query_result] inj.id : 1 inj.query : SELECT * FROM test (read_query_result) releasing backend 2 network-mysqld-proxy.c:576: proxy_connection_pool_add_connection: Connected clients reduced on 2 to 0 [read_query] current backend = 0 client default db = db1 client username = test cmd = COM_QUIT [disconnect_client] 0
[5 Sep 2007 15:57]
Jan Kneschke
fixed in [210] * addr.str per network_socket - duplicate the string on network_socket_init() - free on network_socket_free() - moved addr.str for the client into the accept() call - added proxy.connection.client.address to rw-splitting.lua * leaking con->server when rw-splitting is used - if proxy.connection.backend_ndx = ... is used in rw-splitting and we have a idle connection in the pool con->server is set too in proxy_connect_server() we were calling pool_get() a second time and overwriting con->server. This leaked the con->server handles.