Skip to content

Commit

Permalink
add support to ignore specified functions during profiling; more tests
Browse files Browse the repository at this point in the history 
git-svn-id: https://svn.php.net/repository/pecl/xhprof/trunk@281203 c90b9560-bf6c-de11-be94-00142212c4b1
  • Loading branch information
kannan committed May 27, 2009
1 parent a693abf commit 292d183
Show file tree
Hide file tree
Showing 8 changed files with 757 additions and 49 deletions.
7 changes: 7 additions & 0 deletions CHANGELOG
View file
@@ -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
Expand Down
2 changes: 1 addition & 1 deletion extension/tests/xhprof_005.phpt
View file
Expand Up @@ -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';
Expand Down
78 changes: 78 additions & 0 deletions extension/tests/xhprof_006.phpt
View file
@@ -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.

274 changes: 274 additions & 0 deletions extension/tests/xhprof_007.phpt
View file
@@ -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=*;

0 comments on commit 292d183

Please sign in to comment.