Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MySQLi statement execute ArgumentCountError ("number of parameters") #875

Closed
iaibai opened this issue Apr 10, 2024 · 13 comments · Fixed by #881
Closed

MySQLi statement execute ArgumentCountError ("number of parameters") #875

iaibai opened this issue Apr 10, 2024 · 13 comments · Fixed by #881
Labels
bug Something isn't working
Milestone

Comments

@iaibai
Copy link

iaibai commented Apr 10, 2024

Since upgrading to PHP 8.2, we've been getting frequent "ArgumentCountError: The number of variables must match the number of parameters in the prepared statement" errors when executing mysqli prepared statements. Although there are some really strange circumstances around this error, we can recreate it.

We are binding the correct number of variables using bind_param, but for some reason as you'll see from the stack trace the Error is thrown by execute().

This is preventing us upgrading to PHP 8.2.

Description

This Error is thrown regularly on certain statements (about a dozen) in our codebase, and as you'll see from the recreation steps there are quite a few factors that seem to affect whether a statement will error.

A full stack trace of the error looks like the following:

Fatal error: Uncaught ArgumentCountError: The number of variables must match the number of parameters in the prepared statement in /test.php:29
Stack trace:
#0 [internal function]: mysqli_stmt->bind_param('s', '2017-04-10 00:0...')
#1 /test.php(29): mysqli_stmt->execute()
#2 {main}
  thrown in /test.php on line 29

We first experienced this on Amazon Linux 2023 PHP 8.2 (installed newrelic using the tar archive), but we have recreated this on Amazon Linux 2 PHP 8.1 (installing through rpm), and locally in a docker instance based on php:8.1-cli (again using tar).

We have recreated the Error on 10.16.0.5, 10.19.0.9, and 10.10.0.1.

The errors stop when we set newrelic.enabled = false, or when we remove our license key from newrelic.ini. And of course, the error does not happen when we haven't installed newrelic PHP agent.

Steps to Reproduce

In summary, install PHP >=8.1, with mysqli, enable New Relic and then prepare two statements that have different number of arguments.

Here is our current test script:

<?php 
 
$dbConn = new mysqli( 
    "db", 
    "root", 
    "changeme", 
    "dbtest" 
); 
 
justPrepare($dbConn); 
 
$ts = strtotime("today - 7 years"); 
$stringTs = date('Y-m-d H:i:s', $ts); 
 
