Bug #63908 mysql-proxy with LUA script get stuck when the clients' concurrency too much
| Submitted: | 3 Jan 2012 4:28 | Modified: | 26 Jan 2012 3:04 |
|---|---|---|---|
| Reporter: | zhongliang kang | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Proxy | Severity: | S1 (Critical) |
| Version: | 0.8.2 | OS: | Linux (Suse10-2.6.16.60-0.21 ) |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | mysql-proxy concurrency stuck | ||
[3 Jan 2012 4:44]
zhongliang kang
and more:
we try to add a test print at : chassis-event-thread.c
166 unsigned int m_pid=pthread_self();
167 if(received>0){
168 g_message(" %u now queue event num: %d\n",m_pid,received);
169 }
170 /* the pipe has one . per event, remove as many as we received */
and in the output of mysql-proxy.log ,we got the follow output:
my question is : if the proxy get stuck has some relation with the number of event in the queue?
-----------mysql-proxy.log----------------
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 4
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 1
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 4
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 46
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 15
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 17
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 15
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 14
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 16
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 16
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 17
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 17
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 15
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 75
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 40
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 95
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 32
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 41
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 29
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 79
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 73
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 11
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 73
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 68
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 19
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 113
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 46
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 7
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 6
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 54
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 49
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 37
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 153
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 22
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 47
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 20
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 23
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 39
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 126
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 28
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 31
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 118
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 73
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 96
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 3
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 68
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 83
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 108
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 20
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 153
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 120
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 24
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 68
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 45
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 68
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 55
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 78
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 49
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 114
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 74
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 69
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 68
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 218
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 54
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 43
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 124
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 132
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 112
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 217
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 71
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 64
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 120
2012-01-03 11:37:21: (message) 1082132800 now queue event num: 178
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 89
2012-01-03 11:37:21: (message) 1090525504 now queue event num: 213
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 64
2012-01-03 11:37:21: (message) 1107310912 now queue event num: 112
2012-01-03 11:37:21: (message) 3159565600 now queue event num: 225
2012-01-03 11:37:21: (message) 1098918208 now queue event num: 88
---------------stuck here------------------
[3 Jan 2012 10:45]
zhongliang kang
And one more question:
#event-threads
event-threads = 5
when　the mysql-proxy get stuck, by strace all the mysql-proxy's threads,like bellow,All the threads are send the event,and dead here,that means no thread to receive the event?
---------
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> pstree -p 12807
mysql-proxy(12807)-+-{mysql-proxy}(12808)
|-{mysql-proxy}(12809)
|-{mysql-proxy}(12810)
`-{mysql-proxy}(12811)
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> strace -p 12807
Process 12807 attached - interrupt to quit
sendto(4, ".", 1, 0, NULL, 0 <unfinished ...>
Process 12807 detached
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> strace -p 12808
Process 12808 attached - interrupt to quit
sendto(4, ".", 1, 0, NULL, 0 <unfinished ...>
Process 12808 detached
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> strace -p 12809
Process 12809 attached - interrupt to quit
sendto(4, ".", 1, 0, NULL, 0 <unfinished ...>
Process 12809 detached
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> strace -p 12810
Process 12810 attached - interrupt to quit
sendto(4, ".", 1, 0, NULL, 0 <unfinished ...>
Process 12810 detached
mysql@NODE_2:/usr/local/mysql-proxy-release-sky/bin> strace -p 12811
Process 12811 attached - interrupt to quit
sendto(4, ".", 1, 0, NULL, 0 <unfinished ...>
Process 12811 detached
------------
[14 Jan 2012 10:22]
Sveta Smirnova
Thank you for the report. You wrote: ----<q>---- when I tried to test mysql-proxy without lua script,when the clients' concurrency is 5000,each client got 1000 query, mysql-proxy can handled the task in 163 SEC, and the result is OK. But when I tried to test mysql-proxy with LUA script,the content as above,when the clients' concurrency is 5000(even 1000,in test), the mysql-proxy got stuck and didnot work any more. Then I repeated the test , the case repeated. ----</q>---- What is the difference between 2 cases? I see you mentioned same 5000 number of concurrent client. Also have you tried to connect to MySQL server without proxy? Can it survive such a workload?
[16 Jan 2012 6:16]
zhongliang kang
----<q>---- when I tried to test mysql-proxy without lua script,when the clients' concurrency is 5000,each client got 1000 query, mysql-proxy can handled the task in 163 SEC, and the result is OK. But when I tried to test mysql-proxy with LUA script,the content as above,when the clients' concurrency is 5000(even 1000,in test), the mysql-proxy got stuck and didnot work any more. Then I repeated the test , the case repeated. ----</q>---- What is the difference between 2 cases? I see you mentioned same 5000 number of concurrent client. Also have you tried to connect to MySQL server without proxy? Can it survive such a workload? ============= The difference is: case 1 run with no lua script,but case 2 did. When I tested at the same concurrency of 5000, the proxy with lua script got stuck(case 2),but case 1 (with no lua script) worked good. And I tried the test with no proxy,5000 test clients conneted to mysql server directly,It was OK. This case can repeat at up to 5000 client's concurrency. I guess if this would happened when there is too much event generate by the proxy with lua script,and the proxy cannot handle them in time,so get stuck?
[16 Jan 2012 18:44]
Sveta Smirnova
Thank you for the feedback. Got it. Please also send command you use to start MySQL Proxy, so I can imitate your test as best as possible.
[16 Jan 2012 18:49]
zhongliang kang
OK. Thank you for your help :) the start command is below: ./mysql-proxy --defaults-file=/etc/proxy_my.cnf #cat /etc/proxy_my.cnf |grep -v "#" [mysql-proxy] log-file = /usr/local/mysql-proxy/log/mysql-proxy.log log-level = debug admin-address=0.0.0.0:4401 admin-username=proxy admin-password=proxy admin-lua-script=/usr/local/mysql-proxy/lib/mysql-proxy/lua/admin.lua proxy-address=0.0.0.0:4406 proxy-backend-addresses=10.164.5.111:3306 basedir=/usr/local/mysql-proxy daemon = true event-threads = 5
[25 Jan 2012 19:31]
Sveta Smirnova
Thank you for the feedback.
Verified, although in my case when threads stuck depends from quantity of parallel threads and not only lua script. Also without lua script I only need 2750 threads to notice "stuck" while with lua script I need more.
Your Lua code contained error, I used following:
proxy.global.master_index = proxy.global.master_index or 1
function read_query(packet)
proxy.connection.backend_ndx = proxy.global.master_index
end
[25 Jan 2012 19:32]
Sveta Smirnova
program which creates threads, then sends query
Attachment: bug63908_1.cpp (text/x-c++src), 1.29 KiB.
[26 Jan 2012 3:04]
zhongliang kang
Verified, although in my case when threads stuck depends from quantity of parallel threads and not only lua script. Also without lua script I only need 2750 threads tonotice "stuck" while with lua script I need more. --- Yes,I used mysqlslap,and when 5000 threads without lua, the proxy got stuck. At first I didnot notice its a bug,so I ignored it :( I'm sorry about the lua script error,I'm a beginner to lua. Thank you for your verified,and thank you for your work! Hi Sveta : One of my friends had fix the stuck problem by another way,we are not sure if that is ok,I'll ask him to share his changes later.
Portions of this website are copyright © 2001, 2002 The PHP Group
Page generated in 0.065 sec. using MySQL 8.4.7-u6-cloud
Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the
respective copyright holders.
It is not reviewed in advance
by Oracle and does not necessarily represent the opinion of
Oracle or any other party.
Description: basic info: ./mysql-proxy -V mysql-proxy 0.8.2 chassis: mysql-proxy 0.8.2 glib2: 2.16.6 libevent: 1.4.13-stable LUA: Lua 5.1.4 package.path: /usr/local/mysql-proxy/lib/mysql-proxy/lua/?.lua; package.cpath: /usr/local/mysql-proxy/lib/mysql-proxy/lua/?.so; -- modules proxy: 0.8.2 ------------------------------------------------ testing server info: CPU: CPU frequency is 2.13 GHz * 4 (4 CPUs) RAM: 32G NIC: 1G ---------------basic info end----------------------------- ---------------lua script content------------ proxy.global.master_index = proxy.global.master_index or 1 function read_query(packet) proxy.connection.backend_ndx = proxy.global.master_index return ----------------------lua script end------------------ -----------------the case------------------------------- when I tried to test mysql-proxy without lua script,when the clients' concurrency is 5000,each client got 1000 query, mysql-proxy can handled the task in 163 SEC, and the result is OK. But when I tried to test mysql-proxy with LUA script,the content as above,when the clients' concurrency is 5000(even 1000,in test), the mysql-proxy got stuck and didnot work any more. Then I repeated the test , the case repeated. ------------------describe the case----------------------------- on the mysql-DB server,the phenomenon is like this: all threads are sleep. ..... | 115128 | sky | 10.164.9.218:49614 | test_took_sql | Sleep | 69 | | NULL | | 115129 | sky | 10.164.9.218:49615 | test_took_sql | Sleep | 69 | | NULL | | 115130 | sky | 10.164.9.218:49616 | test_took_sql | Sleep | 69 | | NULL | | 115131 | sky | 10.164.9.218:49617 | test_took_sql | Sleep | 69 | | NULL | | 115132 | sky | 10.164.9.218:49618 | test_took_sql | Sleep | 69 | | NULL | | 115133 | sky | 10.164.9.218:49619 | test_took_sql | Sleep | 69 | | NULL | +--------+------+--------------------+---------------+-------------+--------+----------------+------------------+ 5002 rows in set (0.01 sec) On the mysql-proxy server,the phenomenon is like below,all proxy threads stuck at 'sendto(4,",",1,0,NULL,...': mysql@NODE_1:/usr/local/mysql-proxy/bin> pstree -p 3437 mysql-proxy(3437)-+-{mysql-proxy}(3438) |-{mysql-proxy}(3439) |-{mysql-proxy}(3440) `-{mysql-proxy}(3441) mysql@NODE_1:/usr/local/mysql-proxy/bin> strace -p 3439 Process 3439 attached - interrupt to quit sendto(4, ".", 1, 0, NULL, 0 <unfinished ...> Process 3439 detached On the client server,the mysql-proxy server cannot connect again,when you input the password,no response received(4406 is the port mysql-proxy listen): mysql -h 10.164.9.218 -u sky -p -P 4406 Enter password: How to repeat: 1.start the mysql-proxy 2.get 5000 clients connect the mysql-proxy ,but donot run the query 3.all 5000 clients query at the same time 4.the case repeat Suggested fix: I and my friends found that the stuck's position mybe is here: "chassis-event-thread.c": in function void chassis_event_add(chassis *chas, struct event *ev) { send(chas->threads->event_notify_fds[1], C("."), 0); /* ping the event handler */ //!!!here,all thread were stuck here! and we test by add the follow test print verified it: 1.add some test message int m_pid=pthread_self(); g_message("%d,bf sync\n",m_pid); g_async_queue_push(chas->threads->event_queue, op); g_message("%d,send start...\n",m_pid); send(chas->threads->event_notify_fds[1], C("."), 0); /* ping the event handler */ g_message("%d,send end...\n",m_pid); 2.repeat the case,in the mysql-proxy.log ,when the proxy stuck,we got these info: 2012-01-03 11:37:21: (message) 1082132800,send start... 2012-01-03 11:37:21: (message) -1135401696,send end... 2012-01-03 11:37:21: (message) 1107310912,bf sync 2012-01-03 11:37:21: (message) -1135401696,bf sync 2012-01-03 11:37:21: (message) 1098918208,send end... 2012-01-03 11:37:21: (message) 1090525504,send start... 2012-01-03 11:37:21: (message) 1098918208,bf sync 2012-01-03 11:37:21: (message) 1098918208,send start... 2012-01-03 11:37:21: (message) 1107310912,send start... 2012-01-03 11:37:21: (message) -1135401696,send start... there just many " send start " with no "send end" in the log. and the mysql-proxy start info is like below: 2012-01-03 11:57:53: (message) mysql-proxy 0.8.2 started 2012-01-03 11:57:53: (debug) max open file-descriptors = 102400 2012-01-03 11:57:53: (message) proxy listening on port 0.0.0.0:4406 2012-01-03 11:57:53: (message) added read/write backend: 10.164.5.111:3306 2012-01-03 11:57:53: (message) added read/write backend: 10.164.5.108:3306 2012-01-03 11:57:53: (message) chassis-event-thread.c:383: starting 4 threads ------------------------- so maybe there is something wrong in the notification of the mysql-proxy. /// send(chas->threads->event_notify_fds[1], C("."), 0); ///