php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #64606 php crashes when wrtiting stream
Submitted: 2013-04-07 19:41 UTC Modified: 2020-11-15 04:22 UTC
From: pbxanime at gmail dot com Assigned: cmb (profile)
Status: No Feedback Package: memcache (PECL)
PHP Version: 5.4.14 OS: Centos 5.8
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If this is not your bug, you can add a comment by following this link.
If this is your bug, but you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: pbxanime at gmail dot com
New email:
PHP Version: OS:

 

 [2013-04-07 19:41 UTC] pbxanime at gmail dot com
Description:
------------
I use the latest stable XCache and the latest stable Lighttpd.

I store sessions with memcache:

session.save_handler = memcache
session.save_path = "unix:///tmp/memcached.socket:0?persistent=1&weight=1&timeout=1&retry_interval=15"

php is compiled with the following, I removed directories, but they are correctly linked:

./configure \
--disable-fileinfo \
--disable-pdo \
--enable-exif \
--enable-fpm \
--enable-ftp \
--enable-gd-native-ttf \
--enable-libxml \
--enable-mbstring \
--enable-zip \
--prefix= \
--with-apxs2= \
--with-bz2 \
--with-curl= \
--with-freetype-dir= \
--with-gd \
--with-gettext \
--with-imap= \
--with-imap-ssl= \
--with-jpeg-dir= \
--with-png-dir= \
--with-kerberos \
--with-libxml-dir= \
--with-mcrypt= \
--with-mysql= \
--with-mysql-sock= \
--with-mysqli= \
--with-openssl= \
--with-openssl-dir= \
--with-pcre-regex= \
--with-png-dir= \
--with-xpm-dir= \
--with-zlib \
--with-zlib-dir=

Test script:
---------------
I store sessions like this:

IF (!ISSET($_SESSION)) {
SESSION_START();
}
IF($_SESSION['user_session_last_access']+180 < TIME()){
$_SESSION['user_session_last_access'] = TIME();

}

It's nothing special and it works normally.

Actual result:
--------------
I don't know how to dupicate this bug, it just happens randomly every few to several hours:

FPM Log:

[07-Apr-2013 08:35:05.926454] DEBUG: pid 25374, fpm_got_signal(), line 72: received SIGCHLD
[07-Apr-2013 08:35:05.926552] WARNING: pid 25374, fpm_children_bury(), line 252: [pool ] child 534 exited on signal 11 (SIGSEGV - core dumped) after 34.242946 seconds from start
[07-Apr-2013 08:35:05.926939] NOTICE: pid 25374, fpm_children_make(), line 421: [pool ] child 575 started
[07-Apr-2013 08:35:05.926980] DEBUG: pid 25374, fpm_event_loop(), line 411: event module triggered 1 events

Backtrace:

#0  0x08304f47 in _php_stream_write (stream=0x9556b88,
    buf=0xb77c5000 "set 0b58f7308927b881bd2d5273f0dc8de7 0 1440 38\r\nuser_session_last_access|i:1365338080;\r\n", count=88)
    at /usr/src/php-5.4.13/main/streams/streams.c:1238
1238            if (buf == NULL || count == 0 || stream->ops->write == NULL) {
(gdb) bt
#0  0x08304f47 in _php_stream_write (stream=0x9556b88,
    buf=0xb77c5000 "set 0b58f7308927b881bd2d5273f0dc8de7 0 1440 38\r\nuser_session_last_access|i:1365338080;\r\n", count=88)
    at /usr/src/php-5.4.13/main/streams/streams.c:1238
#1  0x00764506 in ?? ()
#2  0x09556b88 in ?? ()
#3  0xb77c5000 in ?? ()
#4  0x00000058 in ?? ()
#5  0xbfb79f0e in ?? ()
#6  0x00000000 in ?? ()
(gdb) frame 0
#0  0x08304f47 in _php_stream_write (stream=0x9556b88,
    buf=0xb77c5000 "set 0b58f7308927b881bd2d5273f0dc8de7 0 1440 38\r\nuser_session_last_access|i:1365338080;\r\n", count=88)
    at /usr/src/php-5.4.13/main/streams/streams.c:1238
