From: nickw Date: Fri, 16 Oct 2009 22:53:22 +0000 (+0000) Subject: Rewriting core debug messages to be more informative. X-Git-Url: https://gitweb.fluxo.info/?a=commitdiff_plain;h=a61b62e592380fa3be7e4ff812f3e514afabd321;p=lorea%2Felgg.git Rewriting core debug messages to be more informative. Introducing the concept of levels for Elgg debugging: notices, warnings and errors are displayed when the appropriate debugging level is enabled. An additional level of "debug" exists to differentiate from errors. git-svn-id: http://code.elgg.org/elgg/trunk@3560 36083f99-b078-4883-b0ff-0f9b5a30f544 --- diff --git a/engine/lib/api.php b/engine/lib/api.php index 53af1af67..301922636 100644 --- a/engine/lib/api.php +++ b/engine/lib/api.php @@ -104,7 +104,7 @@ abstract class GenericResult { $result->result = $resultdata; } - if ((isset($CONFIG->debug)) && ($CONFIG->debug == true)) { + if (isset($CONFIG->debug)) { if (count($ERRORS)) { $result->runtime_errors = $ERRORS; } @@ -656,9 +656,7 @@ function map_api_hash($algo) { function calculate_hmac($algo, $time, $api_key, $secret_key, $get_variables, $post_hash = "") { global $CONFIG; - if ((isset($CONFIG)) && ($CONFIG->debug)) { - error_log("HMAC Parts: $algo, $time, $api_key, $secret_key, $get_variables, $post_hash"); - } + elgg_log("HMAC Parts: $algo, $time, $api_key, $secret_key, $get_variables, $post_hash"); $ctx = hash_init(map_api_hash($algo), HASH_HMAC, $secret_key); @@ -1115,9 +1113,7 @@ function send_api_call(array $keys, $url, array $call, $method = 'GET', $post_da $context = stream_context_create($opts); // Send the query and get the result and decode. - if ((isset($CONFIG->debug)) && ($CONFIG->debug)) { - error_log("APICALL: $url"); - } + elgg_log("APICALL: $url"); $APICLIENT_LAST_CALL_RAW = file_get_contents($url, false, $context); $APICLIENT_LAST_CALL = unserialize($APICLIENT_LAST_CALL_RAW); diff --git a/engine/lib/database.php b/engine/lib/database.php index 0faa6f029..96dac3846 100644 --- a/engine/lib/database.php +++ b/engine/lib/database.php @@ -11,7 +11,6 @@ * @link http://elgg.org/ */ -$DB_PROFILE = array(); $DB_QUERY_CACHE = array(); $DB_DELAYED_QUERIES = array(); @@ -51,7 +50,7 @@ function establish_db_link($dblinkname = "readwrite") { // Connect to database if (!$dblink[$dblinkname] = mysql_connect($CONFIG->dbhost, $CONFIG->dbuser, $CONFIG->dbpass, true)) { $msg = sprintf(elgg_echo('DatabaseException:WrongCredentials'), - $CONFIG->dbuser, $CONFIG->dbhost, $CONFIG->debug ? $CONFIG->dbpass : "****"); + $CONFIG->dbuser, $CONFIG->dbhost, "****"); throw new DatabaseException($msg); } if (!mysql_select_db($CONFIG->dbname, $dblink[$dblinkname])) { @@ -92,20 +91,9 @@ function setup_db_connections() { * Shutdown hook to display profiling information about db (debug mode) */ function db_profiling_shutdown_hook() { - global $CONFIG, $DB_PROFILE, $dbcalls; - - if (isset($CONFIG->debug) && $CONFIG->debug) { - error_log("***************** DB PROFILING ********************"); - - $DB_PROFILE = array_count_values($DB_PROFILE); - - foreach ($DB_PROFILE as $k => $v) { - error_log("$v times: '$k' "); - } - - error_log("DB Queries for this page: $dbcalls"); - error_log("***************************************************"); - } + global $dbcalls; + + elgg_log("DB Queries for this page: $dbcalls", 'DEBUG'); } /** @@ -123,7 +111,7 @@ function db_delayedexecution_shutdown_hook() { $query_details['h']($result); } } catch (Exception $e) { // Suppress all errors since these can't be delt with here - if (isset($CONFIG->debug) && $CONFIG->debug) { + if (isset($CONFIG->debug)) { error_log($e); } } @@ -183,13 +171,10 @@ function explain_query($query, $link) { * @return Returns a the result of mysql_query */ function execute_query($query, $dblink) { - global $CONFIG, $dbcalls, $DB_PROFILE, $DB_QUERY_CACHE; + global $CONFIG, $dbcalls, $DB_QUERY_CACHE; $dbcalls++; - //if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) - $DB_PROFILE[] = $query; - $result = mysql_query($query, $dblink); if ($DB_QUERY_CACHE) { $DB_QUERY_CACHE[$query] = -1; // Set initial cache to -1 @@ -265,9 +250,7 @@ function get_data($query, $callback = "") { } if ((isset($cached_query)) && ($cached_query)) { - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log ("$query results returned from cache"); - } + elgg_log("$query results returned from cache"); if ($cached_query === -1) { // Last time this query returned nothing, so return an empty array @@ -292,19 +275,14 @@ function get_data($query, $callback = "") { } if (empty($resultarray)) { - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("WARNING: DB query \"$query\" returned no results."); - return false; - } - } - - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("$query results cached"); + elgg_log("DB query \"$query\" returned no results."); + return false; } // Cache result if ($DB_QUERY_CACHE) { $DB_QUERY_CACHE[$query] = $resultarray; + elgg_log("$query results cached"); } return $resultarray; @@ -325,9 +303,7 @@ function get_data_row($query, $callback = "") { } if ((isset($cached_query)) && ($cached_query)) { - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log ("$query results returned from cache"); - } + elgg_log("$query results returned from cache"); if ($cached_query === -1) { // Last time this query returned nothing, so return false @@ -344,12 +320,9 @@ function get_data_row($query, $callback = "") { $row = mysql_fetch_object($result); // Cache result (even if query returned no data) - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("$query results cached"); - } - if ($DB_QUERY_CACHE) { $DB_QUERY_CACHE[$query] = $row; + elgg_log("$query results cached"); } if (!empty($callback) && is_callable($callback)) { @@ -361,11 +334,8 @@ function get_data_row($query, $callback = "") { } } - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("WARNING: DB query \"$query\" returned no results."); - } - - return false; + elgg_log("$query returned no results."); + return FALSE; } /** @@ -384,9 +354,7 @@ function insert_data($query) { $DB_QUERY_CACHE->clear(); } - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("Query cache invalidated"); - } + elgg_log("Query cache invalidated"); if (execute_query("$query", $dblink)) { return mysql_insert_id($dblink); @@ -409,10 +377,7 @@ function update_data($query) { // Invalidate query cache if ($DB_QUERY_CACHE) { $DB_QUERY_CACHE->clear(); - } - - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("Query cache invalidated"); + elgg_log("Query cache invalidated"); } if (execute_query("$query", $dblink)) { @@ -438,10 +403,7 @@ function delete_data($query) { // Invalidate query cache if ($DB_QUERY_CACHE) { $DB_QUERY_CACHE->clear(); - } - - if ((isset($CONFIG->debug)) && ($CONFIG->debug==true)) { - error_log("Query cache invalidated"); + elgg_log("Query cache invalidated"); } if (execute_query("$query", $dblink)) { diff --git a/engine/lib/elgglib.php b/engine/lib/elgglib.php index f0a0b2582..36e87eca9 100644 --- a/engine/lib/elgglib.php +++ b/engine/lib/elgglib.php @@ -256,22 +256,20 @@ function elgg_view($view, $vars = "", $bypass = false, $debug = false, $viewtype foreach($viewlist as $priority => $view) { $view_location = elgg_get_view_location($view, $viewtype); - if (file_exists($view_location . "{$viewtype}/{$view}.php") - && !include($view_location . "{$viewtype}/{$view}.php")) { + if (file_exists("$view_location$viewtype/$view.php") + && !include("$view_location$viewtype/$view.php")) { $success = false; if ($viewtype != "default") { - if (include($view_location . "default/{$view}.php")) { + if (include("{$view_location}default/$view.php")) { $success = true; } } - if (!$success && isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log(" [This view ({$view}) does not exist] "); + if (!$success) { + elgg_log(" [This view ($view) does not exist] ", 'ERROR'); } - } else if (isset($CONFIG->debug) && $CONFIG->debug == true - && !file_exists($view_location . "{$viewtype}/{$view}.php")) { - error_log($view_location . "{$viewtype}/{$view}.php"); - error_log(" [This view ({$view}) does not exist] "); + } else if (!file_exists("$view_location$viewtype/$view.php")) { + elgg_log(" [This view ($view) does not exist] ", 'WARNING'); } } @@ -1711,12 +1709,12 @@ function trigger_plugin_hook($hook, $entity_type, $params = null, $returnvalue = * @param array $vars An array that points to the active symbol table at the point that the error occurred */ function __elgg_php_error_handler($errno, $errmsg, $filename, $linenum, $vars) { - $error = date("Y-m-d H:i:s (T)") . ": \"" . $errmsg . "\" in file " . $filename . " (line " . $linenum . ")"; + $error = date("Y-m-d H:i:s (T)") . ": \"$errmsg\" in file $filename (line $linenum)"; switch ($errno) { case E_USER_ERROR: - error_log("ERROR: " . $error); - register_error("ERROR: " . $error); + error_log("ERROR: $error"); + register_error("ERROR: $error"); // Since this is a fatal error, we want to stop any further execution but do so gracefully. throw new Exception($error); @@ -1724,21 +1722,77 @@ function __elgg_php_error_handler($errno, $errmsg, $filename, $linenum, $vars) { case E_WARNING : case E_USER_WARNING : - error_log("WARNING: " . $error); - // register_error("WARNING: " . $error); + error_log("WARNING: $error"); break; default: global $CONFIG; if (isset($CONFIG->debug)) { - error_log("DEBUG: " . $error); + error_log("NOTICE: $error"); } - // register_error("DEBUG: " . $error); } return true; } +/** + * Throws a message to the Elgg logger + * + * The Elgg log is currently implemented such that any messages sent at a level + * greater than or equal to the debug setting will be dumped to the screen. + * + * Note: No messages will be displayed unless debugging has been enabled. + * + * @param str $message User message + * @param str $level NOTICE | WARNING | ERROR | DEBUG + * @return bool + */ +function elgg_log($message, $level='NOTICE') { + global $CONFIG; + + // only log when debugging is enabled + if (isset($CONFIG->debug)) { + switch ($level) { + case 'DEBUG': + case 'ERROR': + // always report + elgg_dump("$level: $message"); + break; + case 'WARNING': + // report execept if user wants only errors + if ($config->debug != 'ERROR') { + elgg_dump("$level: $message"); + } + break; + case 'NOTICE': + default: + // only report when lowest level is desired + if ($config->debug == 'NOTICE') { + elgg_dump("$level: $message"); + } + break; + } + + return TRUE; + } + + return FALSE; +} + +/** + * Extremely generic var_dump-esque wrapper + * + * Immediately dumps the given $value to the screen as a human-readable string. + * + * @param mixed $value + * @return void + */ +function elgg_dump($value) { + echo '
';
+	print_r($value);
+	echo '
'; +} + /** * Custom exception handler. * This function catches any thrown exceptions and handles them appropriately. @@ -2015,7 +2069,7 @@ function callpath_gatekeeper($path, $include_subdirs = true, $strict_mode = fals return false; } - if ($CONFIG->debug) { + if (isset($CONFIG->debug)) { system_message("Gatekeeper'd function called from {$callstack[1]['file']}:{$callstack[1]['line']}\n\nStack trace:\n\n" . print_r($callstack, true)); } @@ -2263,13 +2317,12 @@ function js_page_handler($page) { * */ function __elgg_shutdown_hook() { - global $CONFIG, $START_MICROTIME; + global $START_MICROTIME; trigger_elgg_event('shutdown', 'system'); - - if ($CONFIG->debug) { - error_log("Page {$_SERVER['REQUEST_URI']} generated in ".(float)(microtime(true)-$START_MICROTIME)." seconds"); - } + + $time = (float)(microtime(TRUE) - $START_MICROTIME); + elgg_log("Page {$_SERVER['REQUEST_URI']} generated in $time seconds", 'DEBUG'); } /** diff --git a/engine/lib/entities.php b/engine/lib/entities.php index 211fbc05c..373654431 100644 --- a/engine/lib/entities.php +++ b/engine/lib/entities.php @@ -1479,27 +1479,9 @@ function get_entity_as_row($guid) { } $guid = (int) $guid; - - /*$row = retrieve_cached_entity_row($guid); - if ($row) - { - // We have already cached this object, so retrieve its value from the cache - if (isset($CONFIG->debug) && $CONFIG->debug) - error_log("** Retrieving GUID:$guid from cache"); - - return $row; - } - else - {*/ - // Object not cached, load it. - if (isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log("** GUID:$guid loaded from DB"); - } - - $access = get_access_sql_suffix(); - - return get_data_row("SELECT * from {$CONFIG->dbprefix}entities where guid=$guid and $access"); - //} + $access = get_access_sql_suffix(); + + return get_data_row("SELECT * from {$CONFIG->dbprefix}entities where guid=$guid and $access"); } /** diff --git a/engine/lib/group.php b/engine/lib/group.php index 664837a27..9fc937ff3 100644 --- a/engine/lib/group.php +++ b/engine/lib/group.php @@ -318,24 +318,7 @@ function get_group_entity_as_row($guid) { $guid = (int)$guid; - /*$row = retrieve_cached_entity_row($guid); - if ($row) - { - // We have already cached this object, so retrieve its value from the cache - if (isset($CONFIG->debug) && $CONFIG->debug) - error_log("** Retrieving sub part of GUID:$guid from cache"); - - return $row; - } - else - {*/ - // Object not cached, load it. - if (isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log("** Sub part of GUID:$guid loaded from DB"); - } - return get_data_row("SELECT * from {$CONFIG->dbprefix}groups_entity where guid=$guid"); - //} } /** diff --git a/engine/lib/languages.php b/engine/lib/languages.php index 19f3c138a..898fc725f 100644 --- a/engine/lib/languages.php +++ b/engine/lib/languages.php @@ -125,10 +125,7 @@ function register_translations($path, $load_all = false) { // Get the current language based on site defaults and user preference $current_language = get_current_language(); - - if (isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log("Translations loaded from : $path"); - } + elgg_log("Translations loaded from: $path"); if ($handle = opendir($path)) { while ($language = readdir($handle)) { @@ -140,7 +137,7 @@ function register_translations($path, $load_all = false) { } } } else { - error_log("Missing translation path $path"); + elgg_log("Missing translation path $path", 'ERROR'); } } diff --git a/engine/lib/memcache.php b/engine/lib/memcache.php index 498d1ff4f..ed93cacf0 100644 --- a/engine/lib/memcache.php +++ b/engine/lib/memcache.php @@ -77,9 +77,7 @@ class ElggMemcache extends ElggSharedMemoryCache { } } } else { - if ((isset($CONFIG->debug)) && ($CONFIG->debug == true)) { - error_log(elgg_echo('memcache:noaddserver')); - } + elgg_log(elgg_echo('memcache:noaddserver'), 'ERROR'); $server = $CONFIG->memcache_servers[0]; if (is_array($server)) { @@ -131,8 +129,8 @@ class ElggMemcache extends ElggSharedMemoryCache { $key = $this->make_memcache_key($key); $result = $this->memcache->set($key, $data, null, $this->expires); - if ((isset($CONFIG->debug)) && ($CONFIG->debug == true) && (!$result)) { - error_log("MEMCACHE: FAILED TO SAVE $key"); + if (!$result) { + elgg_log("MEMCACHE: FAILED TO SAVE $key", 'ERROR'); } return $result; @@ -142,8 +140,8 @@ class ElggMemcache extends ElggSharedMemoryCache { $key = $this->make_memcache_key($key); $result = $this->memcache->get($key); - if ((isset($CONFIG->debug)) && ($CONFIG->debug == true) && (!$result)) { - error_log("MEMCACHE: FAILED TO LOAD $key"); + if (!$result) { + elgg_log("MEMCACHE: FAILED TO LOAD $key", 'ERROR'); } return $result; diff --git a/engine/lib/metastrings.php b/engine/lib/metastrings.php index 519d186e4..3e8796d3f 100644 --- a/engine/lib/metastrings.php +++ b/engine/lib/metastrings.php @@ -28,10 +28,7 @@ function get_metastring_id($string, $case_sensitive = true) { $string = sanitise_string($string); $result = array_search($string, $METASTRINGS_CACHE); if ($result!==false) { - if (isset($CONFIG->debug) && $CONFIG->debug) { - error_log("** Returning id for string:$string from cache."); - } - + elgg_log("** Returning id for string:$string from cache."); return $result; } @@ -68,9 +65,7 @@ function get_metastring_id($string, $case_sensitive = true) { $metastrings_memcache->save($row->string, $row->id); } - if (isset($CONFIG->debug) && $CONFIG->debug) { - error_log("** Cacheing string '{$row->string}'"); - } + elgg_log("** Cacheing string '{$row->string}'"); return $row->id; } else { @@ -92,9 +87,7 @@ function get_metastring($id) { $id = (int) $id; if (isset($METASTRINGS_CACHE[$id])) { - if ($CONFIG->debug) { - error_log("** Returning string for id:$id from cache."); - } + elgg_log("** Returning string for id:$id from cache."); return $METASTRINGS_CACHE[$id]; } @@ -102,10 +95,7 @@ function get_metastring($id) { $row = get_data_row("SELECT * from {$CONFIG->dbprefix}metastrings where id='$id' limit 1"); if ($row) { $METASTRINGS_CACHE[$id] = $row->string; // Cache it - - if ($CONFIG->debug) { - error_log("** Cacheing string '{$row->string}'"); - } + elgg_log("** Cacheing string '{$row->string}'"); return $row->string; } diff --git a/engine/lib/notification.php b/engine/lib/notification.php index 6284e874d..ad65455f3 100644 --- a/engine/lib/notification.php +++ b/engine/lib/notification.php @@ -109,9 +109,7 @@ function notify_user($to, $from, $subject, $message, array $params = NULL, $meth error_log(sprintf(elgg_echo('NotificationException:NoHandlerFound'), $method)); } - if ($CONFIG->debug) { - error_log("Sending message to $guid using $method"); - } + elgg_log("Sending message to $guid using $method"); // Trigger handler and retrieve result. try { diff --git a/engine/lib/objects.php b/engine/lib/objects.php index a81925ce1..7e21550aa 100644 --- a/engine/lib/objects.php +++ b/engine/lib/objects.php @@ -215,25 +215,7 @@ function get_object_entity_as_row($guid) { global $CONFIG; $guid = (int)$guid; - - /*$row = retrieve_cached_entity_row($guid); - if ($row) - { - // We have already cached this object, so retrieve its value from the cache - if (isset($CONFIG->debug) && $CONFIG->debug) - error_log("** Retrieving sub part of GUID:$guid from cache"); - - return $row; - } - else - {*/ - // Object not cached, load it. - if ($CONFIG->debug) { - error_log("** Sub part of GUID:$guid loaded from DB"); - } - - return get_data_row("SELECT * from {$CONFIG->dbprefix}objects_entity where guid=$guid"); - //} + return get_data_row("SELECT * from {$CONFIG->dbprefix}objects_entity where guid=$guid"); } /** diff --git a/engine/lib/sites.php b/engine/lib/sites.php index 7a1375d46..d38113d27 100644 --- a/engine/lib/sites.php +++ b/engine/lib/sites.php @@ -252,25 +252,7 @@ function get_site_entity_as_row($guid) { global $CONFIG; $guid = (int)$guid; - - /*$row = retrieve_cached_entity_row($guid); - if ($row) - { - // We have already cached this object, so retrieve its value from the cache - if (isset($CONFIG->debug) && $CONFIG->debug) - error_log("** Retrieving sub part of GUID:$guid from cache"); - - return $row; - } - else - {*/ - // Object not cached, load it. - if (isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log("** Sub part of GUID:$guid loaded from DB"); - } - return get_data_row("SELECT * from {$CONFIG->dbprefix}sites_entity where guid=$guid"); - //} } /** diff --git a/engine/lib/users.php b/engine/lib/users.php index 7d1fa3d58..29a2dd42f 100644 --- a/engine/lib/users.php +++ b/engine/lib/users.php @@ -372,26 +372,8 @@ class ElggUser extends ElggEntity function get_user_entity_as_row($guid) { global $CONFIG; - /*$row = retrieve_cached_entity_row($guid); - if ($row) - { - // We have already cached this object, so retrieve its value from the cache - if (isset($CONFIG->debug) && $CONFIG->debug == true) - error_log("** Retrieving sub part of GUID:$guid from cache"); - - return $row; - } - else - {*/ - // Object not cached, load it. - if (isset($CONFIG->debug) && $CONFIG->debug == true) { - error_log("** Sub part of GUID:$guid loaded from DB"); - } - $guid = (int)$guid; - return get_data_row("SELECT * from {$CONFIG->dbprefix}users_entity where guid=$guid"); - //} } /** diff --git a/engine/start.php b/engine/start.php index b6699309b..7caa35b0f 100644 --- a/engine/start.php +++ b/engine/start.php @@ -133,9 +133,7 @@ if ($sanitised = sanitised()) { // Include them foreach($files as $file) { - if (isset($CONFIG->debug) && $CONFIG->debug) { - error_log("Loading $file..."); - } + elgg_log("Loading $file..."); if (!include_once($file)) { throw new InstallationException("Could not load {$file}"); } diff --git a/engine/tests/suite.php b/engine/tests/suite.php index 01056a218..c3de185ff 100755 --- a/engine/tests/suite.php +++ b/engine/tests/suite.php @@ -28,19 +28,19 @@ foreach ($test_files as $file) { } // Only run tests in debug mode. -if ($CONFIG->debug > 0) { - if (TextReporter::inCli()) { - // In CLI error codes are returned. - // 0 is success. - elgg_set_ignore_access(TRUE); - exit ($suite->Run(new TextReporter()) ? 0 : 1 ); - } - // Ensure that only logged-in users can see this page - //admin_gatekeeper(); - $old = elgg_set_ignore_access(TRUE); - $suite->Run(new HtmlReporter()); - elgg_set_ignore_access($old); -} else { +if (!isset($CONFIG->debug)) { // @todo display an error? exit (1); } + +if (TextReporter::inCli()) { + // In CLI error codes are returned: 0 is success + elgg_set_ignore_access(TRUE); + exit ($suite->Run(new TextReporter()) ? 0 : 1 ); +} + +// Ensure that only logged-in users can see this page +//admin_gatekeeper(); +$old = elgg_set_ignore_access(TRUE); +$suite->Run(new HtmlReporter()); +elgg_set_ignore_access($old); diff --git a/views/default/messages/exceptions/exception.php b/views/default/messages/exceptions/exception.php index c93883cbc..65ec7cdbf 100644 --- a/views/default/messages/exceptions/exception.php +++ b/views/default/messages/exceptions/exception.php @@ -24,7 +24,7 @@ $body = <<< END

END; -if ($CONFIG->debug) { +if (isset($CONFIG->debug)) { $details = elgg_view('output/longtext', array('value' => htmlentities(print_r($vars['object'], true), ENT_QUOTES, 'UTF-8'))); $body .= <<< END
diff --git a/views/failsafe/messages/exceptions/exception.php b/views/failsafe/messages/exceptions/exception.php index f6fb4d144..d3877f0c8 100644 --- a/views/failsafe/messages/exceptions/exception.php +++ b/views/failsafe/messages/exceptions/exception.php @@ -24,7 +24,7 @@ global $CONFIG;

-debug) { ?> +debug)) { ?>