Support nightmare: a customer reports a random PHP MySQL error. As a support expert you have the strong feeling that it is down to some suspicious SQL sequence. How to proof? 25 lines of PECL/mysqlnd_uh swiss-army knife magic…
prepend.php
class __mysqlnd_logger extends MysqlndUhConnection {
private $protocol;
public function query($conn, $query) {
$ret = parent::query($conn, $query);
if ($errno = $this->getErrorNumber($conn)) {
$this->protocol[] = array(
"query" => $query,
"error" => sprintf("[%d] %s",
$errno, $this->getErrorString($conn)),
"bt" => debug_backtrace()
);
} else {
$this->protocol[] = $query;
}
return $ret;
}
public function getProtocol() {
return $this->protocol;
}
}
$__logger = new __mysqlnd_logger();
mysqlnd_uh_set_connection_proxy($__logger);
The dear customer is convinced that his application, which cannot be modified, is free of faults. The database records hint that there must be something wrong, but where? Easy to find out, if the PHP MySQL extensions are compiled to use mysqlnd library. Let’s hook the mysqlnd library query() function to monitor the SQL and check for error codes, which the app does not do. We kind of create a client-side proxy. If using PECL/mysqlnd_uh this can be done in PHP user space, check yesterdays post for details. Follow yesterday’s pattern: install the PECL extension, save the above to a file named prepend.php and load the script before the application starts using the auto_prepend_file PHP configuration directive.
Create an additional file append.php and load it after the application has finished using the PHP configuration directive auto_prepend_file. Put the following into it. Why not using var_export()? Well, give it a try, it bailed at me about infinite recursion..
append.php
$protocol = $__logger->getProtocol();
foreach ($protocol as $k => $entry) {
if (is_array($entry)) {
ob_start();
var_dump($protocol);
error_log(ob_get_contents());
ob_end_clean();
break ;
}
}
Here comes my the customers fancy but faulty PHP application, which is "randomly" failing. Please note, that the monitoring and debugging performed with PECL/mysqlnd_uh does not require any application changes.
application.php
/* Fancy web application using MySQL */
$mysqli = new mysqli("localhost", "root", "", "test");
$mysqli->query("DROP TABLE IF EXISTS test");
$mysqli->query("CREATE TABLE test(id INT)");
$mysqli->query("INSERT INTO test(id) VALUES (1), (2), (3)");
/* customer says this never, ever happens... */
$mysqli->query("DROP TABLE test");
$mysqli->query("SELECT * FROM test");
Finally, let’s put the pieces together. I’m demoing it on the CLI, but its not a big deal to imagine that application.php would be located on a web server and the PHP configuration directives set with -d would be set in the php.ini, is it?
The proof
nixnutz@owan113:~/php-src/branches/PHP_5_4> sapi/cli/php -d auto_prepend_file=prepend.php -d auto_append_file=append.php application.php
array(5) {
[0]=>
string(25) "DROP TABLE IF EXISTS test"
[1]=>
string(25) "CREATE TABLE test(id INT)"
[2]=>
string(41) "INSERT INTO test(id) VALUES (1), (2), (3)"
[3]=>
string(15) "DROP TABLE test"
[4]=>
array(3) {
["query"]=>
string(18) "SELECT * FROM test"
["error"]=>
string(38) "[1146] Table 'test.test' doesn't exist"
["bt"]=>
array(2) {
[0]=>
array(5) {
["function"]=>
string(5) "query"
["class"]=>
string(16) "__mysqlnd_logger"
["object"]=>
&object(__mysqlnd_logger)#1 (1) {
["protocol":"__mysqlnd_logger":private]=>
*RECURSION*
}
["type"]=>
string(2) "->"
["args"]=>
array(2) {
[0]=>
resource(5) of type (Mysqlnd Connection)
[1]=>
string(18) "SELECT * FROM test"
}
}
[1]=>
array(7) {
["file"]=>
string(54) "/home/nixnutz/php-src/branches/PHP_5_4/application.php"
["line"]=>
int(11)
["function"]=>
string(5) "query"
["class"]=>
string(6) "mysqli"
["object"]=>
object(mysqli)#2 (19) {
["affected_rows"]=>
int(-1)
["client_info"]=>
string(50) "mysqlnd 5.0.9-dev - 20110325 - $Revision: 315975 $"
["client_version"]=>
int(50009)
["connect_errno"]=>
int(0)
["connect_error"]=>
NULL
["errno"]=>
int(1146)
["error"]=>
string(31) "Table 'test.test' doesn't exist"
["error_list"]=>
array(1) {
[0]=>
array(3) {
["errno"]=>
int(1146)
["sqlstate"]=>
string(5) "42S02"
["error"]=>
string(31) "Table 'test.test' doesn't exist"
}
}
["field_count"]=>
int(0)
["host_info"]=>
string(25) "Localhost via UNIX socket"
["info"]=>
string(0) ""
["insert_id"]=>
int(0)
["server_info"]=>
string(12) "5.6.2-m5-log"
["server_version"]=>
int(50602)
["stat"]=>
string(138) "Uptime: 612889 Threads: 1 Questions: 30077 Slow queries: 0 Opens: 1303 Flush tables: 1 Open tables: 30 Queries per second avg: 0.49"
["sqlstate"]=>
string(5) "00000"
["protocol_version"]=>
int(10)
["thread_id"]=>
int(4798)
["warning_count"]=>
int(0)
}
["type"]=>
string(2) "->"
["args"]=>
array(1) {
[0]=>
string(18) "SELECT * FROM test"
}
}
}
}
}
Anybody volunteering to take the idea and add it to the usual PHP database frameworks? Happy hacking!
PS: I appologize for having changed URL schema/style before the planets dropped me from their front pages. Due to the new URL schema, the planets show some posts twice. I did not expect that to happen. To avoid further chaos, I won’t switch back to old schema.