Php5.2's curl-bug server is stuck by the php process for troubleshooting, php5.2curl-bug

Php5.2's curl-bug server is stuck by the php process for troubleshooting, php5.2curl-bug

A few days ago, Dongzheng reported that the Linode server was getting stuck. Today, I have time to troubleshoot the specific cause. The final cause is a little tragic: file_get_contents has not set the timeout time, the php5.2 code I used has a bug about curl, which leads to an endless loop of PHP processes.

This afternoon, I found that the system load was very high. So I went up and looked at it and found that a large PHP process was not exited, which took a lot of CPU,

Problem process:

The script running later is my RSS regular update task. It seems that there is something wrong with the PHP code, so strace-p 14043 looked at it:

select(5, [4], [4], [], {15, 0}) = 1 (out [4], left {14, 999996})poll([{fd=4, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)clock_gettime(CLOCK_MONOTONIC, {4582888, 760370017}) = 0clock_gettime(CLOCK_MONOTONIC, {4582888, 760468615}) = 0clock_gettime(CLOCK_MONOTONIC, {4582888, 760565053}) = 0select(5, [4], [4], [], {15, 0}) = 1 (out [4], left {14, 999997})

There is an endless loop on fd 4, so let's see what FD is: ll/proc/14043/fd

Lrwx -- 1 wuhaiwen 64 July 21 11:00 4-> socket: [53176380]

Again, it turns out to be an endless loop when requesting a web page of CSDN, but I don't know where to request it. Think of the php process in GDB. bt shows:

(Gdb) bt
#0 0x00007f6721f8f013 in _ select_nocancel () at ../sysdeps/unix/syscall-template.S: 82
#1 0 × 0000000000481952 in php_curl_stream_read (stream = 0 × 2280650,
Buf = 0x22ea5d0 "2Fwww.laruence.com % 2 Ftag % 2F % 25e6% 25ad % 25a3% 25e5% 2588% 2599% 27 + class % 3D % 27tag-link-191% 27 + title % 3D % 273 + topics % 27 + style % 3D % 27font-size % 3A + 9.0243902439pt % 3B % 27% 3E % E6 % AD % A3 % E5 % 88% 99% 3C % 2Fa % 3E % 2 Ftags % 3E \" "..., Count = 8192) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/ext/curl/streams. c: 169
#2 0x00000000006738f9 in php_stream_fill_read_buffer (stream = 0x2280650, size = 4283) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/main/streams. c: 554
#3 0x0000000000673c39 in _ php_stream_read (stream = 0 × 2280650,
Buf = 0x2301fd5 "f = 'HTTP: // www.laruence.com/tag/json' class = 'tag-link-79 'title = '3 topics' style = 'font-size: 9.0243902439pt; '> json </a> \ n <a href = 'HTTP: // www.laruence.com/tag/lele' class = 'tag-link-43' title = '2 topics '"…, Size = 4283) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/main/streams. c: 600
#4 0x0000000000674c51 in _ php_stream_copy_to_mem (src = 0x2280650, buf = 0x7fff376ed898, maxlen = <optimized out>, persistent = 0)
At/home/wuhaiwen/install/php-env/src/php/php-5.2.8/main/streams. c: 1267
#5 Records in records (ht = <optimized out>, return_value = 0x2223da0, return_value_ptr = <optimized out>, this_ptr = <optimized out>, return_value_used = <optimized out>)
At/home/wuhaiwen/install/php-env/src/php/php-5.2.8/ext/standard/file. c: 565
#6 0x000000000000006c2a59 in seconds (execute_data = 0x7fff376edc4) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/Zend/zend_vm_execute.h: 200
#7 0x000000000000006c239f in execute (op_array = 0x1f26730) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/Zend/zend_vm_execute.h: 92
·············
#16 0x0000000000730d8e in main (argc = 4, argv = 0x7fff376f2468) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/sapi/cli/php_cli.c: 1133

Let's take a look at the current PHP Execution steps:

(gdb) p *op_array$4 = {type = 2 '\002', function_name = 0x1e54278 "getContent", scope = 0x1f8e850, fn_flags = 257, prototype = 0x0, num_args = 2, required_num_args = 1, arg_info = 0x1fd5e20,pass_rest_by_reference = 0 '\000', return_reference = 0 '\000', refcount = 0x1fd3ab8, opcodes = 0x1fddcc8, last = 28, size = 28, vars = 0x1fd3cc0, last_var = 6, size_var = 16, T = 15,brk_cont_array = 0x0, last_brk_cont = 0, current_brk_cont = 4294967295, try_catch_array = 0x0, last_try_catch = 0, static_variables = 0x0, start_op = 0x0, backpatch_count = 0,done_pass_two = 1 '\001', uses_this = 0 '\000', filename = 0x1fd3b58 "/home/wuhaiwen/webroot/kulvrss/libs/Myrss/Model/UrlContenter.php", line_start = 9, line_end = 30, doc_comment = 0x0,doc_comment_len = 0, reserved = {0x0, 0x0, 0x0, 0x0}}

