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

go to bug id or search bugs for

Bug #57267 Apache stop answering (user cache)
Submitted: 2006-09-30 11:30 UTC Modified: 2009-02-16 20:25 UTC
From: info at astellar dot com Assigned:
Status: No Feedback Package: APC (PECL)
PHP Version: 5.1.2 OS: Centos4
Private report: No CVE-ID: None
View Add Comment Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
You can add a comment by following this link or if you reported this bug, you can edit this bug over here.
Block user comment
Status: Assign to:
Package:
Bug Type:
Summary:
From: info at astellar dot com
New email:
PHP Version: OS:

 

 [2006-09-30 11:30 UTC] info at astellar dot com 
Description:
------------
The version number of the PECL package or files you are using.

APC     3.0.12p2 stable

The list of modules you compiled PHP with (your configure line).

Configure Command 	 
'./configure' '--build=x86_64-redhat-linux-gnu' '--host=x86_64-redhat-linux-gnu' '--target=x86_64-redhat-linux-gnu' '--program-prefix=' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--sysconfdir=/etc' '--datadir=/usr/share' '--includedir=/usr/include' '--libdir=/usr/lib64' '--libexecdir=/usr/libexec' '--localstatedir=/var' '--sharedstatedir=/usr/com' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--cache-file=../config.cache' '--with-libdir=lib64' '--with-config-file-path=/etc' '--with-config-file-scan-dir=/etc/php.d' '--disable-debug' '--with-pic' '--disable-rpath' '--without-pear' '--with-bz2' '--with-curl' '--with-exec-dir=/usr/bin' '--with-freetype-dir=/usr' '--with-png-dir=/usr' '--enable-gd-native-ttf' '--without-gdbm' '--with-gettext' '--with-gmp' '--with-iconv' '--with-jpeg-dir=/usr' '--with-openssl' '--with-png' '--with-pspell' '--with-expat-dir=/usr' '--with-pcre-regex=/usr' '--with-zlib' '--with-layout=GNU' '--enable-exif' '--enable-ftp' '--enable-magic-quotes' '--enable-sockets' '--enable-sysvsem' '--enable-sysvshm' '--enable-sysvmsg' '--enable-track-vars' '--enable-trans-sid' '--enable-yp' '--enable-wddx' '--with-kerberos' '--enable-ucd-snmp-hack' '--with-unixODBC=shared,/usr' '--enable-memory-limit' '--enable-shmop' '--enable-calendar' '--enable-dbx' '--enable-dio' '--with-mime-magic=/etc/httpd/conf/magic' '--without-sqlite' '--with-libxml-dir=/usr' '--with-xml' '--with-apxs2=/usr/sbin/apxs' '--without-mysql' '--without-gd' '--without-odbc' '--disable-dom' '--disable-dba' '--without-unixODBC' '--disable-pdo' '--disable-xmlreader' '--disable-xmlwriter'

gdb backtrace
#0  0x0000002a966b0606 in fcntl () from /lib64/tls/libc.so.6
#1  0x0000002a9eabf5ef in lock_reg (fd=54, cmd=7, type=Variable "type" is not available.
#0  0x0000002a966b0606 in fcntl () from /lib64/tls/libc.so.6
#2  0x0000002a9eabf62b in apc_fcntl_lock (fd=Variable "fd" is not available.
) at /tmp/tmpdbtRCQ/APC-3.0.12p2/apc_fcntl.c:83
#3  0x0000002a9eabb36e in apc_cache_user_insert (cache=0x552b076730, key=      {data = {file = {device = 365800714584, inode = 545460846712}, user = {identifier = 0x552b6bf158 "a%3A2%3A%7Bs%3A4
%3A%22type%22%3Bs%3A14%3A%22NNSL_LOCATIONS%22%3Bs%3A4%3A%22keys%22%3Bs%3A13%3A%22group_id_hash%22%3B%7D", identifier_len
 = 120}, fpfile = {fullpath = 0x552b6bf158 "a%3A2%3A%7Bs%3A4%3A%22type%22%3Bs%3A14%3A%22NNSL_LOCATIONS%22%3Bs%3A4%3A%22k
eys%22%3Bs%3A13%3A%22group_id_hash%22%3B%7D", fullpath_len = 120}}, mtime = 1159611542, type = 2 '\002'},
    value=0x2aa16826e0, t=1159611542) at /tmp/tmpdbtRCQ/APC-3.0.12p2/apc_cache.c:492
