XCache Segfault: error 4 in xcache.so

[foxpa.ws]

Hello,

A few days ago during a high volume period I encountered this issue:

11:29:48 [kernel] apache2[17395]: segfault at 332e352e ip b5ba90f7 sp a4b4cb70 error 4 in xcache.so[b5b96000+1d000]
11:34:22 [kernel] apache2[16754]: segfault at 4320526d ip b5ba4297 sp aab5ad60 error 4 in xcache.so[b5b96000+1d000]
11:34:45 [kernel] apache2[27959]: segfault at 43205445 ip b5ba90f7 sp aab58b70 error 4 in xcache.so[b5b96000+1d000]
11:45:34 [kernel] apache2[15215]: segfault at 2 ip b5ba90f7 sp a534db70 error 4 in xcache.so[b5b96000+1d000]
11:45:55 [kernel] apache2[15536]: segfault at 362e3335 ip b5ba90f7 sp ac35bb70 error 4 in xcache.so[b5b96000+1d000]

This seemed to take out the apache process it was running under so that it remained live but refused new connections.

In this particular environment I am taking advantage of both xcache's opcode cache and shared variable datastore.

I have been running XCache on other high-volume servers for about a month with opcode caching only and have yet to see any problems.

I'm running PHP 5.3.14-pl0-gentoo (hardened) with XCache 1.3.2

Any insight would be greatly appreciated!

Thanks

[xcache]

A PHP 5.3 bug No.62432 ReflectionMethod random corrupt memory on high
concurrent was fixed that cause PHP itself unstable, bogus reported as
XCache bug. It is false positive to reproduce with XCache
loaded/enabled only, just because XCache make PHP run faster than
with/without other opcode cacher. PHP up to 5.3.14 is affected. It is
highly suggested to upgrade to newer PHP
https://bugs.php.net/bug.php?id=62432

so, upgrade to 5.4 if applicable. upgarde to
http://xcache.lighttpd.net/wiki/Release-2.0.1 if you still have
problem with PHP 5.4 + XCache 1.3.2

[foxpa.ws]

Ah ha! Thank you so much!

[Per Hansson]

Hi, I have this problem aswell.
For me it actually appeared when upgrading from PHP v5.3.13 > 5.3.15
I'm using the latest stable version of Xcache v2.0.1 and Nginx v1.2.2

It seems others are seeing this problem too, I have not found a
solution.
I can just see it on my "live" website, not my testserver.
And I don't know how to reproduce the error either, I'm just seeing it
in the logfiles...

This first one appears at normal runtime, also documented here:
http://forum.nginx.org/read.php?3,228753

[23-Jul-2012 11:10:05] WARNING: [pool www] child 30174 exited on
signal 11 (SIGSEGV - core dumped) after 239.854771 seconds from start
[23-Jul-2012 15:24:26] WARNING: [pool www] child 11404 exited on
signal 11 (SIGSEGV - core dumped) after 152.180564 seconds from start
[23-Jul-2012 20:37:14] WARNING: [pool www] child 24299 exited on
signal 11 (SIGSEGV - core dumped) after 1114.054198 seconds from start
[23-Jul-2012 21:41:45] WARNING: [pool www] child 27170 exited on
signal 11 (SIGSEGV - core dumped) after 966.564990 seconds from start

Jul 23 11:10:04 techspot04 kernel: php-fpm[30174]: segfault at
7fffbef2e001 ip 00000000006355ec sp 00007fffbef28430 error 6 in php-
fpm[400000+2db000]
Jul 23 11:10:05 techspot04 abrt[30338]: Saved core dump of pid 30174 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-23-11:10:04-30174
(295804928 bytes)
Jul 23 11:10:05 techspot04 abrtd: Directory
'ccpp-2012-07-23-11:10:04-30174' creation detected
Jul 23 11:10:06 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 23 11:10:06 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-23-11:10:04-30174' exited with 1
Jul 23 11:10:06 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-23-11:10:04-30174, deleting


Jul 23 15:24:25 techspot04 kernel: php-fpm[11404]: segfault at 1000721
ip 00000000005b8ce7 sp 00007fffbef29fe0 error 4 in php-
fpm[400000+2db000]
Jul 23 15:24:26 techspot04 abrt[11529]: Saved core dump of pid 11404 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-23-15:24:25-11404
(295292928 bytes)
Jul 23 15:24:26 techspot04 abrtd: Directory
'ccpp-2012-07-23-15:24:25-11404' creation detected
Jul 23 15:24:26 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 23 15:24:26 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-23-15:24:25-11404' exited with 1
Jul 23 15:24:26 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-23-15:24:25-11404, deleting


