php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #53333 Random crash
Submitted: 2010-11-18 01:26 UTC Modified: 2013-02-18 00:34 UTC
Votes:2
Avg. Score:5.0 ± 0.0
Reproduced:2 of 2 (100.0%)
Same Version:2 (100.0%)
Same OS:2 (100.0%)
From: pajoye@php.net Assigned: mysql (profile)
Status: No Feedback Package: MySQLi related
PHP Version: 5.3.5 OS: Windows
Private report: No CVE-ID: None
View Add Comment Developer Edit
Anyone can comment on a bug. Have a simpler test case? Does it work for you on a different platform? Let us know!
Just going to say 'Me too!'? Don't clutter the database with that please — but make sure to vote on the bug!
Your email address:
MUST BE VALID
Solve the problem:
23 + 22 = ?
Subscribe to this entry?

 
 [2010-11-18 01:26 UTC] pajoye@php.net
Description:
------------
See the backtrace here http://pastie.org/1307118

The crash is hard to reproduce but happens regularly in our tests (using mediawiki, wordpress or other apps).

Does it ring a bell to one of you (mysql devs :)?

It could also be a GC bug. I can send the memory dump if one of you like to do a post morterm debugging.


Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2010-11-20 13:45 UTC] pajoye@php.net
Can reproduce the crash with 5.3.4RC1 as well. It happens while switching apps (new DB connection with different credential). Updated bt:

php5ts!_zend_mm_free_int+0x57 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_alloc.c @ 2018]
php5ts!_efree+0x2e [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_alloc.c @ 2351]
php5ts!zend_hash_destroy+0x27 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_hash.c @ 529]
php5ts!zend_object_std_dtor+0x2b [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_objects.c @ 46]
php_mysqli!mysqli_result_free_storage+0x3f [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\ext\mysqli\mysqli.c @ 270]
php5ts!zend_objects_store_del_ref_by_handle_ex+0x1c1 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_objects_api.c @ 220]
php5ts!zend_objects_store_del_ref+0x1a [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_objects_api.c @ 173]
php5ts!_zval_dtor_func+0x7f [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_variables.c @ 60]
php5ts!_zval_ptr_dtor+0x56 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_execute_api.c @ 443]
php5ts!zend_leave_helper_SPEC+0x6c [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 160]
php5ts!ZEND_RETURN_SPEC_TMP_HANDLER+0xa3 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 4970]
php5ts!execute+0x2e8 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 107]
php5ts!zend_call_function+0x8c9 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_execute_api.c @ 964]
php5ts!zif_call_user_func_array+0x63 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\ext\standard\basic_functions.c @ 4796]
php5ts!zend_do_fcall_common_helper_SPEC+0x920 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 316]
php5ts!ZEND_DO_FCALL_SPEC_CONST_HANDLER+0x11a [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 1606]
php5ts!execute+0x2e8 [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend_vm_execute.h @ 107]
php5ts!zend_execute_scripts+0xfe [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\zend\zend.c @ 1195]
php5ts!php_execute_script+0x24c [d:\php-sdk\snap_5_3\vc9\x86\php-5.3.4rc1\main\main.c @ 2265]
 [2010-11-28 19:06 UTC] felipe@php.net
-Status: Open +Status: Assigned -Assigned To: +Assigned To: mysql
 [2010-11-29 14:09 UTC] uw@php.net
-Status: Assigned +Status: Feedback
 [2010-11-29 14:09 UTC] uw@php.net
Pierre,

of course, we'd love to see an isolated phpt test case. As you state, it is not necessarily a mysqli issue but may have some other cause.

I agree that Andrey should look at the back trace.

Can this reproduced with 5.3.4? If so, please check if you can give us a mysqlnd debug log. It is going to be *very* long. As a first step, please provide us with no more than the last 1000 lines from that log. 1000 lines is a a bit of a random pick to limit the expected long debug log.