#4  0x0000002a9eab9c9c in _apc_store (
    strkey=0x552b6bf158 "a%3A2%3A%7Bs%3A4%3A%22type%22%3Bs%3A14%3A%22NNSL_LOCATIONS%22%3Bs%3A4%3A%22keys%22%3Bs%3A13%3A%
22group_id_hash%22%3B%7D", strkey_len=Variable "strkey_len" is not available.
) at /tmp/tmpdbtRCQ/APC-3.0.12p2/php_apc.c:441
#5  0x0000002a9eab9d92 in zif_apc_store (ht=Variable "ht" is not available.
) at /tmp/tmpdbtRCQ/APC-3.0.12p2/php_apc.c:472
#6  0x0000002a9a714868 in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfff4480)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:192
#7  0x0000002a9a7141b1 in execute (op_array=0x552b240778) at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:92
#8  0x0000002a9a71444a in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfff57a0)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:226
#9  0x0000002a9a7141b1 in execute (op_array=0x552b168558) at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:92
#10 0x0000002a9a71444a in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfff5c40)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:226
#11 0x0000002a9a7141b1 in execute (op_array=0x552b1ef558) at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:92
#12 0x0000002a9a71444a in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfff8100)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:226
#13 0x0000002a9a7141b1 in execute (op_array=0x552b2f0358) at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:92
#14 0x0000002a9a71444a in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfff8920)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:226
#15 0x0000002a9a7141b1 in execute (op_array=0x552b25e628) at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:92
#16 0x0000002a9a71444a in zend_do_fcall_common_helper_SPEC (execute_data=0x7fbfffa910)
    at /usr/src/debug/php-5.1.2/Zend/zend_vm_execute.h:226

Reproduce code:
---------------
$is_ok = apc_store($cache_key, $value);

Expected result:
----------------
put php array variable to cache

Actual result:
--------------
apache hangs up, stop answer queries.

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2006-10-05 18:53 UTC] gopalv82 at yahoo dot com 
On my CentOS release 4.4 (Final) on i686, the code works perfectly. This was my test script 

<?php
$key = "a%3A2%3A%7Bs%3A4%3A%22type%22%3Bs%3A14%3A%22NNSL_LOCATIONS%22%3Bs%3A4%3A%22keys%22%3Bs%3A13%3A%22group_id_hash%22%3B%7D";

$value = array("One" => "1", "Two" => "2");

if(apc_store($key, $value)) 
{
        print_r(apc_fetch($key));
}
?>

So far, nobody else has reported regressions on the user cache (which hasn't changed after 3.0.11).
 [2006-10-05 19:58 UTC] info at astellar dot com 
> On my CentOS release 4.4 (Final) on i686, the code works perfectly.

It took several hours on hi-load web box to reproduce this problem.
 [2006-10-13 16:23 UTC] bartvb at phpbb dot com 
I also seem to be running into this problem, mostly when the box is under high load. The symptom is indeed that Apache just stops responding. When this happens there is just one apache process running and it's using 100% of one processor. 

strace -p ...

only shows:

fcntl(12, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0} 

Haven't tried gdb yet. I'm using apc_store() fairly extensively. I'll try running with apc_store() disabled.

All this on AMD64 with Debian Sarge, default apache2 (2.0.54-5sarge1), PHP 5.1.6-0.dotdeb.2, APC 3.0.12p2

Current load is 2.24 on a dual proc box, it just locked up again. I'll try to get some info out of gdb.
 [2006-10-13 17:10 UTC] gopalv82 at yahoo dot com 
Do you see any children segv'ing in the log before the box locks up ?
 [2006-10-13 17:38 UTC] gopalv82 at yahoo dot com 
This is one of those cases where the locked up apache is probably not to blame - if you can, please build a copy of apc-3.0.12p2 with "-O0 -ggdb" and run the following script when your apache locks up.

#!/bin/sh

apache_children=`ps fax | grep "[a]pache2" | sed "s/^ *\([0-9]*\).*/\1/"`

cat > /tmp/bt.gdb <<EOF
bt full
generate-core-file
q
EOF

for each in $apache_children; do
	sudo gdb -p $each -x /tmp/bt.gdb | tee "apache2.$each.log";
done

It should give me the backtraces of all the apache children.  That'll be of more use to me - please keep the "core.*" files with you (they'll be huge), they are merely for a snapshot to look into if I see something suspicious.
 [2006-10-13 18:05 UTC] bartvb at phpbb dot com 
