Bug #62658 [Asn->Fbk]: When enable –with-curlwrappers option, stream_get_contents() may cpu 100%

Edit report at https://bugs.php.net/bug.php?id=62658&edit=1 ID: 62658 Updated by: pierrick@php.net Reported by: sopl dot wang at gmail dot com Summary: When enable –with-curlwrappers option, stream_get_contents() may cpu 100% -Status: Assigned +Status: Feedback Type: Bug Package: cURL related Operating System: ALL PHP Version: master-Git-2012-07-25 (Git) Assigned To: pierrick Block user comment: N Private report: N New Comment: Here's what I have on my side with today's version of the master branch : select(4, [3], [], [], {15, 0}) = 1 (in [3], left {4, 999876}) poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 1 ([{fd=3, revents=POLLIN}]) recvfrom(3, "1\r\n1\r\n", 16384, 0, NULL, NULL) = 6 select(4, [3], [], [], {15, 0}) = 1 (in [3], left {5, 182}) poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 1 ([{fd=3, revents=POLLIN}]) recvfrom(3, "1\r\n1\r\n", 16384, 0, NULL, NULL) = 6 I compiled it with the same curl version 7.21.6. As you can see I can't reproduce it. My select don't have anything in the Output file descriptor. Can you test if you still have this different output in your strace ? Do you use the exact same script you sent in your previous comment ? Previous Comments: ------------------------------------------------------------------------ [2012-10-07 13:59:43] sopl dot wang at gmail dot com You may try use file_get_contents to open a very slow website to help reproduce this problem. When open a very very slow website, this issue will be more evident. ------------------------------------------------------------------------ [2012-10-07 13:49:51] sopl dot wang at gmail dot com Still have issue (a bit different of output, but still cpu 100%) when I build and test on php-5.4.7 GA release. Follow is my build config: ./configure --prefix=/usr/local/webserver/php5.4.7 --with-config-file- path=/usr/local/webserver/php5.4.7/etc --with-mysql=/usr/local/webserver/mysql5 --with-mysqli=/usr/local/webserver/mysql5/bin/mysql_config --with-iconv-dir=/usr --with-freetype-dir --with-jpeg-dir --with-png-dir --with-zlib --with-libxml- dir=/usr --enable-xml --disable-rpath --enable-bcmath --enable-shmop --enable- sysvsem --enable-inline-optimization --with-curl=/usr --with-curlwrappers -- enable-ftp --enable-mbregex --enable-fpm --with-fpm-user=www --with-fpm- group=www --disable-ipv6 --enable-mbstring --with-mcrypt --with-gd=/usr -- enable-gd-native-ttf --with-openssl --with-mhash --enable-pcntl --enable-sockets --enable-gd-jis-conv --disable-debug --enable-sysvshm --enable-soap --with-pdo- mysql=shared,/usr/local/webserver/mysql5 --with-pdo-sqlite=shared --with- sqlite=shared --enable-pdo=shared Test script ----------- ./sapi/cli/php <<<'<?php while(1) file_get_contents("http://www.l4ka.org");' Output ------ poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) clock_gettime(CLOCK_MONOTONIC, {26871452, 912511643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912536643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912553643}) = 0 select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) clock_gettime(CLOCK_MONOTONIC, {26871452, 912606643}) = 0 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) clock_gettime(CLOCK_MONOTONIC, {26871452, 912643643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912668643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912685643}) = 0 select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) clock_gettime(CLOCK_MONOTONIC, {26871452, 912738643}) = 0 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) clock_gettime(CLOCK_MONOTONIC, {26871452, 912775643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912800643}) = 0 clock_gettime(CLOCK_MONOTONIC, {26871452, 912817643}) = 0 select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) System version -------------- LSB Version: :core-4.0-amd64:core-4.0-ia32:core-4.0-noarch:graphics-4.0- amd64:graphics-4.0-ia32:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0- ia32:printing-4.0-noarch Distributor ID: CentOS Description: CentOS release 5.6 (Final) Release: 5.6 Codename: Final Curl version ------------ curl 7.21.6 (x86_64-unknown-linux-gnu) libcurl/7.21.6 OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5 Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp smtp smtps telnet tftp Features: IDN Largefile NTLM SSL libz ------------------------------------------------------------------------ [2012-09-28 19:44:39] pierrick@php.net Do you still have this issue ? I tried on my local build and everything work as expected. If it doesn't work could you give me more details about your build ? libcurl version ? ------------------------------------------------------------------------ [2012-07-25 10:26:16] sopl dot wang at gmail dot com Description: ------------ When enable –with-curlwrappers option, with http(s)/ftp(s)/other curl-wrapped stream protocols, file_get_contents(), stream_get_contents() and alike functions may lead consume 100% cpu cycle on waiting for receive. When strace problem php process, following will be develop: <pre> select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) select(7, [6], [6], [], {15, 0}) = 1 (out [6], left {15, 0}) poll([{fd=6, events=POLLIN}], 1, 0) = 0 (Timeout) </pre> The reason we found is in 'ext/curl/streams.c', function php_curl_stream_read(), line 174: <code> select(curlstream->maxfd + 1, &curlstream->readfds, &curlstream->writefds, &curlstream->excfds, &tv) </code> When select(), writefds always can write and immediate return, no block at here and, upper module will detect that no data could read and re-invoke this function (php_curl_stream_read()), a nonblock loop, lead this consume 100% cpu bug. If the link very slow, this 100% cpu problem may take the system load very high. Test script: --------------- Enable –with-curlwrappers and test: <code> <?php while (true) file_get_contents('http://soplwang.com'); </code> Expected result: ---------------- Expect the behavior like native php does… When strace, native php generate: <pre> poll([{fd=3, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=3, revents=POLLIN}]) </pre> Actual result: -------------- When strace, generate: <pre> select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) poll([{fd=3, events=POLLIN}], 1, 0) = 0 (Timeout) select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) poll([{fd=3, events=POLLIN}], 1, 0) = 0 (Timeout) select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) poll([{fd=3, events=POLLIN}], 1, 0) = 0 (Timeout) select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) poll([{fd=3, events=POLLIN}], 1, 0) = 0 (Timeout) select(4, [3], [3], [], {15, 0}) = 1 (out [3], left {15, 0}) poll([{fd=3, events=POLLIN}], 1, 0) = 0 (Timeout) ... </pre> ------------------------------------------------------------------------ -- Edit this bug report at https://bugs.php.net/bug.php?id=62658&edit=1