Record the issue of PHP script execution getting stuck once and troubleshoot php

Record the issue of PHP script execution getting stuck once and troubleshoot php

Problems Found

Recently, I suddenly found from monitoring that the load on one of our servers is higher than that of other servers in the same data center, while the inbound and outbound traffic is no different, further Check shows that there is one machine in each data center that has the same phenomenon. After combing, the problematic machines run some PHP scripts more than the normal machines, so I guess it is caused by a script execution error.

Solve the problem

After logging on to the machine and executing the top Command, we found that there was a PHP process with a high CPU usage. Then we executed the following command and found that there was a PHP script started by crontab for a long time:

ps aux | grep 'php' | grep -v 'php-fpm'

I had encountered a similar situation where PHP script execution was stuck. At that time, I suspected that Mysql queries across data centers were stuck during network jitter, so of course, all the stuck processes were killed, and the machine immediately recovered from the load, so I ran to another task with satisfaction.

After a while, I refreshed my monitoring and found that the problem occurred again. After commenting out the crontab and kill the process, I manually executed the script to reproduce the problem! It seems that the problem is too simple. Try to use the strace command to see what the stuck process is currently doing:

[tabalt@localhost ~] sudo strace -p 13793Process 13793 attached - interrupt to quit

No output! Use netstat to check whether the process has opened any port:

[tabalt@localhost ~] sudo netstat -tunpa | grep 13793tcp  0  0 192.168.1.100:38019  192.168.1.101:3306  ESTABLISHED 13793/phptcp  0  0 192.168.1.100:47107  192.168.1.102:6379  CLOSE_WAIT 13793/php 

We can see that the process has opened two ports, respectively establishing a connection with Mysql and Redis, and is in the state of establishing a connection (ESTABLISHED) and the other party actively closing the connection (CLOSE_WAIT; at first glance, it seems that the connection to the database is stuck, but because of the loss, we use tcpdump to capture packets to see the interaction between the Process and the database:

tcpdump -i eth0 host 192.168.1.101 and port 3306 -w ~/mysql.cap

After a while ,~ The/mysql. cap file does not have any output. Is there no interaction between the process and Mysql? Why is connection establishment disabled? It seems that the script execution can only be traced from the beginning:

First, in order to get strace to the process, output the pid of the process at the beginning of the PHP script and sleep for 10 s:

 echo getmypid(); sleep(10); 

Then start tcpdump to capture the interaction process between the local machine and Mysql.

Finally, execute the PHP script, copy the output pid, and then execute the strace command in the new window.

Now both strace and tcpdump have content! From the strace results, we can see that poll no longer exists after recvfrom, but we didn't see any errors:

//...poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}])recvfrom(4, "://xxx.com/\0\0\23jiadia"..., 271, MSG_DONTWAIT, NULL, NULL) = 271poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}])recvfrom(4, "_b?ie=UTF8&node=658390051\0\0008www."..., 271, MSG_DONTWAIT, NULL, NULL) = 206

From the packet capture results, after two SQL query statements are executed, the process does not send the query request package again. From the SQL statement log recorded by the program, it is found that only two queries are executed:

select * from sites where type = 1 limit 50;select * from sites where type = 2 limit 50;

But from these phenomena, there is still no clue, so we have to sacrifice the ultimate method: Output debugging! After reading the code and adding the output statement in the key area, the code looks as follows:

echo("start foreach\n");foreach($types as $type){ echo("foreach $type\n"); $result[$type] = $this->getSites($type);}echo("end foreach\n"); 

After the execution, the output is as follows, and the URL with type 2 is stuck:

start foreachforeach 1foreach 2

The Code is as follows:

$ Sites = array (); // omitting the code for querying from the database $ siteNum = 8; // omitting the code for reading from the configuration $ urlKeys = $ result = array (); for ($ I = 0; $ I <$ siteNum; $ I ++) {do {$ site = array_shift ($ sites ); $ urlKey = md5 ($ site ['url']);} while (array_key_exists ($ urlKey, $ urlKeys); $ urlKeys [$ urlKey] = 1; $ result [] = $ site;} return $ result;

Originally, two loops were written to achieve 8 non-repeated URLs. If there were only 7 Non-repeated URLs in the result, there would be an empty loop. If there were less than 7, there would be an endless loop! So I checked the number of URLs whose type is 2, and there are only 6 URLs!

Summary

It took about one day to discover and solve the problem. Although it proved that it was caused by a low-level code BUG, the entire troubleshooting process was quite rewarding, at the beginning, it was a superficial proof, and the results of tcpdump and strace in the process were already very descriptive. Therefore, we should be more proficient in the application of various tools, the tool results must also be analyzed in depth. The above is all about this article. I hope this article will help you in your study or work. If you have any questions, please leave a message.