php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login

go to bug id or search bugs for

Bug #50312 Opening an https using fopen consumes all cpu time
Submitted: 2009-11-27 13:37 UTC Modified: 2015-02-01 04:42 UTC
Votes:3
Avg. Score:4.7 ± 0.5
Reproduced:1 of 2 (50.0%)
Same Version:1 (100.0%)
Same OS:1 (100.0%)
From: kvr at centrum dot cz Assigned: rasmus (profile)
Status: Closed Package: OpenSSL related
PHP Version: 5.*, 6 OS: *
Private report: No CVE-ID: None
View Developer Edit
 [2009-11-27 13:37 UTC] 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, 60000
<unfinished ...>
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\6\0@\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.

Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2009-11-27 14:28 UTC] jani@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 14:31 UTC] jani@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 16:57 UTC] 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 17:48 UTC] jani@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 17:56 UTC] 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 18:04 UTC] jani@php.net 
Yes, it's the OpenSSL lib doing the read, what's the bug here?
 [2009-11-27 18:14 UTC] kvr at centrum dot cz 
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.
 [2009-11-27 18:24 UTC] rasmus@php.net 
This was reported before and a patch supplied but Pierre blew it off.  
See bug #46685

The patch there looks sane.  I'll try to get some time this weekend to 
play with it.
 [2009-11-27 18:37 UTC] 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.
 [2009-11-27 18:42 UTC] pajoye@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:54 UTC] rasmus@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:56 UTC] pajoye@php.net 
btw, if it happens to be the same issue, can you bogus (duplicate) this one pls?
 [2009-11-27 19:13 UTC] rasmus@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 20:12 UTC] kvr at centrum dot cz 
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.
 [2015-02-01 04:42 UTC] rasmus@php.net
-Status: Assigned +Status: Closed
 [2015-02-01 04:42 UTC] rasmus@php.net 
This doesn't happen anymore. As we can see from the strace, we now sit in poll() until the timeout at 60s:

29667 1422765514.330841 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3 <0.000027> 
29667 1422765514.330914 fcntl(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000014>
29667 1422765514.330967 fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000015>
29667 1422765514.331025 connect(3, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("123.125.114.144")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000050>
29667 1422765514.331138 poll([{fd=3, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 60000) = 0 (Timeout) <60.060063>
29667 1422765574.391342 fcntl(3, F_SETFL, O_RDWR) = 0 <0.000049>
29667 1422765574.391565 close(3)        = 0 <0.000076>
 
PHP Copyright © 2001-2025 The PHP Group
All rights reserved. 		Last updated: Wed Nov 05 04:00:01 2025 UTC