#47712 [Com]: Weird behavior under high load
ID: 47712
Comment by: ninzya at inbox dot lv
Reported By: ninzya at inbox dot lv
Status: Open
Bug Type: Scripting Engine problem
Operating System: Windows XP
PHP Version: 5.3.0beta1
New Comment:
In most cases this bug is being hit when working with mysql, and only
during high concurrency. When there is no concurrency, or concurrency is
not big enough, bug does not trigger. Also i forgot to mention that PHP
is installed as a module.
Downloaded QA's PHP 5.3.0RC1 and tested it with both php_mysql and
php_mysqli extensions, bug is still present.
The page that is being executed during stress test contains 14 SQL
queries, 11 of them are SELECT queries. In most cases the 5th to 7th
SELECT queries are failing to return proper data using
mysql_fetch_assoc(). When the bug triggers, the values of returned array
(usually first on first two keys in the array) are being replaced with
irrelevant to SELECT result data, contents of those values are either
NULL or data that was stored in DB, but used to appear in previous SQL
queries. In the example above you can clearly see that the value of key
'id' in array $row is 'SHARED', but shared is the value of another field
in another SQL query i used to execute. Probably, mysqlnd is somehow
sharing memory between requests, and somehow memory of another request
being processed concurrently is being passed to current request. Another
assumption may be that the mysqlnd somehow bypasses update of currently
used cached zval.
Anyway, if this is mysqlnd related, still don't know how to explain
warning with empty constant mentioned in previous report.
Previous Comments:
[2009-03-24 18:49:53] kak dot serpom dot po dot yaitsam at gmail dot
com
I guess the trouble is in MySQL Native Driver (mysqlnd). No?
[2009-03-21 22:45:24] ninzya at inbox dot lv
Tested under PHP 5.2.9-1, the problem does not exist with that version
of PHP.
[2009-03-20 12:34:59] ninzya at inbox dot lv
And here is the screenshot of the output of MySql query browser after
executing SQL query i mentioned above:
http://www.stepanov.lv/pub/mysql.jpg
[2009-03-20 12:28:51] ninzya at inbox dot lv
I got a little bit closer to the problem. Here's what happens. See this
script:
// load page
$sql ='SELECT id, ' .implode( ', ', $properties) .'
FROM ' .TAB_PREF .'pages
WHERE node_id =' .$Db-escape( $nodeId, 'UINT').'
AND alt_name =' .$Db-escape( $pageAlt, 'STRING') .'
LIMIT 0, 1;';
if(( $row =$Db-queryFirst( $sql)) ===null)
throw new Exception( 'NOT_FOUND');
if( $row['id'] ===null) {// THIS IS WHERE YOU SHOULD LOOK AT
trigger_error( 'Got NULL!', E_USER_WARNING);
trigger_error( 'SQL: ' .$sql, E_USER_WARNING);
ob_start();
var_dump( $row);
trigger_error( ob_get_clean(), E_USER_WARNING);
die();
}
As you can see, i am testing if $row['id'] is null (this is unexpected
situation when this field becomes null, it's an auto column and at this
step i expect successfully fetched row), and if it is NULL, then i wish
to see the debug info for the contents of $row and overall what's going
on.
Now here is the error log when this unexpected situation is being
RANDOMLY triggered during stress test:
[20-Mar-2009 14:20:37] PHP Warning: Got NULL! in D:\...\pages.php on
line 93
[20-Mar-2009 14:20:37] PHP Warning: SQL: SELECT id, `title`,
`keywords`, `descr`, `template_id`
FROM pages
WHERE node_id =11
AND alt_name ='welcome'
LIMIT 0, 1; in D:\...\pages.php on line 94
[20-Mar-2009 14:20:37] PHP Warning: array(5) {
[id]=
string(6) SHARED
[title]=
string(12) My test page
[keywords]=
string(6) asdasd
[descr]=
string(6) asdasd
[template_id]=
string(4) 8567
}
in D:\...\pages.php on line 97
I don't know how to explain this. I guess this is mysqlnd failing this
bad.
[2009-03-20 12:12:15] ninzya at inbox dot lv
Every mentioned error/warning occurs randomly. It is not possible to
trigger these warnings (especially first) during each request, something
related to memory fails i think, or stack is being corrupted or
something.
I was investigating this problem for past day and i found this. Take a
look at the following script:
?php
function throw_exc() {
throw new Exception('TEST_EXCEPTION');
}
class Test {
public function __construct() {
echo 'Constr' .\n;
}
public function __destruct() {
echo 'Destr' .\n;
}
}
try {
$T =new Test( throw_exc());
} catch( Exception $e) {
echo 'Exception: ' .$e-getMessage();
}
?
Execution of this script
#47712 [Com]: Weird behavior under high load
ID: 47712
Comment by: kak dot serpom dot po dot yaitsam at gmail dot com
Reported By: ninzya at inbox dot lv
Status: Open
Bug Type: Scripting Engine problem
Operating System: Windows XP
PHP Version: 5.3.0beta1
New Comment:
Try to test this under PHP 5.3 with libmysql driver (not mysqlnd).
Previous Comments:
[2009-03-25 07:28:35] ninzya at inbox dot lv
In most cases this bug is being hit when working with mysql, and only
during high concurrency. When there is no concurrency, or concurrency is
not big enough, bug does not trigger. Also i forgot to mention that PHP
is installed as a module.
Downloaded QA's PHP 5.3.0RC1 and tested it with both php_mysql and
php_mysqli extensions, bug is still present.
The page that is being executed during stress test contains 14 SQL
queries, 11 of them are SELECT queries. In most cases the 5th to 7th
SELECT queries are failing to return proper data using
mysql_fetch_assoc(). When the bug triggers, the values of returned array
(usually first on first two keys in the array) are being replaced with
irrelevant to SELECT result data, contents of those values are either
NULL or data that was stored in DB, but used to appear in previous SQL
queries. In the example above you can clearly see that the value of key
'id' in array $row is 'SHARED', but shared is the value of another field
in another SQL query i used to execute. Probably, mysqlnd is somehow
sharing memory between requests, and somehow memory of another request
being processed concurrently is being passed to current request. Another
assumption may be that the mysqlnd somehow bypasses update of currently
used cached zval.
Anyway, if this is mysqlnd related, still don't know how to explain
warning with empty constant mentioned in previous report.
[2009-03-24 18:49:53] kak dot serpom dot po dot yaitsam at gmail dot
com
I guess the trouble is in MySQL Native Driver (mysqlnd). No?
[2009-03-21 22:45:24] ninzya at inbox dot lv
Tested under PHP 5.2.9-1, the problem does not exist with that version
of PHP.
[2009-03-20 12:34:59] ninzya at inbox dot lv
And here is the screenshot of the output of MySql query browser after
executing SQL query i mentioned above:
http://www.stepanov.lv/pub/mysql.jpg
[2009-03-20 12:28:51] ninzya at inbox dot lv
I got a little bit closer to the problem. Here's what happens. See this
script:
// load page
$sql ='SELECT id, ' .implode( ', ', $properties) .'
FROM ' .TAB_PREF .'pages
WHERE node_id =' .$Db-escape( $nodeId, 'UINT').'
AND alt_name =' .$Db-escape( $pageAlt, 'STRING') .'
LIMIT 0, 1;';
if(( $row =$Db-queryFirst( $sql)) ===null)
throw new Exception( 'NOT_FOUND');
if( $row['id'] ===null) {// THIS IS WHERE YOU SHOULD LOOK AT
trigger_error( 'Got NULL!', E_USER_WARNING);
trigger_error( 'SQL: ' .$sql, E_USER_WARNING);
ob_start();
var_dump( $row);
trigger_error( ob_get_clean(), E_USER_WARNING);
die();
}
As you can see, i am testing if $row['id'] is null (this is unexpected
situation when this field becomes null, it's an auto column and at this
step i expect successfully fetched row), and if it is NULL, then i wish
to see the debug info for the contents of $row and overall what's going
on.
Now here is the error log when this unexpected situation is being
RANDOMLY triggered during stress test:
[20-Mar-2009 14:20:37] PHP Warning: Got NULL! in D:\...\pages.php on
line 93
[20-Mar-2009 14:20:37] PHP Warning: SQL: SELECT id, `title`,
`keywords`, `descr`, `template_id`
FROM pages
WHERE node_id =11
AND alt_name ='welcome'
LIMIT 0, 1; in D:\...\pages.php on line 94
[20-Mar-2009 14:20:37] PHP Warning: array(5) {
[id]=
string(6) SHARED
[title]=
string(12) My test page
[keywords]=
string(6) asdasd
[descr]=
string(6) asdasd
[template_id]=
string(4) 8567
}
in D:\...\pages.php on line 97
I don't know how to explain this. I guess this is mysqlnd failing this
bad.
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
http://bugs.php.net/47712
--
Edit this bug report at http://bugs.php.net/?id=47712edit=1
#47712 [Com]: Weird behavior under high load
ID: 47712 Comment by: ninzya at inbox dot lv Reported By: ninzya at inbox dot lv Status: Open Bug Type: Scripting Engine problem Operating System: Windows XP PHP Version: 5.3.0beta1 New Comment: I guess i can not switch between libmysql and mysqlnd in PHP 5.3. I have no tools to compile PHP myself with the proper library. If you know where i can find PHP 5.3RC1 with libmysql, i would test it out right away. Previous Comments: [2009-03-25 12:19:04] kak dot serpom dot po dot yaitsam at gmail dot com Try to test this under PHP 5.3 with libmysql driver (not mysqlnd). [2009-03-25 07:28:35] ninzya at inbox dot lv In most cases this bug is being hit when working with mysql, and only during high concurrency. When there is no concurrency, or concurrency is not big enough, bug does not trigger. Also i forgot to mention that PHP is installed as a module. Downloaded QA's PHP 5.3.0RC1 and tested it with both php_mysql and php_mysqli extensions, bug is still present. The page that is being executed during stress test contains 14 SQL queries, 11 of them are SELECT queries. In most cases the 5th to 7th SELECT queries are failing to return proper data using mysql_fetch_assoc(). When the bug triggers, the values of returned array (usually first on first two keys in the array) are being replaced with irrelevant to SELECT result data, contents of those values are either NULL or data that was stored in DB, but used to appear in previous SQL queries. In the example above you can clearly see that the value of key 'id' in array $row is 'SHARED', but shared is the value of another field in another SQL query i used to execute. Probably, mysqlnd is somehow sharing memory between requests, and somehow memory of another request being processed concurrently is being passed to current request. Another assumption may be that the mysqlnd somehow bypasses update of currently used cached zval. Anyway, if this is mysqlnd related, still don't know how to explain warning with empty constant mentioned in previous report. [2009-03-24 18:49:53] kak dot serpom dot po dot yaitsam at gmail dot com I guess the trouble is in MySQL Native Driver (mysqlnd). No? [2009-03-21 22:45:24] ninzya at inbox dot lv Tested under PHP 5.2.9-1, the problem does not exist with that version of PHP. [2009-03-20 12:34:59] ninzya at inbox dot lv And here is the screenshot of the output of MySql query browser after executing SQL query i mentioned above: http://www.stepanov.lv/pub/mysql.jpg 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 http://bugs.php.net/47712 -- Edit this bug report at http://bugs.php.net/?id=47712edit=1
#47712 [Com]: Weird behavior under high load
ID: 47712
Comment by: kak dot serpom dot po dot yaitsam at gmail dot com
Reported By: ninzya at inbox dot lv
Status: Open
Bug Type: Scripting Engine problem
Operating System: Windows XP
PHP Version: 5.3.0beta1
New Comment:
I guess the trouble is in MySQL Native Driver (mysqlnd). No?
Previous Comments:
[2009-03-21 22:45:24] ninzya at inbox dot lv
Tested under PHP 5.2.9-1, the problem does not exist with that version
of PHP.
[2009-03-20 12:34:59] ninzya at inbox dot lv
And here is the screenshot of the output of MySql query browser after
executing SQL query i mentioned above:
http://www.stepanov.lv/pub/mysql.jpg
[2009-03-20 12:28:51] ninzya at inbox dot lv
I got a little bit closer to the problem. Here's what happens. See this
script:
// load page
$sql ='SELECT id, ' .implode( ', ', $properties) .'
FROM ' .TAB_PREF .'pages
WHERE node_id =' .$Db-escape( $nodeId, 'UINT').'
AND alt_name =' .$Db-escape( $pageAlt, 'STRING') .'
LIMIT 0, 1;';
if(( $row =$Db-queryFirst( $sql)) ===null)
throw new Exception( 'NOT_FOUND');
if( $row['id'] ===null) {// THIS IS WHERE YOU SHOULD LOOK AT
trigger_error( 'Got NULL!', E_USER_WARNING);
trigger_error( 'SQL: ' .$sql, E_USER_WARNING);
ob_start();
var_dump( $row);
trigger_error( ob_get_clean(), E_USER_WARNING);
die();
}
As you can see, i am testing if $row['id'] is null (this is unexpected
situation when this field becomes null, it's an auto column and at this
step i expect successfully fetched row), and if it is NULL, then i wish
to see the debug info for the contents of $row and overall what's going
on.
Now here is the error log when this unexpected situation is being
RANDOMLY triggered during stress test:
[20-Mar-2009 14:20:37] PHP Warning: Got NULL! in D:\...\pages.php on
line 93
[20-Mar-2009 14:20:37] PHP Warning: SQL: SELECT id, `title`,
`keywords`, `descr`, `template_id`
FROM pages
WHERE node_id =11
AND alt_name ='welcome'
LIMIT 0, 1; in D:\...\pages.php on line 94
[20-Mar-2009 14:20:37] PHP Warning: array(5) {
[id]=
string(6) SHARED
[title]=
string(12) My test page
[keywords]=
string(6) asdasd
[descr]=
string(6) asdasd
[template_id]=
string(4) 8567
}
in D:\...\pages.php on line 97
I don't know how to explain this. I guess this is mysqlnd failing this
bad.
[2009-03-20 12:12:15] ninzya at inbox dot lv
Every mentioned error/warning occurs randomly. It is not possible to
trigger these warnings (especially first) during each request, something
related to memory fails i think, or stack is being corrupted or
something.
I was investigating this problem for past day and i found this. Take a
look at the following script:
?php
function throw_exc() {
throw new Exception('TEST_EXCEPTION');
}
class Test {
public function __construct() {
echo 'Constr' .\n;
}
public function __destruct() {
echo 'Destr' .\n;
}
}
try {
$T =new Test( throw_exc());
} catch( Exception $e) {
echo 'Exception: ' .$e-getMessage();
}
?
Execution of this script produces:
Destr
Exception: TEST_EXCEPTION
Where it should produce only this part:
Exception: TEST_EXCEPTION
As you can see, destructor is being called, where it shouldn't be. I
will make a temporary work around for this situation and investigate
further, because i guess this is not the problem that has caused first
warning/error message i mentioned above.
[2009-03-19 00:30:38] scott...@php.net
Thank you for this bug report. To properly diagnose the problem, we
need a short but complete example script to be able to reproduce
this bug ourselves.
A proper reproducing script starts with ?php and ends with ?,
is max. 10-20 lines long and does not require any external
resources such as databases, etc. If the script requires a
database to demonstrate the issue, please make sure it creates
all necessary tables, stored procedures etc.
Please avoid embedding huge scripts into the report.
We need an actual reproduce script we can use, I took your small script
and ran it under 5.3.0 without issue.
I'm guessing our errors probably all stem from the same issue, if step
1 or 3 happen then 2 and 4 would be expected due to a lack of database
connection.
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
http://bugs.php.net/47712
--
Edit this bug report at
