Bug #71573 [Com]: Segfault (core dumped)

Edit report at https://bugs.php.net/bug.php?id=71573&edit=1 ID: 71573 Comment by: mfischer@php.net Reported by: johan at x-tnd dot be Summary: Segfault (core dumped) Status: Assigned Type: Bug Package: PDO PgSQL Operating System: Linux CentoOS 7 PHP Version: 7.0.3 Assigned To: laruence Block user comment: N Private report: N New Comment: I'm adding this here too due the similarity of the stacktrace with printfPQExpBuffer I'm getting; however in my case it's on Ubuntu with opcache, specifically opcache.fast_shutdown=1 will reproducible lead to a crash using CakePHP 2.8.3. Unfortunately I'm not able to create a small reproducible script. I originally repoted this at https://github.com/oerdnj/deb.sury.org/issues/322 . Program received signal SIGSEGV, Segmentation fault. resetPQExpBuffer (str=str@entry=0x7fb575b5fe10) at /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/pqexpbuffer.c:152 152 /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/pqexpbuffer.c: No such file or directory. (gdb) bt #0 resetPQExpBuffer (str=str@entry=0x7fb575b5fe10) at /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/pqexpbuffer.c:152 #1 0x00007fb568e99cf7 in PQsendQueryStart (conn=conn@entry=0x7fb575b5fab8) at /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/fe-exec.c:1352 #2 0x00007fb568e9b6cb in PQsendQuery (conn=conn@entry=0x7fb575b5fab8, query=query@entry=0x7fb575ba2550 "DEALLOCATE pdo_stmt_00000007") at /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/fe-exec.c:1115 #3 0x00007fb568e9cd21 in PQexec (conn=0x7fb575b5fab8, query=0x7fb575ba2550 "DEALLOCATE pdo_stmt_00000007") at /build/postgresql-9.5-DVsMQj/postgresql-9.5-9.5.2/build/../src/interfaces/libpq/fe-exec.c:1829 #4 0x00007fb5690c0733 in pgsql_stmt_dtor (stmt=0x7fb55dc72380) at /build/php7.0-kNWWO9/php7.0-7.0.5/ext/pdo_pgsql/pgsql_statement.c:64 #5 0x00007fb574f39d6a in php_pdo_free_statement (stmt=0x7fb55dc72380) at /build/php7.0-kNWWO9/php7.0-7.0.5/ext/pdo/pdo_stmt.c:2316 #6 0x00007fb57845b941 in zend_objects_store_del (object=0x7fb55dc724d0) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_objects_API.c:182 #7 0x00007fb578421926 in _zval_dtor_func_for_ptr (p=<optimized out>) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_variables.c:109 #8 0x00007fb578421959 in i_zval_ptr_dtor (zval_ptr=0x7fb575a98920) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_variables.h:58 #9 _zval_dtor_func_for_ptr (p=0x7fb575a98918) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_variables.c:122 #10 0x00007fb578457014 in i_zval_ptr_dtor (zval_ptr=0x7fb575a60928) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_variables.h:58 #11 zend_object_std_dtor (object=0x7fb575a60800) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_objects.c:69 #12 0x00007fb57845b5a0 in zend_objects_store_free_object_storage (objects=0x7fb575b5fe10, objects@entry=0x7fb578804530 <executor_globals+816>) at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_objects_API.c:103 #13 0x00007fb578414913 in shutdown_executor () at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend_execute_API.c:357 #14 0x00007fb5784231c5 in zend_deactivate () at /build/php7.0-kNWWO9/php7.0-7.0.5/Zend/zend.c:967 #15 0x00007fb5783c5ee1 in php_request_shutdown (dummy=<optimized out>) at /build/php7.0-kNWWO9/php7.0-7.0.5/main/main.c:1826 #16 0x00007fb5782b89c6 in main (argc=<optimized out>, argv=<optimized out>) at /build/php7.0-kNWWO9/php7.0-7.0.5/sapi/fpm/fpm/fpm_main.c:1996 Previous Comments: ------------------------------------------------------------------------ [2016-04-10 02:28:36] laruence@php.net but if no reproduce script(or scripts), I can not do much thing here :< ------------------------------------------------------------------------ [2016-04-09 18:46:54] mbeccati@php.net Apparently GC-related (see last comments), so I can't do much about it myself. I hope Xinchen can pick it up. ------------------------------------------------------------------------ [2016-04-01 14:53:03] phofstetter at sensational dot ch ok. One more update, but that's probably obvious from looking at the callstack: The application in question is keeping cached PDO statement objects around to reuse them when possible. When I disable that cache, so don't keep an array of cached handles around, then the crash goes away. so the application checks whether $cached_handles[md5($query)] exists and if so, it just reuses that handle (the thing is a bit more complicated in that it keeps only up to a certain amount of handles around and only if the query has actual arguments, but that's not relevant here). Interestingly enough, this works fine in a small test script and only fails on that specific request. There are cases where the cache is cleaned using $cached_handles = array(); but there's never an explicit freeing of these handles going on (unless there are more than 50 of them and another one needs to be created). I can make the problem go away if I manually clean these handles out by calling closeCursor and nulling them in the destructor of the class that owns both the cache and the PDO handle. Still - PHP probably shouldn't be segfaulting if it hits code that's relying on PHP to clean up after itself. Also, I still can't provide a reduced testcase. All attempts at filling the cache with just the right amount of statements in an easier setup were not successful. ------------------------------------------------------------------------ [2016-04-01 12:37:47] mbeccati@php.net That's incredibly helpful, thanks. We'll look into it. ------------------------------------------------------------------------ [2016-04-01 12:28:06] phofstetter at sensational dot ch update: By doing a bit of printf-debugging, I can confirm that this crash happens because a statement destructor runs after the connection destructor has run. I have added logging to pdo_pgsql_handle_factory when connecting, to pgsql_stmt_dtor just before the call to PQexec that causes the crash and then once more at the beginning of pgsql_handle_closer Here's a trace: The connection is created with a pdo_pgsql_db_handle of b061d498, then there's a lot of statement destructors being called on the same handle. Then, pgsql_handle_closer is invoked, closing the connection with PQfinish and then, finally, one more statement destructor is running, causing the crash. I have now also disabled opcache in order to make sure this isn't the problem. Also, after so many valgrind errors from OpenSSL, I decided to not do the crypto stuff - the trace is still the same. And, on even better news: I can make this request not crash depending on the input data, so I might soon have a reduced repro (or a fix - who knows). I'd say: it's getting warmer [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "Connect host=db1 dbname=****** user=**** connect_timeout=30. H=b061d498" [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:09] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "pgsql_handle_closer dbh=b79f8f00, handle=b061d498" [01-Apr-2016 14:16:10] WARNING: [pool www] child 2782 said into stderr: "stmt_dtor: deallocate H=b061d498" ------------------------------------------------------------------------ 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=71573 -- Edit this bug report at https://bugs.php.net/bug.php?id=71573&edit=1