- Patch #711108 by Berdir: better exception reporting for watchdog() in the database system.

8 files changed, 63 insertions, 195 deletions

diff --git a/includes/bootstrap.inc b/includes/bootstrap.inc
index 8fc1e0754..209a6abe8 100644
--- a/includes/bootstrap.inc
+++ b/includes/bootstrap.inc
@@ -1535,6 +1535,46 @@ function request_uri() {
 }
 
 /**
+ * Log an exception.
+ *
+ * This is a wrapper function for watchdog() which automatically decodes an
+ * exception.
+ *
+ * @param $type
+ *   The category to which this message belongs.
+ * @param $exception
+ *   The exception that is going to be logged.
+ * @param $message
+ *   The message to store in the log. If empty, a text that contains all useful
+ *   information about the passed in exception is used.
+ * @param $variables
+ *   Array of variables to replace in the message on display. Defaults to the
+ *   return value of drupal_decode_exception().
+ * @param $severity
+ *   The severity of the message, as per RFC 3164.
+ * @param $link
+ *   A link to associate with the message.
+ *
+ * @see watchdog()
+ * @see drupal_decode_exception()
+ */
+function watchdog_exception($type, Exception $exception, $message = NULL, $variables = array(), $severity = WATCHDOG_ERROR, $link = NULL) {
+
+   // Use a default value if $message is not set.
+   if (empty($message)) {
+     $message = '%type: %message in %function (line %line of %file).';
+   }
+   // $variables must be an array so that we can add the exception information.
+   if (!is_array($variables)) {
+     $variables = array();
+   }
+
+   require_once DRUPAL_ROOT . '/includes/errors.inc';
+   $variables += _drupal_decode_exception($exception);
+   watchdog($type, $message, $variables, $severity, $link);
+}
+
+/**
  * Log a system message.
  *
  * @param $type
@@ -1556,8 +1596,6 @@ function request_uri() {
  *
  * @see watchdog_severity_levels()
  * @see hook_watchdog()
- * @see DatabaseConnection::rollback()
- * @see DatabaseTransaction::rollback()
  */
 function watchdog($type, $message, $variables = array(), $severity = WATCHDOG_NOTICE, $link = NULL) {
   global $user, $base_root;
@@ -2105,9 +2143,6 @@ function _drupal_bootstrap_database() {
   // won't be initialized until it is actually requested.
   require_once DRUPAL_ROOT . '/includes/database/database.inc';
 
-  // Set Drupal's watchdog as the logging callback.
-  Database::setLoggingCallback('watchdog', WATCHDOG_NOTICE, WATCHDOG_ERROR);
-
   // Register autoload functions so that we can access classes and interfaces.
   // The database autoload routine comes first so that we can load the database
   // system without hitting the database. That is especially important during
diff --git a/includes/database/database.inc b/includes/database/database.inc
index 2989833be..adc55e879 100644
--- a/includes/database/database.inc
+++ b/includes/database/database.inc
@@ -145,14 +145,14 @@
  *     return $id;
  *   }
  *   catch (Exception $e) {
- *     // Something went wrong somewhere, so flag the entire transaction to
- *     // roll back instead of getting committed.  It doesn't actually roll back
- *     // yet, just gets flagged to do so.
+ *     // Something went wrong somewhere, so roll back now.
  *     $txn->rollback();
+ *     // Log the exception to watchdog.
+ *     watchdog_exception('type', $e);
  *   }
  *
- *   // $txn goes out of scope here.  If there was a problem, it rolls back
- *   // automatically.  If not, it commits automatically.
+ *   // $txn goes out of scope here.  Unless the transaction was rolled back, it
+ *   // gets automatically commited here.
  * }
  *
  * function my_other_function($id) {
@@ -209,13 +209,6 @@ abstract class DatabaseConnection extends PDO {
   protected $transactionLayers = array();
 
   /**
-   * Array of argument arrays for logging post-rollback.
-   *
-   * @var array
-   */
-  protected $rollbackLogs = array();
-
-  /**
    * Index of what driver-specific class to use for various operations.
    *
    * @var array
@@ -863,26 +856,10 @@ abstract class DatabaseConnection extends PDO {
    * @param $savepoint_name
    *   The name of the savepoint. The default, 'drupal_transaction', will roll
    *   the entire transaction back.
-   * @param $type
-   *   The category to which the rollback message belongs.
-   * @param $message
-   *   The message to store in the log. Keep $message translatable
-   *   by not concatenating dynamic values into it! Variables in the
-   *   message should be added by using placeholder strings alongside
-   *   the variables argument to declare the value of the placeholders.
-   * @param $variables
-   *   Array of variables to replace in the message on display or
-   *   NULL if message is already translated or not possible to
-   *   translate.
-   * @param $severity
-   *   The severity of the message, as per RFC 3164.
-   * @param $link
-   *   A link to associate with the message.
    *
    * @see DatabaseTransaction::rollback()
-   * @see watchdog()
    */
-  public function rollback($savepoint_name = 'drupal_transaction', $type = NULL, $message = NULL, $variables = array(), $severity = NULL, $link = NULL) {
+  public function rollback($savepoint_name = 'drupal_transaction') {
     if (!$this->inTransaction()) {
       throw new DatabaseTransactionNoActiveException();
     }
@@ -892,29 +869,6 @@ abstract class DatabaseConnection extends PDO {
       return;
     }
 
-    // Set the severity to the configured default if not specified.
-    if (!isset($severity)) {
-      $logging = Database::getLoggingCallback();
-      if (is_array($logging)) {
-        $severity = $logging['default_severity'];
-      }
-    }
-
-    // Record in an array to send to the log after transaction rollback.
-    // Messages written directly to a log (with a database back-end) will roll
-    // back during the following transaction rollback. This is an array because
-    // rollback could be requested multiple times during a transaction, and all
-    // such errors ought to be logged.
-    if (isset($message)) {
-      $this->rollbackLogs[] = array(
-        'type' => $type,
-        'message' => $message,
-        'variables' => $variables,
-        'severity' => $severity,
-        'link' => $link,
-      );
-    }
-
     // We need to find the point we're rolling back to, all other savepoints
     // before are no longer needed.
     while ($savepoint = array_pop($this->transactionLayers)) {
@@ -932,37 +886,6 @@ abstract class DatabaseConnection extends PDO {
     if ($this->supportsTransactions()) {
       parent::rollBack();
     }
-    else {
-      // Log unsupported rollback.
-      $this->rollbackLogs[] = array(
-        'type' => 'database',
-        'message' => t('Explicit rollback failed: not supported on active connection.'),
-        'variables' => array(),
-      );
-    }
-    $this->logRollback();
-  }
-
-  /**
-   * Logs messages from rollback().
-   */
-  protected function logRollback() {
-    $logging = Database::getLoggingCallback();
-    // If there is no callback defined. We can't do anything.
-    if (!is_array($logging)) {
-      return;
-    }
-
-    $logging_callback = $logging['callback'];
-
-    // Play back the logged errors to the specified logging callback post-
-    // rollback.
-    foreach ($this->rollbackLogs as $log_item) {
-      call_user_func($logging_callback, $log_item['type'], $log_item['message'], $log_item['variables'], $log_item['severity'], $log_item['link']);
-    }
-
-    // Reset the error logs.
-    $this->rollbackLogs = array();
   }
 
   /**
@@ -1254,17 +1177,6 @@ abstract class Database {
   static protected $logs = array();
 
   /**
-   * A logging function callback array.
-   *
-   * The function must accept the same function signature as Drupal's
-   * watchdog(). The array contains key/value pairs for callback (string),
-   * default_severity (int), and error_severity (int).
-   *
-   * @var string
-   */
-  static protected $logging_callback = NULL;
-
-  /**
    * Starts logging a given logging key on the specified connection.
    *
    * @param $logging_key
@@ -1297,38 +1209,6 @@ abstract class Database {
   }
 
   /**
-   * Sets a logging callback for notices and errors.
-   *
-   * @param $logging_callback
-   *   The function to use as the logging callback.
-   * @param $logging_default_severity
-   *   The default severity level to use for logged messages.
-   * @param $logging_error_severity
-   *   The severity level to use for logging error messages.
-   *
-   * @see watchdog()
-   */
-  final public static function setLoggingCallback($callback, $default_severity, $error_severity) {
-    self::$logging_callback = array(
-      'callback' => $callback,
-      'default_severity' => $default_severity,
-      'error_severity' => $error_severity,
-    );
-  }
-
-  /**
-   * Gets the logging callback for notices and errors.
-   *
-   * @return
-   *   An array with the logging callback and severity levels.
-   *
-   * @see watchdog()
-   */
-  final public static function getLoggingCallback() {
-    return self::$logging_callback;
-  }
-
-  /**
    * Retrieves the queries logged on for given logging key.
    *
    * This method also ends logging for the specified key. To get the query log
@@ -1720,35 +1600,17 @@ class DatabaseTransaction {
    * Rolls back the current transaction.
    *
    * This is just a wrapper method to rollback whatever transaction stack we are
-   * currently in, which is managed by the connection object itself.
-   *
-   * @param $type
-   *   The category to which the rollback message belongs.
-   * @param $message
-   *   The message to store in the log. Keep $message translatable by not
-   *   concatenating dynamic values into it! Variables in the message should be
-   *   added by using placeholder strings alongside the variable's argument to
-   *   declare the value of the placeholders.
-   * @param $variables
-   *   Array of variables to replace in the message on display or NULL if the
-   *   message is already translated or not possible to translate.
-   * @param $severity
-   *   The severity of the message, as per RFC 3164.
-   * @param $link
-   *   A link to associate with the message.
+   * currently in, which is managed by the connection object itself. Note that
+   * logging (preferable with watchdog_exception()) needs to happen after a
+   * transaction has been rolled back or the log messages will be rolled back
+   * too.
    *
    * @see DatabaseConnection::rollback()
-   * @see watchdog()
+   * @see watchdog_exception()
    */
-  public function rollback($type = NULL, $message = NULL, $variables = array(), $severity = NULL, $link = NULL) {
+  public function rollback() {
     $this->rolledBack = TRUE;
-    if (!isset($severity)) {
-      $logging = Database::getLoggingCallback();
-      if (is_array($logging)) {
-        $severity = $logging['default_severity'];
-      }
-    }
-    $this->connection->rollback($this->name, $type, $message, $variables, $severity, $link);
+    $this->connection->rollback($this->name);
   }
 }
 
diff --git a/includes/database/sqlite/database.inc b/includes/database/sqlite/database.inc
index ba28ca63b..98ffe32d6 100644
--- a/includes/database/sqlite/database.inc
+++ b/includes/database/sqlite/database.inc
@@ -210,7 +210,7 @@ class DatabaseConnection_sqlite extends DatabaseConnection {
     return (int) $this->query('SELECT value FROM {sequences}')->fetchField();
   }
 
-  public function rollback($savepoint_name = 'drupal_transaction', $type = NULL, $message = NULL, $variables = array(), $severity = NULL, $link = NULL) {
+  public function rollback($savepoint_name = 'drupal_transaction') {
     if ($this->savepointSupport) {
       return parent::rollBack($savepoint_name, $type, $message, $variables, $severity, $link);
     }
@@ -224,29 +224,6 @@ class DatabaseConnection_sqlite extends DatabaseConnection {
       return;
     }
 
-    // Set the severity to the configured default if not specified.
-    if (!isset($severity)) {
-      $logging = Database::getLoggingCallback();
-      if (is_array($logging)) {
-        $severity = $logging['default_severity'];
-      }
-    }
-
-    // Record in an array to send to the log after transaction rollback.
-    // Messages written directly to a log (with a database back-end) will roll
-    // back during the following transaction rollback. This is an array because
-    // rollback could be requested multiple times during a transaction, and all
-    // such errors ought to be logged.
-    if (isset($message)) {
-      $this->rollbackLogs[] = array(
-        'type' => $type,
-        'message' => $message,
-        'variables' => $variables,
-        'severity' => $severity,
-        'link' => $link,
-      );
-    }
-
     // We need to find the point we're rolling back to, all other savepoints
     // before are no longer needed.
     while ($savepoint = array_pop($this->transactionLayers)) {
@@ -265,15 +242,6 @@ class DatabaseConnection_sqlite extends DatabaseConnection {
     if ($this->supportsTransactions()) {
       PDO::rollBack();
     }
-    else {
-      // Log unsupported rollback.
-      $this->rollbackLogs[] = array(
-        'type' => 'database',
-        'message' => t('Explicit rollback failed: not supported on active connection.'),
-        'variables' => array(),
-      );
-    }
-    $this->logRollback();
   }
 
   public function pushTransaction($name) {
@@ -313,7 +281,6 @@ class DatabaseConnection_sqlite extends DatabaseConnection {
         if ($this->willRollback) {
           $this->willRollback = FALSE;
           PDO::rollBack();
-          $this->logRollback();
         }
         elseif (!PDO::commit()) {
           throw new DatabaseTransactionCommitFailedException();
diff --git a/includes/menu.inc b/includes/menu.inc
index cbd2b595a..726c4df6e 100644
--- a/includes/menu.inc
+++ b/includes/menu.inc
@@ -2307,7 +2307,8 @@ function menu_rebuild() {
     }
   }
   catch (Exception $e) {
-    $transaction->rollback('menu', $e->getMessage(), array(), WATCHDOG_ERROR);
+    $transaction->rollback();
+    watchdog_exception('menu', $exception);
   }
 
   lock_release('menu_rebuild');
diff --git a/modules/comment/comment.module b/modules/comment/comment.module
index 66ccef6bc..c997ea2e5 100644
--- a/modules/comment/comment.module
+++ b/modules/comment/comment.module
@@ -1529,7 +1529,8 @@ function comment_save($comment) {
     }
   }
   catch (Exception $e) {
-    $transaction->rollback('comment', $e->getMessage(), array(), WATCHDOG_ERROR);
+    $transaction->rollback('comment');
+    watchdog_exception('comment', $e);
     throw $e;
   }
 
diff --git a/modules/node/node.module b/modules/node/node.module
index bc59ea9b3..b942e2e27 100644
--- a/modules/node/node.module
+++ b/modules/node/node.module
@@ -1090,7 +1090,8 @@ function node_save($node) {
     db_ignore_slave();
   }
   catch (Exception $e) {
-    $transaction->rollback('node', $e->getMessage(), array(), WATCHDOG_ERROR);
+    $transaction->rollback('node');
+    watchdog_exception('node', $e);
     throw $e;
   }
 }
diff --git a/modules/node/node.test b/modules/node/node.test
index db004f6b8..a2ab17308 100644
--- a/modules/node/node.test
+++ b/modules/node/node.test
@@ -490,7 +490,7 @@ class NodeCreationTestCase extends DrupalWebTestCase {
     }
 
     // Check that the rollback error was logged.
-    $records = db_query("SELECT wid FROM {watchdog} WHERE message LIKE 'Test exception for rollback.'")->fetchAll();
+    $records = db_query("SELECT wid FROM {watchdog} WHERE variables LIKE '%Test exception for rollback.%'")->fetchAll();
     $this->assertTrue(count($records) > 0, t('Rollback explanatory error logged to watchdog.'));
   }
 }
diff --git a/modules/user/user.module b/modules/user/user.module
index 0256040b7..ad580dcc3 100644
--- a/modules/user/user.module
+++ b/modules/user/user.module
@@ -548,7 +548,8 @@ function user_save($account, $edit = array(), $category = 'account') {
     return $user;
   }
   catch (Exception $e) {
-    $transaction->rollback('user', $e->getMessage(), array(), WATCHDOG_ERROR);
+    $transaction->rollback();
+    watchdog_exception('user', $e);
     throw $e;
   }
 }