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

Edit report at https://bugs.php.net/bug.php?id=71573&edit=1 ID: 71573 Updated by: laruence@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: but if no reproduce script(or scripts), I can not do much thing here :< Previous Comments: ------------------------------------------------------------------------ [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" ------------------------------------------------------------------------ [2016-04-01 09:53:34] mbeccati@php.net Thanks for your help. Nice investigation work. I would try next to set a gdb breakpoint after the connection is initialised, then a watchpoint to see when the connection data is overwritten. ------------------------------------------------------------------------ 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