2

I'm in a situation which really puzzles me, and nobody seems to know what the problem is.

I've got a website written in php/Laravel, which connects to a mysql server. If I call an api endpoint several times very fast (by clicking on a website button about 10-15 times very fast), the last few times, the call takes very long. When it normally lasts about 200ms, it suddenly takes multiples of 30 full seconds. So one call takes 30 seconds, another one (or more) 60, and another one or more calls take 90 seconds, etc. All calls end successfully, but they just take an enormous time to finish.

enter image description here

I first thought it could maybe be the php max_execution_time, so I set that to 15. Unfortunately, there was no change; the call still takes multiples of 30 seconds. Plus, if that would be the problem, it would return an error, while in this case I get correct 200 responses.

After some fiddling around I ran watch -n 0.3 "mysqladmin processlist" to see if mysql was maybe the cause. During the long lasting calls I see the following:

enter image description here

I'm not exactly sure what this is and why it might happen. I thought that mysql might be hanging, so I surrounded the mysql query in php with syslogs to see if the code actually hangs on the mysql call:

syslog(LOG_ERR, "BEFORE");
$results = TheTable::where('edg', $edg)->get();
$theResponse = response(json_encode($results), 200)->header('Content-Type', 'application/json');
syslog(LOG_ERR, "AFTER");
return $theResponse

But that doesn't seem to be the case. The BEFORE and AFTER syslogs always appear immediately after eachother, even if I see the queries in the mysqladmin processlist on "sleep". Furthermore, as you can see it is a very simply read query, so I guess some kind of mysql lock can't be the problem (because I think locks only get used on writes).

And from this point I'm kinda lost on how to proceed debugging this. Does anybody know what these results tell me and where I can find the solution to this problem? All tips are welcome!

[PS: Some more info on the setup] The setup is slightly more complex than I described above, but since I don't think that has anything to do with it, I saved that information for the last. We've actually got two Ubuntu 16.04 servers with a load balancer in front of them. The two servers both contain a mysql server which is in some kind of master/master sync mode. Although I feel very confortable on Linux, I didn't set this up and I'm not a sysadmin, so I might be missing something there. I asked the guys who administer this setup, but they say the problem must be in the code. I'm not sure where that could be though.

Again; all tips are welcome!

kramer65
  • 50,427
  • 120
  • 308
  • 488
  • Intriguing question, but to find out if a process is *hanging* I would suggest looking at the process tree instead of relying on `mysqladmin`. Personally I think its unlikely because sub-processes may sleep but the main one is always active and one awakens the other. I find `htop` informative enough to see if there is something wrong with any process. – Xorifelse Nov 21 '16 at 22:24
  • 1
    I personally would just be guessing that the load balancer is likely throttling requests as a ddos mitigation. I would start with logging the time of the request on client side, time at the top of your php script and time at the bottom of your php script ([microtime(true)](http://php.net/microtime) would be fine here). That will at least tell you if the issue is with php and how long the php script takes to run and whether php is hanging between the initial request and when the script is run. I'd bet that the php script isn't called for that timeout. – Jonathan Kuhn Nov 21 '16 at 22:25
  • @JonathanKuhn - I also thought that it had something to do with the loadbalancer, but the people who administer that loadbalancer guarantee me that that is not the case. And after I saw the mysql sleep things in mysqladmin I thought it would have something to do with that. But thanks for the tip. I'm going to log those times at the top/bottom of the php script. – kramer65 Nov 21 '16 at 22:30
  • 1
    You could also try making quick requests to a non php file, e.g. text or image, and see if the same issue persists. That would show right there that it isn't a php issue if it does. I guess that also brings up, do you have the same issue with other scripts? Just make a script that has nothing but `="hello"?>` and call it a few times. Or even just add `die('hello')` to the top of your current script. That stops processing the script immediately. It shouldn't be hard to show whether it is your script or not. – Jonathan Kuhn Nov 21 '16 at 22:32

1 Answers1

0

Ideally the code should close the connection post completion of task or should reuse the connection upon requirement based on how to code is written.

If you want MySQL to take care of this task, i would suggest check wait_timeout setting/variable. The value for this setting/veritable represents in second(s).

For example, if you set wait_timeout=10 than any connection inside MySQL in sleep state for more than 10 seconds will be closed by MySQL automatically.

Note: Above setting is global or dynamic in nature hence it can be set without restarting the MySQL. Example command: mysql> set global wait_timeout=10;

Vaibhav
  • 41
  • 3