In 5.3.4 mysqlnd learned to write proper debug logs on Windows. Try running PHP with mysqlnd.debug="d:t:O,C:\mysqlnd_debug.log". You need 5.3.4. 5.3.3 won't do it.

Andrey, 

can you have a look at the backtrace?

Thanks,
Ulf
 [2010-11-29 14:11 UTC] pajoye@php.net
As I said it is not possible yet to get an isolated case. I would have done it already if yes.

However, anyone able to do a post mortem analysis could see where and maybe why the crash occurs. memory dumb available if you have such developer (or someone willing to try, not too hard :).
 [2010-11-29 14:12 UTC] pajoye@php.net
Yes, it happens as well with current SVN (5.3.4RC1 too).
 [2010-11-30 12:24 UTC] uw@php.net
Hi Pierre,

can you provide a mysqlnd debug log, do you have access to the php.ini?

In 5.3.4 mysqlnd learned to write proper debug logs on Windows. Try running PHP with mysqlnd.debug="d:t:O,C:\mysqlnd_debug.log". You need 5.3.4. 5.3.3 won't do it.

Thanks,
Ulf
 [2010-11-30 12:26 UTC] pajoye@php.net
I will ask to enable it and run again the tests. Thanks :)
 [2010-12-01 10:39 UTC] kriscraig@php.net
Hi Ulf,

I've been running the tests for Pierre and am also the one who first discovered this bug.  He asked me to connect with you here because I've been unable to get the debug directive you mentioned to output.

Specifically, I'm running the PHP 5.3.4RC1 ZTS Pierre released, VC9 compile, on Apache 2.2 under one of our Windows 2008 R2 hosts with Windbg attached to the process.  In php.ini, I added the following line to the MYSQLND section:

mysqlnd.debug="d:t:O,C:\temp\mysqlnd_debug.log"


The setting does show up in PHPInfo().  Specifically:

mysqlnd
mysqlnd	enabled
Version 	mysqlnd 5.0.7-dev - 091210 - $Revision: 304625 $
Compression 	supported
SSL 	not supported
Command buffer size 	4096
Read buffer size 	32768
Read timeout 	31536000
Collecting statistics 	Yes
Collecting memory statistics 	Yes
Tracing 	d:t:O,C:\temp\mysqlnd_debug.log


However, the mysqlnd_debug.log file is never created.  I'm not sure under what conditions it's supposed to output, but in this test I was hitting both MediaWiki and WordPress until the crash occured, and at no point was the file created.  The directory has full perms (including write) granted to all users.  I could theoretically use procmon to see if it's attempting to write the file, but since we're dealing with a bug that takes about an hour to repro, that wouldn't be my first choice.

Have you had a chance yet to test this new debug feature?  Do you know if there are any other settings/etc that need to be enabled in order for this to work?  Please let me know and I'll give it another go.


Thanks!

--Kris
 [2010-12-01 10:49 UTC] kriscraig@php.net
Oh and also, could you tell me when this debug is supposed to output the file?  I.e. does it output debug info whenever MySQL is invoked, or only when there's a crash?
 [2010-12-01 11:18 UTC] andrey@php.net
Hi,
I recently fixed the argument parser for the debug log for Windows, because ":" is a separator in the string. Also only since few weeks the trace log is available on Windows. You need a pretty fresh build sources. Also you need a _debug_ build, because the trace functionality is not compiled in in release builds. And please try using / instead of \, if that helps.
 [2010-12-01 14:06 UTC] pajoye@php.net
Wondering if it could be useful to have the logs in non debug builds as well, what do you think?
 [2010-12-01 14:10 UTC] andrey@php.net
Pierre, I'm a fan of this, but it can, and will probably, hit the run-time performance. But I can't tell without a benchmark. Unfortunately Ulf has some other things to do at the moment. It is easy to change that, just edit mysqlnd.h and find MYSQLND_DBG_ENABLED and set it to 1 in all cases.
 [2010-12-01 14:13 UTC] pajoye@php.net
