ID:               47712
 User updated by:  ninzya at inbox dot lv
-Summary:          Weird behavior under high load
 Reported By:      ninzya at inbox dot lv
 Status:           Open
 Bug Type:         MySQL related
 Operating System: Windows XP
-PHP Version:      5.3.0beta1
+PHP Version:      5.3.0RC1
 New Comment:

Changed bug summary.

My configuration:
  Apache 2.2,
  PHP 5.3.0RC1 as module,
  Windows XP SP3,
  MySQL community server 5.1.33

Bug being hit during high concurrency running apache benchmark: "ab -c
30 -n 10000". See previous posts for details.


Previous Comments:
------------------------------------------------------------------------

[2009-04-12 15:08:30] ninzya at inbox dot lv

Please excuse me for the delay. I have been figuring out what's the
cause of this bug and finally i have something to come up with.

The problem is in mysql_free_result function. Not in itself, but it's
behavior has changed. Consider the following example from the PHP manual
on mysql_free_result:

Example #1 A mysql_free_result() example
<?php
$result = mysql_query("SELECT id,email FROM people WHERE id = '42'");
if (!$result) {
    echo 'Could not run query: ' . mysql_error();
    exit;
}
/* Use the result, assuming we're done with it afterwards */
$row = mysql_fetch_assoc($result);

/* Now we free up the result and continue on with our script */
mysql_free_result($result);

echo $row['id'];
echo $row['email'];
?>

This code with PHP 5.3.0 with mysqlnd will now fail under high
concurrency, because mysql_free_result will affect $row variable and
allow another threads to use it's zval to store data. I suspect that
mysql_free_result marks the referenced by $row data as 'free' and
another threads pick that zval up and work with it. As soon as you
release result, another thread may corrupt $row variable. Test this
example under high concurrency and you will get different values for
$row['id'] and $row['email']. Run 10000 req. test and some of them will
fail to produce correct output.

In my framework i use mysql_free_result before referencing last fetched
row of result set very often, that's why i hit this bug 'randomly'.

I have another example i just tested, this is part of my framework. The
idea is the same - mysql_free_result is being called before actually
using fetched data array.

  $con =mysql_pconnect( 'localhost', 'root', '');
  mysql_select_db( 'ewe10');
  $q =mysql_query( $sql ='SELECT id, title, keywords, descr,
template_id, `title`, `keywords`, `descr`, `template_id`
            FROM pages
          WHERE node_id =11
            AND alt_name =\'welcome\'
          LIMIT 0, 1;', $con);
  $row =mysql_fetch_assoc( $q);
  mysql_free_result( $q);
  
  if( $row['id'] ===null || $row['template_id'] !=8567 || $row['title']
!='My test page' || $row['keywords'] !='asdasd' || $row['descr']
!='asdasd') {
    trigger_error( 'FAIL!', E_USER_WARNING);
    trigger_error( 'SQL: ' .$sql, E_USER_WARNING);
    ob_start();
    var_dump( $row);
    trigger_error( ob_get_clean(), E_USER_WARNING);
    die('NOT OK');
  }

  die('OK');

SQL for the table:

CREATE TABLE  `ewe10`.`pages` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT COMMENT 'unique page
id',
  `node_id` int(10) unsigned NOT NULL COMMENT 'node id in which this
page is',
  `title` varchar(128) CHARACTER SET utf8 COLLATE utf8_bin NOT NULL
COMMENT 'page title',
  `keywords` varchar(128) CHARACTER SET utf8 COLLATE utf8_bin NOT NULL
COMMENT 'page keywords',
  `descr` text CHARACTER SET utf8 COLLATE utf8_bin NOT NULL COMMENT
'page description',
  `template_id` int(10) unsigned DEFAULT NULL COMMENT 'template this
page is using (if NULL, template was deleted from database and this page
is stored as a backup)',
  `type` enum('MAIN','PAGE') CHARACTER SET latin1 NOT NULL DEFAULT
'PAGE' COMMENT 'page type',
  `alt_name` varchar(45) CHARACTER SET latin1 NOT NULL COMMENT 'page
alternative name',
  `date_add` datetime NOT NULL COMMENT 'when page was added',
  PRIMARY KEY (`id`),
  UNIQUE KEY `NODE_ID_ALT_NAME` (`node_id`,`alt_name`) USING BTREE,
  KEY `FK_pages_templates` (`template_id`),
  KEY `TYPE` (`type`),
  KEY `FK_pages_map` (`node_id`),
  KEY `DATE_ADD` (`date_add`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=FIXED;

the only row in this table is shown on the screenshot i referenced in
previous report.

To address the issue more quickly, i would like to give you a hint -
after calling mysql_free_result there is no possibility to fetch any
more rows, so there's nothing to worry about mysql_fetch_*(), but there
is possibility that the last fetched row may be referenced. This means -
even if mysql_free_result was called, last fetched row must remain
locked in mysqlnd internal zval cache until the variable is
implicitly/explicitly unset.

------------------------------------------------------------------------

[2009-04-07 13:21:59] johan...@php.net

Can you give me some more details about your system and the
configuration, please.

I spent some time with load testing different configurations now using
mysqlnd, pconnects, and PHP's thread-safe mode and wasn't able to
reproduce this issue.

Maybe even try to come up with the shortest script possible showing the
issue ...

------------------------------------------------------------------------

[2009-03-25 12:24:45] ninzya at inbox dot lv

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.

------------------------------------------------------------------------

[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.

------------------------------------------------------------------------

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=47712&edit=1

Reply via email to