Index: includes/database/database.inc
===================================================================
RCS file: /cvs/drupal/drupal/includes/database/database.inc,v
retrieving revision 1.6
diff -u -p -r1.6 database.inc
--- includes/database/database.inc	20 Sep 2008 20:22:24 -0000	1.6
+++ includes/database/database.inc	20 Sep 2008 23:27:09 -0000
@@ -146,6 +146,22 @@ abstract class DatabaseConnection extend
    */
   public $lastStatement;
 
+  /**
+   * The database target this connection is for.
+   *
+   * We need this information for later auditing and logging.
+   *
+   * @var string
+   */
+  protected $target = NULL;
+
+  /**
+   * The current database logging object for this connection.
+   *
+   * @var DatabaseLog
+   */
+  protected $logger = NULL;
+
   function __construct($dsn, $username, $password, $driver_options = array()) {
     $driver_options[PDO::ATTR_ERRMODE] = PDO::ERRMODE_EXCEPTION; // Because the other methods don't seem to work right.
     parent::__construct($dsn, $username, $password, $driver_options);
@@ -270,6 +286,55 @@ abstract class DatabaseConnection extend
   }
 
   /**
+   * Tell this connection object what its target value is.
+   *
+   * This is needed for logging and auditing.  It's sloppy to do in the
+   * constructor because the constructor for child classes has a different
+   * signature.  We therefore also ensure that this function is only ever
+   * called once.
+   *
+   * @param $target
+   *   The target this connection is for.  Set to NULL (default) to disable
+   *   logging entirely.
+   */
+  public function setTarget($target = NULL) {
+    if (!isset($this->target)) {
+      $this->target = $target;
+    }
+  }
+
+  /**
+   * Returns the target this connection is associated with.
+   *
+   * @return
+   *   The target string of this connection.
+   */
+  public function getTarget() {
+    return $this->target;
+  }
+
+  /**
+   * Associate a logging object with this connection.
+   *
+   * @param $logger
+   *   The logging object we want to use.
+   */
+  public function setLogger(DatabaseLog $logger) {
+    $this->logger = $logger;
+  }
+
+  /**
+   * Get the current logging object for this connection.
+   *
+   * @return
+   *   The current logging object for this connection.  If there isn't one,
+   *   NULL is returned.
+   */
+  public function getLogger() {
+    return $this->logger;
+  }
+
+  /**
    * Create the appropriate sequence name for a given table and serial field.
    *
    * This information is exposed to all database drivers, although it is only
@@ -673,6 +738,67 @@ abstract class Database {
   static protected $activeKey = 'default';
 
   /**
+   * An array of active query log objects.
+   *
+   * @var array
+   */
+  static protected $logs = array();
+
+  /**
+   * Start logging a given logging key on the specified connection.
+   *
+   * @see DatabaseLog
+   * @param $logging_key
+   *   The logging key to log.
+   * @param $key
+   *   The database connection key for which we want to log.
+   * @return
+   *   The query log object.  Note that the log object does support richer
+   *   methods than the few exposed through the Database class, so in some
+   *   cases it may be desirable to access it directly.
+   */
+  final public static function startLog($logging_key, $key = 'default') {
+    if (empty(self::$logs[$key])) {
+      self::$logs[$key] = new DatabaseLog($key);
+
+      // Every target already active for this connection key needs to have
+      // the logging object associated with it.
+      foreach (self::$connections[$key] as $connection) {
+        $connection->setLogger(self::$logs[$key]);
+      }
+    }
+    self::$logs[$key]->start($logging_key);
+
+    return self::$logs[$key];
+  }
+
+  /**
+   * Retrieve the queries logged on for given logging key.
+   *
+   * This method also ends logging for the specified key.  To get the query log
+   * to date without ending the logger request the logging object by starting
+   * it again (which does nothing to an open log key) and call methods on it as
+   * desired.
+   *
+   * @see DatabaseLog
+   * @param $logging_key
+   *   The logging key to log.
+   * @param $key
+   *   The database connection key for which we want to log.
+   * @return
+   *   The query log for the specified logging key and connection.
+   */
+  final public static function getLog($logging_key, $key = 'default') {
+    if (empty(self::$logs[$key])) {
+      return NULL;
+    }
+
+    $queries = self::$logs[$key]->get($logging_key);
+    self::$logs[$key]->end($logging_key);
+    return $queries;
+  }
+
+  /**
    * Gets the active connection object for the specified target.
    *
    * @return
@@ -827,6 +953,15 @@ abstract class Database {
       $driver_class = 'DatabaseConnection_' . $driver;
       require_once DRUPAL_ROOT . '/includes/database/' . $driver . '/database.inc';
       self::$connections[$key][$target] = new $driver_class(self::$databaseInfo[$key][$target]);
+      self::$connections[$key][$target]->setTarget($target);
+
+      // If we have any active logging objects for this connection key, we need
+      // to associate them with the connection we just opened.
+      if (!empty(self::$logs[$key])) {
+        foreach (self::$logs[$key] as $log) {
+          self::$connections[$key][$target]->setLogger($log);
+        }
+      }
 
       // We need to pass around the simpletest database prefix in the request
       // and we put that in the user_agent header.
@@ -1014,7 +1149,20 @@ class DatabaseStatement extends PDOState
       }
     }
     $this->dbh->lastStatement = $this;
-    return parent::execute($args);
+
+    $logger = $this->dbh->getLogger();
+    if (!empty($logger)) {
+      $query_start = microtime(TRUE);
+    }
+
+    $return = parent::execute($args);
+
+    if (!empty($logger)) {
+      $query_end = microtime(TRUE);
+      $logger->log($this, $args, $query_end - $query_start);
+    }
+
+    return $return;
   }
 
   /**
Index: includes/database/log.inc
===================================================================
RCS file: includes/database/log.inc
diff -N includes/database/log.inc
--- /dev/null	1 Jan 1970 00:00:00 -0000
+++ includes/database/log.inc	20 Sep 2008 23:27:09 -0000
@@ -0,0 +1,156 @@
+<?php
+// $Id: $
+
+/**
+ * @file
+ * Logging classes for the database layer.
+ */
+
+/**
+ * Database query logger.
+ *
+ * We log queries in a separate object rather than in the connection object
+ * because we want to be able to see all queries sent to a given database, not
+ * database target.  If we logged the queries in each connection object we
+ * would not be able to track what queries went to which target.
+ */
+class DatabaseLog {
+
+  /**
+   * Cache of logged queries.  This will only be used if the query logger is enabled.
+   *
+   * The structure for the logging array is as follows:
+   *
+   * array(
+   *   $logging_key = array(
+   *     array(query => '', args => array(), caller => '', target => '', time => 0),
+   *     array(query => '', args => array(), caller => '', target => '', time => 0),
+   *   ),
+   * );
+   *
+   * @var array
+   */
+  protected $queryLog = array();
+
+  /**
+   * The connection key for which this object is logging.
+   *
+   * @var string
+   */
+  protected $connectionKey = 'default';
+
+  /**
+   * Constructor.
+   *
+   * @param $key
+   *   The database connection key for which to enable logging.
+   */
+  public function __construct($key = 'default') {
+    $this->connectionKey = $key;
+  }
+
+  /**
+   * Begin logging queries to the specified connection and logging key.
+   *
+   * If the specified logging key is already running this method does nothing.
+   *
+   * @param $logging_key
+   *   The identification key for this log request.  By specifying different
+   *   logging keys we are able to start and stop multiple logging runs
+   *   simultaneously without them colliding.
+   */
+  public function start($logging_key) {
+    if (empty($this->queryLog[$logging_key])) {
+      $this->clear($logging_key);
+    }
+  }
+
+  /**
+   * Retrieve the query log for the specified logging key so far.
+   *
+   * @param $logging_key
+   *   The logging key to fetch.
+   * @return
+   *   An indexed array of all query records for this logging key.
+   */
+  public function get($logging_key) {
+    return $this->queryLog[$logging_key];
+  }
+
+  /**
+   * Empty the query log for the specified logging key.
+   *
+   * This method does not stop logging, it simply clears the log.  To stop
+   * logging, use the end() method.
+   *
+   * @param $logging_key
+   *   The logging key to empty.
+   */
+  public function clear($logging_key) {
+    $this->queryLog[$logging_key] = array();
+  }
+
+  /**
+   * Stop logging for the specified logging key.
+   *
+   * @param $logging_key
+   *   The logging key to stop.
+   */
+  public function end($logging_key) {
+    unset($this->queryLog[$logging_key]);
+  }
+
+  /**
+   * Log a query to all active logging keys.
+   *
+   * @param $statement
+   *   The prepared statement object to log.
+   * @param $args
+   *   The arguments passed to the statement object.
+   * @param $time
+   *   The time in milliseconds the query took to execute.
+   */
+  public function log(DatabaseStatement $statement, $args, $time) {
+    foreach (array_keys($this->queryLog) as $key) {
+      $this->queryLog[$key][] = array(
+        'query' => $statement->queryString,
+        'args' => $args,
+        'target' => $statement->dbh->getTarget(),
+        'caller' => $this->findCaller(),
+        'time' => $time,
+      );
+    }
+  }
+
+  /**
+   * Determine the routine that called this query.
+   *
+   * We define "the routine that called this query" as the first entry in
+   * the call stack that is not inside includes/database.  That makes the
+   * climbing logic very simple, and handles the variable stack depth caused
+   * by the query builders.
+   *
+   * @link http://www.php.net/debug_backtrace
+   * @return
+   *   This method returns a stack trace entry similar to that generated by
+   *   debug_backtrace().  However, it flattens the trace entry and the trace
+   *   entry before it so that we get the function and args of the function that
+   *   called into the database system, not the function and args of the
+   *   database call itself.
+   */
+  public function findCaller() {
+    $stack = debug_backtrace();
+    $stack_count = count($stack);
+    for ($i = 0; $i < $stack_count; ++$i) {
+      if (strpos($stack[$i]['file'], 'includes/database') === FALSE) {
+        return array(
+          'file' => $stack[$i]['file'],
+          'line' => $stack[$i]['line'],
+          'function' => $stack[$i + 1]['function'],
+          'args' => $stack[$i + 1]['args'],
+        );
+        return $stack[$i];
+      }
+    }
+  }
+}
Index: modules/simpletest/tests/database_test.test
===================================================================
RCS file: /cvs/drupal/drupal/modules/simpletest/tests/database_test.test,v
retrieving revision 1.4
diff -u -p -r1.4 database_test.test
--- modules/simpletest/tests/database_test.test	15 Sep 2008 20:48:09 -0000	1.4
+++ modules/simpletest/tests/database_test.test	20 Sep 2008 23:27:09 -0000
@@ -1569,3 +1569,71 @@ class DatabaseAlter2TestCase extends Dat
     }
   }
 }