Jul 23 20:37:14 techspot04 kernel: php-fpm[24299]: segfault at 1000721
ip 00000000005b8ce7 sp 00007fffbef29fe0 error 4 in php-
fpm[400000+2db000]
Jul 23 20:37:14 techspot04 abrt[25090]: Saved core dump of pid 24299 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-23-20:37:14-24299
(295616512 bytes)
Jul 23 20:37:14 techspot04 abrtd: Directory
'ccpp-2012-07-23-20:37:14-24299' creation detected
Jul 23 20:37:15 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 23 20:37:15 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-23-20:37:14-24299' exited with 1
Jul 23 20:37:15 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-23-20:37:14-24299, deleting


Jul 23 21:41:45 techspot04 kernel: php-fpm[27170]: segfault at
7fffbef2e001 ip 00000000006355ec sp 00007fffbef28430 error 6 in php-
fpm[400000+2db000]
Jul 23 21:41:45 techspot04 abrtd: Directory
'ccpp-2012-07-23-21:41:45-27170' creation detected
Jul 23 21:41:45 techspot04 abrt[27799]: Saved core dump of pid 27170 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-23-21:41:45-27170
(295632896 bytes)
Jul 23 21:41:46 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 23 21:41:46 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-23-21:41:45-27170' exited with 1
Jul 23 21:41:46 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-23-21:41:45-27170, deleting



This second one only occurs when stopping and starting php-fpm, also
documented here: http://forum.nginx.org/read.php?3,228578

Jul 22 03:16:07 techspot04 kernel: php-fpm[29733]: segfault at 1000721
ip 00000000005b8ce7 sp 00007fffeb375770 error 4 in php-fpm (deleted)
[400000+2db000]
Jul 22 03:16:07 techspot04 abrt[6402]: File '/usr/sbin/php-fpm' seems
to be deleted
Jul 22 03:16:08 techspot04 abrt[6402]: Saved core dump of pid 29733 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-22-03:16:07-29733
(295350272 bytes)
Jul 22 03:16:08 techspot04 abrtd: Directory
'ccpp-2012-07-22-03:16:07-29733' creation detected
Jul 22 03:16:08 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 22 03:16:08 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-22-03:16:07-29733' exited with 1
Jul 22 03:16:08 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-22-03:16:07-29733, deleting
Jul 22 03:17:28 techspot04 kernel: php[10376]: segfault at 66edee ip
00007f5c2992cd67 sp 00007ffff50f8c18 error 7 in
xcache.so[7f5c29915000+1f000]
Jul 22 03:17:28 techspot04 abrt[6476]: File '/usr/bin/php' seems to be
deleted
Jul 22 03:17:28 techspot04 abrt[6476]: Saved core dump of pid 10376 (/
usr/bin/php) to /var/spool/abrt/ccpp-2012-07-22-03:17:28-10376
(37822464 bytes)
Jul 22 03:17:28 techspot04 abrtd: Directory
'ccpp-2012-07-22-03:17:28-10376' creation detected
Jul 22 03:17:28 techspot04 abrtd: Package 'php-cli' isn't signed with
proper key
Jul 22 03:17:28 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-22-03:17:28-10376' exited with 1
Jul 22 03:17:28 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-22-03:17:28-10376, deleting
Jul 22 03:17:32 techspot04 kernel: php-fpm[6489]: segfault at
7f90f15f1598 ip 0000003bfc00eb83 sp 00007fff5882a1e0 error 4 in
ld-2.12.so[3bfc000000+20000]
Jul 22 03:17:32 techspot04 abrt[6497]: Saved core dump of pid 6489 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-22-03:17:32-6489
(15032320 bytes)
Jul 22 03:17:32 techspot04 abrtd: Directory
'ccpp-2012-07-22-03:17:32-6489' creation detected
Jul 22 03:17:32 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 22 03:17:32 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-22-03:17:32-6489' exited with 1
Jul 22 03:17:32 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-22-03:17:32-6489, deleting


And no, it does NOT seem to be caused by Xcache!

Regards,
Per Hansson

On 22 Juli, 19:48, xcache <phpxca...@gmail.com> wrote:
> A  PHP 5.3 bug No.62432 ReflectionMethod random corrupt memory on high
> concurrent was fixed that cause PHP itself unstable, bogus reported as
> XCache bug. It is false positive to reproduce with XCache
> loaded/enabled only, just because XCache make PHP run faster than
> with/without other opcode cacher. PHP up to 5.3.14 is affected. It is

