6 * Logs detailed and/or summary page generation time and memory
7 * consumption for page requests.
9 * Copyright Khalid Baheyeldin 2008 of http://2bits.com
12 define('PERFORMANCE_KEY', 'dru-perf:'.
$_SERVER['HTTP_HOST'] .
':');
13 define('PERFORMANCE_MEMCACHE_BIN', 'cache_performance');
15 function performance_memcache_enabled() {
18 if (function_exists('dmemcache_set') && isset($conf['memcache_bins']['cache_performance'])) {
24 function performance_menu() {
27 $items['admin/settings/performance_logging'] = array(
28 'title' => 'Performance logging',
29 'description' => 'Logs performance data: page generation times and memory usage.',
30 'page callback' => 'drupal_get_form',
31 'page arguments' => array('performance_settings'),
32 'access arguments' => array('access administration pages'),
35 $items['admin/settings/performance_logging/apc_clear'] = array(
36 'title' => 'Clear APC',
37 'description' => 'Clears performance statistics collected in APC.',
38 'page callback' => 'drupal_get_form',
39 'page arguments' => array('performance_clear_apc_confirm'),
40 'access arguments' => array('access administration pages'),
43 $items['admin/settings/performance_logging/memcache_clear'] = array(
44 'title' => 'Clear Memcache',
45 'description' => 'Clears performance statistics collected in Memcache.',
46 'page callback' => 'drupal_get_form',
47 'page arguments' => array('performance_clear_memcache_confirm'),
48 'access arguments' => array('access administration pages'),
51 $items['admin/reports/performance_logging_summary'] = array(
52 'title' => 'Performance Logs: Summary',
53 'description' => 'View summary performance logs: page generation times and memory usage.',
54 'page callback' => 'performance_view_summary',
55 'access arguments' => array('access site reports'),
58 $items['admin/reports/performance_logging_details'] = array(
59 'title' => 'Performance Logs: Details',
60 'description' => 'View detailed, per page, performance logs: page generation times and memory usage.',
61 'page callback' => 'performance_view_details',
62 'access arguments' => array('access site reports'),
68 function performance_settings() {
74 if (function_exists('apc_cache_info')) {
75 drupal_set_message(t('APC is enabled. It is reasonably safe to enable summary logging on live sites.'), 'status', FALSE
);
78 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
);
81 $form['mode'] = array(
82 '#type' => 'fieldset',
83 '#title' => t('Logging mode'),
84 '#collapsible' => TRUE
,
87 $form['mode']['performance_detail'] = array(
89 '#title' => t('Detailed logging'),
90 '#default_value' => variable_get('performance_detail', 0),
91 '#options' => $options,
92 '#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.'),
95 $form['mode']['performance_summary_db'] = array(
97 '#title' => t('Summary logging (DB)'),
98 '#default_value' => variable_get('performance_summary_db', 0),
99 '#options' => $options,
100 '#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.'),
104 if (function_exists('apc_cache_info')) {
108 $form['mode']['performance_summary_apc'] = array(
110 '#title' => t('Summary logging (APC)'),
111 '#default_value' => variable_get('performance_summary_apc', 0),
112 '#options' => $options,
113 '#disabled' => $disabled,
114 '#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.'),
118 if (performance_memcache_enabled()) {
122 $form['mode']['performance_summary_memcache'] = array(
124 '#title' => t('Summary logging (Memcached)'),
125 '#default_value' => variable_get('performance_summary_memcache', 0),
126 '#options' => $options,
127 '#disabled' => $disabled,
128 '#description' => t('Log summary data, such as average and maximum page generation times and memory usage to Memcached, if installed. The summary will be stored in Memcached memory, and hence there is no load on the database. This logging to Memcached is suitable for most live sites, unless the number of unique page accesses is excessively high.'),
131 $form['other'] = array(
132 '#type' => 'fieldset',
133 '#title' => t('Other'),
134 '#collapsible' => TRUE
,
137 $form['other']['dev_query'] = array(
140 '#title' => t('Database Query timing and count'),
141 '#default_value' => variable_get('dev_query', 0),
142 '#options' => $options,
143 '#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. Please note that this settings is enabled or disabled in the settings of the devel module.'),
146 $form['other']['performance_threshold_accesses'] = array(
148 '#title' => t('Accesses threshold'),
149 '#default_value' => variable_get('performance_threshold_accesses', 0),
150 '#options' => array(0, 1, 2, 5, 10),
151 '#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.'),
154 return system_settings_form($form);
157 function performance_boot() {
158 register_shutdown_function('performance_shutdown');
161 function performance_shutdown() {
165 if (isset($_GET['q']) && ($_GET['q'])) {
166 // q= has a value, use that for the path
170 // q= is empty, use whatever the site_frontpage is set to
171 $path = variable_get('site_frontpage', 'node');
175 'timer' => timer_read('page'),
180 if (function_exists('memory_get_peak_usage')) {
181 $params['mem'] = memory_get_peak_usage(TRUE
);
187 // Query time and count
191 if (variable_get('dev_query', 0) && is_array($queries)) {
192 foreach ($queries as
$query) {
195 $query_count = count($queries);
196 $query_timer = round($sum * 1000, 2);
199 $params['query_count'] = $query_count;
200 $params['query_timer'] = $query_timer;
202 $anon = (!empty($data['anon']))?
'Yes' : 'No';
206 'timer' => $params['timer'],
209 module_invoke_all('performance', 'header', $header);
211 if (variable_get('performance_detail', 0)) {
212 $data = module_invoke_all('performance', 'data');
213 if (!empty($data[0])) {
214 $params['data'] = $data[0];
217 performance_log_details($params);
220 module_invoke_all('performance', 'disable');
223 if (variable_get('performance_summary_db', 0)) {
224 performance_log_summary_db($params);
227 if (variable_get('performance_summary_apc', 0)) {
228 if (function_exists('apc_cache_info')) {
229 performance_log_summary_apc($params);
233 if (variable_get('performance_summary_memcache', 0)) {
234 if (performance_memcache_enabled()) {
235 performance_log_summary_memcache($params);
240 function performance_log_summary_apc($params = array()) {
241 $key = PERFORMANCE_KEY .
$params['path'];
242 if ($data = apc_fetch($key)) {
244 'path' => $data['path'],
245 'last_access' => time(),
246 'bytes_max' => max($params['mem'], $data['bytes_max']),
247 'bytes_avg' => ($data['bytes_avg'] + $params['mem']) / 2,
248 'ms_max' => max($params['timer'], $data['ms_max']),
249 'ms_avg' => ($data['ms_avg'] + $params['timer']) / 2,
250 'query_timer_max' => max($params['query_timer'], $data['query_timer_max']),
251 'query_timer_avg' => ($data['query_timer_avg'] + $params['query_timer']) / 2,
252 'query_count_max' => max($params['query_count'], $data['query_count_max']),
253 'query_count_avg' => ($data['query_count_avg'] + $params['query_count']) / 2,
254 'num_accesses' => $data['num_accesses'] + 1,
259 'path' => $params['path'],
260 'bytes_max' => $params['mem'],
261 'bytes_avg' => $params['mem'],
262 'ms_max' => $params['timer'],
263 'ms_avg' => $params['timer'],
264 'query_timer_max' => $params['query_timer'],
265 'query_timer_avg' => $params['query_timer'],
266 'query_count_max' => $params['query_count'],
267 'query_count_avg' => $params['query_count'],
269 'last_access' => time(),
272 apc_store($key, $data);
275 function performance_log_summary_memcache($params = array()) {
276 $key = PERFORMANCE_KEY .
$params['path'];
277 if ($cache = cache_get($key, PERFORMANCE_MEMCACHE_BIN
)) {
279 $values = $cache->data
;
281 'path' => $params['path'],
282 'last_access' => time(),
283 'bytes_max' => max($params['mem'], $values['bytes_max']),
284 'bytes_avg' => ($values['bytes_avg'] + $params['mem']) / 2,
285 'ms_max' => max($params['timer'], $values['ms_max']),
286 'ms_avg' => ($values['ms_avg'] + $params['timer']) / 2,
287 'query_timer_max' => max($params['query_timer'], $values['query_timer_max']),
288 'query_timer_avg' => ($values['query_timer_avg'] + $params['query_timer']) / 2,
289 'query_count_max' => max($params['query_count'], $values['query_count_max']),
290 'query_count_avg' => ($values['query_count_avg'] + $params['query_count']) / 2,
291 'num_accesses' => $values['num_accesses'] + 1,
298 'path' => $params['path'],
299 'bytes_max' => $params['mem'],
300 'bytes_avg' => $params['mem'],
301 'ms_max' => $params['timer'],
302 'ms_avg' => $params['timer'],
303 'query_timer_max' => $params['query_timer'],
304 'query_timer_avg' => $params['query_timer'],
305 'query_count_max' => $params['query_count'],
306 'query_count_avg' => $params['query_count'],
308 'last_access' => time(),
311 if ($keys_cache = cache_get(PERFORMANCE_KEY
, PERFORMANCE_MEMCACHE_BIN
)) {
312 $keys_values = $keys_cache->data
;
314 $keys_values[$key] = 1;
315 cache_set(PERFORMANCE_KEY
, $keys_values, PERFORMANCE_MEMCACHE_BIN
, CACHE_PERMANENT
);
317 cache_set($key, $values, PERFORMANCE_MEMCACHE_BIN
, CACHE_PERMANENT
);
320 function performance_log_summary_db($params = array()) {
321 $row = db_fetch_object(db_query("SELECT * FROM {performance_summary} WHERE path = '%s'", $params['path']));
323 db_query("UPDATE {performance_summary}
324 SET last_access = %d,
325 num_accesses = num_accesses + 1,
330 query_timer_max = %d,
331 query_timer_avg = %d,
332 query_count_max = %d,
336 max($params['mem'], $row->bytes_max
),
337 ($row->bytes_avg
+ $params['mem']) / 2,
338 max($params['timer'], $row->ms_max
),
339 ($row->ms_avg
+ $params['timer']) / 2,
340 max($params['query_timer'], $row->query_timer_max
),
341 ($row->query_timer_avg
+ $params['query_timer']) / 2,
342 max($params['query_count'], $row->query_count_max
),
343 ($row->query_count_avg
+ $params['query_count']) / 2,
347 // First time we log this path, write fresh values
348 db_query("INSERT INTO {performance_summary}
349 (path, last_access, num_accesses,
350 bytes_max, bytes_avg, ms_max, ms_avg,
351 query_count_max, query_count_avg, query_timer_max, query_timer_avg)
353 ('%s', %d, %d, %d, %d, %d, %d, %d, %d, %d, %d)",
361 $params['query_count'],
362 $params['query_count'],
363 $params['query_timer'],
364 $params['query_timer']
369 function performance_log_details($params = array()) {
371 $anon = ($user->uid
) ? FALSE
: TRUE
;
372 db_query("INSERT INTO {performance_detail} (path, anon, bytes, ms, timestamp, query_timer, query_count, data) VALUES ('%s', %d, %d, %d, %d, %d, %d, '%s')",
378 $params['query_timer'],
379 $params['query_count'],
384 function performance_apc_list_all() {
386 $list = apc_cache_info('user');
387 if (!empty($list['cache_list'])) {
388 foreach ($list['cache_list'] as
$cache_id => $cache_data) {
389 $regex = '/^'. PERFORMANCE_KEY .
'/';
390 if (preg_match($regex, $cache_data['info'])) {
391 $key_list[] = $cache_data['info'];
399 * Custom sort for summary performance report
405 function performance_summary_sort($x, $y) {
406 // This function is not working
410 function performance_view_summary() {
412 $data_list = array();
415 $sum[] = variable_get('performance_summary_db', 0);
416 $sum[] = variable_get('performance_summary_apc', 0);
417 $sum[] = variable_get('performance_summary_memcache', 0);
418 $go = array_sum($sum);
421 return t('Summary performance log is not enabled. Go to the <a href="@link">settings page</a> to enable it.', array('@link' => url('admin/settings/performance_logging')));
426 $header[] = array('data' => t('Path'), 'field' => 'path');
427 $header[] = array('data' => t('Last access'), 'field' => 'last_access');
428 $header[] = array('data' => t('# accesses'), 'field' => 'num_accesses');
429 $header[] = array('data' => t('Max Memory (MB)'), 'field' => 'bytes_max');
430 $header[] = array('data' => t('Avg Memory (MB)'), 'field' => 'bytes_avg');
431 $header[] = array('data' => t('ms (Max)'), 'field' => 'ms_max');
432 $header[] = array('data' => t('ms (Avg)'), 'field' => 'ms_avg');
434 if (variable_get('dev_query', 0)) {
435 $header[] = array('data' => t('Query ms (Max)'), 'field' => 'query_timer_max');
436 $header[] = array('data' => t('Query ms (Avg)'), 'field' => 'query_timer_avg');
437 $header[] = array('data' => t('Query Count (Max)'), 'field' => 'query_count_max');
438 $header[] = array('data' => t('Query Count (Avg)'), 'field' => 'query_count_avg');
441 $total_rows = $shown = $last_max = $total_bytes = $total_ms = $total_accesses = 0;
444 $threshold = variable_get('performance_threshold_accesses', 0);
446 if (variable_get('performance_summary_memcache', 0) && performance_memcache_enabled()) {
447 $tablesort = tablesort_init($header);
448 // Get the data from memcache
449 if ($keys_cache = cache_get(PERFORMANCE_KEY
, PERFORMANCE_MEMCACHE_BIN
)) {
450 if ($keys_cache->data
) {
451 foreach ($keys_cache->data as
$key => $v) {
452 $cache = cache_get($key, PERFORMANCE_MEMCACHE_BIN
);
453 $data_list[] = $cache->data
;
457 usort($data_list, 'performance_summary_sort');
459 else if (variable_get('performance_summary_apc', 0) && function_exists('apc_cache_info')) {
460 $tablesort = tablesort_init($header);
461 // Get the data from the APC cache
462 foreach (performance_apc_list_all() as
$key) {
463 $data_list[] = apc_fetch($key) + $tablesort;
465 usort($data_list, 'performance_summary_sort');
468 // Get the data form the database table
469 $sql = "SELECT * FROM {performance_summary}";
470 $tablesort = tablesort_sql($header);
471 $result = pager_query($sql .
$tablesort, 50);
472 while ($row = db_fetch_array($result)) {
477 foreach ($data_list as
$data) {
479 $last_max = max($last_max, $data['last_access']);
480 $last_min = min($last_min, $data['last_access']);
482 // Calculate running averages
483 $total_bytes += $data['bytes_avg'];
484 $total_ms += $data['ms_avg'];
485 $total_accesses += $data['num_accesses'];
489 if ($data['num_accesses'] > $threshold) {
491 $row_data[] = check_plain($data['path']);
492 $row_data[] = format_date($data['last_access'], 'small');
493 $row_data[] = $data['num_accesses'];
494 $row_data[] = number_format($data['bytes_max']/1024/1024, 2);
495 $row_data[] = number_format($data['bytes_avg']/1024/1024, 2);
496 $row_data[] = number_format($data['ms_max'], 1);
497 $row_data[] = number_format($data['ms_avg'], 1);
498 if (variable_get('dev_query', 0)) {
499 $row_data[] = number_format($data['query_timer_max'], 1);
500 $row_data[] = number_format($data['query_timer_avg'], 1);
501 $row_data[] = $data['query_count_max'];
502 $row_data[] = $data['query_count_avg'];
505 $rows[] = array('data' => $row_data);
509 $rows[] = array(array('data' => t('No statistics available yet.'), 'colspan' => count($header)));
514 $output .
= t('Showing !shown paths with more than !threshold accesses, out of !total total paths.',
515 array('!threshold' => $threshold, '!shown' => $shown, '!total' => $total_rows)) .
'<br/>';
518 $output .
= t('Showing all !total paths.', array('!total' => $total_rows)) .
'<br/>';
521 // Protect against divide by zero
522 if ($total_rows > 0) {
523 $mb_avg = number_format($total_bytes/$total_rows/1024/1024, 1);
524 $ms_avg = number_format($total_ms/$total_rows, 2);
531 $output .
= t('Average memory per page: !mb_avg MB', array('!mb_avg' => $mb_avg)) .
'<br/>';
532 $output .
= t('Average ms per page: !ms_avg', array('!ms_avg' => $ms_avg)) .
'<br/>';
533 $output .
= t('Total number of page accesses: !accesses', array('!accesses' => $total_accesses)) .
'<br/>';
534 $output .
= t('First access: !access.', array('!access' => format_date($last_min, 'small'))) .
'<br/>';
535 $output .
= t('Last access: !access.', array('!access' => format_date($last_max, 'small'))) .
'<br/>';
537 $output .
= theme('table', $header, $rows);
538 $output .
= theme('pager', NULL
, 50, 0);
543 function performance_view_details() {
544 if (!variable_get('performance_detail', 0)) {
545 return t('Detail performance log is not enabled. Go to the <a href="@link">settings page</a> to enable it.', array('@link' => url('admin/settings/performance_logging')));
549 array('data' => t('#'), 'field' => 'pid', 'sort' => 'desc'),
550 array('data' => t('Date'), 'field' => 'timestamp'),
551 array('data' => t('Path'), 'field' => 'path'),
552 array('data' => t('Memory (MB)'), 'field' => 'bytes'),
553 array('data' => t('ms (Total)'), 'field' => 'ms'),
554 array('data' => t('Anonymous?'), 'field' => 'anon'),
557 if (variable_get('dev_query', 0)) {
558 $header[] = array('data' => t('# Queries'), 'field' => 'query_count');
559 $header[] = array('data' => t('Query ms'), 'field' => 'query_timer');
562 $sql = "SELECT * FROM {performance_detail}";
563 $tablesort = tablesort_sql($header);
564 $result = pager_query($sql .
$tablesort, 50);
566 while ($data = db_fetch_array($result)) {
569 $row_data[] = $data['pid'];
570 $row_data[] = format_date($data['timestamp'], 'small');
571 $row_data[] = check_plain($data['path']);
572 $row_data[] = number_format($data['bytes']/1024/1024, 2);
573 $row_data[] = $data['ms'];
574 $row_data[] = ($data['anon']) ?
t('Yes') : t('No');
576 if (variable_get('dev_query', 0)) {
577 $row_data[] = $data['query_count'];
578 $row_data[] = $data['query_timer'];
581 $rows[] = array('data' => $row_data);
585 $rows[] = array(array('data' => t('No log messages available.'), 'colspan' => count($header)));
588 $output = theme('table', $header, $rows);
589 $output .
= theme('pager', NULL
, 50, 0);
594 function performance_cron() {
596 $timestamp = time() - 24*60*60;
598 performance_cron_db_prune($timestamp);
599 performance_cron_apc_prune($timestamp);
602 function performance_cron_db_prune($timestamp = 0) {
603 // Remove rows which have not been accessed since a certain timestamp
604 db_query("DELETE FROM {performance_summary} WHERE last_access <= %d", $timestamp);
606 // Remove performance_detail rows on a daily basis
607 db_query("DELETE FROM {performance_detail} WHERE timestamp <= %d", $timestamp);
610 function performance_cron_apc_prune($timestamp = 0) {
611 if (!function_exists('apc_cache_info')) {
612 // APC not enabled, nothing to do ...
616 // Get all entries in APC's user cache
617 $list = performance_apc_list_all();
619 // Nothing stored yet
623 foreach ($list as
$key) {
624 if ($data = apc_fetch($key)) {
625 if ($data['last_access'] <= $timestamp) {
632 function performance_clear_apc_confirm() {
633 $form['confirm'] = array(
634 '#value' => t('Confirm APC clear'),
638 t('Are you sure you want to clear the APC statistics for this site?'),
639 'admin/settings/performance_logging',
640 t('This will clear all the collected performance statistics stored in APC. This action cannot be undone.'),
645 function performance_clear_apc_confirm_submit($form, &$form_state) {
646 if (!function_exists('apc_cache_info')) {
647 drupal_set_message(t('APC is not enabled. Nothing to do ...'), 'status', FALSE
);
648 drupal_goto('admin/settings/performance');
652 $list = performance_apc_list_all();
654 // Nothing stored yet
658 foreach ($list as
$key) {
659 if ($data = apc_fetch($key)) {
664 drupal_set_message(t('Performance statistics collected in APC has been cleared.'), 'status', FALSE
);
665 drupal_goto('admin/settings/performance');
668 function performance_clear_memcache_confirm() {
669 $form['confirm'] = array(
670 '#value' => t('Confirm Memcache clear'),
674 t('Are you sure you want to clear the Memcache statistics for this site?'),
675 'admin/settings/performance_logging',
676 t('This will clear all the collected performance statistics stored in Memcache. This action cannot be undone.'),
681 function performance_clear_memcache_confirm_submit($form, &$form_state) {
682 if (!performance_memcache_enabled()) {
683 drupal_set_message(t('Memcache is not enabled. Nothing to do ...'), 'status', FALSE
);
684 drupal_goto('admin/settings/performance');
688 // We have to iterate over all entries and delete them, reaching down
689 // the API stack and calling dmemcache_delete directly.
690 // This is suboptimal, but there is no other alternative
691 if ($keys_cache = cache_get(PERFORMANCE_KEY
, PERFORMANCE_MEMCACHE_BIN
)) {
692 if ($keys_cache->data
) {
693 foreach ($keys_cache->data as
$key => $v) {
694 dmemcache_delete($key, PERFORMANCE_MEMCACHE_BIN
);
696 dmemcache_delete(PERFORMANCE_KEY
, PERFORMANCE_MEMCACHE_BIN
);
700 drupal_set_message(t('Performance statistics collected in Memcache has been cleared.'), 'status', FALSE
);
701 drupal_goto('admin/settings/performance');
705 * Implementation of hook_nagios_info().
707 function performance_nagios_info() {
709 'name' => 'Performance logging',
715 * Implementation of hook_nagios().
717 function performance_nagios() {
718 $info = performance_nagios_info();
721 // Find out if we have what we need enabled
724 $sum[] = variable_get('performance_summary_db', 0);
725 $sum[] = variable_get('performance_summary_apc', 0);
726 $go = array_sum($sum);
731 'status' => NAGIOS_STATUS_UNKNOWN
,
733 'text' => t('Performance logging is not enabled'),
738 // Initialize variables
739 $total_rows = $total_bytes = $total_ms = $total_accesses = $total_query_time = $total_query_count = 0;
741 // Check which data store to use
742 if (variable_get('performance_summary_apc', 0) && function_exists('apc_cache_info')) {
743 // Get the data from the APC cache
744 foreach (performance_apc_list_all() as
$key) {
745 $data_list[] = apc_fetch($key);
749 // Get the data form the database table for URLs that have been accessed in the last 15 minutes
750 $result = db_query("SELECT * FROM {performance_summary} WHERE last_access >= %d", time() - 15*60);
751 while (is_array($row = db_fetch_array($result))) {
756 foreach ($data_list as
$data) {
759 // Calculate running averages
760 $total_bytes += $data['bytes_avg'];
761 $total_ms += $data['ms_avg'];
762 $total_accesses += $data['num_accesses'];
763 $total_query_time += $data['query_timer_avg'];
764 $total_query_count += $data['query_count_avg'];
767 // Protect against divide by zero
768 if ($total_rows > 0) {
769 $ms_avg = number_format($total_ms / $total_rows, 1, '.', '');
770 $ms_query = number_format($total_query_time / $total_rows, 1, '.', '');
771 $query_count = number_format($total_query_count / $total_rows, 2, '.', '');
772 $mb_avg = number_format($total_bytes / $total_rows/1024/1024, 1);
781 $status = NAGIOS_STATUS_OK
;
787 'text' => $total_accesses,
802 'text' => $query_count,