- Added the ability to track page generation times in the statistics module.

  (Made some improvements as per the suggestions in the issue.)

- Added extended timer implementation.

CHANGELOG.txt

@@ -13,6 +13,7 @@ Drupal x.x.x, xxxx-xx-xx (Development version)
     * added support for private profile fields.
 - performance:
     * added 'loose caching' option for high-traffic sites.
+    * added the ability to track page generation times.
 
 Drupal 4.6.0, 2005-04-15
 ------------------------

database/database.mysql

@@ -26,6 +26,7 @@ CREATE TABLE accesslog (
   url varchar(255) default NULL,
   hostname varchar(128) default NULL,
   uid int(10) unsigned default '0',
+  timer int(10) unsigned NOT NULL default '0',
   timestamp int(11) unsigned NOT NULL default '0',
   KEY accesslog_timestamp (timestamp),
   PRIMARY KEY (aid)

database/database.pgsql

@@ -25,6 +25,7 @@ CREATE TABLE accesslog (
   url varchar(255) default NULL,
   hostname varchar(128) default NULL,
   uid integer default '0',
+  timer integer NOT NULL default '0',
   timestamp integer NOT NULL default '0',
   PRIMARY KEY (aid)
 );

database/updates.inc

@@ -114,7 +114,8 @@
   "2005-05-06" => "update_135",
   "2005-05-08" => "update_136",
   "2005-05-09" => "update_137",
-  "2005-05-10" => "update_138"
+  "2005-05-10" => "update_138",
+  "2005-05-11" => "update_139"
 );
 
 function update_32() {
@@ -2482,6 +2483,12 @@ function update_138() {
   return $ret;
 }
 
+function update_139() {
+  $ret = array();
+  $ret[] = update_sql("ALTER TABLE {accesslog} ADD timer int(10) unsigned NOT NULL default '0'");
+  return $ret;
+}
+
 function update_sql($sql) {
   $edit = $_POST["edit"];
   $result = db_query($sql);

includes/bootstrap.inc

@@ -17,6 +17,63 @@
 define('WATCHDOG_WARNING', 1);
 define('WATCHDOG_ERROR', 2);
 
+/**
+ * Start the timer with the specified name.  If you start and stop
+ * the same timer multiple times, the measured intervals will be
+ * accumulated.
+ *
+ * @param name
+ *   The name of the timer.
+ */
+function timer_start($name) {
+  global $timers;
+
+  list($usec, $sec) = explode(' ', microtime());
+  $timers[$name]['start'] = (float)$usec + (float)$sec;
+  $timers[$name]['count']++;
+}
+
+/**
+ * Read the current timer value without stopping the timer.
+ *
+ * @param name
+ *   The name of the timer.
+ * @return
+ *   The current timer value in ms.
+ */
+function timer_read($name) {
+  global $timers;
+
+  list($usec, $sec) = explode(' ', microtime());
+  $stop = (float)$usec + (float)$sec;
+  $diff = round(($stop - $timers[$name]['start']) * 1000, 2);
+
+  return $timers[$name]['time'] + $diff;
+}
+
+/**
+ * Stop the timer with the specified name.
+ *
+ * @param name
+ *   The name of the timer.
+ * @return
+ *   A timer array.  The array contains the number of times the
+ *   timer has been started and stopped (count) and the accumulated
+ *   timer value in ms (time).
+ */
+function timer_stop($name) {
+  global $timers;
+
+  list($usec, $sec) = explode(' ', microtime());
+  $stop = (float)$usec + (float)$sec;
+  $diff = round(($stop - $timers[$name]['start']) * 1000, 2);
+
+  $timers[$name]['time'] += $diff;
+
+  unset($timers[$name]['start']);
+
+  return $timers[$name];
+}
 
 /**
  * Locate the appropriate configuration file.
@@ -171,8 +228,11 @@ function variable_get($name, $default) {
 function variable_set($name, $value) {
   global $conf;
 
+  db_query('LOCK TABLES {variable} WRITE');
   db_query("DELETE FROM {variable} WHERE name = '%s'", $name);
   db_query("INSERT INTO {variable} (name, value) VALUES ('%s', '%s')", $name, serialize($value));
+  db_query('UNLOCK TABLES');
+
   cache_clear_all('variables');
 
   $conf[$name] = $value;
@@ -255,10 +315,12 @@ function cache_get($key) {
 function cache_set($cid, $data, $expire = CACHE_PERMANENT, $headers = NULL) {
   $data = db_encode_blob($data);
 
+  db_query('LOCK TABLES {cache} WRITE');
   db_query("UPDATE {cache} SET data = '%s', created = %d, expire = %d, headers = '%s' WHERE cid = '%s'", $data, time(), $expire, $headers, $cid);
   if (!db_affected_rows()) {
     @db_query("INSERT INTO {cache} (cid, data, created, expire, headers) VALUES ('%s', '%s', %d, %d, '%s')", $cid, $data, time(), $expire, $headers);
   }
+  db_query('UNLOCK TABLES');
 }
 
 /**
@@ -471,10 +533,6 @@ function drupal_set_title($title = NULL) {
  * Set HTTP headers in preparation for a page response.
  */
 function drupal_page_header() {
-  if (variable_get('dev_timer', 0)) {
-    timer_start();
-  }
-
   if (variable_get('cache', 0)) {
     if ($cache = page_get_cache()) {
       bootstrap_invoke_all('init');
@@ -625,15 +683,6 @@ function request_uri() {
   return $uri;
 }
 
-/**
- * Begin a global timer, for benchmarking of page execution time.
- */
-function timer_start() {
-  global $timer;
-  list($usec, $sec) = explode(' ', microtime());
-  $timer = (float)$usec + (float)$sec;
-}
-
 /**
  * Log a system message.
  *
@@ -690,6 +739,9 @@ function drupal_get_messages() {
   return $messages;
 }
 
+// Start a page timer:
+timer_start('page');
+
 unset($conf);
 $config = conf_init();
 

modules/statistics.module

@@ -71,12 +71,8 @@ function statistics_exit() {
     }
   }
   if ((variable_get('statistics_enable_access_log', 0)) && (module_invoke('throttle', 'status') == 0)) {
-    // Statistical logs are enabled.
-    $referrer = referer_uri();
-    $hostname = $_SERVER['REMOTE_ADDR'];
-
     // Log this page access.
-    db_query("INSERT INTO {accesslog} (title, path, url, hostname, uid, timestamp) values('%s', '%s', '%s', '%s', %d, %d)", drupal_get_title(), $_GET['q'], $referrer, $hostname, $user->uid, time());
+    db_query("INSERT INTO {accesslog} (title, path, url, hostname, uid, timer, timestamp) values('%s', '%s', '%s', '%s', %d, %d, %d)", drupal_get_title(), $_GET['q'], referer_uri(), $_SERVER['REMOTE_ADDR'], $user->uid, timer_read('page'), time());
   }
 }
 
@@ -220,7 +216,7 @@ function statistics_user_tracker() {
 }
 
 /**
- * Menu callback; presents the "Recent hits" page.
+ * Menu callback; presents the "recent hits" page.
  */
 function statistics_recent_hits($type = 'all', $id = 0) {
   $header = array(
@@ -249,24 +245,27 @@ function statistics_recent_hits($type = 'all', $id = 0) {
 }
 
 /**
- * Menu callback; presents the "Top pages" page.
+ * Menu callback; presents the "top pages" page.
  */
 function statistics_top_pages() {
-  $sql = "SELECT COUNT(path) AS hits, path, title FROM {accesslog} GROUP BY path, title";
+  $sql = "SELECT COUNT(path) AS hits, path, title, AVG(timer) AS average_time, SUM(timer) AS total_time FROM {accesslog} GROUP BY path, title";
   $sql_cnt = "SELECT COUNT(DISTINCT(path)) FROM {accesslog}";
 
   $header = array(
     array('data' => t('Hits'), 'field' => 'hits', 'sort' => 'desc'),
-    array('data' => t('Page'), 'field' => 'path')
+    array('data' => t('Page'), 'field' => 'path'),
+    array('data' => t('Average generation time'), 'field' => 'average_time'),
+    array('data' => t('Total generation time'), 'field' => 'total_time')
   );
   $sql .= tablesort_sql($header);
   $result = pager_query($sql, 30, 0, $sql_cnt);
 
   while ($page = db_fetch_object($result)) {
-    $rows[] = array($page->hits, _statistics_format_item($page->title, $page->path));
+    $rows[] = array($page->hits, _statistics_format_item($page->title, $page->path), t('%time ms', array('%time' => round($page->average_time))), format_interval(round($page->total_time / 1000)));
   }
+
   if ($pager = theme('pager', NULL, 30, 0, tablesort_pager())) {
-    $rows[] = array(array('data' => $pager, 'colspan' => '2'));
+    $rows[] = array(array('data' => $pager, 'colspan' => '4'));
   }
 
   drupal_set_title(t('Top pages in the past %interval', array('%interval' => format_interval(variable_get('statistics_flush_accesslog_timer', 259200)))));
@@ -274,7 +273,7 @@ function statistics_top_pages() {
 }
 
 /**
- * Menu callback; presents the "Top users" page.
+ * Menu callback; presents the "top users" page.
  */
 function statistics_top_users() {
 
@@ -300,7 +299,7 @@ function statistics_top_users() {
 }
 
 /**
- * Menu callback; presents the "Top referrers" page.
+ * Menu callback; presents the "referrer" page.
  */
 function statistics_top_referrers() {
   $query = "SELECT url, COUNT(url) AS hits, MAX(timestamp) AS last FROM {accesslog} WHERE url NOT LIKE '%%%s%%' AND url <> '' GROUP BY url";

modules/statistics/statistics.module

@@ -71,12 +71,8 @@ function statistics_exit() {
     }
   }
   if ((variable_get('statistics_enable_access_log', 0)) && (module_invoke('throttle', 'status') == 0)) {
-    // Statistical logs are enabled.
-    $referrer = referer_uri();
-    $hostname = $_SERVER['REMOTE_ADDR'];
-
     // Log this page access.
-    db_query("INSERT INTO {accesslog} (title, path, url, hostname, uid, timestamp) values('%s', '%s', '%s', '%s', %d, %d)", drupal_get_title(), $_GET['q'], $referrer, $hostname, $user->uid, time());
+    db_query("INSERT INTO {accesslog} (title, path, url, hostname, uid, timer, timestamp) values('%s', '%s', '%s', '%s', %d, %d, %d)", drupal_get_title(), $_GET['q'], referer_uri(), $_SERVER['REMOTE_ADDR'], $user->uid, timer_read('page'), time());
   }
 }
 
@@ -220,7 +216,7 @@ function statistics_user_tracker() {
 }
 
 /**
- * Menu callback; presents the "Recent hits" page.
+ * Menu callback; presents the "recent hits" page.
  */
 function statistics_recent_hits($type = 'all', $id = 0) {
   $header = array(
@@ -249,24 +245,27 @@ function statistics_recent_hits($type = 'all', $id = 0) {
 }
 
 /**
- * Menu callback; presents the "Top pages" page.
+ * Menu callback; presents the "top pages" page.
  */
 function statistics_top_pages() {
-  $sql = "SELECT COUNT(path) AS hits, path, title FROM {accesslog} GROUP BY path, title";
+  $sql = "SELECT COUNT(path) AS hits, path, title, AVG(timer) AS average_time, SUM(timer) AS total_time FROM {accesslog} GROUP BY path, title";
   $sql_cnt = "SELECT COUNT(DISTINCT(path)) FROM {accesslog}";
 
   $header = array(
     array('data' => t('Hits'), 'field' => 'hits', 'sort' => 'desc'),
-    array('data' => t('Page'), 'field' => 'path')
+    array('data' => t('Page'), 'field' => 'path'),
+    array('data' => t('Average generation time'), 'field' => 'average_time'),
+    array('data' => t('Total generation time'), 'field' => 'total_time')
   );
   $sql .= tablesort_sql($header);
   $result = pager_query($sql, 30, 0, $sql_cnt);
 
   while ($page = db_fetch_object($result)) {
-    $rows[] = array($page->hits, _statistics_format_item($page->title, $page->path));
+    $rows[] = array($page->hits, _statistics_format_item($page->title, $page->path), t('%time ms', array('%time' => round($page->average_time))), format_interval(round($page->total_time / 1000)));
   }
+
   if ($pager = theme('pager', NULL, 30, 0, tablesort_pager())) {
-    $rows[] = array(array('data' => $pager, 'colspan' => '2'));
+    $rows[] = array(array('data' => $pager, 'colspan' => '4'));
   }
 
   drupal_set_title(t('Top pages in the past %interval', array('%interval' => format_interval(variable_get('statistics_flush_accesslog_timer', 259200)))));
@@ -274,7 +273,7 @@ function statistics_top_pages() {
 }
 
 /**
- * Menu callback; presents the "Top users" page.
+ * Menu callback; presents the "top users" page.
  */
 function statistics_top_users() {
 
@@ -300,7 +299,7 @@ function statistics_top_users() {
 }
 
 /**
- * Menu callback; presents the "Top referrers" page.
+ * Menu callback; presents the "referrer" page.
  */
 function statistics_top_referrers() {
   $query = "SELECT url, COUNT(url) AS hits, MAX(timestamp) AS last FROM {accesslog} WHERE url NOT LIKE '%%%s%%' AND url <> '' GROUP BY url";

modules/user.module

@@ -1664,7 +1664,6 @@ function user_admin_account() {
   $header = array(
     array('data' => t('Username'), 'field' => 'u.name'),
     array('data' => t('Status'), 'field' => 'u.status'),
-    array('data' => t('Roles')),
     array('data' => t('Member for'), 'field' => 'u.created', 'sort' => 'desc'),
     array('data' => t('Last access'), 'field' => 'u.access'),
     t('Operations')
@@ -1676,20 +1675,13 @@ function user_admin_account() {
   $status = array(t('blocked'), t('active'));
   $destination = drupal_get_destination();
   while ($account = db_fetch_object($result)) {
-    $rolesresult = db_query('SELECT r.name FROM {role} r INNER JOIN {users_roles} ur ON ur.rid = r.rid WHERE ur.uid = %d', $account->uid);
-    $roles = array();
-
-    while ($role = db_fetch_object($rolesresult)) {
-      $roles[] = $role->name;
-    }
-
-    $rows[] = array(format_name($account), $status[$account->status], implode(', ', $roles), format_interval(time() - $account->created), t('%time ago', array('%time' => format_interval(time() - $account->access))), l(t('edit'), "user/$account->uid/edit", array(), $destination));
+    $rows[] = array(format_name($account), $status[$account->status], format_interval(time() - $account->created), t('%time ago', array('%time' => format_interval(time() - $account->access))), l(t('edit'), "user/$account->uid/edit", array(), $destination));
 
   }
 
   $pager = theme('pager', NULL, 50, 0, tablesort_pager());
   if (!empty($pager)) {
-    $rows[] = array(array('data' => $pager, 'colspan' => '6'));
+    $rows[] = array(array('data' => $pager, 'colspan' => '5'));
   }
   return theme('table', $header, $rows);
 }

modules/user/user.module

@@ -1664,7 +1664,6 @@ function user_admin_account() {
   $header = array(
     array('data' => t('Username'), 'field' => 'u.name'),
     array('data' => t('Status'), 'field' => 'u.status'),
-    array('data' => t('Roles')),
     array('data' => t('Member for'), 'field' => 'u.created', 'sort' => 'desc'),
     array('data' => t('Last access'), 'field' => 'u.access'),
     t('Operations')
@@ -1676,20 +1675,13 @@ function user_admin_account() {
   $status = array(t('blocked'), t('active'));
   $destination = drupal_get_destination();
   while ($account = db_fetch_object($result)) {
-    $rolesresult = db_query('SELECT r.name FROM {role} r INNER JOIN {users_roles} ur ON ur.rid = r.rid WHERE ur.uid = %d', $account->uid);
-    $roles = array();
-
-    while ($role = db_fetch_object($rolesresult)) {
-      $roles[] = $role->name;
-    }
-
-    $rows[] = array(format_name($account), $status[$account->status], implode(', ', $roles), format_interval(time() - $account->created), t('%time ago', array('%time' => format_interval(time() - $account->access))), l(t('edit'), "user/$account->uid/edit", array(), $destination));
+    $rows[] = array(format_name($account), $status[$account->status], format_interval(time() - $account->created), t('%time ago', array('%time' => format_interval(time() - $account->access))), l(t('edit'), "user/$account->uid/edit", array(), $destination));
 
   }
 
   $pager = theme('pager', NULL, 50, 0, tablesort_pager());
   if (!empty($pager)) {
-    $rows[] = array(array('data' => $pager, 'colspan' => '6'));
+    $rows[] = array(array('data' => $pager, 'colspan' => '5'));
   }
   return theme('table', $header, $rows);
 }