> highly suggested to upgrade to newer PHPhttps://bugs.php.net/bug.php?id=62432
>
> so, upgrade to 5.4 if applicable. upgarde tohttp://xcache.lighttpd.net/wiki/Release-2.0.1if you still have

[foxpa.ws]

It seems that due to the high concurrency requirement the problem stems from a race condition which means your test server will likely never exhibit the problem unless you simulate the same (or higher) level of load your production server comes under.

Just to confirm, you are seeing this only NOW that you are running 5.3.15? Have you restarted FPM to make sure the new version of PHP is live?

Thanks

[xcache]

> And no, it does NOT seem to be caused by Xcache!

sure? reproduced without XCache loaded?

[Per Hansson]

foxpa: Yes, only now after installing PHP v5.3.15
As for your question I have even done a full server reboot after the
upgrade to enable the latest kernel for RHEL6 aswell :)

xcache: Sorry for the long delay, yes I did reproduce it once without
xcache loaded, that is this error:
[root@xeon ~]# service php-fpm restart
Stopping php-fpm: [ OK ]
Starting php-fpm: /bin/bash: line 1: 2210 Segmentation fault
(core dumped) php-fpm
[FAILED]

But I realize this must have been a false positive, I removed xcache
from my testserver and was unable to reproduce it again,
But as soon as I re-enabled it php-fpm failed to do a "restart"

As for the other error, the problem with the php-fpm children exiting
on signal 11 I have not yet tried to disable Xcache on our live
website to see if it disappears.
But we have had another problem for a long time (before the upgrade to
PHP v5.3.15) and that does not go away by disabling Xcache...
Those errors look like this, it's an exit on signal 7 instead, but it
seems to be related to only a specific area of our site and could be
due to old PHP code...

[24-Jul-2012 18:09:49] WARNING: [pool www] child 30660 exited on
signal 7 (SIGBUS - core dumped) after 181.389477 seconds from start

Regards,
Per Hansson

[xcache]

> [root@xeon ~]# service php-fpm restart
> Stopping php-fpm: [ OK ]
> Starting php-fpm: /bin/bash: line 1: 2210 Segmentation fault
> (core dumped) php-fpm
> [FAILED]
>
> But I realize this must have been a false positive, I removed xcache
> from my testserver and was unable to reproduce it again,
> But as soon as I re-enabled it php-fpm failed to do a "restart"

PHP 5.3.15 (fpm-fcgi) (built: Jul 25 2012 21:15:29) (DEBUG)
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2012 Zend Technologies
with XCache v2.0.1, Copyright (c) 2005-2012, by mOo
./php-fpm -c devel.ini -y devel.fpm
[25-Jul-2012 21:24:42] NOTICE: fpm is running, pid 15810
[25-Jul-2012 21:24:42] NOTICE: ready to handle connections
[25-Jul-2012 21:24:54] NOTICE: Terminating ...
[25-Jul-2012 21:24:54] NOTICE: exiting, bye-bye!

what zend_extension do you load? maybe they conflict with each other

try php-fpm -c php-with-xcache.ini -v
try php-fpm -c php-with-xcache.ini -i

[Per Hansson]

Hi, I'm using this version of Zend:
[root@xeon ~]# php-fpm -v
PHP 5.3.15 (fpm-fcgi) (built: Jul 20 2012 12:52:37)

Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2012 Zend Technologies
with XCache v2.0.1, Copyright (c) 2005-2012, by mOo

Zend Extension => 220090626
Zend Extension Build => API220090626,NTS
Zend Memory Manager => enabled
Zend Multibyte Support => disabled

Regards,
Per Hansson

[xcache]

> [root@xeon ~]# php-fpm -v
> PHP 5.3.15 (fpm-fcgi) (built: Jul 20 2012 12:52:37)
> Copyright (c) 1997-2009 The PHP Group
> Zend Engine v2.3.0, Copyright (c) 1998-2012 Zend Technologies
> with XCache v2.0.1, Copyright (c) 2005-2012, by mOo
>
> Zend Extension => 220090626
> Zend Extension Build => API220090626,NTS
> Zend Memory Manager => enabled
> Zend Multibyte Support => disabled

now you can start it without core dump. how strange

i wonder what arguments does the init script pass to php-fpm, you
should start it exactly the same arguments
see http://xcache.lighttpd.net/wiki/HowToReportABug/GenerateBacktrace
btw, it seems a core file was generated there already when it is
started by service init script

[Per Hansson]

Hi xcache,
The problem with php-fpm segfaulting when restarting can be avoided.
If I do a "service php-fpm stop"
Then I wait 30 seconds
And then "service php-fpm start"
It works fine, but it is strange because the INIT script in /etc/rc.d/
init.d/php-fpm has not changed from version 5.3.13 > 5.3.15

