Newer
Older
<?php
// $Id$
/**
* @file
* Logs detailed and/or summary page generation time and memory consumption for page requests.
* Copyright Khalid Baheyeldin 2008 of http://2bits.com
*/
define('PERFORMANCE_KEY', 'dru-perf:' . $_SERVER['HTTP_HOST'] . ':');
function performance_menu() {
$items = array();
$items['admin/config/development/performance_logging'] = array(
'title' => 'Performance logging',
Moshe Weitzman
committed
'description' => 'Logs performance data: page generation times and memory usage.',
'page callback' => 'drupal_get_form',
'page arguments' => array('performance_settings'),
'access arguments' => array('access administration pages'),
);
$items['admin/config/development/performance_logging/apc_clear'] = array(
Moshe Weitzman
committed
'title' => 'Clear APC',
'description' => 'Clears performance statistics collected in APC.',
'page callback' => 'drupal_get_form',
'page arguments' => array('performance_clear_apc_confirm'),
'access arguments' => array('access administration pages'),
);
$items['admin/reports/performance_logging_summary'] = array(
Moshe Weitzman
committed
'title' => 'Performance Logs: Summary',
'description' => 'View summary performance logs: page generation times and memory usage.',
'page callback' => 'performance_view_summary',
'access arguments' => array('access site reports'),
);
$items['admin/reports/performance_logging_details'] = array(
Moshe Weitzman
committed
'title' => 'Performance Logs: Details',
'description' => 'View detailed, per page, performance logs: page generation times and memory usage.',
'page callback' => 'performance_view_details',
'access arguments' => array('access site reports'),
);
return $items;
}
function performance_settings() {
$options = array(
0 => t('Disabled'),
1 => t('Enabled'),
);
if (function_exists('apc_cache_info')) {
drupal_set_message(t('APC is enabled. It is reasonably safe to enable summary logging on live sites.'), 'status', FALSE);
}
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', FALSE);
}
$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_cache_info')) {
$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,
);
Khalid Baheyeldin
committed
$form['other']['performance_query'] = array(
'#type' => 'select',
'#title' => t('Database Query timing and count'),
Khalid Baheyeldin
committed
'#default_value' => variable_get('performance_query', 0),
'#options' => $options,
Khalid Baheyeldin
committed
'#description' => t('Log database query timing and query 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. Enabling this will incurr some memory overhead as query times and the actual query strings are cached in memory as arrays for each page, hence skewing the overall page memory reported.'),
);
$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);
}
Khalid Baheyeldin
committed
function performance_boot() {
register_shutdown_function('performance_shutdown');
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0)) {
//TODO: See if devel.module has changed this ...
@include_once DRUPAL_ROOT . '/includes/database/log.inc';
Database::startLog('performance', 'default');
}
}
function performance_shutdown() {
Khalid Baheyeldin
committed
$queries = Database::getLog('performance', 'default');
if ($_GET['q']) {
// q= has a value, use that for the path
$path = $_GET['q'];
}
else {
// q= is empty, use whatever the site_frontpage is set to
$path = variable_get('site_frontpage', 'node');
}
$params = array(
'timer' => timer_read('page'),
);
// 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;
Khalid Baheyeldin
committed
$sum = 0;
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0) && is_array($queries)) {
foreach ($queries as $query) {
Khalid Baheyeldin
committed
$sum += $query['time'];
$query_count++;
}
$query_timer = round($sum * 1000, 2);
}
$params['query_count'] = $query_count;
$params['query_timer'] = $query_timer;
$anon = (!empty($data['anon'])) ? t('Yes') : t('No');
$header = array(
'path' => $path,
'timer' => $params['timer'],
'anon' => $anon,
);
module_invoke_all('performance', 'header', $header);
if (variable_get('performance_detail', 0)) {
$data = module_invoke_all('performance', 'data');
$params['data'] = !empty($data[0]) ? $data[0] : NULL;
performance_log_details($params);
}
else {
module_invoke_all('performance', 'disable');
}
if (variable_get('performance_summary_db', 0)) {
performance_log_summary_db($params);
}
if (variable_get('performance_summary_apc', 0)) {
if (function_exists('apc_cache_info')) {
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' => REQUEST_TIME,
'bytes_max' => max($params['mem'], $data['bytes_max']),
'bytes_avg' => ($data['bytes_avg'] + $params['mem']) / 2,
'ms_max' => max($params['timer'], $data['ms_max']),
'ms_avg' => ($data['ms_avg'] + $params['timer']) / 2,
'query_timer_max' => max($params['query_timer'], $data['query_timer_max']),
'query_timer_avg' => ($data['query_timer_avg'] + $params['query_timer']) / 2,
'query_count_max' => max($params['query_count'], $data['query_count_max']),
'query_count_avg' => ($data['query_count_avg'] + $params['query_count']) / 2,
'num_accesses' => $data['num_accesses'] + 1,
);
}
else {
$data = array(
'path' => $params['path'],
'bytes_max' => $params['mem'],
'bytes_avg' => $params['mem'],
'ms_max' => $params['timer'],
'ms_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' => REQUEST_TIME,
);
}
apc_store($key, $data);
}
function performance_log_summary_db($params = array()) {
$row = db_query("SELECT * FROM {performance_summary} WHERE path = :path", array(':path' => $params['path']))->fetch();
if ($row) {
db_update('performance_summary')
->condition('path', $params['path'])
->fields(array(
'last_access' => REQUEST_TIME,
'num_accesses' => $row->num_accesses + 1,
'bytes_max' => max($params['mem'], $row->bytes_max),
'bytes_avg' => ($row->bytes_avg + $params['mem']) / 2,
'ms_max' => max($params['timer'], $row->ms_max),
'ms_avg' => ($row->ms_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,
))
->execute();
}
else {
// First time we log this path, write fresh values
$fields = array(
'last_access' => REQUEST_TIME,
'num_accesses' => 1,
'bytes_max' => $params['mem'],
'bytes_avg' => $params['mem'],
'ms_max' => $params['timer'],
'ms_avg' => $params['timer'],
'query_timer_max' => $params['query_count'],
'query_timer_avg' => $params['query_count'],
'query_count_max' => $params['query_timer'],
'query_count_avg' => $params['query_timer'],
'path' => $params['path'],
db_insert('performance_summary')
->fields($fields)
->execute();
}
}
function performance_log_details($params = array()) {
global $user;
$fields = array(
'timestamp' => REQUEST_TIME,
'bytes' => $params['mem'],
'ms' => $params['timer'],
'query_count' => $params['query_count'],
'query_timer' => $params['query_timer'],
'anon' => ($user->uid) ? 0 : 1,
'path' => $params['path'],
'data' => $params['data'],
db_insert('performance_detail')
->fields($fields)
->execute();
} catch (Exception $e) {
echo $e->getMessage();
}
}
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;
}
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
/**
* Custom sort for summary performance report
*
* @param $x
* @param $y
* @return int
*/
function performance_summary_sort($x, $y) {
$epsilon = 1E-8; // arbitrary (mostly)
$column = $x['sql']; // N.B.: === $y['sql']
// These arrays only contain integer and float values, so can use "-"
$diff = $x[$column] - $y[$column];
// Specific floating-point equality test
if (gettype($x[$column]) == 'float') {
if (abs($diff) < $epsilon) {
return 0;
}
}
if ($diff === 0) { // Will never happen for floats
return 0;
}
else {
$ret = ($diff < 0) ? -1 : 1;
if ($x['sort'] == 'desc') {
$ret = - $ret;
}
return $ret;
}
}
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 <a href="!link">settings page</a> to enable it.',
Khalid Baheyeldin
committed
array('!link' => url('admin/config/development/performance_logging')));
}
Khalid Baheyeldin
committed
$header = array();
$header[] = array('data' => t('Path'), 'field' => 'path');
$header[] = array('data' => t('Last access'), 'field' => 'last_access');
$header[] = array('data' => t('# accesses'), 'field' => 'num_accesses');
$header[] = array('data' => t('MB Memory (Max)'), 'field' => 'bytes_max');
$header[] = array('data' => t('MB Memory (Avg)'), 'field' => 'bytes_avg');
$header[] = array('data' => t('ms (Max)'), 'field' => 'ms_max');
$header[] = array('data' => t('ms (Avg)'), 'field' => 'ms_avg');
Khalid Baheyeldin
committed
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0)) {
$header[] = array('data' => t('Query ms (Max)'), 'field' => 'query_timer_max');
$header[] = array('data' => t('Query ms (Avg)'), 'field' => 'query_timer_avg');
$header[] = array('data' => t('Query Count (Max)'), 'field' => 'query_count_max');
$header[] = array('data' => t('Query Count (Avg)'), 'field' => 'query_count_avg');
Khalid Baheyeldin
committed
}
$total_rows = $shown = $last_max = $total_bytes = $total_ms = $total_accesses = 0;
$last_min = REQUEST_TIME;
$threshold = variable_get('performance_threshold_accesses', 0);
Khalid Baheyeldin
committed
$data_list = array();
Khalid Baheyeldin
committed
$pager_height = 50;
if (variable_get('performance_summary_apc', 0) && function_exists('apc_cache_info')) {
$tablesort = tablesort_init($header);
// Get the data from the APC cache
foreach (performance_apc_list_all() as $key) {
$data_list[] = apc_fetch($key) + $tablesort;
usort($data_list, 'performance_summary_sort');
Khalid Baheyeldin
committed
// Set up pager since this is not done automatically when not using DB
$page = isset($_GET['page']) ? $_GET['page'] : 0; // unsafe
$page = sprintf('%d', $page); // now safe
Khalid Baheyeldin
committed
$pager_page_array, // array of element-keyed current page - 1
$pager_total, // array of element-keyed total number of pages
$pager_total_items, // array of element-keyed total number of data rows
Khalid Baheyeldin
committed
$pager_limits; // array of element-keyed number of rows per page
Khalid Baheyeldin
committed
$pager_page_array = array(0 => $page);
$pager_total_items = array(0 => count($data_list));
$pager_limits = array(0 => $pager_height);
$pager_total = array(0 => ceil($pager_total_items[0] / $pager_limits[0]));
Khalid Baheyeldin
committed
// Extract the data subset we need
$data_list = array_slice($data_list, $page * $pager_height, $pager_height);
}
else {
// Get the data form the database table
$result = db_select('performance_summary', 'p')
->fields('p')
->extend('PagerDefault')
->limit($pager_height)
->extend('TableSort')
->orderByHeader($header)
->execute();
foreach ($result as $row) {
$data_list[] = $row;
}
}
foreach ($data_list as $data) {
$data = (object) $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_ms += $data->ms_avg;
$total_accesses += $data->num_accesses;
Khalid Baheyeldin
committed
$row_data = array();
if ($data->num_accesses > $threshold) {
$shown++;
$row_data[] = $data->path;
$row_data[] = format_date($data->last_access, 'small');
$row_data[] = $data->num_accesses;
$row_data[] = number_format($data->bytes_max/1024/1024, 2);
$row_data[] = number_format($data->bytes_avg/1024/1024, 2);
$row_data[] = number_format($data->ms_max, 1);
$row_data[] = number_format($data->ms_avg, 1);
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0)) {
$row_data[] = number_format($data->query_timer_max, 1);
$row_data[] = number_format($data->query_timer_avg, 1);
$row_data[] = $data->query_count_max;
$row_data[] = $data->query_count_avg;
Khalid Baheyeldin
committed
}
Khalid Baheyeldin
committed
$rows[] = array('data' => $row_data);
}
if (!$rows) {
$rows[] = array(array('data' => t('No statistics available yet.'), 'colspan' => count($header)));
}
$output = '';
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_ms/$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 duration per page: !ms_avg ms', 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/>';
Khalid Baheyeldin
committed
$output .= theme_table(array(
'header' => $header,
'rows' => $rows,
Khalid Baheyeldin
committed
'attributes' => array(),
'caption' => NULL,
'colgroups' => NULL,
'sticky' => TRUE,
'empty' => t('No data has been collected.'),
Khalid Baheyeldin
committed
));
$output .= theme_pager(array(
'tags' => NULL,
'element' => 0,
'parameters' => $header,
Khalid Baheyeldin
committed
'quantity' => 9));
return $output;
}
function performance_view_details() {
if (!variable_get('performance_detail', 0)) {
return t('Detail performance log is not enabled. Go to the <a href="@link">settings page</a> to enable it.',
array('@link' => url('admin/config/development/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('ms (Total)'), 'field' => 'ms'),
array('data' => t('Anonymous?'), 'field' => 'anon'),
);
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0)) {
$header[] = array('data' => t('# Queries'), 'field' => 'query_count');
$header[] = array('data' => t('Query ms'), 'field' => 'query_timer');
Khalid Baheyeldin
committed
}
Khalid Baheyeldin
committed
$pager_height = 50;
$result = db_select('performance_detail', 'p')
->fields('p')
->extend('PagerDefault')
->limit($pager_height)
->extend('TableSort')
->orderByHeader($header)
->execute();
Khalid Baheyeldin
committed
foreach ($result as $data) {
Khalid Baheyeldin
committed
$row_data = array();
Khalid Baheyeldin
committed
$row_data[] = $data->pid;
$row_data[] = format_date($data->timestamp, 'small');
$row_data[] = $data->path;
$row_data[] = number_format($data->bytes/1024/1024, 2);
$row_data[] = $data->ms;
Khalid Baheyeldin
committed
$row_data[] = ($data->anon) ? t('Yes') : t('No');
Khalid Baheyeldin
committed
Khalid Baheyeldin
committed
if (variable_get('performance_query', 0)) {
Khalid Baheyeldin
committed
$row_data[] = $data->query_count;
$row_data[] = $data->query_timer;
Khalid Baheyeldin
committed
}
$rows[] = array('data' => $row_data);
}
if (!$rows) {
$rows[] = array(array('data' => t('No log messages available.'), 'colspan' => count($header)));
}
$output = theme('table', array('header' => $header, 'rows' => $rows));
$output .= theme('pager', array('tags' => NULL, 'quantity' => $pager_height));
return $output;
}
function performance_cron() {
// One day ago ...
$timestamp = time() - 24*60*60;
performance_cron_db_prune($timestamp);
performance_cron_apc_prune($timestamp);
}
function performance_cron_db_prune($timestamp = 0) {
// Remove rows which have not been accessed since a certain timestamp
db_delete('performance_summary')->condition('last_access', $timestamp, '<=');
// Remove performance_detail rows on a daily basis
db_delete('performance_detail')->condition('timestamp', $timestamp, '<=');
}
function performance_cron_apc_prune($timestamp = 0) {
if (!function_exists('apc_cache_info')) {
// APC not enabled, nothing to do ...
return;
}
// Get all entries in APC's user cache
$list = performance_apc_list_all();
if (!count($list)) {
// Nothing stored yet
return;
}
foreach ($list as $key) {
if ($data = apc_fetch($key)) {
if ($data['last_access'] <= $timestamp) {
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/config/development/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) {
if (!function_exists('apc_cache_info')) {
drupal_set_message(t('APC is not enabled. Nothing to do ...'), 'status', FALSE);
drupal_goto('admin/config/development/performance');
return;
}
$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.'), 'status', FALSE);
drupal_goto('admin/config/development/performance');
}
/**
* Implementation of hook_nagios_info()
*/
function performance_nagios_info() {
return array(
'name' => 'Performance logging',
'id' => 'PERF',
);
}
/**
* Implementation of hook_nagios()
*/
function performance_nagios() {
$info = performance_nagios_info();
// Find out if we have what we need enabled
$sum = array();
$sum[] = variable_get('performance_summary_db', 0);
$sum[] = variable_get('performance_summary_apc', 0);
$go = array_sum($sum);
if (!$go) {
return array(
$id => array(
'status' => NAGIOS_STATUS_UNKNOWN,
Khalid Baheyeldin
committed
'type' => 'perf',
'text' => t('Performance logging is not enabled'),
),
);
}
// Initialize variables
$total_rows = $total_bytes = $total_ms = $total_accesses = $total_query_time = $total_query_count = 0;
if (variable_get('performance_summary_apc', 0) && function_exists('apc_cache_info')) {
foreach (performance_apc_list_all() as $key) {
}
else {
Khalid Baheyeldin
committed
// Get the data form the database table for URLs that have been accessed in the last 15 minutes
$result = db_query("SELECT * FROM {performance_summary} WHERE last_access >= %d", time() - 15*60);
while ($row = db_fetch_array($result)) {
foreach ($data_list as $data) {
$total_rows++;
// Calculate running averages
$total_bytes += $data['bytes_avg'];
$total_ms += $data['ms_avg'];
$total_accesses += $data['num_accesses'];
$total_query_time += $data['query_timer_avg'];
$total_query_count += $data['query_count_avg'];
}
// Protect against divide by zero
if ($total_rows > 0) {
$ms_avg = number_format($total_ms / $total_rows, 1, '.', '');
$ms_query = number_format($total_query_time / $total_rows, 1, '.', '');
$query_count = number_format($total_query_count / $total_rows, 2, '.', '');
$mb_avg = number_format($total_bytes / $total_rows/1024/1024, 1);
Khalid Baheyeldin
committed
$mb_avg = '';
$ms_avg = '';
$ms_query = '';
$query_count = '';
}
$status = NAGIOS_STATUS_OK;
return array(
Khalid Baheyeldin
committed
'ACC' => array(
Khalid Baheyeldin
committed
'type' => 'perf',
'text' => $total_accesses,
),
'MS' => array(
'status' => $status,
'type' => 'perf',
'text' => $ms_avg,
),
'MMB' => array(
'status' => $status,
'type' => 'perf',
'text' => $mb_avg,
),
'QRC' => array(
'status' => $status,
'type' => 'perf',
'text' => $query_count,
),
'QRT' => array(
'status' => $status,
'type' => 'perf',
'text' => $ms_query,