Magento is a complex beast and tracking down the source of a database query can be a huge pain. Recently I had to track down the source of a set of queries. I could see the queries in the SQL query logs but wasn’t able to figure out which particular piece of code would execute them because the functionality that triggered these was used all over the place.

I ended up adding the PHP stack trace that executed a SQL query to each query as a comment before the query. That way the full stack trace would show up in the MySQL query logs.

To achieve that I temporarily modified lib/Zend/Db/Statement/Pdo.php (GIST)

diff --git a/lib/Zend/Db/Statement/Pdo.php b/lib/Zend/Db/Statement/Pdo.php
index 4530897..3561d05 100644
--- a/lib/Zend/Db/Statement/Pdo.php
+++ b/lib/Zend/Db/Statement/Pdo.php
@@ -54,6 +54,7 @@ class Zend_Db_Statement_Pdo extends Zend_Db_Statement implements IteratorAggrega
      */
     protected function _prepare($sql)
     {
+        $sql = $this->_trace() . $sql;
         try {
             $this->_stmt = $this->_adapter->getConnection()->prepare($sql);
         } catch (PDOException $e) {
@@ -63,6 +64,22 @@ class Zend_Db_Statement_Pdo extends Zend_Db_Statement implements IteratorAggrega
     }

     /**
+     * Add a PHP stack trace comment to every SQL statement
+     *
+     * @return string Stack trace comment
+     */
+    protected function _trace() {
+        $trace = array();
+        foreach (debug_backtrace() as $call) {
+            if (isset($call['file']) && isset($call['line'])) {
+                $trace[] = $call['file'] . ' ' . $call['line'];
+            }
+        }
+
+        return "\n/*" . addslashes(implode("\n", $trace)) . "*/\n";
+    }
+
+    /**
      * Bind a column of the statement result set to a PHP variable.
      *
      * @param string $column Name the column in the result set, either by

I was afraid that that would add significant overhead due to the debug_backtrace() call but even on a production site with 5,000qps there was no noticeable impact.

One notable side effect is that if you do a full query log the log file size will become significantly (>5x) larger due to the additionally logged information.

To temporarily enable query logging from the command line client execute the following 3 commands:

SET GLOBAL long_query_time = 0;
SET GLOBAL slow_query_log_file = '/tmp/full_query.log';
SET GLOBAL slow_query_log = 'ON';

and to disable it again

SET GLOBAL slow_query_log = 'OFF';