php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #51382 session_start() blocks execution
Submitted: 2010-03-24 18:44 UTC Modified: 2013-02-18 00:34 UTC
Votes:2
Avg. Score:4.0 ± 0.0
Reproduced:2 of 2 (100.0%)
Same Version:0 (0.0%)
Same OS:0 (0.0%)
From: info at lategoodbye dot de Assigned:
Status: No Feedback Package: Session related
PHP Version: 5.3.2 OS: Linux 2.4.35.4 mips
Private report: No CVE-ID: None
Have you experienced this issue?
Rate the importance of this bug to you:

 [2010-03-24 18:44 UTC] info at lategoodbye dot de
Description:
------------
Hi, i'm running PHP 5.3.2 via FastCGI with lighttpd 1.4.25 and uclibc 0.9.29. I experienced that after a period of time, all session driven pages hang and deliver no content to the client. But all static content like images are accessible. Below i appended a little script, how the problem can be reproduced.

Here are the options from the php.ini:

session.save_handler = files
session.save_path = "/tmp"
session.gc_probability = 1
session.gc_divisor     = 100
session.gc_maxlifetime = 1440

Here is the configure line:

'./configure' '--target=mipsel-linux' '--host=mipsel-linux' '--build=i486-linux-gnu' '--program-prefix=' '--program-suffix=' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--libexecdir=/usr/lib' '--sysconfdir=/etc' '--datadir=/usr/share' '--localstatedir=/var' '--mandir=/usr/man' '--infodir=/usr/info' '--disable-nls' '--enable-shared' '--disable-static' '--disable-rpath' '--disable-debug' '--without-pear' '--with-config-file-path=/etc' '--enable-magic-quotes' '--disable-short-tags' '--without-gettext' '--disable-simplexml' '--with-zlib=/home/10_openwrt/staging_dir/mipsel/usr' '--with-zlib-dir=/home/10_openwrt/staging_dir/mipsel/usr' '--with-pcre-regex=/home/10_openwrt/staging_dir/mipsel/usr' '--disable-phar' '--enable-ctype=shared' '--without-curl' '--disable-fileinfo' '--disable-dom' '--disable-exif' '--disable-ftp' '--without-gd' '--without-gmp' '--disable-hash' '--without-iconv' '--enable-json=shared' '--without-ldap' '--disable-mbstring' '--without-mcrypt' '--without-mysql' '--without-openssl' '--enable-pdo=shared' '--without-pdo-mysql' '--without-pdo-pgsql' '--with-pdo-sqlite=shared,/home/10_openwrt/staging_dir/mipsel/usr' '--without-pgsql' '--enable-session=shared' '--disable-soap' '--enable-sockets=shared' '--without-sqlite' '--with-sqlite3=shared,/home/10_openwrt/staging_dir/mipsel/usr' '--disable-tokenizer' '--enable-xml=shared,/home/10_openwrt/staging_dir/mipsel/usr' '--with-libexpat-dir=/home/10_openwrt/staging_dir/mipsel/usr' '--disable-xmlreader' '--disable-xmlwriter' '--disable-apc' '--disable-filter' '--disable-libxml' '--enable-sysvsem' '--enable-sysvshm' '--enable-sysvmsg' '--enable-pcntl' '--disable-cli' '--enable-cgi'

The filesystem behind /tmp is tmpfs.

After that i played a little bit with option session.gc_divisor. If i set the option to 2, then the problem happend immediately. But if i set the option to 100000, the problem is not reproducable.

Is this a dead lock caused by the session garbage collector?

Test script:
---------------
<?php
session_start();
session_write_close();  
?>
<html><body>Content</body></html>

Expected result:
----------------
PHP delivers "Content" to the browser.

Actual result:
--------------
The browser didn't get "Content" and wait for a response.

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2010-03-24 19:04 UTC] rasmus@php.net
One way to figure that out is to attach gdb to a hanging fcgi process and get a 
backtrace (bt) from gdb which should show where it is stuck.
 [2010-03-25 08:47 UTC] abca_b_cabcom at hotmail dot com