Right, but only for the ini setting tests, as it should not be enabled by default :)
 [2010-12-01 23:25 UTC] kriscraig@php.net
Alrighty, I'll try using forward slashes and will post the outcome when it's done.  The bug typically takes anywhere from 1 hour up to around 4 hours to repro under stress, so stand by for now.  =)
 [2010-12-02 08:45 UTC] kriscraig@php.net
Unfortunately, still no go with the forward slashes.  Has this new debug feature actually been tested yet, or perhaps it needs to be enabled in the source then rebuilt?  I'm fresh out of ideas.  :/
 [2010-12-02 11:26 UTC] pajoye@php.net
You need a debug build to get it working.
 [2011-01-22 04:28 UTC] kriscraig@php.net
Sorry for not keeping these comments up-to-date.  I've had my head buried triaging this for the last two months now.

Anyway, there's a few things to cover.  First, I was able to get your mysqlnd debug to work.  However, because you have it outputting the debug to a file on each and every PHP run, this filesystem stress is creating a major bottleneck, bringing PHP's perf understress down from around 50 tps (transactions per second) to about 1 or 2 tps.  As a result, I am unable to repro this crash with this enabled as you specified in your comment.

I would recommend that you perhaps find a way to store this data as an object or whatever and only output to a file in the event of a crash or other error.

In any case, I spent some time backtracing this and I believe what we're dealing with is a classic double-free and/or corruption.  I have no explanation as to what's causing the corruption to begin with though.

I also investigated whether or not this is a threading issue.  Contrary to what common sense would suggest, this does not appear to be the case, either.  I ran the stress test again on Apache with the -X option (Debug mode), which forces httpd.exe to run as a single process.  The crash still occured.  No relevant change in the repro.

I have also confirmed that this bug is still present in the latest release of 5.3.5.


Finally, given the difficulty in reproducing this bug, not to mention the general difficulty in tracking down memory corruption issues in ANSI C in general, I'm now trying a bandaid approach.  I added an ifcheck to _zend_mm_free_int in zend_alloc.c at the spot of the top of the crash stack, forcing it to skip the free attempt if the variable in question (next_block) is NULL.  I then added some exception handling (using setjmp.h) code to mysqli_result_free_storage in mysqli.c at a spot earlier in the stack, forcing it to throw a PHP warning error (which is set to output to a log file) if there's an exception.  I've never tried this in ANSI C before but I think I've got it right.

The test is running now and may take awhile to yield a result.  I will post a patch early next week.  If successful, this won't fix whatever the underlying cause of the corruption is, but it will at least throw an error and spare us a crash, which will allow me to start generating PHP perf results under stress conditions along with the standard perf data.


I'll post again when I have the results of this latest test run.
 [2011-01-22 04:31 UTC] kriscraig@php.net
I believe it would also be helpful to allow the mysqlnd debug setting to be used on a non-debug PHP build as well.
 [2011-01-24 20:00 UTC] kriscraig@php.net
-Operating System: * +Operating System: Windows -PHP Version: 5.3.3 +PHP Version: 5.3.5
 [2011-01-26 12:41 UTC] pajoye@php.net
On a shorter note, do you really have nobody able to deal with a dump?

That's really the way to go with such bug and we spent already a fair amount of 
time to get all the possible details. The next step should really be a mysql 
developer sitting down and analyze the dump to see the condition where it 
happens.

Please note that this bug is not really random as it happens on a regular basis, 
I got a couple of users reporting it as well. Is there anything else that you 
need to begin to work on it? Except a small reproduce script, can't produce one 
at this stage.
 [2011-01-28 14:55 UTC] pajoye@php.net
ok, can you please at least say if there is someone in your team able to deal with 
a dump? We can try to work together to solve it.

This bug is preventing us to run daily automated QA tests. It is a stopping and is 
also filling our bugs databases from many users.
 [2013-02-18 00:34 UTC] php-bugs 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 "Open". Thank you.
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Apr 25 20:01:45 2024 UTC