Bug #68486 [Opn]: PHP SegFault zend_hash_find

Edit report at https://bugs.php.net/bug.php?id=68486&edit=1 ID: 68486 Updated by: ab@php.net Reported by: wattwood at tcstire dot com Summary: PHP SegFault zend_hash_find Status: Open Type: Bug Package: Apache2 related Operating System: Ubuntu 14.04.1 LTS PHP Version: 5.5.19 Block user comment: N Private report: N New Comment: Patrick, somehow the latest patch is broken, it won't apply to any of 5.5 through master. Also, is there any piece of code to be used for the tests? Thanks. Previous Comments: ------------------------------------------------------------------------ [2015-03-15 10:17:28] php at bof dot de Reworked the patch another round, see updated gist: https://gist.github.com/bof/15173c7a11cb12a7b96f The pool cleanup logic is reworked, with the goal of never cleaning up the SG(server_context) of something other than the currently running + not yet complete request - regardless of when and how delayed a pool cleanup callback comes in. This I do by 1) adding a ctx->server_context pointer to the context structure, 2) registering ctx instead of &SG(server_context) with the pool cleanup callback, and finally 3) in php_server_context_cleanup() I check that *ctx->server_context == ctx, and only in that case I NULL it. I also rearranged the php_handler() config handling a bit, so that the xbithack-during-reentry case should now be correct, too; and there's some all-around cleanup. The debug output of the previous patch is gone (available on request). I tested this patch, lightly, with my testcases and our normal codebase, under both Apache 2.4.12, the openSUSE 13.1 Apache 2.4.6, and an older Apache 2.2 setup as I use it in normal production so far. No issues were found, the new logic seems to work the same everywhere. I also ran the apache 2.4.12 variant under valgrind, also without any issues flagged. THIS STILL NEEDS REVIEW from somebody who previously worked on the apache2handler code. But I think it's solid enough now, and I'll probably test it in production on monday ------------------------------------------------------------------------ [2015-03-14 10:34:07] php at bof dot de Here's a gist with a patch, against 5.6.7RC1, that appears to fix the issue for me, at least for the things I tested. https://gist.github.com/bof/15173c7a11cb12a7b96f (patch contains lots of extra debug output, none of the ap_log_error calls I added would be good for merging) I basically rip out the whole parent_req handling attempts in php_handler(), and make ctx->request_processed be the only indicator regarding reentrancy to the interpreter. In case such a reentrancy is attempted, I error out early in php_handler() before any manipulation to interpreter state is done. The PHP virtual() function (provided in php_functions.c) will now cleanly fail when used to "embed" another PHP script (the worst reentrancy), but it continues to work when embedding an URI handled by any other handler (the not_for_us case). While testing I had a final issue with the ap_rflush() call in virtual() resulting in pool destruction of the in-flight request, due to the apache 2.4 EOR thing gmoniker mentioned in the previous comment. If anybody is curious, drop me an email, I've got the backtrace saved. For now I have disabled that ap_rflush() call in virtual(), and I don't know what could break by that. Anyway, after some light testing with this gist's patch applied, my own codebase keeps working normally, and the double-echo test now works without crashes for any of these cases: - two normal PHP requests in a row - two PHP requests in a row, each using virtual to embed another PHP script (embedded script NOT run, PHP warning message in virtual() caller) - two PHP requests in a row, using virtual to embed a non-PHP thing (/robots.txt tested...) - works as it should. ------------------------------------------------------------------------ [2015-03-13 18:59:54] gmoniker at gmail dot com Bug hunting: I am trying to reopen this bug at the Apache httpd bugzilla: https://bz.apache.org/bugzilla/show_bug.cgi?id=56984 Thanks to the mention of php_server_context_cleanup() by *php at bof dot de* I decided to look at the source code of the php sapi module and the Apache/APR code which causes it to be called. The PHP sapi module uses the pool register/cleanup philosophy enabled by the APR module of Apache (@see http://www.apachetutor.org/dev/pools) and stores its SG(server_context) in the request pool, depending on it to be cleaned up at the end of the request, before the Apache worker feeds it a new request. In Apache 2.2 the code in modules/http/http_core.c is fairly straightforward: static int ap_process_http_connection(conn_rec *c) [...] while ((r = ap_read_request(c)) != NULL) { [...] if (r->status == HTTP_OK) ap_process_request(r); if (ap_extended_status) ap_increment_counts(c->sbh, r); if (c->keepalive != AP_CONN_KEEPALIVE || c->aborted) break; ap_update_child_status(c->sbh, SERVER_BUSY_KEEPALIVE, r); apr_pool_destroy(r->pool); [...] } So before handling the next request the pool is destroyed and ergo the php_server_context_cleanup() gets called because it is registered to the pools cleanup list. In Apache 2.4 things have been rewritten quite extensively and in a way that is completely breaking the primary functionality of the APR pools, in that they should provide an easy declarative cleanup where a client registers a cleanup and can count on the server to execute it at the moment the server sees the pool should be destroyed. Apache 2.4.7 code (and 2.4.12):: static int ap_process_http_sync_connection(conn_rec *c) [...] while ((r = ap_read_request(c)) != NULL) { c->keepalive = AP_CONN_UNKNOWN; /* process the request if it was read without error */ ap_update_child_status(c->sbh, SERVER_BUSY_WRITE, r); if (r->status == HTTP_OK) { if (cs) cs->state = CONN_STATE_HANDLER; ap_process_request(r); /* After the call to ap_process_request, the * request pool will have been deleted. We set * r=NULL here to ensure that any dereference * of r that might be added later in this function * will result in a segfault immediately instead * of nondeterministic failures later. */ r = NULL; } [...] } So, there clearly is no pool cleanup anymore in this place. But surely, you say, it has just been moved to a place deeper in the stack? Following the ap_process_request, ap_process_async_request chain, however crushes this hope slowly but surely. There is still an attempt to let the pool be cleaned up after the request. After the handler (for example PHP) had its go at the request, the method ap_process_request_after_handler(r) is called. (it's in modules/http/http_request.c) The after_handler routine creates an EOR bucket and puts it in the output of the request connection. This bucket registers a eor_bucket_cleanup function to the request pool pre_cleanup list that would instruct the destruction of the request pool. However this routine can only be called by apr_pool_clear of apr_pool_destroy and the problem is exactly that as long as the connection with requests or responses doesn't end, then those methods are not called for this pool or a parent pool that might exist, at least not anywhere in the prefork worker that I could see. So it seems that in Apache 2.4 at present the request pool has become a connection pool after all. Apparently the problem is well masked by PHP opcaching, which has practically become the default. When the script gets cached it apparently doesn't matter that the server_context is reused (because it doesn't have to use the Zend_cache?). And also in many cases there might be multiple requests on one pipeline but just one of them would be a php script. This could be a major problem for the PHP5 sapi module on current Apache 2.4 servers. ------------------------------------------------------------------------ [2015-03-13 17:48:33] php at bof dot de For completeness, here's a gist with the patch against PHP 5.6.7RC1 that I created the second trace output in the previous comment with: https://gist.github.com/anonymous/449a2726c876d187165b In addition to the added logging, it contains the "1 ||" change at the start of php_handler() which makes the issue go away for me in the normal, non-subrequest cases. ------------------------------------------------------------------------ [2015-03-13 14:50:56] php at bof dot de To make sure the issue is not with the somewhat old Apache 2.4.6 of openSUSE 13.1, I have now compiled a fresh Apache 2.4.12 (current release), and the problem still persists. I also added some trace logging to the apache2handler code. Using the already described two-request echo|netcat test, I see this with a segfaulting request: [Fri Mar 13 15:31:13.034800 2015] [:error] [pid 22003] php_handler(ctx=0, ctx->r=0, r=3f425b0) request_processed=-1 [Fri Mar 13 15:31:13.034818 2015] [:error] [pid 22003] php_handler(NEW ctx=3f47b80, ctx->r=3f425b0, r=3f425b0) [Fri Mar 13 15:31:13.034841 2015] [:error] [pid 22003] php_apache_request_ctor(SG(server_context)=3f47b80, ctx=3f47b80, ctx->r=3f425b0, r=3f425b0) [Fri Mar 13 15:31:13.037026 2015] [:error] [pid 22003] php_apache_request_dtor(ctx=3f47b80, ctx->r=3f425b0, r=3f425b0) [Fri Mar 13 15:31:13.045265 2015] [:error] [pid 22003] php_handler(ctx=3f47b80, ctx->r=3f425b0, r=3f54b00) request_processed=1 [Fri Mar 13 15:31:13.045372 2015] [:error] [pid 22003] php_handler(OLD ctx=3f47b80, parent_req=3f425b0, r=3f54b00) [Fri Mar 13 15:31:13.045407 2015] [:error] [pid 22003] php_handler(ctx=3f47b80, parent_req=3f425b0, r=3f54b00) PROCESSING SUBREQUEST Compare this to the following trace, done with the patch I sent in [2015-03-10 09:22 UTC] applied: [Fri Mar 13 15:44:26.381174 2015] [:error] [pid 19155] php_handler(ctx=0, ctx->r=0, r=4f7fb30) request_processed=-1 [Fri Mar 13 15:44:26.381197 2015] [:error] [pid 19155] php_handler(NEW ctx=4f830f0, ctx->r=4f7fb30, r=4f7fb30) [Fri Mar 13 15:44:26.381218 2015] [:error] [pid 19155] php_apache_request_ctor(SG(server_context)=4f830f0, ctx=4f830f0, ctx->r=4f7fb30, r=4f7fb30) [Fri Mar 13 15:44:26.383660 2015] [:error] [pid 19155] php_apache_request_dtor(ctx=4f830f0, ctx->r=4f7fb30, r=4f7fb30) [Fri Mar 13 15:44:26.391144 2015] [:error] [pid 19155] php_handler(ctx=4f830f0, ctx->r=4f7fb30, r=4f69300) request_processed=1 [Fri Mar 13 15:44:26.391192 2015] [:error] [pid 19155] php_handler(NEW ctx=4f8c3b0, ctx->r=4f69300, r=4f69300) [Fri Mar 13 15:44:26.391222 2015] [:error] [pid 19155] php_apache_request_ctor(SG(server_context)=4f8c3b0, ctx=4f8c3b0, ctx->r=4f69300, r=4f69300) [Fri Mar 13 15:44:26.392970 2015] [:error] [pid 19155] php_apache_request_dtor(ctx=4f8c3b0, ctx->r=4f69300, r=4f69300) [Fri Mar 13 15:44:26.398950 2015] [:error] [pid 19155] php_server_context_cleanup(4f8c3b0) [Fri Mar 13 15:44:26.399008 2015] [:error] [pid 19155] php_server_context_cleanup(0) So it is clear that apache 2.4 delays the call to the pool cleanup function, php_server_context_cleanup. Now, how to solve this... I would just rip out all the attempts to handle a parent_req with interpreter reentrancy. This will make the virtual() function fail when both parent and subrequest go to the PHP handler, but some testing even on apache 2.2 suggested to me that that is broken anyway, resulting in crashes sometimes. However, the comments / core about POST errors and 413 and so on, makes me nervous, because I have no idea how that would be related, affected, or triggered. Some testing with post requests, also overly long ones, did not show me reentrancy, but the code must have had some reason in the past. HELP! ------------------------------------------------------------------------ The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at https://bugs.php.net/bug.php?id=68486 -- Edit this bug report at https://bugs.php.net/bug.php?id=68486&edit=1