The location of the problematic code was found. It turned out to be a file_get_contents ($ url) call, and no timeout time was set, so PHP was stuck in the network request. Set the timeout time with stream_context_create.

It seems that the problem has been solved here, but why does the php process occupy the CPU without setting the timeout time? Why is the system load so high? Why should I/O be waited? According to the above CPU situation, it is completely in an endless cycle.

Based on the above bt stack, first look at the call of the penultimate function:

#1 0 × 0000000000481952 in php_curl_stream_read (stream = 0 × 2280650,
Buf = 0x22ea5d0 "2Fwww.laruence.com % 2 Ftag % 2F % 25e6% 25ad % 25a3% 25e5% 2588% 2599% 27 + class % 3D % 27tag-link-191% 27 + title % 3D % 273 + topics % 27 + style % 3D % 27font-size % 3A + 9.0243902439pt % 3B % 27% 3E % E6 % AD % A3 % E5 % 88% 99% 3C % 2Fa % 3E % 2 Ftags % 3E \" "..., Count = 8192) at/home/wuhaiwen/install/php-env/src/php/php-5.2.8/ext/curl/streams. c: 169

Let's take a look at the code. PHP 5.2.8 is old. The Code is as follows:

static size_t php_curl_stream_read(php_stream *stream, char *buf, size_t count TSRMLS_DC){    php_curl_stream *curlstream = (php_curl_stream *) stream->abstract;    size_t didread = 0;    if (curlstream->readbuffer.readpos >= curlstream->readbuffer.writepos && curlstream->pending) {//········        do {            /* get the descriptors from curl */            curl_multi_fdset(curlstream->multi, &curlstream->readfds, &curlstream->writefds, &curlstream->excfds, &curlstream->maxfd);            /* if we are in blocking mode, set a timeout */            tv.tv_usec = 0;            tv.tv_sec = 15; /* TODO: allow this to be configured from the script */            /* wait for data */            switch (select(curlstream->maxfd + 1, &curlstream->readfds, &curlstream->writefds, &curlstream->excfds, &tv)) {                case -1:                    /* error */                    return 0;                case 0:                    /* no data yet: timed-out */                    return 0;                default:                    /* fetch the data */                    do {                        curlstream->mcode = curl_multi_perform(curlstream->multi, &curlstream->pending);                    } while (curlstream->mcode == CURLM_CALL_MULTI_PERFORM);            }        } while (curlstream->readbuffer.readpos >= curlstream->readbuffer.writepos && curlstream->pending > 0);    }//··········    return didread;}

GDB went in and found that the Code had been circulating in do-while! Why don't I need to clear the FD with FD_ZERO first in curl_multi_fdset? Generally, it is cleared first.

It was not a PHP bug, so I found this Pierrick-Charron commit on the Internet. It was indeed a bug. In fact, the curl_multi_fdset document was written at the beginning:

Copy codeThe Code is as follows:
This function extracts file descriptor information from a given multi_handle. libcurl returns its fd_set sets. the application can use these to select () on, but be sure to FD_ZERO them before calling this function as curl_multi_fdset (3) only adds its own descriptors,

Okay. Finally, use GDB to verify that I manually cleared the fd before calling curl_multi_fdset under the above do to see if the loop can be exited:

(Gdb) print FD_ZERO (& curlstream-> readfds)
No symbol "FD_ZERO" in current context.

FD_ZERO does not exist. No matter what it is, it is a macro definition. Just expand it: # define FD_ZERO (p) bzero (char *) (p ), sizeof (* (p )))

Directly use call to modify the three parameter arrays of curl_muti_fdset as follows:

Copy codeThe Code is as follows:
(Gdb) call bzero (char *) (& curlstream-> readfds), sizeof (* (& curlstream-> readfds )))
$5 = 17055392
(Gdb) call bzero (char *) (& curlstream-> writefds), sizeof (* (& curlstream-> writefds )))
$6 = 17055520
(Gdb) call bzero (char *) (& curlstream-> excfds), sizeof (* (& curlstream-> excfds )))
$7 = 17055648

Next, GDB executes the statement in one step. As scheduled, because the value of curlstream-> pending is 0, it exits the loop and returns to the large function of php_stream_fill_read_buffer.

This is basically the end. The problematic PHP version should be 5.2. For details, refer to the above submitted changes or check whether your version code is correct.