Oh, forgot to mention that I was using APC 3.0.10 (IIRC) when I first noticed this problem (I used the version in DotDeb).
 [2006-10-14 06:56 UTC] bartvb at phpbb dot com 
It's rather hard to get a good look because the problem seems to fix itself after about a minute or something like that. 

I just managed to sort of catch it but Apache resumed normal operation while the gdb was running. I cancelled the script at that moment.

This is the result:
http://www.bokt.nl/apc_debug/1/apache2.20290.log
(cores are also available)

Most of them seem to have a backtrace like:

#0  0x00002b71ae6d2bc4 in __fcntl_nocancel () from /lib/libpthread.so.0
No symbol table info available.
#1  0x00002b71ae6d2cb6 in fcntl () from /lib/libpthread.so.0
No symbol table info available.
#2  0x00002b71b2f85b3a in lock_reg (fd=13, cmd=7, type=1, offset=0, whence=0, len=0) at /archive/APC-3.0.12p2/apc_fcntl.c:76
	ret = 11121
	lock = {l_type = 1, l_whence = 0, l_start = 0, l_len = 0, l_pid = 0}
#3  0x00002b71b2f85b80 in apc_fcntl_lock (fd=13) at /archive/APC-3.0.12p2/apc_fcntl.c:83
No locals.
#4  0x00002b71b2f7fd6d in apc_cache_user_find (cache=0x849e60, strkey=0x8b50a8 "vars", keylen=5, t=1160822883)
    at /archive/APC-3.0.12p2/apc_cache.c:601
	slot = (slot_t **) 0x7ffffd7e8900
#5  0x00002b71b2f7e5a6 in zif_apc_fetch (ht=1, return_value=0xada618, return_value_ptr=0x0, this_ptr=0x0, return_value_used=1)
    at /archive/APC-3.0.12p2/php_apc.c:507
	strkey = 0x8b50a8 "vars"
	strkey_len = 4
	entry = (apc_cache_entry_t *) 0x7ffffd7e8e48
	t = 1160822883
#6  0x00002b71af620592 in execute () from /usr/lib/apache2/modules/libphp5.so
No symbol table info available.
#7  0x00002b71af61fdfc in execute () from /usr/lib/apache2/modules/libphp5.so
No symbol table info available.


So I guess apc_store blocks APC in some rare circumstances?
 [2006-10-14 09:16 UTC] bartvb at phpbb dot com 
I managed to finish running the script while Apache was stuck. I did this by doing a kernel compile in the background :D

The results are here:

http://www.bokt.nl/apc_debug/2/
coredumps and shell access are available on request.

APC stats/config is here:
http://www.bokt.nl/ apc.php
 [2006-10-15 17:08 UTC] bartvb at phpbb dot com 
I've disabled all code that uses apc_store() and that seems to have fixed my problem (not a big surprise) even with a system load higher than 10.
 [2007-01-07 14:29 UTC] bartvb at phpbb dot com 
Is there anything else that I can do? Can I test something? Try CVS? Any progress on this or an ETA?
 [2007-02-17 23:38 UTC] shire@php.net 
It would be great if you could test out the latest CVS to see if this is still occuring and let us know so we can continue to investigate.  Thanks.
 [2007-02-24 19:48 UTC] rasmus@php.net 
Please try version 3.0.13 which was just released.
 [2009-02-16 20:25 UTC] shire@php.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-2024 The PHP Group
All rights reserved. 		Last updated: Fri Apr 19 09:01:27 2024 UTC