From you description I traced back to the line 1475 in ./etc/session/session.c,
it is the only line which will be affect by the php.ini variable session.gc_divisor you describe.

The line is show below:
nrand = (int) ((float) PS(gc_divisor) * php_combined_lcg(TSRMLS_C));

So, I think it may be a compiling error.
 [2010-03-25 15:11 UTC] info at lategoodbye dot de
May be i expressed myself bad about the option session.gc_divisor. Setting the option to 100000 is nearly like disabling garbage collection. The chance to reproduce the problem is very, very low but possible.

How can i findout that it's a compile error?

Nevertheless i will make the backtrace.
 [2010-03-25 17:59 UTC] abca_b_cabcom at hotmail dot com
Maybe you can post your backtrace result here first, i just guess it is a compiler error, cause php_combined_lcg function should have no error.
 [2010-03-31 16:29 UTC] info at lategoodbye dot de
I'm sorry, i didn't get gdb running on the Asus Router (Flash too small).

But i've a strace for you, may be it helps:

accept(0, {sa_family=AF_FILE, NULL}, [2]) = 3
poll([{fd=3, events=POLLIN}], 1, 5000)  = 1 ([{fd=3, revents=POLLIN}])
read(3, "\1\1\0\1\0\10\0\0", 8)         = 8
read(3, "\0\1\0\0\0\0\0\0", 8)          = 8
read(3, "\1\4\0\1\3H\0\0", 8)           = 8
read(3, "\17\17SERVER_SOFTWARElighttpd/1.4.25"..., 840) = 840
read(3, "\1\4\0\1\0\0\0\0", 8)          = 8
time(NULL)                              = 946686768
lstat("/www/pc/power.php", {st_mode=S_IFREG|0644, st_size=8269, ...}) = 0
lstat("/www/pc", {st_mode=0, st_size=97, ...}) = 0
lstat("/www", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
old_mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 0, 0) = 0x2afaa000
time(NULL)                              = 946686768
stat("/www/.user.ini", 0x7fff46e8)      = -1 ENOENT (No such file or directory)
stat("/www/pc/.user.ini", 0x7fff46e8)   = -1 ENOENT (No such file or directory)
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x10000000, [RT_68 RT_69 RT_76 RT_77 RT_79 RT_81 RT_82 RT_83 RT_84 RT_85 RT_86 RT_87 RT_88 RT_89 RT_90 RT_91 RT_92 RT_93 RT_94], SA_SIGINFO|0x66b990}, {SIG_DFL, [RT_65 RT_66], 0}, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 16) = 0
time(NULL)                              = 946686768
open("/www/pc/power.php", O_RDONLY)     = 4
ioctl(4, TIOCNXCL, 0x7fff5888)          = -1 ENOTTY (Inappropriate ioctl for device)
brk(0x956000)                           = 0x956000
fstat(4, {st_mode=S_IFREG|0644, st_size=2606, ...}) = 0
read(4, "<?php\n\nrequire_once(\"/www/power_"..., 4096) = 2606
_llseek(4, 0, [0], SEEK_SET)            = 0
getcwd("", 4095)                        = 9
chdir("\35\2")                          = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
ioctl(4, TIOCNXCL, 0x7fff3678)          = -1 ENOTTY (Inappropriate ioctl for device)
fstat(4, {st_mode=S_IFREG|0644, st_size=2606, ...}) = 0
old_mmap(NULL, 2638, PROT_READ, MAP_PRIVATE, 718909632, 0) = 0x2aaae000
_llseek(4, 0, [0], SEEK_SET)            = 0
munmap(0x2aaae000, 2606)                = 0
close(4)                                = 0
time(NULL)                              = 946686768
lstat("/www/power_logic.inc.php", {st_mode=S_IFREG|0644, st_size=2385, ...}) = 0
time(NULL)                              = 946686768
open("/www/power_logic.inc.php", O_RDONLY) = 4
fstat(4, {st_mode=S_IFCHR|S_ISUID|030000554, st_rdev=makedev(0, 0), ...}) = 0
fstat(4, {st_mode=05273160660, st_size=720167216, ...}) = 0
fstat(4, {st_mode=0, st_size=0, ...})   = 0
old_mmap(NULL, 2385, PROT_READ, MAP_SHARED, 4, 0) = 0x2aaae000
munmap(0x2aaae000, 2385)                = 0
close(4)                                = 0
brk(0x957000)                           = 0x957000
time(NULL)                              = 946686768
lstat("/www/defines.inc.php", {st_mode=S_IFREG|0644, st_size=5087, ...}) = 0
time(NULL)                              = 946686768
open("/www/defines.inc.php", O_RDONLY)  = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=5087, ...}) = 0
fstat(4, {st_mode=0, st_size=0, ...})   = 0
fstat(4, {st_mode=S_IFREG|040000130, st_size=0, ...}) = 0
old_mmap(NULL, 5087, PROT_READ, MAP_SHARED, 4, 0) = 0x2aaae000
munmap(0x2aaae000, 5087)                = 0
close(4)                                = 0
brk(0x958000)                           = 0x958000
brk(0x959000)                           = 0x959000
time(NULL)                              = 946686769
lstat("/www/functions.inc.php", {st_mode=S_IFREG|0644, st_size=8586, ...}) = 0
time(NULL)                              = 946686769
open("/www/functions.inc.php", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=8586, ...}) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=18, ...}) = 0
fstat(4, {st_mode=S_IFREG|040000130, st_size=4, ...}) = 0
old_mmap(NULL, 8586, PROT_READ, MAP_SHARED, 4, 0) = 0x2aaae000
brk(0x95a000)                           = 0x95a000
munmap(0x2aaae000, 8586)                = 0
close(4)                                = 0
open("/tmp/sess_29fa4b85a40a392a7955de8cdc62d5f6", O_RDWR|O_CREAT, 0600) = 4
flock(4, LOCK_EX)                       = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fstat(4, {st_mode=S_IFSOCK|S_ISGID|05273600020, st_size=19, ...}) = 0
lseek(4, 0, SEEK_SET)                   = 0
read(4, "authentication|b:1;", 19)      = 19
gettimeofday({946686769, 156033}, NULL) = 0
getpid()                                = 789
gettimeofday({946686769, 156033}, NULL) = 0
open("/tmp", O_RDONLY|O_NONBLOCK|O_DIRECTORY) = 5
fstat(5, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=360, ...}) = 0
fcntl(5, F_SETFD, FD_CLOEXEC)           = 0
brk(0x95b000)                           = 0x95b000
time([946686769])                       = 946686769
getdents64(5, /* 18 entries */, 4096)   = 560
rt_sigprocmask(SIG_SETMASK, NULL, [RT_0], 16) = 0
rt_sigsuspend([]
 [2010-05-04 10:55 UTC] info at lategoodbye dot de
Looking at the strace, i can see that the garbage collector is invoked, after the current session is locked.

Is it possible that the garbage collector hangs because of the locked session?
 [2012-03-31 04:18 UTC] yohgaki@php.net
Do you still have this problem or resolved by yourself?
 [2012-03-31 04:18 UTC] yohgaki@php.net
-Status: Open +Status: Feedback
 [2012-03-31 09:06 UTC] info at lategoodbye dot de
In 2010, i could isolate the problem by writing my own session handler. The hanging appeared after the second call of the PHP function readdir(). The problem with readdir() could also reproduced outside the session handler:

Test script:

<?php

$dp = opendir("/tmp");

while (($file = readdir($dp)) !== FALSE)
{
    echo $file."< br>";
}

closedir($dp);

?>

Luckily the hanging didn't appear by using the DirectoryIterator. As a workaround, i written my own session handler with the DirectoryIterator.
 [2013-02-18 00:34 UTC] php-bugs at lists dot php dot net
No feedback was provided. The bug is being suspended because
we assume that you are no longer experiencing the problem.
If this is not the case and you are able to provide the
information that was requested earlier, please do so and
change the status of the bug back to "Open". Thank you.
 
PHP Copyright © 2001-2020 The PHP Group
All rights reserved.
Last updated: Sun Feb 23 17:01:28 2020 UTC