1238            if (buf == NULL || count == 0 || stream->ops->write == NULL) {


Another Backtrace:


#0  _php_stream_write_filtered (stream=0x95564a8, buf=0x96c9100 "", count=3216473280, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,
(gdb) bt
#0  _php_stream_write_filtered (stream=0x95564a8, buf=0x96c9100 "", count=3216473280, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
#1  0x007620bb in ?? ()
#2  0x00000000 in ?? ()
(gdb) frame 0
#0  _php_stream_write_filtered (stream=0x95564a8, buf=0x96c9100 "", count=3216473280, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2013-04-08 16:10 UTC] sixd@php.net
Does it reproduce without XCache?
Do you have a standalone testcase?
 [2013-04-08 16:10 UTC] sixd@php.net
-Status: Open +Status: Feedback
 [2013-04-08 16:40 UTC] pbxanime at gmail dot com
-Status: Feedback +Status: Open
 [2013-04-08 16:40 UTC] pbxanime at gmail dot com
No, I haven't tested it with Xcache disabled. I didn't even think Xcache would be an issue since it doesn't interact with the writing of the sessions. I will disable Xcache for a few hours and see what results, I get thank you for the response.
 [2013-04-08 20:42 UTC] sixd@php.net
-Status: Open +Status: Feedback
 [2013-04-08 22:57 UTC] pbxanime at gmail dot com
-Status: Feedback +Status: Open
 [2013-04-08 22:57 UTC] pbxanime at gmail dot com
here's php -v:

PHP 5.4.13 (cli) (built: Apr  2 2013 15:57:48)
Copyright (c) 1997-2013 The PHP Group
Zend Engine v2.4.0, Copyright (c) 1998-2013 Zend Technologies


I turned off Xcache and here's results from 5 different core dumps spanning 5 hours:

#0  0x08304f47 in _php_stream_write (stream=0x90f5b08,
    buf=0xb77495bc "set 34e0f7080b10afd7af2e03e9b1536c33 0 1440 38\r\nuser_session_last_access|i:1365458365;\r\n", count=88)
    at /usr/src/php-5.4.13/main/streams/streams.c:1238
1238            if (buf == NULL || count == 0 || stream->ops->write == NULL) {


----------------------------


#0  0x04939510 in ?? ()
(gdb) bt
#0  0x04939510 in ?? ()
#1  0x08303995 in _php_stream_write_buffer (stream=0x90f5b18, buf=0x95e6958 "get 8185df46afa3fa484826ee530507445e\r\n",
    count=38) at /usr/src/php-5.4.13/main/streams/streams.c:1134
#2  0x009a00bb in ?? ()
#3  0x090f5b18 in ?? ()
#4  0x095e6958 in ?? ()
#5  0x00000026 in ?? ()
#6  0x082f5029 in spprintf (pbuf=0x95e9374, max_len=3214955994, format=0x20 <Address 0x20 out of bounds>)
    at /usr/src/php-5.4.13/main/spprintf.c:818
#7  0x009a346a in ?? ()
#8  0x095e9374 in ?? ()
#9  0xbfa055da in ?? ()
#10 0x00000020 in ?? ()
#11 0xbfa055da in ?? ()
#12 0x00000000 in ?? ()
(gdb) frame 1
#1  0x08303995 in _php_stream_write_buffer (stream=0x90f5b18, buf=0x95e6958 "get 8185df46afa3fa484826ee530507445e\r\n",
    count=38) at /usr/src/php-5.4.13/main/streams/streams.c:1134
1134                    justwrote = stream->ops->write(stream, buf, towrite TSRMLS_CC);
(gdb) frame 6
#6  0x082f5029 in spprintf (pbuf=0x95e9374, max_len=3214955994, format=0x20 <Address 0x20 out of bounds>)
    at /usr/src/php-5.4.13/main/spprintf.c:818
818             cc = vspprintf(pbuf, max_len, format, ap);

----------------------------

