Index: project-usage-process.php
===================================================================
RCS file: /cvs/drupal-contrib/contributions/modules/project/usage/project-usage-process.php,v
retrieving revision 1.1
diff -u -p -u -p -r1.1 project-usage-process.php
--- project-usage-process.php	4 Dec 2008 05:47:41 -0000	1.1
+++ project-usage-process.php	5 Dec 2008 07:55:49 -0000
@@ -112,44 +112,73 @@ cache_clear_all(NULL, 'cache_project_usa
 function project_usage_process_daily() {
   // Timestamp for begining of the previous day.
   $timestamp = project_usage_daily_timestamp(NULL, 1);
+  $time_0 = time();
 
-  watchdog('project_usage', t('Starting to process daily usage data for @date.', array('@date' => format_date($timestamp))));
+  watchdog('project_usage', t('Starting to process daily usage data for !date.', array('!date' => format_date($timestamp, 'custom', 'Y-m-d'))));
 
   // Assign API version term IDs.
   $terms = array();
   foreach (project_release_get_api_taxonomy() as $term) {
     $terms[$term->tid] = $term->name;
   }
+  $num_updates = 0;
   $query = db_query("SELECT DISTINCT api_version FROM {project_usage_raw} WHERE tid = 0");
   while ($row = db_fetch_object($query)) {
     $tid = array_search($row->api_version, $terms);
     db_query("UPDATE {project_usage_raw} SET tid = %d WHERE api_version = '%s'", $tid, $row->api_version);
+    $num_updates += db_affected_rows();
   }
-  watchdog('project_usage', t('Assigned API version term IDs.'));
+  $time_1 = time();
+  $substitutions = array(
+    '!rows' => format_plural($num_updates, '1 row', '@count rows'),
+    '!delta' => format_interval($time_1 - $time_0),
+  );
+  watchdog('project_usage', t('Assigned API version term IDs for !rows (!delta).', $substitutions));
 
   // Asign project and release node IDs.
+  $num_updates = 0;
   $query = db_query("SELECT DISTINCT project_uri, project_version FROM {project_usage_raw} WHERE pid = 0 OR nid = 0");
   while ($row = db_fetch_object($query)) {
     $pid = db_result(db_query("SELECT pp.nid AS pid FROM {project_projects} pp WHERE pp.uri = '%s'", $row->project_uri));
     if ($pid) {
       $nid = db_result(db_query("SELECT prn.nid FROM {project_release_nodes} prn WHERE prn.pid = %d AND prn.version = '%s'", $pid, $row->project_version));
       db_query("UPDATE {project_usage_raw} SET pid = %d, nid = %d WHERE project_uri = '%s' AND project_version = '%s'", $pid, $nid, $row->project_uri, $row->project_version);
+      $num_updates += db_affected_rows();
     }
   }
-  watchdog('project_usage', t('Assigned project and release node IDs.'));
+  $time_2 = time();
+  $substitutions = array(
+    '!rows' => format_plural($num_updates, '1 row', '@count rows'),
+    '!delta' => format_interval($time_2 - $time_1),
+  );
+  watchdog('project_usage', t('Assigned project and release node IDs to !rows (!delta).', $substitutions));
 
   // Move usage records with project node IDs into the daily table and remove
   // the rest.
   db_query("INSERT INTO {project_usage_day} (timestamp, site_key, pid, nid, tid, ip_addr) SELECT timestamp, site_key, pid, nid, tid, ip_addr FROM {project_usage_raw} WHERE timestamp < %d AND pid <> 0", $timestamp);
+  $num_new_day_rows = db_affected_rows();
   db_query("DELETE FROM {project_usage_raw} WHERE timestamp < %d", $timestamp);
-  watchdog('project_usage', t('Moved usage from raw to daily.'));
+  $num_deleted_raw_rows = db_affected_rows();
+  $time_3 = time();
+  $substitutions = array(
+    '!day_rows' => format_plural($num_new_day_rows, '1 row', '@count rows'),
+    '!raw_rows' => format_plural($num_deleted_raw_rows, '1 row', '@count rows'),
+    '!delta' => format_interval($time_3 - $time_2),
+  );
+  watchdog('project_usage', t('Moved usage from raw to daily: !day_rows added to {project_usage_day}, !raw_rows deleted from {project_usage_raw} (!delta).', $substitutions));
 
   // Remove old daily records.
   $seconds = variable_get('project_usage_life_daily', 4 * PROJECT_USAGE_WEEK);
   db_query("DELETE FROM {project_usage_day} WHERE timestamp < %d", time() - $seconds);
-  watchdog('project_usage', t('Removed old daily rows.'));
+  $num_deleted_day_rows = db_affected_rows();
+  $time_4 = time();
+  $substitutions = array(
+    '!rows' => format_plural($num_deleted_day_rows, '1 old daily row', '@count old daily rows'),
+    '!delta' => format_interval($time_4 - $time_3),
+  );
+  watchdog('project_usage', t('Removed !rows (!delta).', $substitutions));
 
-  watchdog('project_usage', t('Completed daily usage data processing.'));
+  watchdog('project_usage', t('Completed daily usage data processing (total time: !delta).', array('!delta' => format_interval($time_4 - $time_0))));
 }
 
 /**
@@ -160,6 +189,7 @@ function project_usage_process_daily() {
  */
 function project_usage_process_weekly($timestamp) {
   watchdog('project_usage', t('Starting to process weekly usage data.'));
+  $time_0 = time();
 
   // Get all the weeks since we last ran.
   $weeks = project_usage_get_weeks_since($timestamp);
@@ -168,26 +198,58 @@ function project_usage_process_weekly($t
   for ($i = 0; $i < $count; $i++) {
     $start = $weeks[$i];
     $end = $weeks[$i + 1];
-    $date = format_date($start);
+    $date = format_date($start, 'custom', 'Y-m-d');
+    $time_1 = time();
 
     // Try to compute the usage tallies per project and per release. If there
     // is a problem--perhaps some rows existed from a previous, incomplete
     // run that are preventing inserts, throw a watchdog error.
 
     $sql = "INSERT INTO {project_usage_week_project} (nid, timestamp, tid, count) SELECT pid, %d, tid, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= %d AND timestamp < %d AND pid <> 0 GROUP BY pid, tid";
-    if (!db_query($sql, array($start, $start, $end))) {
-      watchdog('project_usage', t('Query failed inserting weekly project tallies for @date.', array('@date' => $date)), WATCHDOG_ERROR);
+    $query_args = array($start, $start, $end);
+    $result = db_query($sql, $query_args);
+    $time_2 = time();
+    if (!$result) {
+      _db_query_callback($query_args, TRUE);
+      $substitutions = array(
+        '!date' => $date,
+        '%query' => preg_replace_callback(DB_QUERY_REGEXP, '_db_query_callback', $sql),
+        '!delta' => format_interval($time_2 - $time_1),
+      );
+      watchdog('project_usage', t('Query failed inserting weekly project tallies for !date, query: %query (!delta).', $substitutions), WATCHDOG_ERROR);
     }
     else {
-      watchdog('project_usage', t('Computed weekly project tallies for @date.', array('@date' => $date)));
+      $num_rows = db_affected_rows();
+      $substitutions = array(
+        '!date' => $date,
+        '!projects' => format_plural($num_rows, '1 project', '@count projects'),
+        '!delta' => format_interval($time_2 - $time_1),
+      );
+      watchdog('project_usage', t('Computed weekly project tallies for !date for !projects (!delta).', $substitutions));
     }
 
     $sql = "INSERT INTO {project_usage_week_release} (nid, timestamp, count) SELECT nid, %d, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= %d AND timestamp < %d AND nid <> 0 GROUP BY nid";
-    if (!db_query($sql, array($start, $start, $end))) {
-      watchdog('project_usage', t('Query failed inserting weekly release tallies for @date.', array('@date' => $date)), WATCHDOG_ERROR);
+    $query_args = array($start, $start, $end);
+    $result = db_query($sql, $query_args);
+    $time_3 = time();
+    if (!$result) {
+      _db_query_callback($query_args, TRUE);
+      $substitutions = array(
+        '!date' => $date,
+        '%query' => preg_replace_callback(DB_QUERY_REGEXP, '_db_query_callback', $sql),
+        '!delta' => format_interval($time_3 - $time_2),
+      );
+      watchdog('project_usage', t('Query failed inserting weekly release tallies for !date, query: %query (!delta).', $substitutions), WATCHDOG_ERROR);
     }
     else {
-      watchdog('project_usage', t('Computed weekly release tallies for @date.', array('@date' => $date)));
+      $num_rows = db_affected_rows();
+      $substitutions = array(
+        '!date' => $date,
+        '!releases' => format_plural($num_rows, '1 release', '@count releases'),
+        '!delta' => format_interval($time_3 - $time_2),
+      );
+
+      watchdog('project_usage', t('Computed weekly release tallies for !date for !releases (!delta).', $substitutions));
     }
   }
 
@@ -195,12 +257,24 @@ function project_usage_process_weekly($t
   $now = time();
   $project_life = variable_get('project_usage_life_weekly_project', PROJECT_USAGE_YEAR);
   db_query("DELETE FROM {project_usage_week_project} WHERE timestamp < %d", $now - $project_life);
-  watchdog('project_usage', t('Removed old weekly project rows.'));
+  $num_rows = db_affected_rows();
+  $time_1 = time();
+  $substitutions = array(
+    '!rows' => format_plural($num_rows, '1 old weekly project row', '@count old weekly project rows'),
+    '!delta' => format_interval($time_1 - $now),
+  );
+  watchdog('project_usage', t('Removed !rows (!delta).'));
 
   $release_life = variable_get('project_usage_life_weekly_release', 26 * PROJECT_USAGE_WEEK);
   db_query("DELETE FROM {project_usage_week_release} WHERE timestamp < %d", $now - $release_life);
-  watchdog('project_usage', t('Removed old weekly release rows.'));
+  $time_2 = time();
+  $substitutions = array(
+    '!rows' => format_plural($num_rows, '1 old weekly release row', '@count old weekly release rows'),
+    '!delta' => format_interval($time_2 - $time_1),
+  );
+
+  watchdog('project_usage', t('Removed !rows (!delta).', $substitutions));
 
-  watchdog('project_usage', t('Completed weekly usage data processing.'));
+  watchdog('project_usage', t('Completed weekly usage data processing (total time: !delta).', array('!delta' => format_interval($time_2 - $time_0))));
 }