How to log Magento database queries

In this short article we will show you how to debug your database queries by enabling database logging. Logging is somewhat underused feature and the official guide offers lots of great tips for how to utilize it.

Logging | Magento 2 Developer Documentation

Magento 2 Developer Documentation.

Adobe Magento DevDocs

Today we are specifically going to look into how the database logging can be enabled and how to read it.

Enable query logging

It is extremely simple to enable this just run the following 2 commands in command line:

bin/magento dev:query-log:enable

bin/magento cache:flush

After this is done you should be able to see the log file at var/debug/db.log

To understand how the command works we can take a look at its implementation. Simply searching for the command name we can find that this class is responsible \Magento\Developer\Console\Command\QueryLogEnableCommand

Possible command input options:

• include-all-queries - if set logs everything
• query-time-threshold - determines the query time threshold that are logged. This way you can limit the logging to only slow queries.
• include-call-stack - determines if stack trace should be included in the logs

The command itself only saves the environment configuration. The rest of the magic happens in Magento\Framework\DB\Logger\LoggerProxy. The configuration is passed in as an arguments for the class.

<type name="Magento\Framework\DB\Logger\LoggerProxy">
    <arguments>
        <argument name="loggerAlias" xsi:type="init_parameter">Magento\Framework\Config\ConfigOptionsListConstants::CONFIG_PATH_DB_LOGGER_OUTPUT</argument>
        <argument name="logAllQueries" xsi:type="init_parameter">Magento\Framework\Config\ConfigOptionsListConstants::CONFIG_PATH_DB_LOGGER_LOG_EVERYTHING</argument>
        <argument name="logQueryTime" xsi:type="init_parameter">Magento\Framework\Config\ConfigOptionsListConstants::CONFIG_PATH_DB_LOGGER_QUERY_TIME_THRESHOLD</argument>
        <argument name="logCallStack" xsi:type="init_parameter">Magento\Framework\Config\ConfigOptionsListConstants::CONFIG_PATH_DB_LOGGER_INCLUDE_STACKTRACE</argument>
    </arguments>
</type>

The proxy class is preference for the default LoggerInterface in the same di.xml file.

<preference for="Magento\Framework\DB\LoggerInterface" type="Magento\Framework\DB\Logger\LoggerProxy"/>

From this point on everything is built in the core classes. If the database logger interface is used anywhere then the logger will already output the stats for each query using the following abstract function \Magento\Framework\DB\Logger\LoggerAbstract::getStats

public function getStats($type, $sql, $bind = [], $result = null)
{
    $message = '## ' . getmypid() . ' ## ';
    $nl   = "\n";
    $time = sprintf('%.4f', microtime(true) - $this->timer);

    if (!$this->logAllQueries && $time < $this->logQueryTime) {
        return '';
    }
    switch ($type) {
        case self::TYPE_CONNECT:
            $message .= 'CONNECT' . $nl;
            break;
        case self::TYPE_TRANSACTION:
            $message .= 'TRANSACTION ' . $sql . $nl;
            break;
        case self::TYPE_QUERY:
            $message .= 'QUERY' . $nl;
            $message .= 'SQL: ' . $sql . $nl;
            if ($bind) {
                $message .= 'BIND: ' . var_export($bind, true) . $nl;
            }
            if ($result instanceof \Zend_Db_Statement_Pdo) {
                $message .= 'AFF: ' . $result->rowCount() . $nl;
            }
            break;
    }
    $message .= 'TIME: ' . $time . $nl;

    if ($this->logCallStack) {
        $message .= 'TRACE: ' . Debug::backtrace(true, false) . $nl;
    }

    $message .= $nl;

    return $message;
}

Output

Output for the above will be found in var/debug/db.log. It will look similar to this:

## 2021-02-20 12:25:31
## 8 ## QUERY
SQL: SELECT `flag`.* FROM `flag` WHERE (`flag`.`flag_code`='config_hash')
AFF: 1
TIME: 0.0005
TRACE: #1 Magento\Framework\DB\Logger\File[Magento\Framework\DB\Logger\LoggerAbstract]#000000005e3d95fd000000002089ef9c#->getStats('query', 'SELECT `flag`.* ...', array(), &Magento\Framework\DB\Statement\Pdo\Mysql#000000005e3d96cb000000002089ef9c#) called at [vendor/magento/framework/DB/Logger/File.php:67]
#2 Magento\Framework\DB\Logger\File#000000005e3d95fd000000002089ef9c#->logStats('query', 'SELECT `flag`.* ...', array(), &Magento\Framework\DB\Statement\Pdo\Mysql#000000005e3d96cb000000002089ef9c#) called at [vendor/magento/framework/DB/Logger/LoggerProxy.php:152]

Disable query logging

After you are done debugging make sure to disable the logs. Otherwise you might end up with extremely large files and storage could fill up quickly. You can use this command to disable the database query logging:

bin/magento dev:query-log:disable

That is it for this article. Hopefully this helps when debugging performance problems for your store or perhaps when you need to find specific queries that may be causing any issues.