Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

add support to ignore specified functions during profiling; more tests

git-svn-id: https://svn.php.net/repository/pecl/xhprof/trunk@281203 c90b9560-bf6c-de11-be94-00142212c4b1
  • Loading branch information...
commit 292d183942c1898e172fc409842b0e48e2716be7 1 parent a693abf
kannan authored
View
7 CHANGELOG
@@ -1,5 +1,12 @@
Modification History:
+ *** NOTE ***
+ DO NOT UPDATE THIS FILE. UPDATE package.xml INSTEAD.
+ This file contains the CHANGELOG for the initial release. For subsequent
+ releases, the CHANGLELOG is maintained in the package.xml file itself.
+ Please edit package.xml instead.
+ ************
+
03/02/2008 kannan, checkin xhprof_html/ and xhprof_lib/ directories.
cjiang [These contain PHP sources for the UI as well
as various supporting libraries to compute
View
2  extension/tests/xhprof_005.phpt
@@ -8,7 +8,7 @@ Author: Kannan
// Some coarse grained sanity tests for the time just
// to make sure profiler's timer implementation isn't
// way off.
-// The test allows for gives a 25% margin of error.
+// The test allows for a 25% margin of error.
//
include_once dirname(__FILE__).'/common.php';
View
78 extension/tests/xhprof_006.phpt
@@ -0,0 +1,78 @@
+--TEST--
+XHPRrof: Basic Sampling Test
+Author: mpal
+--FILE--
+<?php
+
+include_once dirname(__FILE__).'/common.php';
+
+function individual_strings($limit) {
+ $sum = 0;
+ $t1 = microtime(true);
+ $half = $limit/2;
+ for ($idx = 0; $idx < $limit; $idx++) {
+ $query = 'SELECT ';
+ if ($idx < $half) {
+ $query .= 'first_half';
+ } else {
+ $query .= 'second_half';
+ }
+ $query .= ' FROM database';
+ $sum += strlen($query);
+ }
+ $t2 = microtime(true);
+ $delta = $t2 - $t1;
+ return $delta;
+}
+
+function folded_strings($limit) {
+ $sum = 0;
+ $t1 = microtime(true);
+ $half = $limit/2;
+ for ($idx = 0; $idx < $limit; $idx++) {
+ if ($idx < $half) {
+ $query = 'SELECT first_half FROM database';
+ } else {
+ $query = 'SELECT second_half FROM database';
+ }
+ $sum += strlen($query);
+ }
+ $t2 = microtime(true);
+ $delta = $t2 - $t1;
+ return $delta;
+}
+
+function foo($x) {
+ $time_individual = individual_strings($x);
+ $time_folded = folded_strings($x);
+ $time_total = $time_individual + $time_folded;
+ $percent_individual = ($time_individual / $time_total) * 100;
+ $percent_folded = ($time_folded / $time_total) * 100;
+ echo "Test Case : Percent of Total Time\n";
+ echo "Individual :" /* . " $percent_individual" */ . "\n";
+ echo "Folded :" /* . " $percent_folded" */ . "\n";
+ return strlen("hello: {$x}");
+}
+
+// 1: Sanity test a sampling profile run
+echo "Part 1: Sampling Profile\n";
+xhprof_sample_enable();
+foo(5000);
+$output = xhprof_sample_disable();
+
+echo "Part 1: output\n";
+echo "In general, sampling output depends upon execution speed.\n";
+echo "Currently checking that this runs to completion.\n";
+// print_r($output);
+echo "\n";
+
+?>
+--EXPECT--
+Part 1: Sampling Profile
+Test Case : Percent of Total Time
+Individual :
+Folded :
+Part 1: output
+In general, sampling output depends upon execution speed.
+Currently checking that this runs to completion.
+
View
274 extension/tests/xhprof_007.phpt
@@ -0,0 +1,274 @@
+--TEST--
+XHPRrof: Test excluding call_user_func and similar functions
+Author: mpal
+--FILE--
+<?php
+
+include_once dirname(__FILE__).'/common.php';
+
+$xhprof_ignored_functions = array( 'ignored_functions' =>
+ array('call_user_func',
+ 'call_user_func_array',
+ 'my_call_user_func_safe',
+ 'my_call_user_func_array_safe'));
+function bar() {
+ return 1;
+}
+
+function foo($x) {
+ $sum = 0;
+ for ($idx = 0; $idx < 2; $idx++) {
+ $sum += bar();
+ }
+ echo "hello: {$x}\n" ;
+ return strlen("hello: {$x}");
+}
+
+function foo_array($x1, $x2 = 'test') {
+ $sum = 0;
+ $x = array($x1, $x2);
+ foreach ($x as $idx) {
+ $sum += bar();
+ }
+ echo "hello: " . $x[0] . $x[1] . "\n";
+ return strlen("hello: {$x[0]} {$x[1]}");
+}
+
+function my_call_user_func_safe($function, $args = 'my_safe') {
+ if (!is_callable($function, true)) {
+ throw new Exception('my_call_user_func_safe() invoked without ' .
+ 'a valid callable.');
+ }
+
+ call_user_func($function, array($args));
+}
+
+function my_call_user_func_array_safe($function, $args = array()) {
+ if (!is_callable($function, true)) {
+ throw new Exception('my_call_user_func_array_safe() invoked without ' .
+ 'a valid callable.');
+ }
+
+ call_user_func_array($function, $args);
+}
+
+
+class test_call_user_func {
+ function test_call_user_func($test_func = 'foo',
+ $arg1 = 'user_func test') {
+ call_user_func($test_func, $arg1);
+ }
+}
+
+function test_call_user_func_array($test_func = 'foo_array',
+ $arg1 = array(0 => 'user_func_array',
+ 'test')) {
+ call_user_func_array($test_func, $arg1);
+}
+
+function test_my_call_user_func_safe($test_func = 'foo',
+ $arg1 = 'my_user_func_safe test') {
+ my_call_user_func_safe($test_func, $arg1);
+}
+
+function test_my_call_user_func_array_safe(
+ $test_func = 'foo_array',
+ $arg1 = array('my_user_func_array_safe',
+ 'test')) {
+ my_call_user_func_array_safe($test_func, $arg1);
+}
+
+
+// 1: Sanity test a simple profile run
+echo "Part 1: Default Flags\n";
+xhprof_enable(0, $xhprof_ignored_functions);
+foo("this is a test");
+$array_arg = array();
+$array_arg[] = 'calling ';
+$array_arg[] = 'foo_array';
+foo_array($array_arg);
+
+$output = xhprof_disable();
+echo "Part 1 output:\n";
+print_canonical($output);
+echo "\n";
+
+// 2a: Sanity test ignoring call_user_func
+echo "Part 2a: Ignore call_user_func\n";
+xhprof_enable(0, $xhprof_ignored_functions);
+$indirect_foo = new test_call_user_func('foo');
+$output = xhprof_disable();
+echo "Part 2a output:\n";
+print_canonical($output);
+echo "\n";
+
+// 2b: Confirm that profiling without parameters still works
+echo "Part 2b: Standard profile without parameters\n";
+xhprof_enable();
+$indirect_foo = new test_call_user_func('foo');
+$output = xhprof_disable();
+echo "Part 2b output:\n";
+print_canonical($output);
+echo "\n";
+
+// 2c: Confirm that empty array of ignored functions works
+echo "Part 2c: Standard profile with empty array of ignored functions\n";
+xhprof_enable(0, array());
+$indirect_foo = new test_call_user_func('foo');
+$output = xhprof_disable();
+echo "Part 2c output:\n";
+print_canonical($output);
+echo "\n";
+
+// 3: Sanity test ignoring call_user_func_array
+echo "Part 3: Ignore call_user_func_array\n";
+xhprof_enable(XHPROF_FLAGS_CPU, $xhprof_ignored_functions);
+test_call_user_func_array('foo_array', $array_arg);
+$output = xhprof_disable();
+echo "Part 3 output:\n";
+print_canonical($output);
+echo "\n";
+
+// 4: Sanity test ignoring my_call_user_func_safe
+echo "Part 4: Ignore my_call_user_func_safe\n";
+xhprof_enable(0, $xhprof_ignored_functions);
+test_my_call_user_func_safe('foo');
+$output = xhprof_disable();
+echo "Part 4 output:\n";
+print_canonical($output);
+echo "\n";
+
+// 5a: Sanity test ignoring my_call_user_func_array_safe and strlen
+echo "Part 5a: Ignore my_call_user_func_array_safe and strlen\n";
+$tmp1 = $xhprof_ignored_functions['ignored_functions'];
+$tmp1[] = 'strlen';
+$ignore_strlen_also = array('ignored_functions' => $tmp1);
+xhprof_enable(XHPROF_FLAGS_MEMORY, $ignore_strlen_also);
+test_my_call_user_func_array_safe('foo_array');
+$output = xhprof_disable();
+echo "Part 5a output:\n";
+print_canonical($output);
+echo "\n";
+
+// 5b: Sanity test to not ignore call_user_func variants
+echo "Part 5b: Profile call_user_func_array and my_call_user_func_array_safe\n";
+xhprof_enable(XHPROF_FLAGS_MEMORY, array());
+test_my_call_user_func_array_safe('foo_array');
+$output = xhprof_disable();
+echo "Part 5b output:\n";
+print_canonical($output);
+echo "\n";
+
+// 5c: Sanity test to only ignore my_call_user_func_array_safe
+echo "Part 5c: Only ignore call_user_func_array\n";
+$xhprof_ignored_functions = array('ignored_functions' =>
+ 'my_call_user_func_array_safe');
+xhprof_enable(XHPROF_FLAGS_MEMORY, $xhprof_ignored_functions);
+test_my_call_user_func_array_safe('foo_array');
+$output = xhprof_disable();
+echo "Part 5c output:\n";
+print_canonical($output);
+echo "\n";
+
+?>
+--EXPECT--
+Part 1: Default Flags
+hello: this is a test
+hello: Arraytest
+Part 1 output:
+foo==>bar : ct= 2; wt=*;
+foo==>strlen : ct= 1; wt=*;
+foo_array==>bar : ct= 2; wt=*;
+foo_array==>strlen : ct= 1; wt=*;
+main() : ct= 1; wt=*;
+main()==>foo : ct= 1; wt=*;
+main()==>foo_array : ct= 1; wt=*;
+main()==>xhprof_disable : ct= 1; wt=*;
+
+Part 2a: Ignore call_user_func
+hello: user_func test
+Part 2a output:
+foo==>bar : ct= 2; wt=*;
+foo==>strlen : ct= 1; wt=*;
+main() : ct= 1; wt=*;
+main()==>test_call_user_func::test_call_user_func: ct= 1; wt=*;
+main()==>xhprof_disable : ct= 1; wt=*;
+test_call_user_func::test_call_user_func==>foo: ct= 1; wt=*;
+
+Part 2b: Standard profile without parameters
+hello: user_func test
+Part 2b output:
+call_user_func==>foo : ct= 1; wt=*;
+foo==>bar : ct= 2; wt=*;
+foo==>strlen : ct= 1; wt=*;
+main() : ct= 1; wt=*;
+main()==>test_call_user_func::test_call_user_func: ct= 1; wt=*;
+main()==>xhprof_disable : ct= 1; wt=*;
+test_call_user_func::test_call_user_func==>call_user_func: ct= 1; wt=*;
+
+Part 2c: Standard profile with empty array of ignored functions
+hello: user_func test
+Part 2c output:
+call_user_func==>foo : ct= 1; wt=*;
+foo==>bar : ct= 2; wt=*;
+foo==>strlen : ct= 1; wt=*;
+main() : ct= 1; wt=*;
+main()==>test_call_user_func::test_call_user_func: ct= 1; wt=*;
+main()==>xhprof_disable : ct= 1; wt=*;
+test_call_user_func::test_call_user_func==>call_user_func: ct= 1; wt=*;
+
+Part 3: Ignore call_user_func_array
+hello: calling foo_array
+Part 3 output:
+foo_array==>bar : cpu=*; ct= 2; wt=*;
+foo_array==>strlen : cpu=*; ct= 1; wt=*;
+main() : cpu=*; ct= 1; wt=*;
+main()==>test_call_user_func_array : cpu=*; ct= 1; wt=*;
+main()==>xhprof_disable : cpu=*; ct= 1; wt=*;
+test_call_user_func_array==>foo_array : cpu=*; ct= 1; wt=*;
+
+Part 4: Ignore my_call_user_func_safe
+hello: Array
+Part 4 output:
+foo==>bar : ct= 2; wt=*;
+foo==>strlen : ct= 1; wt=*;
+main() : ct= 1; wt=*;
+main()==>test_my_call_user_func_safe : ct= 1; wt=*;
+main()==>xhprof_disable : ct= 1; wt=*;
+test_my_call_user_func_safe==>foo : ct= 1; wt=*;
+test_my_call_user_func_safe==>is_callable: ct= 1; wt=*;
+
+Part 5a: Ignore my_call_user_func_array_safe and strlen
+hello: my_user_func_array_safetest
+Part 5a output:
+foo_array==>bar : ct= 2; mu=*; pmu=*; wt=*;
+main() : ct= 1; mu=*; pmu=*; wt=*;
+main()==>test_my_call_user_func_array_safe: ct= 1; mu=*; pmu=*; wt=*;
+main()==>xhprof_disable : ct= 1; mu=*; pmu=*; wt=*;
+test_my_call_user_func_array_safe==>foo_array: ct= 1; mu=*; pmu=*; wt=*;
+test_my_call_user_func_array_safe==>is_callable: ct= 1; mu=*; pmu=*; wt=*;
+
+Part 5b: Profile call_user_func_array and my_call_user_func_array_safe
+hello: my_user_func_array_safetest
+Part 5b output:
+call_user_func_array==>foo_array : ct= 1; mu=*; pmu=*; wt=*;
+foo_array==>bar : ct= 2; mu=*; pmu=*; wt=*;
+foo_array==>strlen : ct= 1; mu=*; pmu=*; wt=*;
+main() : ct= 1; mu=*; pmu=*; wt=*;
+main()==>test_my_call_user_func_array_safe: ct= 1; mu=*; pmu=*; wt=*;
+main()==>xhprof_disable : ct= 1; mu=*; pmu=*; wt=*;
+my_call_user_func_array_safe==>call_user_func_array: ct= 1; mu=*; pmu=*; wt=*;
+my_call_user_func_array_safe==>is_callable: ct= 1; mu=*; pmu=*; wt=*;
+test_my_call_user_func_array_safe==>my_call_user_func_array_safe: ct= 1; mu=*; pmu=*; wt=*;
+
+Part 5c: Only ignore call_user_func_array
+hello: my_user_func_array_safetest
+Part 5c output:
+call_user_func_array==>foo_array : ct= 1; mu=*; pmu=*; wt=*;
+foo_array==>bar : ct= 2; mu=*; pmu=*; wt=*;
+foo_array==>strlen : ct= 1; mu=*; pmu=*; wt=*;
+main() : ct= 1; mu=*; pmu=*; wt=*;
+main()==>test_my_call_user_func_array_safe: ct= 1; mu=*; pmu=*; wt=*;
+main()==>xhprof_disable : ct= 1; mu=*; pmu=*; wt=*;
+test_my_call_user_func_array_safe==>call_user_func_array: ct= 1; mu=*; pmu=*; wt=*;
+test_my_call_user_func_array_safe==>is_callable: ct= 1; mu=*; pmu=*; wt=*;
View
75 extension/tests/xhprof_008.phpt
@@ -0,0 +1,75 @@
+--TEST--
+XHPRrof: Sampling Mode Test
+Author: kannan
+--FILE--
+<?php
+
+include_once dirname(__FILE__).'/common.php';
+
+function foo() {
+ // sleep 0.8 seconds
+ usleep(800000);
+}
+
+function bar() {
+ foo();
+}
+
+function goo() {
+ bar();
+}
+
+// call goo() once
+xhprof_sample_enable();
+goo();
+$output1 = xhprof_sample_disable();
+
+
+// call goo() twice
+xhprof_sample_enable();
+goo();
+goo();
+$output2 = xhprof_sample_disable();
+
+// how many usleep samples did we get in single call to goo()?
+$count1 = 0;
+foreach ($output1 as $sample) {
+ if ($sample == "main()==>goo==>bar==>foo==>usleep") {
+ $count1++;
+ }
+}
+
+// how many usleep samples did we get in two calls to goo()?
+$count2 = 0;
+foreach ($output2 as $sample) {
+ if ($sample == "main()==>goo==>bar==>foo==>usleep") {
+ $count2++;
+ }
+}
+
+//
+// our default sampling frequency is 0.1 seconds. So
+// we would expect about 8 samples (given that foo()
+// sleeps for 0.8 seconds). However, we might in future
+// allow the sampling frequency to be modified. So rather
+// than depend on the absolute number of samples, we'll
+// check to see if $count2 is roughly double of $count1.
+//
+
+if (($count1 == 0)
+ || (($count2 / $count1) > 2.5)
+ || (($count2 / $count1) < 1.5)) {
+ echo "Test failed\n";
+ echo "Count of usleep samples in one call to goo(): $count1\n";
+ echo "Count of usleep samples in two calls to goo(): $count2\n";
+ echo "Samples in one call to goo(): \n";
+ var_dump($output1);
+ echo "Samples in two calls to goo(): \n";
+ var_dump($output2);
+} else {
+ echo "Test passed\n";
+}
+
+?>
+--EXPECT--
+Test passed
View
320 extension/xhprof.c
@@ -60,7 +60,7 @@
*/
/* XHProf version */
-#define XHPROF_VERSION "0.9.0"
+#define XHPROF_VERSION "0.9.2"
/* Fictitious function name to represent top of the call tree. The paranthesis
* in the name is to ensure we don't conflict with user function names. */
@@ -80,13 +80,18 @@
* The following optional flags can be used to control other aspects of
* profiling.
*/
-#define XHPROF_FLAGS_NO_BUILTINS 0x0001 /* do not profile builtins */
-#define XHPROF_FLAGS_CPU 0x0002 /* gather CPU times for funcs */
-#define XHPROF_FLAGS_MEMORY 0x0004 /* gather memory usage for funcs */
+#define XHPROF_FLAGS_NO_BUILTINS 0x0001 /* do not profile builtins */
+#define XHPROF_FLAGS_CPU 0x0002 /* gather CPU times for funcs */
+#define XHPROF_FLAGS_MEMORY 0x0004 /* gather memory usage for funcs */
/* Constants for XHPROF_MODE_SAMPLED */
#define XHPROF_SAMPLING_INTERVAL 100000 /* In microsecs */
+/* Constant for ignoring functions, transparent to hierarchical profile */
+#define XHPROF_MAX_IGNORED_FUNCTIONS 256
+#define XHPROF_IGNORED_FUNCTION_FILTER_SIZE \
+ ((XHPROF_MAX_IGNORED_FUNCTIONS + 7)/8)
+
#if !defined(uint64)
typedef unsigned long long uint64;
#endif
@@ -197,6 +202,10 @@ typedef struct hp_global_t {
/* counter table indexed by hash value of function names. */
uint8 func_hash_counters[256];
+ /* Table of ignored function names and their filter */
+ char **ignored_function_names;
+ uint8 ignored_function_filter[XHPROF_IGNORED_FUNCTION_FILTER_SIZE];
+
} hp_global_t;
@@ -219,6 +228,10 @@ static ZEND_DLEXPORT void (*_zend_execute_internal) (zend_execute_data *data,
static zend_op_array * (*_zend_compile_file) (zend_file_handle *file_handle,
int type TSRMLS_DC);
+/* Bloom filter for function names to be ignored */
+#define INDEX_2_BYTE(index) (index >> 3)
+#define INDEX_2_BIT(index) (1 << (index & 0x7));
+
/**
* ****************************
@@ -243,6 +256,15 @@ static void get_all_cpu_frequencies();
static long get_us_interval(struct timeval *start, struct timeval *end);
static void incr_us_interval(struct timeval *start, uint64 incr);
+static void hp_get_ignored_functions_from_arg(zval *args);
+static void hp_ignored_functions_filter_clear();
+static void hp_ignored_functions_filter_init();
+
+static inline zval *hp_zval_at_key(char *key,
+ zval *values);
+static inline char **hp_strings_in_zval(zval *values);
+static inline void hp_array_del(char **name_array);
+
/**
* *********************
* PHP EXTENSION GLOBALS
@@ -313,6 +335,8 @@ PHP_FUNCTION(xhprof_enable) {
return;
}
+ hp_get_ignored_functions_from_arg(optional_array);
+
hp_begin(XHPROF_MODE_HIERARCHICAL, xhprof_flags TSRMLS_CC);
}
@@ -340,6 +364,7 @@ PHP_FUNCTION(xhprof_disable) {
*/
PHP_FUNCTION(xhprof_sample_enable) {
long xhprof_flags = 0; /* XHProf flags */
+ hp_get_ignored_functions_from_arg(NULL);
hp_begin(XHPROF_MODE_SAMPLED, xhprof_flags TSRMLS_CC);
}
@@ -393,6 +418,8 @@ PHP_MINIT_FUNCTION(xhprof) {
hp_globals.func_hash_counters[i] = 0;
}
+ hp_ignored_functions_filter_clear();
+
#if defined(DEBUG)
/* To make it random number generator repeatable to ease testing. */
srand(0);
@@ -508,6 +535,59 @@ static inline uint8 hp_inline_hash(char * str) {
}
/**
+ * Parse the list of ignored functions from the zval argument.
+ *
+ * @author mpal
+ */
+static void hp_get_ignored_functions_from_arg(zval *args) {
+ if (args != NULL) {
+ zval *zresult = NULL;
+
+ zresult = hp_zval_at_key("ignored_functions", args);
+ hp_globals.ignored_function_names = hp_strings_in_zval(zresult);
+ } else {
+ hp_globals.ignored_function_names = NULL;
+ }
+}
+
+/**
+ * Clear filter for functions which may be ignored during profiling.
+ *
+ * @author mpal
+ */
+static void hp_ignored_functions_filter_clear() {
+ memset(hp_globals.ignored_function_filter, 0,
+ XHPROF_IGNORED_FUNCTION_FILTER_SIZE);
+}
+
+/**
+ * Initialize filter for ignored functions using bit vector.
+ *
+ * @author mpal
+ */
+static void hp_ignored_functions_filter_init() {
+ if (hp_globals.ignored_function_names != NULL) {
+ int i = 0;
+ for(; hp_globals.ignored_function_names[i] != NULL; i++) {
+ char *str = hp_globals.ignored_function_names[i];
+ uint8 hash = hp_inline_hash(str);
+ int idx = INDEX_2_BYTE(hash);
+ hp_globals.ignored_function_filter[idx] |= INDEX_2_BIT(hash);
+ }
+ }
+}
+
+/**
+ * Check if function collides in filter of functions to be ignored.
+ *
+ * @author mpal
+ */
+int hp_ignored_functions_filter_collision(uint8 hash) {
+ uint8 mask = INDEX_2_BIT(hash);
+ return hp_globals.ignored_function_filter[INDEX_2_BYTE(hash)] & mask;
+}
+
+/**
* Initialize profiler state
*
* @author kannan, veeve
@@ -541,6 +621,9 @@ void hp_init_profiler_state(int level TSRMLS_DC) {
/* Call current mode's init cb */
hp_globals.mode_cb.init_cb(TSRMLS_C);
+
+ /* Set up filter of functions which may be ignored during profiling */
+ hp_ignored_functions_filter_init();
}
/**
@@ -561,6 +644,10 @@ void hp_clean_profiler_state(TSRMLS_D) {
hp_globals.entries = NULL;
hp_globals.profiler_level = 1;
hp_globals.ever_enabled = 0;
+
+ /* Delete the array storing ignored function names */
+ hp_array_del(hp_globals.ignored_function_names);
+ hp_globals.ignored_function_names = NULL;
}
/*
@@ -571,17 +658,23 @@ void hp_clean_profiler_state(TSRMLS_D) {
* CALLING FUNCTION OR BY CALLING TSRMLS_FETCH()
* TSRMLS_FETCH() IS RELATIVELY EXPENSIVE.
*/
-#define BEGIN_PROFILING(entries, symbol) \
+#define BEGIN_PROFILING(entries, symbol, profile_curr) \
do { \
- hp_entry_t *cur_entry = hp_fast_alloc_hprof_entry(); \
- (cur_entry)->name_hprof = symbol; \
- (cur_entry)->prev_hprof = (*(entries)); \
- /* Call the universal callback */ \
- hp_mode_common_beginfn((entries), (cur_entry) TSRMLS_CC); \
- /* Call the mode's beginfn callback */ \
- hp_globals.mode_cb.begin_fn_cb((entries), (cur_entry) TSRMLS_CC); \
- /* Update entries linked list */ \
- (*(entries)) = (cur_entry); \
+ /* Use a hash code to filter most of the string comparisons. */ \
+ uint8 hash_code = hp_inline_hash(symbol); \
+ profile_curr = !hp_ignore_entry(hash_code, symbol); \
+ if (profile_curr) { \
+ hp_entry_t *cur_entry = hp_fast_alloc_hprof_entry(); \
+ (cur_entry)->hash_code = hash_code; \
+ (cur_entry)->name_hprof = symbol; \
+ (cur_entry)->prev_hprof = (*(entries)); \
+ /* Call the universal callback */ \
+ hp_mode_common_beginfn((entries), (cur_entry) TSRMLS_CC); \
+ /* Call the mode's beginfn callback */ \
+ hp_globals.mode_cb.begin_fn_cb((entries), (cur_entry) TSRMLS_CC); \
+ /* Update entries linked list */ \
+ (*(entries)) = (cur_entry); \
+ } \
} while (0)
/*
@@ -592,20 +685,22 @@ void hp_clean_profiler_state(TSRMLS_D) {
* CALLING FUNCTION OR BY CALLING TSRMLS_FETCH()
* TSRMLS_FETCH() IS RELATIVELY EXPENSIVE.
*/
-#define END_PROFILING(entries) \
+#define END_PROFILING(entries, profile_curr) \
do { \
- hp_entry_t *cur_entry; \
- /* Call the mode's endfn callback. */ \
- /* NOTE(cjiang): we want to call this 'end_fn_cb' before */ \
- /* 'hp_mode_common_endfn' to avoid including the time in */ \
- /* 'hp_mode_common_endfn' in the profiling results. */ \
- hp_globals.mode_cb.end_fn_cb((entries) TSRMLS_CC); \
- cur_entry = (*(entries)); \
- /* Call the universal callback */ \
- hp_mode_common_endfn((entries), (cur_entry) TSRMLS_CC); \
- /* Free top entry and update entries linked list */ \
- (*(entries)) = (*(entries))->prev_hprof; \
- hp_fast_free_hprof_entry(cur_entry); \
+ if (profile_curr) { \
+ hp_entry_t *cur_entry; \
+ /* Call the mode's endfn callback. */ \
+ /* NOTE(cjiang): we want to call this 'end_fn_cb' before */ \
+ /* 'hp_mode_common_endfn' to avoid including the time in */ \
+ /* 'hp_mode_common_endfn' in the profiling results. */ \
+ hp_globals.mode_cb.end_fn_cb((entries) TSRMLS_CC); \
+ cur_entry = (*(entries)); \
+ /* Call the universal callback */ \
+ hp_mode_common_endfn((entries), (cur_entry) TSRMLS_CC); \
+ /* Free top entry and update entries linked list */ \
+ (*(entries)) = (*(entries))->prev_hprof; \
+ hp_fast_free_hprof_entry(cur_entry); \
+ } \
} while (0)
@@ -649,6 +744,34 @@ size_t hp_get_entry_name(hp_entry_t *entry,
}
/**
+ * Check if this entry should be ignored, first with a conservative Bloomish
+ * filter then with an exact check against the function names.
+ *
+ * @author mpal
+ */
+int hp_ignore_entry_work(uint8 hash_code, char *curr_func) {
+ int ignore = 0;
+ if (hp_ignored_functions_filter_collision(hash_code)) {
+ int i = 0;
+ for (; hp_globals.ignored_function_names[i] != NULL; i++) {
+ char *name = hp_globals.ignored_function_names[i];
+ if ( !strcmp(curr_func, name)) {
+ ignore++;
+ break;
+ }
+ }
+ }
+
+ return ignore;
+}
+
+inline int hp_ignore_entry(uint8 hash_code, char *curr_func) {
+ /* First check if ignoring functions is enabled */
+ return hp_globals.ignored_function_names != NULL &&
+ hp_ignore_entry_work(hash_code, curr_func);
+}
+
+/**
* Build a caller qualified name for a callee.
*
* For example, if A() is caller for B(), then it returns "A==>B".
@@ -1249,9 +1372,6 @@ void hp_mode_common_beginfn(hp_entry_t **entries,
/* This symbol's recursive level */
int recurse_level = 0;
- /* use a hash code to fend off most of the call-stack traversal. */
- current->hash_code = hp_inline_hash(current->name_hprof);
-
if (hp_globals.func_hash_counters[current->hash_code] > 0) {
/* Find this symbols recurse level */
for(p = (*entries); p; p = p->prev_hprof) {
@@ -1461,7 +1581,8 @@ void hp_mode_sampled_endfn_cb(hp_entry_t **entries TSRMLS_DC) {
* @author hzhao, kannan
*/
ZEND_DLEXPORT void hp_execute (zend_op_array *ops TSRMLS_DC) {
- char *func = NULL;
+ char *func = NULL;
+ int hp_profile_flag = 1;
func = hp_get_function_name(ops TSRMLS_CC);
if (!func) {
@@ -1469,10 +1590,11 @@ ZEND_DLEXPORT void hp_execute (zend_op_array *ops TSRMLS_DC) {
return;
}
- BEGIN_PROFILING(&hp_globals.entries, func);
+ BEGIN_PROFILING(&hp_globals.entries, func, hp_profile_flag);
_zend_execute(ops TSRMLS_CC);
- if (hp_globals.entries)
- END_PROFILING(&hp_globals.entries);
+ if (hp_globals.entries) {
+ END_PROFILING(&hp_globals.entries, hp_profile_flag);
+ }
efree(func);
}
@@ -1489,13 +1611,14 @@ ZEND_DLEXPORT void hp_execute (zend_op_array *ops TSRMLS_DC) {
ZEND_DLEXPORT void hp_execute_internal(zend_execute_data *execute_data,
int ret TSRMLS_DC) {
zend_execute_data *current_data;
- char *func = NULL;
+ char *func = NULL;
+ int hp_profile_flag = 1;
current_data = EG(current_execute_data);
func = hp_get_function_name(current_data->op_array TSRMLS_CC);
if (func) {
- BEGIN_PROFILING(&hp_globals.entries, func);
+ BEGIN_PROFILING(&hp_globals.entries, func, hp_profile_flag);
}
if (!_zend_execute_internal) {
@@ -1515,7 +1638,7 @@ ZEND_DLEXPORT void hp_execute_internal(zend_execute_data *execute_data,
if (func) {
if (hp_globals.entries) {
- END_PROFILING(&hp_globals.entries);
+ END_PROFILING(&hp_globals.entries, hp_profile_flag);
}
efree(func);
}
@@ -1534,16 +1657,18 @@ ZEND_DLEXPORT zend_op_array* hp_compile_file(zend_file_handle *file_handle,
char *func;
int len;
zend_op_array *ret;
+ int hp_profile_flag = 1;
filename = hp_get_base_filename(file_handle->filename);
len = strlen("load") + strlen(filename) + 3;
func = (char *)emalloc(len);
snprintf(func, len, "load::%s", filename);
- BEGIN_PROFILING(&hp_globals.entries, func);
+ BEGIN_PROFILING(&hp_globals.entries, func, hp_profile_flag);
ret = _zend_compile_file(file_handle, type TSRMLS_CC);
- if (hp_globals.entries)
- END_PROFILING(&hp_globals.entries);
+ if (hp_globals.entries) {
+ END_PROFILING(&hp_globals.entries, hp_profile_flag);
+ }
efree(func);
return ret;
@@ -1563,8 +1688,9 @@ ZEND_DLEXPORT zend_op_array* hp_compile_file(zend_file_handle *file_handle,
*/
static void hp_begin(long level, long xhprof_flags TSRMLS_DC) {
if (!hp_globals.enabled) {
+ int hp_profile_flag = 1;
- hp_globals.enabled = 1;
+ hp_globals.enabled = 1;
hp_globals.xhprof_flags = (uint32)xhprof_flags;
/* Replace zend_compile with our proxy */
@@ -1609,7 +1735,7 @@ static void hp_begin(long level, long xhprof_flags TSRMLS_DC) {
hp_init_profiler_state(level TSRMLS_CC);
/* start profiling from fictitious main() */
- BEGIN_PROFILING(&hp_globals.entries, ROOT_SYMBOL);
+ BEGIN_PROFILING(&hp_globals.entries, ROOT_SYMBOL, hp_profile_flag);
}
}
@@ -1638,10 +1764,11 @@ static void hp_end(TSRMLS_D) {
static void hp_stop(TSRMLS_D) {
zval *ret;
char *out_url;
+ int hp_profile_flag = 1;
/* End any unfinished calls */
while (hp_globals.entries) {
- END_PROFILING(&hp_globals.entries);
+ END_PROFILING(&hp_globals.entries, hp_profile_flag);
}
/* Remove proxies, restore the originals */
@@ -1655,3 +1782,110 @@ static void hp_stop(TSRMLS_D) {
/* Stop profiling */
hp_globals.enabled = 0;
}
+
+
+/**
+ * *****************************
+ * XHPROF ZVAL UTILITY FUNCTIONS
+ * *****************************
+ */
+
+/** Look in the PHP assoc array to find a key and return the zval associated
+ * with it.
+ *
+ * @author mpal
+ **/
+static zval *hp_zval_at_key(char *key,
+ zval *values) {
+ zval *result = NULL;
+
+ if (values->type == IS_ARRAY) {
+ HashTable *ht;
+ zval **value;
+ uint len = strlen(key) + 1;
+
+ ht = Z_ARRVAL_P(values);
+ if (zend_hash_find(ht, key, len, (void**)&value) == SUCCESS) {
+ result = *value;
+ }
+ } else {
+ result = NULL;
+ }
+
+ return result;
+}
+
+/** Convert the PHP array of strings to an emalloced array of strings. Note,
+ * this method duplicates the string data in the PHP array.
+ *
+ * @author mpal
+ **/
+static char **hp_strings_in_zval(zval *values) {
+ char **result;
+ size_t count;
+ size_t ix = 0;
+
+ if (!values) {
+ return NULL;
+ }
+
+ if (values->type == IS_ARRAY) {
+ HashTable *ht;
+
+ ht = Z_ARRVAL_P(values);
+ count = zend_hash_num_elements(ht);
+
+ if((result =
+ (char**)emalloc(sizeof(char*) * (count + 1))) == NULL) {
+ return result;
+ }
+
+ for (zend_hash_internal_pointer_reset(ht);
+ zend_hash_has_more_elements(ht) == SUCCESS;
+ zend_hash_move_forward(ht)) {
+ char *str;
+ uint len;
+ ulong idx;
+ int type;
+ zval **data;
+
+ type = zend_hash_get_current_key_ex(ht, &str, &len, &idx, 0, NULL);
+ /* Get the names stored in a standard array */
+ if(type == HASH_KEY_IS_LONG) {
+ if ((zend_hash_get_current_data(ht, (void**)&data) == SUCCESS) &&
+ Z_TYPE_PP(data) == IS_STRING &&
+ strcmp(Z_STRVAL_PP(data), ROOT_SYMBOL)) { /* do not ignore "main" */
+ result[ix] = estrdup(Z_STRVAL_PP(data));
+ ix++;
+ }
+ }
+ }
+ } else if(values->type == IS_STRING) {
+ if((result = (char**)emalloc(sizeof(char*) * 2)) == NULL) {
+ return result;
+ }
+ result[0] = estrdup(Z_STRVAL_P(values));
+ ix = 1;
+ } else {
+ result = NULL;
+ }
+
+ /* NULL terminate the array */
+ if (result != NULL) {
+ result[ix] = NULL;
+ }
+
+ return result;
+}
+
+/* Free this memory at the end of profiling */
+static inline void hp_array_del(char **name_array) {
+ if (name_array != NULL) {
+ int i = 0;
+ for(; name_array[i] != NULL && i < XHPROF_MAX_IGNORED_FUNCTIONS; i++) {
+ efree(name_array[i]);
+ }
+ efree(name_array);
+ }
+}
+
View
5 package.xml
@@ -44,6 +44,8 @@ XHProf is a function-level hierarchical profiler for PHP and has a simple HTML b
</stability>
<license uri="http://www.apache.org/licenses/LICENSE-2.0.html">Apache 2.0</license>
<notes>
+-- add a sanity test for sampling mode in xhprof (kannan)
+-- add support to ignore functions (such as call_user_func) during profiling (mpal)
-- fix #16098: suppress notices due to use of FILE_BINARY (kannan)
-- add a sanity test for timer (kannan)
-- fix for compile error on debian linux (russ)
@@ -69,6 +71,9 @@ XHProf is a function-level hierarchical profiler for PHP and has a simple HTML b
<file role="test" name="xhprof_004_inc.php" />
<file role="test" name="xhprof_004.phpt" />
<file role="test" name="xhprof_005.phpt" />
+ <file role="test" name="xhprof_006.phpt" />
+ <file role="test" name="xhprof_007.phpt" />
+ <file role="test" name="xhprof_008.phpt" />
</dir>
</dir>
<dir name="xhprof_html">
View
45 xhprof_html/docs/index.html
@@ -293,11 +293,11 @@
<pre>
[xhprof]
extension=xhprof.so
-#
-# directory used by default implementation of the iXHProfRuns
-# interface (namely, the XHProfRuns_Default class) for storing
-# XHProf runs.
-#
+;
+; directory used by default implementation of the iXHProfRuns
+; interface (namely, the XHProfRuns_Default class) for storing
+; XHProf runs.
+;
xhprof.output_dir=&lt;directory_for_storing_xhprof_runs&gt;
</pre>
@@ -466,6 +466,7 @@
)
</pre>
+<p><b>Skipping builtin functions during profiling</b>
<p>By default PHP builtin functions (such as <code>strlen</code>) are
profiled. If you do not want to profile builtin functions (to either
@@ -474,10 +475,44 @@
flag as in for example:
<ul><pre>
+// do not profile builtin functions
<b>xhprof_enable(XHPROF_FLAGS_NO_BUILTINS)</b>;
</pre></ul>
+<p><b>Ignoring specific functions during profiling (0.9.2 or higher)</b>
+
+<p>Starting with release 0.9.2 of xhprof, you can tell XHProf to
+ignore a specified list of functions during profiling. This allows you
+to ignore, for example, functions used for indirect function calls
+such as <code>call_user_func</code> and
+<code>call_user_func_array</code>. These intermediate functions
+unnecessarily complicate the call hierarchy and make the XHProf
+reports harder to interpret since they muddle the parent-child
+relationship for functions called indirectly.
+
+<p> To specify the list of functions to be ignored during profiling
+use the 2nd (optional) argument to <code>xhprof_enable</code>.
+For example,
+
+<pre>
+<ul><pre>
+<b>
+// elapsed time profiling; ignore call_user_func* during profiling
+xhprof_enable(0,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array'));
+</b>
+or,
+<b>
+// elapsed time + memory profiling; ignore call_user_func* during profiling
+xhprof_enable(XHPROF_FLAGS_MEMORY,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array'));
+</b>
+</pre></ul>
+
+
</li>
<li><a name="ui_setup"><h2>Setting up XHProf UI</h2></a>
Please sign in to comment.
Something went wrong with that request. Please try again.