fancy-debug-print.php

<?php

# originally for use in includes/bootstrap.php in Drupal but intentionally self-contained and suitable for any PHP project

# uses /**/ comments so that it can be squished into a single line for easy copy/pasting

/* intended use: l("debug message"); l(array('foo', $random_object));
/* l() was already taken */
function ll($logged_thing, $no_backtrace = false) { 
  static $req_id = 0;
  if ($req_id == 0) {
    /* make it easy to correlate entries within the same request and ensure that $req_id always has the same length so log entries line up nicely */
    $req_id = rand(10000, 99999);
  }
  $logfile = "/tmp/drupal-debug.log";
  $preamble = '';
  $preamble .= "$req_id ";
  $preamble .= "PHP ".phpversion();
  $preamble .= ' ';
  /* in case we're on a misconfigured machine and need to set this manually */
  date_default_timezone_set('America/Los_Angeles');
  $preamble .= date('Y-m-d H:i:s');

  if (version_compare(PHP_VERSION, '5.4.0') >= 0) {
    $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 2);
  }
  elseif (version_compare(PHP_VERSION, '5.3.6') >= 0) {
    $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
  }
  else {
    $backtrace = debug_backtrace(true);
  }
  $file_name = array_key_exists('file', $backtrace[1]) ? $backtrace[1]['file'] : '(unknown file)';
  $line_num = array_key_exists('line', $backtrace[1]) ? $backtrace[1]['line'] : '(unknown line)';
  $line = $backtrace[1]['function'] ." called in $file_name:$line_num]";
  
  $backtrace_summary = '';
  foreach ($backtrace as $frame) {
    $class_info = '';
    if (array_key_exists('class', $frame)) {
      $class_info = $frame['class'] . $frame['type'];
    }
    $call_site_info = $class_info . $frame['function'];
    $call_site_info = str_pad($call_site_info, 40);
    $file_name = array_key_exists('file', $frame) ? $frame['file'] : '(unknown file)';
    $line_num = array_key_exists('line', $frame) ? $frame['line'] : '(unknown line)';
    $backtrace_summary .= "$call_site_info called in $file_name: $line_num\n";
  }
  $backtrace_summary .= "\n";

  $preamble = "[[$preamble $line]]";
  $log_msg = '';
  if (!is_string($logged_thing)) {
    $log_msg = print_r($logged_thing, 1);
  }
  else {
    $log_msg = $logged_thing;
  }

  $msg = "$preamble $log_msg\n";
  if (!$no_backtrace) {
    $msg .= "$backtrace_summary\n";
  }
  file_put_contents($logfile, $msg, FILE_APPEND);
}

/* write to the debug log if recursion is detected */
function rec_check() {
  if (version_compare(PHP_VERSION, '5.4.0') >= 0) {
    $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 2);
  }
  elseif (version_compare(PHP_VERSION, '5.3.6') >= 0) {
    $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
  }
  else {
    $backtrace = debug_backtrace(true);
  }
  $caller_name = $backtrace[1]['function'];

  /* use $i=2 to skip recursion checks against this function and its immediate invocant's stack frames */
  for ($i = 2; $i < count($backtrace); $i++) {
    $frame = $backtrace[$i];
    if (!strcmp($frame['function'], $caller_name)) {
      ll("detected recursive call to '$caller_name'");
    }
  }
}

I wrote this while debugging a particularly slippery Drupal bug. The bug lives on but the debug printing function was useful enough that I felt bad throwing it away.