$stmt = $dbConn->prepare(" SELECT q.id 
FROM query_test_table q 
CROSS JOIN query_test_table AS q2 
WHERE MD5(`q`.`key`) = MD5(?) 
; 
"); 
if (! $stmt) { 
    throw new Exception("Prepare Failed : " . $dbConn->error); 
} 
$stmt->bind_param('s', $stringTs); 
if (! $stmt->execute()) { 
    throw new Exception("Execute Failed : " . $stmt->error); 
} 
$stmt->bind_result($someId); 
$stmt->fetch(); 
$stmt->close(); 
 
echo "If you see this message, it didn't crash\n"; 
 
function justPrepare($dbConn) 
{ 
    // note: we don't even execute this
    $stmt2 = $dbConn->prepare("SELECT ?, ?"); 
    $stmt2->close(); 
    $stmt2 = null; 
}

Some conditions seem to apply:

  • The second statement when executed seems to need to take at least half a second or the Error doesn't happen.
  • If you don't call justPrepare() then the Error doesn't happen.
  • If you do call justPrepare() but change $stmt2 in it to have the same number of placeholders as $stmt, then the error doesn't happen.
  • Minor changes to the query in $stmt sometimes stop the error. For example, removing the space before SELECT, or the semi colon after the query. However, most of the queries that have failed haven't had extra characters like this. This was just the easiest one to recreate.

Locally, we recreated the issue using docker php:8.1-cli image and mysql:8.0.36. We seeded the test table with 2 million rows with the following sql:


CREATE TABLE `query_test_table` (
                                    `id` int NOT NULL AUTO_INCREMENT,
                                    `key` varchar(45) DEFAULT NULL,
                                    PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;

DELIMITER $$
CREATE PROCEDURE InsertRandomRows()
BEGIN
  DECLARE i INT DEFAULT 0;
  DECLARE randomKey VARCHAR(45);

  WHILE i < 2200000 DO
    SET randomKey = SUBSTRING(MD5(RAND()) FROM 1 FOR 45);
INSERT INTO query_test_table (`key`) VALUES (randomKey);
SET i = i + 1;
END WHILE;
END$$
DELIMITER ;

CALL InsertRandomRows();

Expected Behavior

$stmt->execute() should not throw an ArgumentCountError when we have bound the correct number of parameters with bind_param. And it shouldn't be affected by the previously prepared query.

Your Environment

We've recreated this on:

  • Amazon Linux 2023, PHP 8.2 (Elastic Beanstalk)
  • Amazon Linux 2, PHP 8.1 (Elastic Beanstalk)
  • Docker, on php:8.1-cli

This may be related to this change in PHP 8.1, php/php-src#6271

@mfulb
Copy link
Contributor

mfulb commented Apr 15, 2024

Thank you for the detailed report - we will investigate this issue.

@mfulb
Copy link
Contributor

mfulb commented Apr 16, 2024

Thank you again for the detailed report - I was able to reproduce the behavior you are reporting and will be investigating this further.

@mfulb
Copy link
Contributor

mfulb commented Apr 18, 2024

I believe it is related to the agent attempting to "explain" the slower query and the issue reported is triggered. As a temporary workaround you could try setting newrelic.transaction_tracer.explain_enabled=false - this would of course remove the explanation of slow SQL queries but would remove the warnings you are experiencing. See the docs for more info on this setting. Our goal is to remove the need for this workaround with a fix of course.

@iaibai
Copy link
Author

iaibai commented Apr 18, 2024

Thanks! That's really helpful. As long as we know which queries are slow (and how slow they are) we can probably do without the explain for now.

@mfulb
Copy link
Contributor

mfulb commented Apr 19, 2024

Thanks! That's really helpful. As long as we know which queries are slow (and how slow they are) we can probably do without the explain for now.

I believe the duration is still available.

@mfulb
Copy link
Contributor

mfulb commented Apr 19, 2024

I made some good progress understanding this issue. You noticed the space at the beginning of the SQL for $stmt might be related - and it is. But also the spaces AFTER the ";". Either of those can cause a case where you will see this warning. If you remove the leading and trailing spaces then your test runs just fine. Just wanted to pass this along if it helped you in the time before we are able to ship a proper solution for this case.

Thank you again for this report - it was well documented and made my job of troubleshooting it much more efficient!

@iaibai
Copy link
Author

iaibai commented Apr 19, 2024

Thanks, sorry I think we knew removing the semi-colon also helped this particular query, but we were also experiencing the issue on some queries that didn't have spaces at the start or semi-colons at the end (in fact most of them don't). We just didn't manage to make a re-creatable example of one like that.

We couldn't find any clear pattern in the queries that failed. 😔

@mfulb
Copy link
Contributor

mfulb commented Apr 22, 2024

Your report with all the details you provided was excellent and extremely useful in determining this pattern.

mfulb added a commit that referenced this issue Apr 25, 2024
…s (GH issue 875) (#881)

In GH issue #875 it was reported a warning is generated when using
prepared statements with `mysqli`. The issue included excellent
instructions on how to reproduce the issue. This PR addresses the cause
of the warning.

To understand the cause of the warning requires understanding how the
agent handles `mysqli::stmt` objects. When a SQL statement is prepared
via mysqli the agent will store the SQL string in a global hashmap
called `mysqli_queries` *if* the SQL is considered explainable
(determined via `nr_php_explain_mysql_query_is_explainable()`),
otherwise it is just ignored. Later when a slow SQL query is detected
the SQL string is retrieved and used to explain the query.

An additional factor is when a `mysqli::stmt` object is released it goes
into a free pool PHP keeps which allows it to quickly hand out an
allocated section of memory when a new object is created. Each object
has a `object ID` (referenced as a `handle` in the agent for the
relevant code). When an the allocated object is reused from the free
pool it retains the same `object ID`.

The agent used the `object ID` (`handle`) as the key for storing the
prepared SQL string for explainable SQL strings. Now what if an
explainable query comes through, the string is stored, and then that
object is released. A new query is prepared with a string that is NOT
explainable and gets the object container with the same `object ID` as
the explainable one just released. The string stored in `mysqli_queries`
using that `object ID` as the key is now stale. If the new,
unexplainable query is slow then the agent will pull this stale string
and try to run an explain with it - leading to the warning.

The fix is to clear any query string for a given `object ID` if the
query string is unexplainable.

Integration tests were added (based on the reproduction case) that test
for a regression of this fix.
@lavarou lavarou added this to the next-release milestone Apr 26, 2024
@curtisblack2004
Copy link

I am running into the same issue on PHP 8.1.28, when will the new version of Newrelic be released? I have 10.19.0.9 installed.

@lavarou lavarou closed this as completed May 6, 2024
@mfulb
Copy link
Contributor

mfulb commented May 6, 2024

This issue has been fixed in the 10.20.0.10 release. Thank you again for the thorough bug report!

@iaibai
Copy link
Author

iaibai commented May 7, 2024

Thank you!

@mfulb
Copy link
Contributor

mfulb commented May 14, 2024

I wanted to check back and see if the new release has addressed this report.

@curtisblack2004
Copy link

curtisblack2004 commented May 14, 2024 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
4 participants