You are here

performance.module in Performance Logging and Monitoring 5

File

performance.module
View source
<?php

// Copyright Khalid Baheyeldin 2008 of http://2bits.com
define('PERFORMANCE_KEY', 'dru-perf:' . $_SERVER['HTTP_HOST'] . ':');
function performance_menu($may_cache) {
  $items = array();
  if ($may_cache) {
    $access = user_access('access administration pages');
    $items[] = array(
      'path' => 'admin/settings/performance_logging',
      'title' => t('Performance Logging'),
      'description' => t('Logs performance data: page generation times and memory usage.'),
      'access' => $access,
      'callback' => 'drupal_get_form',
      'callback arguments' => array(
        'performance_settings',
      ),
    );
    $items[] = array(
      'path' => 'admin/settings/performance_logging/apc_clear',
      'title' => t('Clear APC'),
      'description' => t('Clears performance statistics collected in APC.'),
      'access' => $access,
      'callback' => 'drupal_get_form',
      'callback arguments' => array(
        'performance_clear_apc_confirm',
      ),
    );
    $items[] = array(
      'path' => 'admin/logs/performance_logging',
      'title' => t('Performance Logs'),
      'description' => t('View performance logs: summary and details.'),
      'access' => $access,
    );
    $items[] = array(
      'path' => 'admin/logs/performance_logging/summary',
      'title' => t('Performance Logs: Summary'),
      'description' => t('View summary performance logs: page generation times and memory usage.'),
      'access' => $access,
      'callback' => 'performance_view_summary',
    );
    $items[] = array(
      'path' => 'admin/logs/performance_logging/details',
      'title' => t('Performance Logs: Details'),
      'description' => t('View detailed, per page, performance logs: page generation times and memory usage.'),
      'access' => $access,
      'callback' => 'performance_view_details',
    );
  }
  return $items;
}
function performance_settings() {
  $options = array(
    0 => t('Disabled'),
    1 => t('Enabled'),
  );
  if (function_exists('apc_store')) {
    drupal_set_message(t('APC is enabled. It is reasonably safe to enable summary logging on live sites.'));
  }
  else {
    drupal_set_message(t('APC is not enabled. It is <strong>not</strong> safe to enable summary logging to the database on live sites.'), 'error');
  }
  $form['mode'] = array(
    '#type' => 'fieldset',
    '#title' => t('Logging mode'),
    '#collapsible' => TRUE,
  );
  $form['mode']['performance_detail'] = array(
    '#type' => 'select',
    '#title' => t('Detailed logging'),
    '#default_value' => variable_get('performance_detail', 0),
    '#options' => $options,
    '#description' => t('Log memory usage and page generation times for every page. This logging mode is <strong>not</strong> suitable for large sites, as it can degrade performance severly. It is intended for use by developers, or on a test copy of the site.'),
  );
  $form['mode']['performance_summary_db'] = array(
    '#type' => 'select',
    '#title' => t('Summary logging (DB)'),
    '#default_value' => variable_get('performance_summary_db', 0),
    '#options' => $options,
    '#description' => t('Log summary data, such as average and maximum page generation times and memory usage to the database. This logging mode is <strong>not</strong> suitable for most live sites.'),
  );
  $disabled = TRUE;
  if (function_exists('apc_store')) {
    $disabled = FALSE;
  }
  $form['mode']['performance_summary_apc'] = array(
    '#type' => 'select',
    '#title' => t('Summary logging (APC)'),
    '#default_value' => variable_get('performance_summary_apc', 0),
    '#options' => $options,
    '#disabled' => $disabled,
    '#description' => t('Log summary data, such as average and maximum page generation times and memory usage to APC, if installed. The summary will be stored in APC memory, and hence there is no load on the database. This logging to APC is suitable for most live sites, unless the number of unique page accesses is excessively high.'),
  );
  $form['other'] = array(
    '#type' => 'fieldset',
    '#title' => t('Other'),
    '#collapsible' => TRUE,
  );
  $form['other']['performance_titles'] = array(
    '#type' => 'select',
    '#title' => t('Show titles instead of URLs'),
    '#default_value' => variable_get('performance_titles', 0),
    '#options' => array(
      0 => t('URLs only'),
      1 => t('URLs and Titles as hyperlinks'),
    ),
    '#description' => t('In the reports, show path titles hyperlinked to the URLs, or just the path URLs.'),
  );
  $form['other']['dev_query'] = array(
    '#type' => 'select',
    '#title' => t('Database Query timing and count'),
    '#default_value' => variable_get('dev_query', 0),
    '#options' => $options,
    '#description' => t('Log database timing and count for each page. This is useful to know if the bottleneck is in excessive database query counts, or the time required to execute those queries is high. Please note that this will automatically be enabled and disabled in the settings of the devel module. Also note that enabling this will incurr some memory overhead as query times and the actual query strings are cached in memory as arrays.'),
  );
  $form['other']['performance_threshold_accesses'] = array(
    '#type' => 'select',
    '#title' => t('Accesses threshold'),
    '#default_value' => variable_get('performance_threshold_accesses', 0),
    '#options' => array(
      0,
      1,
      2,
      5,
      10,
    ),
    '#description' => t('When displaying the summary report and using APC, only pages with the number of accesses larger than the specified threshold will be shown. Also, when cron runs, pages with that number of accesses or less will be removed, so as not to overflow APC\'s shared memory. This is useful on a live site with a high volume of hits. On a development site, you probably want this set to 0, so you can see all pages.'),
  );
  return system_settings_form($form);
}
function performance_init() {
  if (!variable_get('cache', 0)) {

    // When page caching is off, we don't hook_exit(), instead
    // we register a function that runs as late as possible.
    register_shutdown_function('performance_shutdown');
  }
  global $user;

  // Give a message on all admin pages, so they are warned.
  if ($user->uid && arg(0) == 'admin') {
    if (variable_get('performance_detail', 0)) {
      drupal_set_message(t('Performance detailed logging is !link. This can cause severe issues on live sites.', array(
        '!link' => l(t('enabled'), 'admin/settings/performance_logging'),
      )), 'error');
    }
    if (variable_get('dev_query', 0)) {
      if (variable_get('performance_detail', 0) || variable_get('performance_summary_db', 0) || variable_get('performance_summary_apc', 0)) {
        drupal_set_message(t('Query timing and count logging is !link. This can cause memory size per page to be larger than normal.', array(
          '!link' => l(t('enabled'), 'admin/settings/performance_logging'),
        )), 'error');
      }
    }
    if (variable_get('performance_summary_apc', 0)) {
      $shm_size = ini_get('apc.shm_size');
      if ($shm_size < 48) {
        drupal_set_message(t('APC has been configured for !size, which is less than the recommended 48 MB of memory. If you encounter errors when viewing the summary report, then try to increase that limit for APC.', array(
          '!size' => $shm_size,
        )), 'warning');
      }
    }
  }
}
function performance_exit() {
  if (variable_get('cache', 0)) {

    // Page caching is on, so we run the shutdown function directly
    performance_shutdown();
  }
}
function performance_shutdown() {
  global $queries;
  $params = array(
    'timer' => timer_read('page'),
    'path' => $_GET['q'],
  );

  // Memory
  if (function_exists('memory_get_peak_usage')) {
    $params['mem'] = memory_get_peak_usage(TRUE);
  }
  else {
    $params['mem'] = 0;
  }

  // Query time and count
  $query_count = 0;
  $query_timer = 0;
  if (variable_get('dev_query', 0) && is_array($queries)) {
    foreach ($queries as $query) {
      $sum += $query[1];
    }
    $query_count = count($queries);
    $query_timer = round($sum * 1000, 2);
  }
  $params['query_count'] = $query_count;
  $params['query_timer'] = $query_timer;
  if (variable_get('performance_detail', 0)) {
    performance_log_details($params);
  }
  if (variable_get('performance_summary_db', 0)) {
    performance_log_summary_db($params);
  }
  if (variable_get('performance_summary_apc', 0)) {
    if (function_exists('apc_store')) {
      performance_log_summary_apc($params);
    }
  }
}
function performance_log_summary_apc($params = array()) {
  $key = PERFORMANCE_KEY . $params['path'];
  if ($data = apc_fetch($key)) {
    $data = array(
      'path' => $data['path'],
      'last_access' => time(),
      'bytes_max' => max($params['mem'], $data['bytes_max']),
      'bytes_avg' => ($data['bytes_avg'] + $params['mem']) / 2,
      'millisecs_max' => max($params['timer'], $data['millisecs_max']),
      'millisecs_avg' => ($data['millisecs_avg'] + $params['timer']) / 2,
      'query_timer_max' => max($params['query_timer'], $row->query_timer_max),
      'query_timer_avg' => ($row->query_timer_avg + $params['query_timer']) / 2,
      'query_count_max' => max($params['query_count'], $row->query_count_max),
      'query_count_avg' => ($row->query_count_avg + $params['query_count']) / 2,
      'num_accesses' => $data['num_accesses'] + 1,
      'title' => $data['title'],
    );
  }
  else {
    $data = array(
      'title' => strip_tags(drupal_get_title()),
      'path' => $params['path'],
      'bytes_max' => $params['mem'],
      'bytes_avg' => $params['mem'],
      'millisecs_max' => $params['timer'],
      'millisecs_avg' => $params['timer'],
      'query_timer_max' => $params['query_timer'],
      'query_timer_avg' => $params['query_timer'],
      'query_count_max' => $params['query_count'],
      'query_count_avg' => $params['query_count'],
      'num_accesses' => 1,
      'last_access' => time(),
    );
  }
  apc_store($key, $data);
}
function performance_log_summary_db($params = array()) {
  $result = db_query("SELECT * FROM {performance_summary} WHERE path = '%s'", $params['path']);
  if (db_num_rows($result)) {
    $row = db_fetch_object($result);
    db_query("UPDATE {performance_summary} \n      SET last_access = %d,\n      num_accesses = num_accesses + 1,\n      bytes_max = %d,\n      bytes_avg = %d,\n      millisecs_max = %d,\n      millisecs_avg = %d,\n      query_timer_max = %d,\n      query_timer_avg = %d,\n      query_count_max = %d,\n      query_count_avg = %d\n      WHERE path = '%s'", time(), max($params['mem'], $row->bytes_max), ($row->bytes_avg + $params['mem']) / 2, max($params['timer'], $row->millisecs_max), ($row->millisecs_avg + $params['timer']) / 2, max($params['query_timer'], $row->query_timer_max), ($row->query_timer_avg + $params['query_timer']) / 2, max($params['query_count'], $row->query_count_max), ($row->query_count_avg + $params['query_count']) / 2, $params['path']);
  }
  else {

    // First time we log this path, write fresh values
    db_query("INSERT INTO {performance_summary}\n      (title, path, last_access, num_accesses,\n      bytes_max, bytes_avg, millisecs_max, millisecs_avg,\n      query_count_max, query_count_avg, query_timer_max, query_timer_avg)\n      VALUES \n      ('%s', '%s', %d, %d, %d, %d, %d, %d, %d, %d, %d, %d)", strip_tags(drupal_get_title()), $params['path'], time(), 1, $params['mem'], $params['mem'], $params['timer'], $params['timer'], $params['query_count'], $params['query_count'], $params['query_timer'], $params['query_timer']);
  }
}
function performance_log_details($params = array()) {
  global $user;
  $anon = $user->uid ? FALSE : TRUE;
  db_query("INSERT INTO {performance_detail} (title, path, anon, bytes, millisecs, timestamp, query_timer, query_count) VALUES ('%s', '%s', %d, %d, %d, %d, %d, %d)", strip_tags(drupal_get_title()), $params['path'], $anon, $params['mem'], $params['timer'], time(), $params['query_timer'], $params['query_count']);
}
function performance_apc_list_all() {
  $key_list = array();
  $list = apc_cache_info('user');
  foreach ($list['cache_list'] as $cache_id => $cache_data) {
    $regex = '/^' . PERFORMANCE_KEY . '/';
    if (preg_match($regex, $cache_data['info'])) {
      $key_list[] = $cache_data['info'];
    }
  }
  return $key_list;
}
function performance_view_summary() {
  $sum = array();
  $sum[] = variable_get('performance_summary_db', 0);
  $sum[] = variable_get('performance_summary_apc', 0);
  $go = array_sum($sum);
  if (!$go) {
    return t('Summary performance log is not enabled. Go to the !link to enable it.', array(
      '!link' => l(t('settings page'), 'admin/settings/performance_logging'),
    ));
  }
  $header = array(
    array(
      'data' => t('Path'),
      'field' => 'path',
    ),
    array(
      'data' => t('Last access'),
      'field' => 'last_access',
    ),
    array(
      'data' => t('# accesses'),
      'field' => 'num_accesses',
    ),
    array(
      'data' => t('Max Memory (MB)'),
      'field' => 'bytes_max',
    ),
    array(
      'data' => t('Avg Memory (MB)'),
      'field' => 'bytes_avg',
    ),
    array(
      'data' => t('Milliseconds (Max)'),
      'field' => 'millisecs_max',
    ),
    array(
      'data' => t('Milliseconds (Avg)'),
      'field' => 'millisecs_avg',
    ),
    array(
      'data' => t('Query Millisecs (Max)'),
      'field' => 'query_timer_max',
    ),
    array(
      'data' => t('Query Millisecs (Avg)'),
      'field' => 'query_timer_avg',
    ),
    array(
      'data' => t('Query Count (Max)'),
      'field' => 'query_count_max',
    ),
    array(
      'data' => t('Query Count (Avg)'),
      'field' => 'query_count_avg',
    ),
  );
  $total_rows = $shown = $last_max = $total_bytes = $total_millisecs = $total_accesses = 0;
  $last_min = time();
  $threshold = variable_get('performance_threshold_accesses', 0);
  if (variable_get('performance_summary_apc', 0) && function_exists('apc_cache_info')) {

    // Get the data from the APC cache
    foreach (performance_apc_list_all() as $key) {
      $data_list[] = apc_fetch($key);
    }
  }
  else {

    // Get the data form the database table
    $sql = "SELECT * FROM {performance_summary}";
    $tablesort = tablesort_sql($header);
    $result = pager_query($sql . $tablesort, 5000);
    while ($row = db_fetch_array($result)) {
      $data_list[] = $row;
    }
  }
  foreach ($data_list as $data) {
    $total_rows++;
    $last_max = max($last_max, $data['last_access']);
    $last_min = min($last_min, $data['last_access']);

    // Calculate running averages
    $total_bytes += $data['bytes_avg'];
    $total_millisecs += $data['millisecs_avg'];
    $total_accesses += $data['num_accesses'];
    if ($data['num_accesses'] > $threshold) {
      $shown++;
      $rows[] = array(
        'data' => array(
          performance_url($data['path'], $data['title']),
          format_date($data['last_access'], 'small'),
          $data['num_accesses'],
          number_format($data['bytes_max'] / 1024 / 1024, 2),
          number_format($data['bytes_avg'] / 1024 / 1024, 2),
          number_format($data['millisecs_max'], 1),
          number_format($data['millisecs_avg'], 1),
          number_format($data['query_timer_max'], 1),
          number_format($data['query_timer_avg'], 1),
          $data['query_count_max'],
          $data['query_count_avg'],
        ),
      );
    }
  }
  if (!$rows) {
    $rows[] = array(
      array(
        'data' => t('No statistics available yet.'),
        'colspan' => count($header),
      ),
    );
  }
  if ($threshold) {
    $output .= t('Showing !shown paths with more than !threshold accesses, out of !total total paths.', array(
      '!threshold' => $threshold,
      '!shown' => $shown,
      '!total' => $total_rows,
    )) . '<br/>';
  }
  else {
    $output .= t('Showing all !total paths.', array(
      '!total' => $total_rows,
    )) . '<br/>';
  }

  // Protect against divide by zero
  if ($total_rows > 0) {
    $mb_avg = number_format($total_bytes / $total_rows / 1024 / 1024, 1);
    $ms_avg = number_format($total_millisecs / $total_rows, 2);
  }
  else {
    $mb_avg = 'n/a';
    $ms_avg = 'n/a';
  }
  $output .= t('Average memory per page: !mb_avg MB', array(
    '!mb_avg' => $mb_avg,
  )) . '<br/>';
  $output .= t('Average milliseconds per page: !ms_avg', array(
    '!ms_avg' => $ms_avg,
  )) . '<br/>';
  $output .= t('Total number of page accesses: !accesses', array(
    '!accesses' => $total_accesses,
  )) . '<br/>';
  $output .= t('First access: !access.', array(
    '!access' => format_date($last_min, 'small'),
  )) . '<br/>';
  $output .= t('Last access: !access.', array(
    '!access' => format_date($last_max, 'small'),
  )) . '<br/>';
  $output .= theme('table', $header, $rows);
  $output .= theme('pager', NULL, 50, 0);
  return $output;
}
function performance_view_details() {
  if (!variable_get('performance_detail', 0)) {
    return t('Detail performance log is not enabled. Go to the !link to enable it.', array(
      '!link' => l(t('settings page'), 'admin/settings/performance_logging'),
    ));
  }
  $header = array(
    array(
      'data' => t('#'),
      'field' => 'pid',
      'sort' => 'desc',
    ),
    array(
      'data' => t('Date'),
      'field' => 'timestamp',
    ),
    array(
      'data' => t('Path'),
      'field' => 'path',
    ),
    array(
      'data' => t('Memory (MB)'),
      'field' => 'bytes',
    ),
    array(
      'data' => t('Milliseconds (Total)'),
      'field' => 'millisecs',
    ),
    array(
      'data' => t('Anonymous?'),
      'field' => 'anon',
    ),
    array(
      'data' => t('# Queries'),
      'field' => 'query_count',
    ),
    array(
      'data' => t('Query Milliseconds'),
      'field' => 'query_timer',
    ),
  );
  $sql = "SELECT * FROM {performance_detail}";
  $tablesort = tablesort_sql($header);
  $result = pager_query($sql . $tablesort, 50);
  while ($data = db_fetch_array($result)) {
    $rows[] = array(
      'data' => array(
        $data['pid'],
        format_date($data['timestamp'], 'small'),
        performance_url($data['path'], $data['title']),
        number_format($data['bytes'] / 1024 / 1024, 2),
        $data['millisecs'],
        $data['anon'] ? t('Yes') : t('No'),
        $data['query_count'],
        $data['query_timer'],
      ),
    );
  }
  if (!$rows) {
    $rows[] = array(
      array(
        'data' => t('No log messages available.'),
        'colspan' => count($header),
      ),
    );
  }
  $output .= theme('table', $header, $rows);
  $output .= theme('pager', NULL, 50, 0);
  return $output;
}
function performance_cron() {
  performance_cron_apc_prune();
}
function performance_cron_apc_prune() {

  // Remove entries from apc cache that has less than so many accesses
  // to prevent clutter
  $threshold = variable_get('performance_threshold_accesses', 0);
  if (!$threshold) {

    // Threshold not set
    return;
  }
  $list = performance_apc_list_all();
  if (!count($list)) {

    // Nothing stored yet
    return;
  }
  foreach ($list as $key) {
    if ($data = apc_fetch($key)) {
      if ($data['num_accesses'] <= $threshold) {
        apc_delete($key);
      }
    }
  }
}
function performance_clear_apc_confirm() {
  $form['confirm'] = array(
    '#value' => t('Confirm APC clear'),
  );
  return confirm_form($form, t('Are you sure you want to clear the APC statistics for this site?'), 'admin/settings/performance_logging', t('This will clear all the collected performance statistics stored in APC. This action cannot be undone.'), t('Clear'), t('Cancel'));
}
function performance_clear_apc_confirm_submit($form_id, &$form) {
  $list = performance_apc_list_all();
  if (!count($list)) {

    // Nothing stored yet
    return;
  }
  foreach ($list as $key) {
    if ($data = apc_fetch($key)) {
      apc_delete($key);
    }
  }
  drupal_set_message(t('Performance statistics collected in APC has been cleared.'));
  drupal_goto('admin/settings/performance');
}
function performance_url($path = '', $title = '') {
  if (variable_get('performance_titles', 0)) {

    // Show titles
    $ret = $title ? l($title, $path) : l($path, $path);
    return $ret;
  }
  else {

    // Show URLs only
    return $path;
  }
}