Fix ticket 1816: Database errors recorded as "Array"

PEAR error backtrace lines are now correctly formatted as strings in debug log, roughly as debug_print_backtrace() does (but with argument values swapped out for types to avoid being overly verbose).

Todo: exceptions and PEAR error objects should log backtraces the same way; right now it doesn't look like exceptions get backtraces logged.

Todo: At one line per line, it's potentially tough to figure out what backtrace goes with what event if traffic is heavy; even if not heavy it's awkward to jump back into a log file after grepping to find the backtrace. Consider using a random per-event ID which can go in the log output -- bonus points for exposing the error ID to users so ops can track down actual error details in logs from a user report.

diff --git a/index.php b/index.php
index 577b491ed05b677dc9480d27fd04cdafe4a7fa21..997ee6197f27a1b55e222dc932def5f24a4dbd79 100644 (file)
--- a/index.php
+++ b/index.php
@@ -76,11 +76,16 @@ function handleError($error)
     if (common_config('site', 'logdebug')) {
         $logmsg .= " : ". $error->getDebugInfo();
     }
+    // DB queries often end up with a lot of newlines; merge to a single line
+    // for easier grepability...
+    $logmsg = str_replace("\n", " ", $logmsg);
     common_log(LOG_ERR, $logmsg);
+
+    // @fixme backtrace output should be consistent with exception handling
     if (common_config('site', 'logdebug')) {
         $bt = $error->getBacktrace();
-        foreach ($bt as $line) {
-            common_log(LOG_ERR, $line);
+        foreach ($bt as $n => $line) {
+            common_log(LOG_ERR, formatBacktraceLine($n, $line));
         }
     }
     if ($error instanceof DB_DataObject_Error
@@ -109,6 +114,38 @@ function handleError($error)
     exit(-1);
 }
 
+/**
+ * Format a backtrace line for debug output roughly like debug_print_backtrace() does.
+ * Exceptions already have this built in, but PEAR error objects just give us the array.
+ *
+ * @param int $n line number
+ * @param array $line per-frame array item from debug_backtrace()
+ * @return string
+ */
+function formatBacktraceLine($n, $line)
+{
+    $out = "#$n ";
+    if (isset($line['class'])) $out .= $line['class'];
+    if (isset($line['type'])) $out .= $line['type'];
+    if (isset($line['function'])) $out .= $line['function'];
+    $out .= '(';
+    if (isset($line['args'])) {
+        $args = array();
+        foreach ($line['args'] as $arg) {
+            // debug_print_backtrace seems to use var_export
+            // but this gets *very* verbose!
+            $args[] = gettype($arg);
+        }
+        $out .= implode(',', $args);
+    }
+    $out .= ')';
+    $out .= ' called at [';
+    if (isset($line['file'])) $out .= $line['file'];
+    if (isset($line['line'])) $out .= ':' . $line['line'];
+    $out .= ']';
+    return $out;
+}
+
 function checkMirror($action_obj, $args)
 {
     global $config;