MySQLnd Plugins: Writing a MySQL Query Logger in PHP

During the development of an application, not all time is spent on writing code. A lot of time is spent on reading debug output, crawling through log files and firing up the debugger to figure out what the application does. While the debugger helps us to inspect details of a running application on a testing environment, logfiles are often the only indication of the origin of an error on a production system. In this blogpost I want to describe how to log SQL statements on an existing application without touching any existing line of code at all. We will use a new MySQLnd Extension developed at the Mayflower OpenSource Labs for
that purpose.

As an example, I will use PHProjekt 6. The project is particularly suitable for demonstration purposes as it has a logging infrastructure for function calls, but does not log SQL statements.

MySQLnd Userland Handler

A new approach to implementing a query logger and potentially more complex features such as monitoring or read/write-splitting is the MySQLnd Userland Handler Extension (mysqlnd_uh, pecl website). The extension lets you register a PHP class as a proxy for every MySQLnd connection. Every call to a function to MySQLnd (usually indirect through mysqli, mysql, pdo_mysql) is passed to the PHP class, which then calls the original MySQLnd function. The extension makes it possible to use a custom userland class as a transparent proxy for all MySQLnd frontend (again mysqli, mysql, pdo_myslq).

In the next section, I’ll outline the requirements of mysqlnd_uh and show a sample implementation.

Prequisites

To use MySQLnd Userland Handler, you need to install the mysqlnd_uh extension using pecl. The extension is currently in alpha state. Therefore you have to specify the -alpha postfix.

$ pecl install mysqlnd_uh-alpha

The extension depends on the mysqli extension with enabled mysqlnd support. To learn how to install mysqli with mysqlnd support, check the PHP.net manual.

The MySQLnd Userland Handler provides the MySQLndUhConnection class. To write a proxy class you need to extend the class and overwrite the methods you want to proxy. A simple example:

class MySQLDebugLog extends MySQLndUhConnection {
  public function query($connection, $query) {
    log($query);
    /* the original mysqli_query method is available as parent */
    return parent::query($connection, $query);
  }
}

To use the proxy class we have to pass an instance of the class to the mysqlnd_uh extension. It will then pass every mysqlnd function call to the object and check if the return values correspond with the return value of the proxied mysqlnd function. The following snippet registers our proxy object:

mysqlnd_uh_set_connection_proxy(new MySQLDebugLog());

That’s it. We finished our query logger. No need for a database abstraction layer with a custom factory method or whatever. The MySQLDebug class will log our queries.

The MySQLnd Userland Handler extension uses a plugin interface provided by the MySQLnd extension. A well written overview on MySQLnd plugins can be found on Ulf Wendel’s blog:
http://blog.ulf-wendel.de/?p=284.

Configuration

MySQLnd Userland Handler provides two INI settings. mysqlnd_uh.enabled can be set to 0 to disable the extension temporarly. The extension is enabled by default if it is installed. Unless you set mysqlnd_uh.report_wrong_types to 0, mysqlnd_uh will check if the return values of the userland methods are correct and will issue a PHP warning otherwise. An
example:

class MySQLDebugLog extends MySQLndUhConnection {
  public function query($connection, $query) {
    /* no return */
    parent::query($connection, $query);
  }
}

mysqlnd_uh_set_connection_proxy(new MySQLDebugLog());
$mysqli = /* ... init ... */
mysqli_do_query($mysqli, "SELECT foo FROM foobar");

Warning: mysqli::query(): (MySQLnd User Handler) The method
MySQLndUhConnection::query() did not return a boolean value
as it should in /home/test/foo.php on line 5

A real world scenario

Let’s assume we want to provide a Debug module for PHProjekt 6. If the module is installed, SQL statements are logged. Let’s use our extension to write the module. We will use an experimental PHProjekt API to hook into the startup process of PHProjekt.

The Phprojekt_Extension_Abstract class defines a startup method that will be called during the initial PHProjekt dispatch. I use the startup method to register our MySQLnd proxy class. The application/Debug/Extension.php file:

class Debug_Extension extends Phprojekt_Extension_Abstract {
    public function startup() {    
        if (extension_loaded("mysqlnd_uh")) {               
            mysqlnd_uh_set_connection_proxy(new MySQLDebug());
        }     
    }
}

I use the PHProjekt logging methods to log the query:

class MySQLDebug extends MySQLndUhConnection {
    public function query($res, $query) {
        PHProjekt::getInstance()->getLog()->debug($query);
        return parent::query($res, $query);
    }
}

Looks as simple as it is. Our SQL query logger module is ready.

The given example is just a simple use case of the mysqlnd_uh extension. More complex applications can be implemented using the Userland Handler, such as sophisticated sharding or slow query analyzer.

 

MySQLnd Userland Handler at Mayflower OpenSource Labs

The MySQLnd Userland Handler is developed at the Mayflower OpenSource Labs and released under the PHP License 3.01.

A first alpha version is available via PECL. Our current goal is to get people to test the
extension and provide feedback. Further versions will also provide classes to override other MySQLnd internal classes such as the MySQlnd statement class.