From 498c933fe8a1aee0a759374090512871b5332124 Mon Sep 17 00:00:00 2001 From: Bob Vincent Date: Sat, 24 Mar 2012 11:06:48 -0400 Subject: [PATCH] Issue #1492898 by pfournier, adharris, pillarsdotnet: A bad call to watchdog should not break the error logging system. --- core/includes/bootstrap.inc | 11 ++++++++++ core/modules/dblog/dblog.admin.inc | 33 +++++++++++++++++++++++++++++- core/modules/dblog/dblog.test | 39 +++++++++++++++++++++++++++++++++++- 3 files changed, 81 insertions(+), 2 deletions(-) diff --git a/core/includes/bootstrap.inc b/core/includes/bootstrap.inc index c26ec86293be5eac7a4bab8b336a50514258b252..066e387494cc7da2e3ddd45e1913d35f6db74731 100644 --- a/core/includes/bootstrap.inc +++ b/core/includes/bootstrap.inc @@ -1585,6 +1585,17 @@ function watchdog($type, $message, $variables = array(), $severity = WATCHDOG_NO if (!$in_error_state && function_exists('module_implements')) { $in_error_state = TRUE; + // Perform a sanity check on input data and abort immediately if it is not + // valid, so that improper calls to watchdog() may be found and fixed. + if (isset($variables) && !is_array($variables)) { + throw new Exception('The third parameter to watchdog() must be NULL or an array.'); + } + else { + $levels = array(WATCHDOG_EMERGENCY, WATCHDOG_ALERT, WATCHDOG_CRITICAL, WATCHDOG_ERROR, WATCHDOG_WARNING, WATCHDOG_NOTICE, WATCHDOG_INFO, WATCHDOG_DEBUG); + if (!in_array($severity, $levels)) { + throw new Exception('The fourth parameter to watchdog() must be a valid logging severity level constant.'); + } + } // Prepare the fields to be logged $log_entry = array( 'type' => $type, diff --git a/core/modules/dblog/dblog.admin.inc b/core/modules/dblog/dblog.admin.inc index b2da7eddf2d3963c8765ebffa6edf373eef4c1a4..6616fc15e4448b8a46de6cfe73132b34783c41d8 100644 --- a/core/modules/dblog/dblog.admin.inc +++ b/core/modules/dblog/dblog.admin.inc @@ -6,6 +6,34 @@ */ /** + * Perform sanity check on retrieved dblog data. + * + * @param object $dblog + * An object representing a single row from the watchdog table. + */ +function dblog_sanity_check($dblog) { + $errors = array('', 'Data errors:'); + $variables = @unserialize($dblog->variables); + if (!is_array($variables)) { + if (isset($variables)) { + $errors[] = t('The variables value "@variables" is not a serialized array.', array('@variables' => $dblog->variables)); + } + $variables = array(); + } + $levels = array(WATCHDOG_EMERGENCY, WATCHDOG_ALERT, WATCHDOG_CRITICAL, WATCHDOG_ERROR, WATCHDOG_WARNING, WATCHDOG_NOTICE, WATCHDOG_INFO, WATCHDOG_DEBUG); + if (!in_array($dblog->severity, $levels)) { + $errors[] = t('The severity value !severity is not a valid logging severity level.', array('!severity' => $dblog->severity)); + $dblog->severity = WATCHDOG_ERROR; + } + if (count($errors) > 2) { + $key = '!DBLOG_INVALID_VARIABLES'; + $dblog->message .= $key; + $variables[$key] = implode('
', $errors); + $dblog->variables = serialize($variables); + } +} + +/** * Menu callback; displays a listing of log messages. * * Messages are truncated at 56 chars. Full-length message could be viewed at @@ -51,6 +79,7 @@ function dblog_overview() { ->execute(); foreach ($result as $dblog) { + dblog_sanity_check($dblog); $rows[] = array('data' => array( // Cells @@ -99,7 +128,7 @@ function dblog_top($type) { $query = db_select('watchdog', 'w')->extend('PagerDefault')->extend('TableSort'); $query->addExpression('COUNT(wid)', 'count'); $query = $query - ->fields('w', array('message', 'variables')) + ->fields('w', array('severity', 'message', 'variables')) ->condition('w.type', $type) ->groupBy('message') ->groupBy('variables') @@ -110,6 +139,7 @@ function dblog_top($type) { $rows = array(); foreach ($result as $dblog) { + dblog_sanity_check($dblog); $rows[] = array($dblog->count, theme('dblog_message', array('event' => $dblog))); } @@ -131,6 +161,7 @@ function dblog_event($id) { $severity = watchdog_severity_levels(); $result = db_query('SELECT w.*, u.name, u.uid FROM {watchdog} w INNER JOIN {users} u ON w.uid = u.uid WHERE w.wid = :id', array(':id' => $id))->fetchObject(); if ($dblog = $result) { + dblog_sanity_check($dblog); $rows = array( array( array('data' => t('Type'), 'header' => TRUE), diff --git a/core/modules/dblog/dblog.test b/core/modules/dblog/dblog.test index e3a997e258395268d3c8591435b051450c74488a..eb33250dfc68119e7e31a9cc4f12aa0c5de6a0c8 100644 --- a/core/modules/dblog/dblog.test +++ b/core/modules/dblog/dblog.test @@ -48,6 +48,43 @@ class DBLogTestCase extends DrupalWebTestCase { } /** + * Test passing improper $variables parameter to watchdog function. + */ + function testImproperWatchdogVariables() { + // Log in the admin user so we can view the dblog. + $this->drupalLogin($this->big_user); + $random_type = $this->randomString(10); + $random_message = $this->randomString(10); + $assertion = 'Calling watchdog with a scalar third parameter should fail.'; + try { + watchdog($random_type, $random_message, WATCHDOG_ERROR); + $this->fail($assertion); + } + catch (Exception $e) { + $this->pass($assertion); + } + // Check whether the dblog is still viewable. + $this->drupalGet('admin/reports/dblog'); + $this->assertResponse(200); + $this->assertText('Recent log messages', 'The dblog is viewable after an improper watchdog call.'); + // Manually insert bad data into the watchdog table. + db_insert('watchdog') + ->fields(array( + 'type' => 'test', + 'message' => 'Test Watchdog message with bad data.', + 'variables' => 'This is not a serialized array.', + 'severity' => WATCHDOG_DEBUG + 1, + 'location' => 'This is not a valid url.', + 'hostname' => 'This is not a valid hostname.' + )) + ->execute(); + // Check whether the dblog is still viewable. + $this->drupalGet('admin/reports/dblog'); + $this->assertResponse(200); + $this->assertText('Recent log messages', 'The dblog is viewable after bad data has been inserted into the watchdog table.'); + } + + /** * Verify setting of the dblog row limit. * * @param integer $count Log row limit. @@ -472,7 +509,7 @@ class DBLogTestCase extends DrupalWebTestCase { $count = $this->getTypeCount($types); $this->assertEqual(array_sum($count), $type['count'], 'Count matched'); } - + // Clear all logs and make sure the confirmation message is found. $this->drupalPost('admin/reports/dblog', array(), t('Clear log messages')); $this->assertText(t('Database log cleared.'), t('Confirmation message found')); -- 1.7.5.4