#0  0x08304eb3 in _php_stream_write_filtered (stream=0x90992a0, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,
(gdb) bt
#0  0x08304eb3 in _php_stream_write_filtered (stream=0x90992a0, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
#1  0x009a2506 in ?? ()
#2  0x00000000 in ?? ()
(gdb) frame 0
#0  0x08304eb3 in _php_stream_write_filtered (stream=0x90992a0, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,

----------------------------

#0  0x30320032 in ?? ()
(gdb) bt
#0  0x30320032 in ?? ()
#1  0x08304ee5 in _php_stream_write_filtered (stream=0x90f5b18, buf=<value optimized out>, count=<value optimized out>, flags=0)
    at /usr/src/php-5.4.13/main/streams/streams.c:1177
#2  0x009a00bb in ?? ()
#3  0x00000000 in ?? ()
(gdb) frame 1
#1  0x08304ee5 in _php_stream_write_filtered (stream=0x90f5b18, buf=<value optimized out>, count=<value optimized out>, flags=0)
    at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,

----------------------------

#0  0x08304eb3 in _php_stream_write_filtered (stream=0x9098890, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,
(gdb) bt
#0  0x08304eb3 in _php_stream_write_filtered (stream=0x9098890, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
#1  0x009a2506 in ?? ()
#2  0x00000000 in ?? ()
(gdb) frame 0
#0  0x08304eb3 in _php_stream_write_filtered (stream=0x9098890, buf=<value optimized out>, count=3214964224, flags=0) at /usr/src/php-5.4.13/main/streams/streams.c:1177
1177                    status = filter->fops->filter(stream, filter, brig_inp, brig_outp,
 [2013-04-11 16:57 UTC] pbxanime at gmail dot com
I don't know what other information I can supply, but if there's anything else I can provide, just tell me.
 [2013-04-14 16:23 UTC] pbxanime at gmail dot com
These same errors still occur in 5.4.14 I think I have a better clue of why this is happening. When I upgraded to 5.4.14 I ran the make test and got these results:

=====================================================================
FAILED TEST SUMMARY
---------------------------------------------------------------------
Bug #43073 (TrueType bounding box is wrong for angle<>0) freetype < 2.4.10 [ext/gd/tests/bug43073.phpt]
Bug #48801 (Problem with imagettfbbox) freetype < 2.4.10 [ext/gd/tests/bug48801.phpt]
Test posix_getgrgid() function : basic functionality [ext/posix/tests/posix_getgrgid_basic.phpt]
Bug #32330 (session_destroy, "Failed to initialize storage module", custom session handler) [ext/session/tests/bug32330.phpt]
Bug #60634 (Segmentation fault when trying to die() in SessionHandler::write()) - fatal error in close during exec [ext/session/tests/bug60634_error_5.phpt]
session rfc1867 [ext/session/tests/rfc1867.phpt]
session rfc1867 [ext/session/tests/rfc1867_cleanup.phpt]
session rfc1867 disabled [ext/session/tests/rfc1867_disabled.phpt]
session rfc1867 disabled 2 [ext/session/tests/rfc1867_disabled_2.phpt]
session rfc1867 [ext/session/tests/rfc1867_inter.phpt]
session rfc1867 no name [ext/session/tests/rfc1867_no_name.phpt]
session rfc1867 sid cookie [ext/session/tests/rfc1867_sid_cookie.phpt]
session rfc1867 sid get [ext/session/tests/rfc1867_sid_get.phpt]
session rfc1867 sid get 2 [ext/session/tests/rfc1867_sid_get_2.phpt]
session rfc1867 sid cookie [ext/session/tests/rfc1867_sid_invalid.phpt]
session rfc1867 sid only cookie [ext/session/tests/rfc1867_sid_only_cookie.phpt]
session rfc1867 sid only cookie 2 [ext/session/tests/rfc1867_sid_only_cookie_2.phpt]
session rfc1867 sid post [ext/session/tests/rfc1867_sid_post.phpt]
Test session_module_name() function : variation [ext/session/tests/session_module_name_variation3.phpt]
Test session_name() function : error functionality [ext/session/tests/session_name_basic.phpt]
Test session_name() function : variation [ext/session/tests/session_name_variation1.phpt]
Test session_save_path() function : error functionality [ext/session/tests/session_save_path_error.phpt]
Test session_save_path() function : variation [ext/session/tests/session_save_path_variation1.phpt]
Test session_set_save_handler() function : basic functionality [ext/session/tests/session_set_save_handler_basic.phpt]
Test session_set_save_handler() function : using closures as callbacks [ext/session/tests/session_set_save_handler_closures.phpt]
Test session_set_save_handler() function : error functionality [ext/session/tests/session_set_save_handler_error3.phpt]
Test session_set_save_handler() function : variation [ext/session/tests/session_set_save_handler_variation4.phpt]
Bug #44394 (Last two bytes missing from output) with session.use_trans_id [ext/standard/tests/general_functions/bug44394_2.phpt]
Test setlocale() function : usage variations - Setting all available locales in the platform [ext/standard/tests/strings/setlocale_variation2.phpt]
=====================================================================

=====================================================================
WARNED TEST SUMMARY
---------------------------------------------------------------------
Bug #52062 (large timestamps with DateTime::getTimestamp and DateTime::setTimestamp) (32 bit) [ext/date/tests/bug52062.phpt] (warn: XFAIL section but test passes)
=====================================================================
 [2013-04-14 16:23 UTC] pbxanime at gmail dot com
-PHP Version: 5.4.13 +PHP Version: 5.4.14
 [2013-04-15 04:32 UTC] laruence@php.net
what the failed diff of these session test scripts?

like the output of:

cat ext/session/tests/ext/session/tests/rfc1867.diff
 [2013-04-15 04:32 UTC] laruence@php.net
-Status: Open +Status: Feedback
 [2013-04-15 04:57 UTC] pbxanime at gmail dot com
-Status: Feedback +Status: Open
 [2013-04-15 04:57 UTC] pbxanime at gmail dot com
Well I commented out memcache as save_handler in php.ini and went back to saving sessions by files. And I haven't had php crash on me since, the output is below for the .diff file.

my problem had to do with memcache though, the php pecl version i'm running is memcache-2.2.7. It almost doesn't make sense though, because now I have 300 plus session files that only take up 15KB total space. And if that's all it was taking up in memcache, I don't know why it would cause php to crash. 

cat /usr/src/php-5.4.14/ext/session/tests/rfc1867.diff:

001+ Fatal error: Unknown: No storage module chosen - failed to initialize session in Unknown on line 0
001- string(%d) "rfc1867-tests"
002- bool(true)
003- array(2) {
004-   [%u|b%"file1"]=>
005-   array(5) {
006-     [%u|b%"name"]=>
007-     %string|unicode%(9) "file1.txt"
008-     [%u|b%"type"]=>
009-     %string|unicode%(0) ""
010-     [%u|b%"tmp_name"]=>
011-     %string|unicode%(%d) "%s"
012-     [%u|b%"error"]=>
013-     int(0)
014-     [%u|b%"size"]=>
015-     int(1)
016-   }
017-   [%u|b%"file2"]=>
018-   array(5) {
019-     [%u|b%"name"]=>
020-     %string|unicode%(9) "file2.txt"
021-     [%u|b%"type"]=>
022-     %string|unicode%(0) ""
023-     [%u|b%"tmp_name"]=>
024-     %string|unicode%(%d) "%s"
025-     [%u|b%"error"]=>
026-     int(0)
027-     [%u|b%"size"]=>
028-     int(1)
029-   }
030- }
031- array(5) {
032-   [%u|b%"start_time"]=>
033-   int(%d)
034-   [%u|b%"content_length"]=>
035-   int(%d)
036-   [%u|b%"bytes_processed"]=>
037-   int(%d)
038-   [%u|b%"done"]=>
039-   bool(true)
040-   [%u|b%"files"]=>
041-   array(2) {
042-     [0]=>
043-     array(7) {
044-       [%u|b%"field_name"]=>
045-       %unicode|string%(5) "file1"
046-       [%u|b%"name"]=>
047-       %unicode|string%(9) "file1.txt"
048-       [%u|b%"tmp_name"]=>
049-       %unicode|string%(%d) "%s"
050-       [%u|b%"error"]=>
051-       int(0)
052-       [%u|b%"done"]=>
053-       bool(true)
054-       [%u|b%"start_time"]=>
055-       int(%d)
056-       [%u|b%"bytes_processed"]=>
057-       int(1)
058-     }
059-     [1]=>
060-     array(7) {
061-       [%u|b%"field_name"]=>
062-       %unicode|string%(5) "file2"
063-       [%u|b%"name"]=>
064-       %unicode|string%(9) "file2.txt"
065-       [%u|b%"tmp_name"]=>
066-       %unicode|string%(%d) "%s"
067-       [%u|b%"error"]=>
068-       int(0)
069-       [%u|b%"done"]=>
070-       bool(true)
071-       [%u|b%"start_time"]=>
072-       int(%d)
073-       [%u|b%"bytes_processed"]=>
074-       int(1)
075-     }
076-   }
077- }
 [2013-04-15 05:26 UTC] pajoye@php.net
Please try using latest memcache release (3.0.8)
 [2013-04-15 05:26 UTC] pajoye@php.net
-Status: Open +Status: Feedback -Package: Streams related +Package: memcache
 [2013-04-15 05:31 UTC] pbxanime at gmail dot com
-Status: Feedback +Status: Open
 [2013-04-15 05:31 UTC] pbxanime at gmail dot com
Okay I'll try it out, only reason I never upgraded was because it was beta and didn't know if it had bugs that the stable wouldn't have.
 [2013-04-15 05:51 UTC] laruence@php.net
then I think it relates to memcache ..

change to pecl memcache related issue
 [2013-04-15 06:04 UTC] pbxanime at gmail dot com
This is way too early to say but I upgraded to version (3.0.8) of memcache and my actual site seems to be loading faster. I also changed the php.ini save handler back to memcache. I'm going to sleep soon, but when I wake up, I'll check for any errors that may have happened. Hopefully none will happen, I'm very glad I made this bug report. It's made me a slightly better troubleshooter, of course with everyone's suggestions.
 [2013-04-15 13:55 UTC] pbxanime at gmail dot com
Okay when I switched back to save handler "memcache" I received some more php crashes and something brand new in my error log. It seems something changed "&" to "&amp;" for a short time, because it's written like this in php.ini:

session.save_path = "unix:///tmp/memcached.socket:0?persistent=1&weight=1&timeout=1&retry_interval=15"

maybe those extra options are not supported through unix socket. Since the error I received was as follows:

[15-Apr-2013 06:15:13 America/New_York] PHP Warning:  Unknown: Failed to write session data (memcache). Please verify that the current setting of session.save_path is correct (unix:///tmp/memcached.socket:0?persistent=1&amp;weight=1&amp;timeout=1&amp;retry_interval=15) in Unknown on line 0

[15-Apr-2013 06:15:14 America/New_York] PHP Warning:  Unknown: Failed to write session data (memcache). Please verify that the current setting of session.save_path is correct (unix:///tmp/memcached.socket:0?persistent=1&amp;weight=1&amp;timeout=1&amp;retry_interval=15) in Unknown on line 0

which only showed up twice.

Also all the core dumps are simpler now, they all look like this:

Program terminated with signal 11, Segmentation fault.
#0  0x04f1a249 in ?? ()
------------------------------------------------------------------ 
Program terminated with signal 11, Segmentation fault.
#0  0x04f1a249 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04f1a1ea in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04e32fb0 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04e32f69 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04f1a249 in ?? ()
(gdb) frame 0
#0  0x04f1a249 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x00000089 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04f1a249 in ?? ()
------------------------------------------------------------------
Program terminated with signal 11, Segmentation fault.
#0  0x04e32f69 in ?? ()
 [2020-11-06 17:46 UTC] cmb@php.net
-Status: Open +Status: Feedback -Assigned To: +Assigned To: cmb
 [2020-11-06 17:46 UTC] cmb@php.net
Is that still an issue with the latest memcache version?
 [2020-11-15 04:22 UTC] pecl-dev 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 "Re-Opened". Thank you.
 
PHP Copyright © 2001-2020 The PHP Group
All rights reserved.
Last updated: Wed Dec 02 13:01:23 2020 UTC