From d94050aa3362dd4589b33c69ca75464ad9e221bf Mon Sep 17 00:00:00 2001
From: moshe weitzman <weitzman@cyrve.com>
Date: Sun, 21 Feb 2010 05:31:27 +0000
Subject: [PATCH] #694036 by mikeryan. print a timers table at end of debug
 log. i'm open to alternate ways of triggerring the printing of this table.

---
 drush.php          |  4 +++-
 includes/drush.inc | 35 ++++++++++++++++++++++++++++++-----
 2 files changed, 33 insertions(+), 6 deletions(-)

diff --git a/drush.php b/drush.php
index 736a640214..709cbda248 100755
--- a/drush.php
+++ b/drush.php
@@ -89,7 +89,9 @@ function drush_main() {
           // Dispatch the command(s).
           $return = drush_dispatch($command);
 
-          drush_log_timers();
+          if (drush_get_context('DRUSH_DEBUG'))
+            drush_print_timers();
+          }
           drush_log(dt('Peak memory usage was !peak', array('!peak' => drush_format_size(memory_get_peak_usage()))), 'memory');
           break;
         }
diff --git a/includes/drush.inc b/includes/drush.inc
index 4dc6d909ca..6122179809 100644
--- a/includes/drush.inc
+++ b/includes/drush.inc
@@ -1154,15 +1154,40 @@ function _drush_print_log($entry) {
   return $return;
 }
 
-// Log all timers for the request.
-// Useful for migrate commands. Lets see if others find it useful.
-// Called at end of request. @see drush.php
-function drush_log_timers() {
+// Print all timers for the request.
+function drush_print_timers() {
   global $timers;
+  $temparray = array();
   foreach ((array)$timers as $name => $timerec) {
-    drush_log("Timer '$name' is  "  . sprintf('%s sec.', round(timer_read($name)/1000, 2)), 'timer');
+    // We have to use timer_read() for active timers, and check the record for others
+    if (isset($timerec['start'])) {
+      $temparray[$name] = timer_read($name);
+    }
+    else {
+      $temparray[$name] = $timerec['time'];
+    }
+  }
+  // Go no farther if there were no timers
+  if (count($temparray) > 0) {
+    // Put the highest cumulative times first
+    arsort($temparray);
+    $table = array();
+    $table[] = array('Timer', 'Cum (sec)', 'Count', 'Avg (msec)');
+    foreach ($temparray as $name => $time) {
+      $cum = round($time/1000, 3);
+      $count = $timers[$name]['count'];
+      if ($count > 0) {
+        $avg = round($time/$count, 3);
+      }
+      else {
+        $avg = 'N/A';
+      }
+      $table[] = array($name, $cum, $count, $avg);
+    }
+    drush_print_table($table, TRUE);
   }
 }
+
 /**
 * Turn drupal_set_message errors into drush_log errors
 */