Logging all SQL in Magento

I’ve been looking for a way to log all the sql that Magento is running for debugging purposes. There are a number of logging mechanisms built in to Magento, but none that would allow you to log all the sql that’s being run. Finally, I’ve found a simple change that can be made to a core file (I know, not ideal because it will get overwritten when you upgrade Magento – but it’s only a few lines in one file).

The Change

1. Open the file <magentoroot>/lib/Varien/Db/Adapter/Pdo/Mysql.php.

2. Add the following lines:

[sourcecode language='php']
$code = 'SQL: ' . $sql . "rn";
if ($bind) {
     $code .= 'BIND: ' . print_r($bind, true) . "rn";
}
$this->_debugWriteToFile("[".date('Y-m-d H:i:s')."] ".$code);
[/sourcecode]

Add it to the “query” function as shown below:

[sourcecode language='php']
public function query($sql, $bind = array())
{
     $this->_debugTimer();

     try {
          $sql = (string)$sql;
          if (strpos($sql, ':') !== false || strpos($sql, '?') !== false) {
               $this->_bindParams = $bind;
               $sql = preg_replace_callback('#((['"])((2)|((.*?[^\])2)))#', array($this, 'proccessBindCallback'), $sql);
               $bind = $this->_bindParams;
          }

          $code = 'SQL: ' . $sql . "rn";
          if ($bind) {
               $code .= 'BIND: ' . print_r($bind, true) . "rn";
          }
          $this->_debugWriteToFile("[".date('Y-m-d H:i:s')."] ".$code);

          $result = parent::query($sql, $bind);
     }
     catch (Exception $e) {
          $this->_debugStat(self::DEBUG_QUERY, $sql, $bind);
          $this->_debugException($e);
     }
     $this->_debugStat(self::DEBUG_QUERY, $sql, $bind, $result);
     return $result;
 }
[/sourcecode]

The Log

By default your sql will be logged to:

<magentoroot>/var/debug/sql.txt

Limitations

1. As mentioned above, the file will likely be overwritten during a Magento upgrade.

2. There’s nothing that will turn logging off (except a Magento upgrade).  So you need to be careful that this is a temporary setting for debugging only.

=============================
“e-commerce done right

http://www.ifuelinteractive.com

8 Responses to “Logging all SQL in Magento”

  1. Fabien Petermann

    Thanks for that post, that gave me a clue as to where I should start off.

    I have slightly enhanced your code to get control over query logging through the configuration file. Just replace your code with :

    $this->_logQuery($sql, $bind);

    and add this at the bottom of the /path/to/magento/lib/Varien/Db/Adapter/Pdo/Mysql.php file :

    protected function _logQuery($sql, $bind = array(), $result = null)
    {
    // configuration of the query logger
    static $logConfig = null;

    if (null === $logConfig) {
    // first time function is executed
    // query logger needs to be configured
    if (array_key_exists(‘log’, $this->_config)) {
    $logConfig[‘enabled’] = (bool) $this->_config[‘log’];
    }
    if (array_key_exists(‘log_file’, $this->_config)) {
    $logConfig[‘file_name’] = $this->_config[‘log_file’];
    }
    }

    if (!$logConfig[‘enabled’]) {
    // query logger is not enabled, nothing to do
    return $this;
    }

    // build the log message
    // note: from this part on, code is inspired by _debugStat() and
    // _debugWriteFile() methods of the Varien_Db_Adapter_Pdo_Mysql
    // class, with only small modifications
    $code = ‘## ‘ . getmypid() . ‘ ## ‘;
    $nl = “n”;

    $code .= ‘QUERY’ . $nl;
    $code .= ‘SQL: ‘ . $sql . $nl;
    if ($bind) {
    $code .= ‘BIND: ‘ . print_r($bind, true) . $nl;
    }
    if ($result instanceof Zend_Db_Statement_Pdo) {
    $code .= ‘AFF: ‘ . $result->rowCount() . $nl;
    }
    $code .= $nl . $nl;

    if (!array_key_exists(‘adapter’, $logConfig)) {
    $logConfig[‘adapter’] = new Varien_Io_File();
    $dir = $logConfig[‘adapter’]->dirname($logConfig[‘file_name’]);
    $logConfig[‘adapter’]->checkAndCreateFolder($dir);
    $logConfig[‘adapter’]->open(array(‘path’ => $dir));
    $logConfig[‘file_name’] = basename($logConfig[‘file_name’]);
    }

    $logConfig[‘adapter’]->streamOpen($logConfig[‘file_name’], ‘a’);
    $logConfig[‘adapter’]->streamLock();
    $logConfig[‘adapter’]->streamWrite($code);
    $logConfig[‘adapter’]->streamUnlock();
    $logConfig[‘adapter’]->streamClose();

    return $this;
    }

    Now, edit your /path/to/magento/app/etc/local.xml and add these two lines to your database connection configuration :

    1

    like in the following :

    <![CDATA[]]>
    <![CDATA[]]>
    1
    1

    Now, all queries can be seen from that sql.txt file. Sweet! 🙂

    By the way, did you notice this ** HUGE ** security hole: for some reason that I do not understand, on Magento version 1.3.2.3 (maybe this behaviour has changed in newer versions), the default value of Varien_Db_Adapter_Pdo_Mysql::$_debugFile is ‘var/debug/sql.txt’. If you have multiple stores configured like I do , this file will be located in the DOCUMENT_ROOT of your website (that is /path/to/magento/stores/store1/var/store/sql.txt), hence, making this file ** PUBLIC ** at this URL : http://store1.your-magento-shop.com/var/debug/sql.txt !

    Knowing this file may contain database credentials (including your database password), I consider this as a very serious threat to the security of your database. Thus, I ** STRONGLY ** recommend to keep this file out of the DOCUMENT_ROOT of the web server by overriding this value, or at least to protect this directory with a .htaccess file.

    Yet, you don’t have to worry too much if you only have 1 store configured, as the /path/to/magento_dir/var directory is already protected with a .htacces file.

    Thanks again for that code snippet! 😉

    Cheers!

  2. Fabien Petermann

    Whoops! This blog doesn’t seem to like XML code 😉 So, here’s what should go in your etc/local.xml file (hopefully, this time it will work.. :-)) :

    <log>1</log>
    <log_file><![CDATA[../../../var/debug/sql.txt]]></log_file>

    e.g. :

    <default_setup>
    <connection>
    <host><![CDATA[localhost]]></host>
    <username><![CDATA[magento]]></username>
    <password><![CDATA[<database_password>]]></password>
    <dbname><![CDATA[<database_name>]]></dbname>
    <active>1</active>
    <log>1</log>
    <log_file><![CDATA[/path/to/magento/var/debug/sql.txt]]></log_file>
    </connection>
    </default_setup>

  3. Thanks, this pointed me in the right direction and provided me with usable code.

    I also added a bit to filter out certain SQL verbs. It’s not very efficient, but running in debug mode seldom is 🙂

    * Add to local.xml. Comma-separated list of SQL verbs to log:

    SELECT,INSERT

    * Above the “//build the log message” in the above code:

    /* Filter SQL verbs */
    if ( strlen( $logConfig[‘log_verbs’] ) ) {
    $arr = explode( “,”, $logConfig[‘log_verbs’] );

    $words = explode(‘ ‘, $sql);
    $verb = $words[0];

    if ( !in_array( $verb, $arr ) ) {
    return $this;
    }
    }

    * Add this

  4. I guess it still interprets things in pre tags 🙂

    that should be an XML element called “log_verbs” in your DB config.

    Unfortunately I also forgot that I modified this piece of code, which puts the log_verbs config into logConfig:

    if (null === $logConfig) {
    // first time function is executed
    // query logger needs to be configured
    if (array_key_exists(“log”, $this->_config)) {
    $logConfig[‘enabled’] = (bool) $this->_config[‘log’];
    }
    if (array_key_exists(‘log_file’, $this->_config)) {
    $logConfig[‘file_name’] = $this->_config[‘log_file’];
    }
    if (array_key_exists(‘log_verbs’, $this->_config)) {
    $logConfig[‘log_verbs’] = $this->_config[‘log_verbs’];
    } else {
    $logConfig[‘log_verbs’] = “SELECT,UPDATE,INSERT,DELETE”;
    }
    }

  5. Gershon H

    Worked real well here is the same code :

    public function query($sql, $bind = array())
    {
    $this->_debugTimer();
    try {
    $this->_prepareQuery($sql, $bind);
    $code = ‘SQL: ‘ . $sql . “rn”;
    if ($bind) {
    $code .= ‘BIND: ‘ . print_r($bind, true) . “rn”;
    }
    $this->_debugWriteToFile(“[“.date(‘Y-m-d H:i:s’).”] “.$code);
    $result = parent::query($sql, $bind);
    } catch (Exception $e) {
    $this->_debugStat(self::DEBUG_QUERY, $sql, $bind);
    $this->_debugException($e);
    }
    $this->_debugStat(self::DEBUG_QUERY, $sql, $bind, $result);
    return $result;
    }?

Leave a Reply

XHTML: You can use these tags: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>