-
Notifications
You must be signed in to change notification settings - Fork 7.9k
Measure startup, each bench run and shutdown separately #13162
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
61db456
6a47d3b
48c1057
66c27d7
5ac6812
74ae907
c92fa3c
3a718b3
25f33f7
b338be1
eff4cfb
ba44c9f
eef3071
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -63,7 +63,8 @@ function runSymfonyDemo(bool $jit): array { | |
| cloneRepo($dir, 'https://github.com/php/benchmarking-symfony-demo-2.2.3.git'); | ||
| runPhpCommand([$dir . '/bin/console', 'cache:clear']); | ||
| runPhpCommand([$dir . '/bin/console', 'cache:warmup']); | ||
| return runValgrindPhpCgiCommand('symfony-demo', [$dir . '/public/index.php'], cwd: $dir, jit: $jit, warmup: 50, repeat: 50); | ||
|
|
||
| return runValgrindPhpCgiCommand('symfony-demo', [$dir . '/public/index.php'], cwd: $dir, jit: $jit, repeat: 100); | ||
| } | ||
|
|
||
| function runWordpress(bool $jit): array { | ||
|
|
@@ -86,7 +87,8 @@ function runWordpress(bool $jit): array { | |
|
|
||
| // Warmup | ||
| runPhpCommand([$dir . '/index.php'], $dir); | ||
| return runValgrindPhpCgiCommand('wordpress', [$dir . '/index.php'], cwd: $dir, jit: $jit, warmup: 50, repeat: 50); | ||
|
|
||
| return runValgrindPhpCgiCommand('wordpress', [$dir . '/index.php'], cwd: $dir, jit: $jit, repeat: 100); | ||
| } | ||
|
|
||
| function runPhpCommand(array $args, ?string $cwd = null): ProcessResult { | ||
|
|
@@ -98,41 +100,94 @@ function runValgrindPhpCgiCommand( | |
| array $args, | ||
| ?string $cwd = null, | ||
| bool $jit = false, | ||
| int $warmup = 0, | ||
| int $repeat = 1, | ||
| ): array { | ||
| global $phpCgi; | ||
|
|
||
| $profileOut = __DIR__ . "/profiles/callgrind.out.$name"; | ||
| $profileOut = __DIR__ . "/profiles/callgrind.$name"; | ||
| if ($jit) { | ||
| $profileOut .= '.jit'; | ||
| $profileOut .= '-jit'; | ||
| } | ||
|
|
||
| $process = runCommand([ | ||
| 'valgrind', | ||
| '--tool=callgrind', | ||
| '--dump-instr=yes', | ||
| '--collect-jumps=yes', | ||
| '--trace-children=yes', | ||
| "--callgrind-out-file=$profileOut", | ||
| '--verbose', | ||
| '--', | ||
| $phpCgi, | ||
| '-T' . ($warmup ? $warmup . ',' : '') . $repeat, | ||
| '-T' . $repeat, | ||
| '-d max_execution_time=0', | ||
| '-d opcache.enable=1', | ||
| '-d opcache.jit=' . ($jit ? 'tracing' : 'disable'), | ||
| '-d opcache.jit_buffer_size=128M', | ||
| '-d opcache.validate_timestamps=0', | ||
| ...$args, | ||
| ]); | ||
| $instructions = extractInstructionsFromValgrindOutput($process->stderr); | ||
| if ($repeat > 1) { | ||
| $instructions = gmp_strval(gmp_div_q($instructions, $repeat)); | ||
| ], null, array_merge(getenv(), ['BENCHMARK_DUMP_SEPARATE_PROFILES' => '1'])); | ||
|
|
||
| // collect metrics for startup, each benchmark run and shutdown | ||
| $metricsArr = []; | ||
| foreach (['startup' => 1, ...range(2, $repeat + 1), 'shutdown' => ''] as $k => $kCallgrindOut) { | ||
| $profileOutSpecific = $profileOut . '.' . $k; | ||
| rename($profileOut . ($kCallgrindOut === '' ? '' : '.' . $kCallgrindOut), $profileOutSpecific); | ||
|
|
||
| $metricsArr[$k] = extractMetricsFromCallgrindFile($profileOutSpecific); | ||
| } | ||
|
|
||
| // print all collected metrics | ||
| print_r(array_map(fn ($metrics) => array_map(fn ($v) => number_format($v, 0, '.', '_'), $metrics), $metricsArr)); | ||
|
|
||
| // find median benchmark run | ||
| $metricsForMedianArr = $metricsArr; | ||
| unset($metricsForMedianArr['startup']); | ||
| unset($metricsForMedianArr['shutdown']); | ||
| uasort($metricsForMedianArr, fn ($a, $b) => $a['Ir'] <=> $b['Ir']); | ||
| $medianRunIndex = array_keys($metricsForMedianArr)[max(0, floor((count($metricsForMedianArr) - 3 /* -1 for count to index, -1 for first slow run due compliation, -1 for second run which is a little slower too */) / 2.0))]; | ||
|
|
||
| // remove non-first-non-median profiles from artifacts | ||
| foreach (range(0, $repeat - 1) as $k) { | ||
| $profileOutSpecific = $profileOut . '.' . $k; | ||
|
|
||
| if ($k !== 0 && $k !== $medianRunIndex) { | ||
| unlink($profileOutSpecific); | ||
| } | ||
| } | ||
|
|
||
| // annotate profiles for artifacts | ||
| foreach (['startup', 0, $medianRunIndex, 'shutdown'] as $k) { | ||
| $profileOutSpecific = $profileOut . '.' . $k; | ||
|
|
||
| runCommand([ | ||
| 'callgrind_annotate', | ||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Any idea how to convince There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. You would need to compile with There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. in the example you can see some examples of unresolved functions (from All unresolved functions are listed in the end of each annotated profile file (like There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Not for SQLite, since we're not compiling its source files. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Debug symbols for Debian packages are commonly available via the corresponding There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. In Ubuntu docker, after apt update, I get only these: There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Thank you!! That link brought me to https://valgrind.org/docs/manual/manual-core.html#manual-core.debuginfod . Commited in d4fe3ef. Now I still see some missing source for the core linux libs: any idea? |
||
| '--threshold=100', | ||
| '--auto=yes', | ||
| '--show-percs=no', | ||
| $profileOutSpecific, | ||
| new UnescapedArg('>'), | ||
| "$profileOutSpecific.txt", | ||
| ]); | ||
| } | ||
|
|
||
| $instructions = $metricsArr[$medianRunIndex]['Ir']; | ||
| if ($repeat === 1) { // return the same data as before https://github.com/php/php-src/pull/13162 | ||
| $instructions += $metricsArr['startup']['Ir']; | ||
| } | ||
|
|
||
| return ['instructions' => $instructions]; | ||
| } | ||
|
|
||
| function extractInstructionsFromValgrindOutput(string $output): string { | ||
| preg_match("(==[0-9]+== Events : Ir\n==[0-9]+== Collected : (?<instructions>[0-9]+))", $output, $matches); | ||
| return $matches['instructions'] ?? throw new \Exception('Unexpected valgrind output'); | ||
| /** | ||
| * @return array<non-empty-string, numeric-string> | ||
| */ | ||
| function extractMetricsFromCallgrindFile(string $path): array { | ||
| if (!preg_match('/\nevents:((?: +\w+)+)\nsummary:((?: +\d+)+)\n/', file_get_contents($path, length: 10_000), $matches)) { | ||
| throw new \Exception('Unexpected callgrind data'); | ||
| } | ||
|
|
||
| return array_combine(explode(' ', ltrim($matches[1], ' ')), explode(' ', ltrim($matches[2], ' '))); | ||
| } | ||
|
|
||
| main(); | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -1696,6 +1696,16 @@ PHP_FUNCTION(apache_response_headers) /* {{{ */ | |
| } | ||
| /* }}} */ | ||
|
|
||
| #ifdef HAVE_VALGRIND | ||
| static inline void callgrind_dump_stats(void) | ||
| { | ||
| char *tmp = getenv("BENCHMARK_DUMP_SEPARATE_PROFILES"); | ||
| if (tmp && ZEND_ATOL(tmp)) { | ||
| CALLGRIND_DUMP_STATS; | ||
| } | ||
| } | ||
| #endif | ||
|
|
||
| static zend_module_entry cgi_module_entry = { | ||
| STANDARD_MODULE_HEADER, | ||
| "cgi-fcgi", | ||
|
|
@@ -2216,13 +2226,6 @@ consult the installation file that came with this distribution, or visit \n\ | |
| if (comma) { | ||
| warmup_repeats = atoi(php_optarg); | ||
| repeats = atoi(comma + 1); | ||
| #ifdef HAVE_VALGRIND | ||
| if (warmup_repeats > 0) { | ||
| CALLGRIND_STOP_INSTRUMENTATION; | ||
| /* We're not interested in measuring startup */ | ||
| CALLGRIND_ZERO_STATS; | ||
| } | ||
| #endif | ||
| } else { | ||
| repeats = atoi(php_optarg); | ||
| } | ||
|
|
@@ -2264,6 +2267,13 @@ consult the installation file that came with this distribution, or visit \n\ | |
| } | ||
| #endif | ||
| while (!fastcgi || fcgi_accept_request(request) >= 0) { | ||
| #ifdef HAVE_VALGRIND | ||
| if (benchmark) { | ||
| /* measure startup and each benchmark run separately */ | ||
| callgrind_dump_stats(); | ||
| } | ||
| #endif | ||
|
|
||
| SG(server_context) = fastcgi ? (void *)request : (void *) 1; | ||
| init_request_info(request); | ||
|
|
||
|
|
@@ -2430,12 +2440,6 @@ consult the installation file that came with this distribution, or visit \n\ | |
| } | ||
| } /* end !cgi && !fastcgi */ | ||
|
|
||
| #ifdef HAVE_VALGRIND | ||
| if (warmup_repeats == 0) { | ||
| CALLGRIND_START_INSTRUMENTATION; | ||
| } | ||
| #endif | ||
|
|
||
| /* request startup only after we've done all we can to | ||
| * get path_translated */ | ||
| if (php_request_startup() == FAILURE) { | ||
|
|
@@ -2554,11 +2558,6 @@ consult the installation file that came with this distribution, or visit \n\ | |
| SG(request_info).query_string = NULL; | ||
| } | ||
|
|
||
| #ifdef HAVE_VALGRIND | ||
| /* We're not interested in measuring shutdown */ | ||
| CALLGRIND_STOP_INSTRUMENTATION; | ||
| #endif | ||
|
|
||
| if (!fastcgi) { | ||
| if (benchmark) { | ||
| if (warmup_repeats) { | ||
|
|
@@ -2586,6 +2585,12 @@ consult the installation file that came with this distribution, or visit \n\ | |
| script_file = NULL; | ||
| goto do_repeat; | ||
| } | ||
|
|
||
| #ifdef HAVE_VALGRIND | ||
| /* measure shutdown separately */ | ||
| callgrind_dump_stats(); | ||
| #endif | ||
|
|
||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. As mentioned, I don't think dumping stats to stdout/stderr repeatedly is a good solution, because it makes Valgrind useless for all other use-cases where this script is not used. A better solution would be if we could calculate the mean or whatever metric we find most useful, from C, and output that when the script terminates. Valgrind allows specifying the output file using There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yes, What do you want to achive, does
This is not possible with Valgrind and also probably not wanted, as having multiple Callgrind files is helpful to investigate time differences. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What I mean is that Dmitry and others use There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. In 9d77734 I have put the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. @iluuu1994 can I ask you to review this PR |
||
| break; | ||
| } | ||
|
|
||
|
|
||