+
+/**
+ * Query logging tests.
+ */
+class DatabaseLoggingTestCase extends DatabaseTestCase {
+
+  function getInfo() {
+    return array(
+      'name' => t('Query logging'),
+      'description' => t('Test the query logging facility.'),
+      'group' => t('Database'),
+    );
+  }
+
+  /**
+   * Test that we can log the existence of a query.
+   */
+  function testEnableLogging() {
+    try {
+      Database::startLog('testing');
+
+      db_query("SELECT name FROM {test} WHERE age > :age", array(':age' => 25))->fetchCol();
+      db_query("SELECT age FROM {test} WHERE name > :name", array(':name' => 'Ringo'))->fetchCol();
+
+      $queries = Database::getLog('testing', 'default');
+
+      // For debugging, since SimpleTest offers no good debugging mechanism (irony!).
+      // $this->pass(print_r($queries, 1));
+
+      $this->assertEqual(count($queries), 2, 'Correct number of queries recorded.');
+
+      foreach ($queries as $query) {
+        $this->assertEqual($query['caller']['function'], __FUNCTION__, "Correct function in query log.");
+      }
+
+      // For debugging, since SimpleTest offers no good debugging meachnism (irony!)
+      $this->pass(print_r($_SESSION['lg_debug'], 1));
+      $_SESSION['lg_debug'] = array();
+    }
+    catch(Exception $e) {
+      $this->assertTrue(FALSE, $e->getMessage());
+    }
+  }
+
+  /**
+   * Test that we can run two logs in parallel.
+   */
+  function testEnableMultiLogging() {
+    try {
+      Database::startLog('testing1');
+
+      db_query("SELECT name FROM {test} WHERE age > :age", array(':age' => 25))->fetchCol();
+
+      Database::startLog('testing2');
+
+      db_query("SELECT age FROM {test} WHERE name > :name", array(':name' => 'Ringo'))->fetchCol();
+
+      $queries1 = Database::getLog('testing1');
+      $queries2 = Database::getLog('testing2');
+
+      $this->assertEqual(count($queries1), 2, 'Correct number of queries recorded for log 1.');
+      $this->assertEqual(count($queries2), 1, 'Correct number of queries recorded for log 2.');
+    }
+    catch(Exception $e) {
+      $this->assertTrue(FALSE, $e->getMessage());
+    }
+  }
+}