As for the "error 4" as seen in the /var/log/messages logfile or
"child exited on signal 11 (SIGSEGV - core dumped)" in the /var/log/
php-fpm/error.log file
Have you been able to resolve this foxpa?
I still get it but not as frequently any more.
I still also get the other problem that I had on v5.3.13 aswell:
"child exited on signal 7 (SIGBUS - core dumped)"
Xcache: the core dump file is never generated for php-fpm, it is
always corrupt, see this output:

Jul 25 09:49:35 techspot04 kernel: php-fpm[8316]: segfault at 1000721

ip 00000000005b8ce7 sp 00007fffbef29fe0 error 4 in php-
fpm[400000+2db000]

Jul 25 09:49:36 techspot04 abrt[8339]: Saved core dump of pid 8316 (/
usr/sbin/php-fpm) to /var/spool/abrt/ccpp-2012-07-25-09:49:35-8316
(298528768 bytes)
Jul 25 09:49:36 techspot04 abrtd: Directory
'ccpp-2012-07-25-09:49:35-8316' creation detected
Jul 25 09:49:36 techspot04 abrtd: Package 'php-fpm' isn't signed with
proper key
Jul 25 09:49:36 techspot04 abrtd: 'post-create' on '/var/spool/abrt/
ccpp-2012-07-25-09:49:35-8316' exited with 1
Jul 25 09:49:36 techspot04 abrtd: Corrupted or bad directory /var/
spool/abrt/ccpp-2012-07-25-09:49:35-8316, deleting

Regards,
Per Hansson

On 26 Juli, 04:17, xcache <phpxca...@gmail.com> wrote:
> > [root@xeon ~]# php-fpm -v
> > PHP 5.3.15 (fpm-fcgi) (built: Jul 20 2012 12:52:37)
> > Copyright (c) 1997-2009 The PHP Group
> > Zend Engine v2.3.0, Copyright (c) 1998-2012 Zend Technologies
> >     with XCache v2.0.1, Copyright (c) 2005-2012, by mOo
>
> > Zend Extension => 220090626
> > Zend Extension Build => API220090626,NTS
> > Zend Memory Manager => enabled
> > Zend Multibyte Support => disabled
>
> now you can start it without core dump. how strange
>
> i wonder what arguments does the init script pass to php-fpm, you
> should start it exactly the same arguments

> seehttp://xcache.lighttpd.net/wiki/HowToReportABug/GenerateBacktrace

[foxpa.ws]

I haven't encountered it yet but I have been scrambling to get things sea-worthy for a deadline. Since you've been having trouble with 5.3.15 I took this as a cue to bump all the way up to 5.4.5 and will probably be running without XCache for a couple days because my situation is unfortunately do-or-die. I have just installed nginx and rebuilt PHP with FPM because I think apache might be the culprit for some of my bigger problems so on the bright side (I hope!) I will very shortly have an environment which is similar to yours.

[xcache]

On Thu, Jul 26, 2012 at 5:50 PM, Per Hansson <han...@gmail.com> wrote:
> Hi xcache,
> The problem with php-fpm segfaulting when restarting can be avoided.

pardon? i don't quite get you. you mean quick restart = segv,
stop/wait/start=ok, right?

> If I do a "service php-fpm stop"
> Then I wait 30 seconds
> And then "service php-fpm start"
> It works fine, but it is strange because the INIT script in /etc/rc.d/
> init.d/php-fpm has not changed from version 5.3.13 > 5.3.15

it's taking longer than expected without getting a solution on this
problem, or find the reason at least
in which way do you think to make me reproduce this issue? php.ini?
the init script? php-fpm.conf?
send me in private anything you think necessary to reproduce, or send
me the ssh access (ssh-host/ssh-port/root-password)

[Per Hansson]

foxpa: upgrading to PHP 5.4 is something I will probably do myself
soon aswell.
Because I got a message from another site owner some months ago that
it fixed this problem for him:

"child exited on signal 7 (SIGBUS - core dumped)"

The reason I'm holding out with 5.3 is that it actually works quite
well even with the errors it produces.
And I don't want to introduce more problems by upgrading to a new
version of PHP with even more deprecated old functions...
(The problem with "signal 7" specifically only occurs on an old part
of our site...)

Regards,
Per Hansson

[Per Hansson]

Hi, I tried to send you a private message, perhaps you did not get it?
If so try sending me one with the IP you will be connecting from so I
can allow it in my testservers firewall for SSH access...

Regards,
Per Hansson

[xcache]

i did reply to you in private, maybe it's you didn't get me? check spam box