#50312 [Fbk->Opn]: Opening an https using fopen consumes all cpu time
ID: 50312 User updated by: kvr at centrum dot cz Reported By: kvr at centrum dot cz -Status: Feedback +Status: Open Bug Type: HTTP related Operating System: Linux, Debian PHP Version: 5.3SVN-2009-11-27 (snap) New Comment: Not personally as it's not my case :) But yes, I mean to take care when stream_select is called, not to perform system select/poll on one ssl socket. Previous Comments: [2009-11-27 19:13:28] ras...@php.net kvr, you mean you are worried about nested selects if you are doing a stream_select() in userspace and internally the SSL reading is selecting as well? [2009-11-27 18:56:49] paj...@php.net btw, if it happens to be the same issue, can you bogus (duplicate) this one pls? [2009-11-27 18:54:58] ras...@php.net It's not so much a matter of reproducing it as it is reading the openssl docs and looking at our code. If you read about SSL_read and SSL_get_error it seems pretty clear that we are not handling errors efficiently here. We are simply busy-looping on an SSL_ERROR_WANT_READ which is something you are going to have a hard time reproducing consistently, but when it happens it sucks. [2009-11-27 18:42:36] paj...@php.net IIRC I did not blew it, I was simply not able to reproduce this problem, same as here. I did not blindly apply the patch as every attempt to fix smtg that was not reproducable always had bad side effect. I'm still not able to reproduce, Rasmus, feel free to take the hand on both bugs if you can reproduce these problems and can fix them. [2009-11-27 18:37:23] kvr at centrum dot cz Yes, it looks related. The patch looks quite logical but I'm not sure if it would work with stream_select() functions. Anyway, thank you and sorry the bug report was not clear from the first description. The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at http://bugs.php.net/50312 -- Edit this bug report at http://bugs.php.net/?id=50312&edit=1
#50312 [Fbk->Opn]: Opening an https using fopen consumes all cpu time
ID: 50312
User updated by: kvr at centrum dot cz
Reported By: kvr at centrum dot cz
-Status: Feedback
+Status: Open
Bug Type: HTTP related
Operating System: Linux, Debian
PHP Version: 5.3SVN-2009-11-27 (snap)
New Comment:
php (or OpenSSL library) doesn't handle the error code EAGAIN and
instead of waiting for data using select() or poll(), it calls read()
again and again, taking all the cpu time.
Previous Comments:
[2009-11-27 18:04:20] j...@php.net
Yes, it's the OpenSSL lib doing the read, what's the bug here?
[2009-11-27 17:56:41] kvr at centrum dot cz
Yes, I tried it exactly as written in your example.
The php version was the latest: ~/iphp/bin/php -v
PHP 5.3.2-dev (cli) (built: Nov 27 2009 17:39:57)
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2009 Zend Technologies
Did you check the strace output (or whatever tool your system
provides to trace program syscalls) ? Could you please attach it?
[2009-11-27 17:48:47] j...@php.net
Well, did you try the short example I provided? That site isn't
exactly "slow" but since you're not providing anything to work with
that's what I tested and that works..
[2009-11-27 16:57:04] kvr at centrum dot cz
Well, sorry, the URL address was supposed to be replaced with
anything real but preferably slow.
I compiled the php5.3-latest as proposed and the problem is there as
well.
[2009-11-27 14:31:01] j...@php.net
Unless of course your provided "code" is supposed to work at all?
This works too:
# php -r '$fd = fopen("https://master.php.net/manage/users.php";, "r");'
The remainder of the comments for this report are too long. To view
the rest of the comments, please view the bug report online at
http://bugs.php.net/50312
--
Edit this bug report at http://bugs.php.net/?id=50312&edit=1
#50312 [Fbk->Opn]: Opening an https using fopen consumes all cpu time
ID: 50312
User updated by: kvr at centrum dot cz
Reported By: kvr at centrum dot cz
-Status: Feedback
+Status: Open
Bug Type: HTTP related
Operating System: Linux, Debian
PHP Version: 5.3SVN-2009-11-27 (snap)
New Comment:
Yes, I tried it exactly as written in your example.
The php version was the latest: ~/iphp/bin/php -v
PHP 5.3.2-dev (cli) (built: Nov 27 2009 17:39:57)
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2009 Zend Technologies
Did you check the strace output (or whatever tool your system
provides to trace program syscalls) ? Could you please attach it?
Previous Comments:
[2009-11-27 17:48:47] j...@php.net
Well, did you try the short example I provided? That site isn't
exactly "slow" but since you're not providing anything to work with
that's what I tested and that works..
[2009-11-27 16:57:04] kvr at centrum dot cz
Well, sorry, the URL address was supposed to be replaced with
anything real but preferably slow.
I compiled the php5.3-latest as proposed and the problem is there as
well.
[2009-11-27 14:31:01] j...@php.net
Unless of course your provided "code" is supposed to work at all?
This works too:
# php -r '$fd = fopen("https://master.php.net/manage/users.php";, "r");'
[2009-11-27 14:28:31] j...@php.net
Please try using this snapshot:
http://snaps.php.net/php5.3-latest.tar.gz
For Windows:
http://windows.php.net/snapshots/
Works fine for me. Try without any 3rd party patches.
[2009-11-27 13:37:07] kvr at centrum dot cz
Description:
When connecting to https server using fopen("https://...";), php
consumes all cpu time until the connection is established. When there
is problem with the remote https server, the cpu is occupied until
the script runs out of time.
Full version information: PHP 5.3.0-0.dotdeb.8 with Suhosin-Patch
0.9.7 (cli) (built: Aug 12 2009 18:11:27)
Reproduce code:
---
The following code can be used to reproduce:
$fd = fopen("https://whatever.com/index.html";, "r")
Expected result:
The code should open the connection without busy waits.
Actual result:
--
The code keeps trying reading on non-blocked socket until some data
is received, see the strace:
25832 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 38
25832 fcntl64(38, F_GETFL) = 0x2 (flags O_RDWR)
25832 fcntl64(38, F_SETFL, O_RDWR|O_NONBLOCK) = 0
25832 connect(38, {sa_family=AF_INET, sin_port=htons(443),
sin_addr=inet_addr("w.x.y.z")}, 16) = -1 EINPROGRESS (Operation now
in progress)
25832 poll([{fd=38, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 6
25832 <... poll resumed> ) = 1 ([{fd=38,
revents=POLLOUT}])
25832 getsockopt(38, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
25832 fcntl64(38, F_SETFL, O_RDWR) = 0
25832 fcntl64(38, F_GETFL) = 0x2 (flags O_RDWR)
25832 fcntl64(38, F_SETFL, O_RDWR|O_NONBLOCK) = 0
25832 gettimeofday({1259327624, 794801}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 time(NULL)= 1259327624
25832 write(38,
"\200d\1\3\1\0K\0\0\0\20\0\0009\0\0008\0\0005\0\0\26\0\0\23\0\0\n\7\0
0\200\0\0\25\0\0\22\0\0\t\...@\0\0\24\0\0\21\0\0\10\0\0\6\4\0\200\0\0
25832 read(38, 0x8e62f78, 7)= -1 EAGAIN (Resource
temporarily unavailable)
25832 gettimeofday({1259327624, 795389}, {4294967176, 0}) = 0
25832 gettimeofday({1259327624, 795463}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 read(38, 0x8e62f78, 7)= -1 EAGAIN (Resource
temporarily unavailable)
... read repeats many times / or forever instead of polling socket
for POLLIN.
25832 read(38, 0x8e62f78, 5)= -1 EAGAIN (Resource
temporarily unavailable)
25832 gettimeofday({1259327624, 893179}, {4294967176, 0}) = 0
25832 gettimeofday({1259327624, 893222}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 read(38, "\24\3\1\0\1", 5)= 5
When / if the data is received, the communication continues
correctly.
--
Edit this bug report at http://bugs.php.net/?id=50312&edit=1
#50312 [Fbk->Opn]: Opening an https using fopen consumes all cpu time
ID: 50312
User updated by: kvr at centrum dot cz
Reported By: kvr at centrum dot cz
-Status: Feedback
+Status: Open
Bug Type: HTTP related
Operating System: Linux, Debian
PHP Version: 5.3SVN-2009-11-27 (snap)
New Comment:
Well, sorry, the URL address was supposed to be replaced with
anything real but preferably slow.
I compiled the php5.3-latest as proposed and the problem is there as
well.
Previous Comments:
[2009-11-27 14:31:01] j...@php.net
Unless of course your provided "code" is supposed to work at all?
This works too:
# php -r '$fd = fopen("https://master.php.net/manage/users.php";, "r");'
[2009-11-27 14:28:31] j...@php.net
Please try using this snapshot:
http://snaps.php.net/php5.3-latest.tar.gz
For Windows:
http://windows.php.net/snapshots/
Works fine for me. Try without any 3rd party patches.
[2009-11-27 13:37:07] kvr at centrum dot cz
Description:
When connecting to https server using fopen("https://...";), php
consumes all cpu time until the connection is established. When there
is problem with the remote https server, the cpu is occupied until
the script runs out of time.
Full version information: PHP 5.3.0-0.dotdeb.8 with Suhosin-Patch
0.9.7 (cli) (built: Aug 12 2009 18:11:27)
Reproduce code:
---
The following code can be used to reproduce:
$fd = fopen("https://whatever.com/index.html";, "r")
Expected result:
The code should open the connection without busy waits.
Actual result:
--
The code keeps trying reading on non-blocked socket until some data
is received, see the strace:
25832 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 38
25832 fcntl64(38, F_GETFL) = 0x2 (flags O_RDWR)
25832 fcntl64(38, F_SETFL, O_RDWR|O_NONBLOCK) = 0
25832 connect(38, {sa_family=AF_INET, sin_port=htons(443),
sin_addr=inet_addr("w.x.y.z")}, 16) = -1 EINPROGRESS (Operation now
in progress)
25832 poll([{fd=38, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 6
25832 <... poll resumed> ) = 1 ([{fd=38,
revents=POLLOUT}])
25832 getsockopt(38, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
25832 fcntl64(38, F_SETFL, O_RDWR) = 0
25832 fcntl64(38, F_GETFL) = 0x2 (flags O_RDWR)
25832 fcntl64(38, F_SETFL, O_RDWR|O_NONBLOCK) = 0
25832 gettimeofday({1259327624, 794801}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 time(NULL)= 1259327624
25832 write(38,
"\200d\1\3\1\0K\0\0\0\20\0\0009\0\0008\0\0005\0\0\26\0\0\23\0\0\n\7\0
0\200\0\0\25\0\0\22\0\0\t\...@\0\0\24\0\0\21\0\0\10\0\0\6\4\0\200\0\0
25832 read(38, 0x8e62f78, 7)= -1 EAGAIN (Resource
temporarily unavailable)
25832 gettimeofday({1259327624, 795389}, {4294967176, 0}) = 0
25832 gettimeofday({1259327624, 795463}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 read(38, 0x8e62f78, 7)= -1 EAGAIN (Resource
temporarily unavailable)
... read repeats many times / or forever instead of polling socket
for POLLIN.
25832 read(38, 0x8e62f78, 5)= -1 EAGAIN (Resource
temporarily unavailable)
25832 gettimeofday({1259327624, 893179}, {4294967176, 0}) = 0
25832 gettimeofday({1259327624, 893222}, {4294967176, 0}) = 0
25832 time(NULL)= 1259327624
25832 read(38, "\24\3\1\0\1", 5)= 5
When / if the data is received, the communication continues
correctly.
--
Edit this bug report at http://bugs.php.net/?id=50312&edit=1
