Jump to content

Excimer: Difference between revisions

From mediawiki.org
Content deleted Content added
No edit summary
Line 89: Line 89:
</syntaxhighlight>
</syntaxhighlight>


=== Per-process flame graph ===
=== Per-process flame graph (Speedscope) ===
In this example, a web request is traced at a high resolution (1ms samples), with a Speedscope-compatible data file written afterward. This can be drag-n-dropped directly into [https://www.speedscope.app/ Speedscope]. To do this automatically, we use [[git:performance/excimer-ui-client|excimer-ui-client]] and [[git:performance/excimer-ui-server|excimer-ui-server]] ([[phab:T291015|T291015]]).<syntaxhighlight lang="php">
function startExcimer() {
static $excimer;
$excimer = new ExcimerProfiler;
$excimer->setPeriod(0.001); // 1ms
$excimer->setEventType(EXCIMER_REAL);
$excimer->start();
register_shutdown_function(function () use ( $excimer ) {
$excimer->stop();
$data = $excimer->getLog()->getSpeedscopeData();
$data['profiles'][0]['name'] = $_SERVER['REQUEST_URI'];
file_put_contents('/tmp/speedscope.json', json_encode($data, JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE ));
});
}
startExcimer();
</syntaxhighlight>

=== Per-process flame graph (SVG) ===
In this example, a web request is traced at a high resolution (1ms samples), with an interactive flame graph SVG generated afterward. [https://github.com/brendangregg/FlameGraph FlameGraph] is presumed to be installed at <code>/usr/local/bin/flamegraph.pl</code>. An SVG file is written to <code>/tmp/profile.svg</code>. A demo of the typical output can be seen at https://tstarling.com/stuff/excimer-flamegraph.svg .<syntaxhighlight lang="php">
In this example, a web request is traced at a high resolution (1ms samples), with an interactive flame graph SVG generated afterward. [https://github.com/brendangregg/FlameGraph FlameGraph] is presumed to be installed at <code>/usr/local/bin/flamegraph.pl</code>. An SVG file is written to <code>/tmp/profile.svg</code>. A demo of the typical output can be seen at https://tstarling.com/stuff/excimer-flamegraph.svg .<syntaxhighlight lang="php">
$profiler = new ExcimerProfiler;
$profiler = new ExcimerProfiler;

Revision as of 02:23, 24 March 2023

MediaWiki extensions manual
Excimer
Release status: stable
Implementation PHP
MediaWiki
License Apache License 2.0
Download
Issues Open tasks · Report a bug

Excimer is a PHP 7.1+ extension that provides an interrupting timer and a low-overhead sampling profiler.

Installation

Linux package manager

apt-get install php-excimer

See packages.debian.org and packages.ubuntu.com. For alternate PHP versions, Excimer is also packaged at https://deb.sury.org/.

For Fedora and other RPM-based distributions (e.g. using yum), Excimer is packaged at https://rpms.remirepo.net.

PECL

pecl install excimer

See our PECL entry.

Source

Download the source code into an appropriate directory from git:

git clone https://gerrit.wikimedia.org/r/mediawiki/php/excimer.git

Or download a snapshot and unpack.

Build

Excimer requires Linux.

Below excimer/ is the directory that excimer Git repository was cloned to.

cd excimer/
phpize && ./configure && make && sudo make install

Then add extension=excimer.so to the PHP configuration in an appropriate place. For example, in modern Debian-derived distributions you'd add a file to /etc/php/$version/mods-available (where $version is the version of PHP for which you compiled Excimer) and use the phpenmod command to enable it.

Background

We found that just enabling Tideways XHProf on a server with PHP 7.2 caused a performance degradation of about 4%. We believe this is due to it installing a zend_execute_ex hook, which intercepts all function calls in PHP.[1] Even though this hook does nothing by default, just having it causes PHP's VM to omit certain optimisations. The hook can only be installed globally, and it is not possible to enable it just for a particular request.

Excimer does not install any zend_execute_ex hook. This means it cannot count function calls, but makes it suitable for production-wide installation.

Reference documentation

For now, please see the function stubs in the extension source.

Examples

For locally profiling a MediaWiki request, see: MediaWiki-Docker/Configuration recipes/Profiling.

One-shot timer to limit the execution time of a function

$timer = new ExcimerTimer;
$timer->setInterval( 10 /* seconds */ );
$timer->setCallback( function () {
    throw new Exception( "The allowed time has been exceeded" );
} );
$timer->start();
do_expensive_thing();

The "interval" timer fires only once. The way this works internally is that, when the timer thread expires, Excimer sets a flag in memory that the PHP VM checks every time a function returns, and on every loop iteration. This check exists in PHP VM and happens regardless of whether Excimer is installed or used. For CPU-intensive tasks, this is usually often enough. However, note that Excimer will not interrupt long-running native C functions (such as MySQL connection attempts).

When the exception is thrown, the backtrace will show the callback being called from the interrupted code.

Note that the $timer variable must be kept alive, for example by keeping it in scope. If the timer object is destroyed, the timer is automatically cleaned up and the callback never called.

Periodic timer to gather time-series memory usage statistics

A long-running process (e.g. command-line job) can be interrupted periodically, and the current memory usage appended to a file.

$timer = new ExcimerTimer;
$timer->setPeriod( 0.1 ); // every 100ms
$startTime = microtime( true );
$timer->setCallback( function () use ( $startTime ) {
	$usage = sprintf( "%.2f", memory_get_usage() / 1048576 );
	$interval = microtime( true ) - $startTime;
	$date = sprintf( "%.2f", $interval );
	file_put_contents(
		'/tmp/php-memory-usage',
		"$date\t$usage\n",
		FILE_APPEND );
} );
$timer->start();
...

Per-process flame graph (Speedscope)

In this example, a web request is traced at a high resolution (1ms samples), with a Speedscope-compatible data file written afterward. This can be drag-n-dropped directly into Speedscope. To do this automatically, we use excimer-ui-client and excimer-ui-server (T291015).

function startExcimer() {
	static $excimer;
	$excimer = new ExcimerProfiler;
	$excimer->setPeriod(0.001); // 1ms
	$excimer->setEventType(EXCIMER_REAL);
	$excimer->start();
	register_shutdown_function(function () use ( $excimer ) {
		$excimer->stop();
		$data = $excimer->getLog()->getSpeedscopeData();
		$data['profiles'][0]['name'] = $_SERVER['REQUEST_URI'];
		file_put_contents('/tmp/speedscope.json', json_encode($data, JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE ));
	});
}
startExcimer();

Per-process flame graph (SVG)

In this example, a web request is traced at a high resolution (1ms samples), with an interactive flame graph SVG generated afterward. FlameGraph is presumed to be installed at /usr/local/bin/flamegraph.pl. An SVG file is written to /tmp/profile.svg. A demo of the typical output can be seen at https://tstarling.com/stuff/excimer-flamegraph.svg .

$profiler = new ExcimerProfiler;
$profiler->setPeriod( 0.001 ); // every 1ms
$profiler->setEventType( EXCIMER_CPU );
$profiler->start();
register_shutdown_function( function () use ( $profiler ) {
	$profiler->stop();
	$pipe = popen( "/usr/local/bin/flamegraph.pl > /tmp/profile.svg", "w" );
	fwrite( $pipe, $profiler->getLog()->formatCollapsed() );
} );

Per-process function table

In this example, event counts are aggregated by function name, formatted in a fixed-width table, and written to a file. An example of typical output can be seen at https://tstarling.com/stuff/excimer-aggregated.txt .

$profiler = new ExcimerProfiler;
$profiler->setPeriod( 0.01 ); // every 10ms
$profiler->setEventType( EXCIMER_CPU );
$profiler->start();
register_shutdown_function( function () use ( $profiler ) {
	$profiler->stop();
	$report = sprintf( "%-79s %14s %14s\n", 'Function', 'Self', 'Inclusive' );
	foreach ( $profiler->getLog()->aggregateByFunction() as $id => $info ) {
		$report .= sprintf( "%-79s %14d %14d\n", $id, $info['self'], $info['inclusive'] );
	}
	file_put_contents( '/tmp/aggregated.txt', $report );
} );

Site-wide sample profiling

You can generate flame graphs that represent production requests with very low overhead. Starting the Excimer profiler with a very high period (e.g. 60 seconds), means most requests will never be observed, and a fraction of your requests will have 1 sample taken that we then flush to a tracelog buffer. This could be Redis, rsyslog, ZeroMQ, Multicast UDP-to-file, Kafka, etc. The below example will write it to a local file for testing purposes. This file could then be turned into a flame graph by running cat /tmp/excimer-traces.log | /usr/local/bin/flamegraph.pl > flamegraph.svg. Or load the trace log directly into Speedscope.

function start_my_sampling_profiler() {
    static $prof; // Keep object until the end of the request
    $prof = new ExcimerProfiler;
    $prof->setEventType( EXCIMER_REAL );
    $prof->setPeriod( 60 ); // every 60s
    $prof->setMaxDepth( 250 ); // https://phabricator.wikimedia.org/T176916#5105095

    // In production, assuming requests generally take far less than 60s,
    // most web requests will never call this, and some will call it once.
    $prof->setFlushCallback( function ( $log ) {
        // e.g. send to Redis, UDP, or local file
		file_put_contents( '/tmp/excimer-traces.log', $log->formatCollapsed(), FILE_APPEND );
	}, 1 );
    $prof->start();
}
start_my_sampling_profiler();

Eximer ensures that samples are representative by automatically staggering the first (and likely, only) interval by a random fraction of the sampling period.

As of December 2022, Wikipedia's web-facing Apache servers receive about 1.6 billion requests per day (~20,000 req/s) from 300 physical servers across its 2 main data centers.[2] The median latency is ~100ms, with p95 of ~600ms.[3] With the sampling period of 60 seconds, we end up collecting 3 million stack traces per day. This translates to roughly 1 sample from 0.2% of requests, and 0 samples from the other 99.8%. Refer to Arc Lamp for how we do this in production. More details on Profiling PHP in production at scale at our Techblog. Our hourly and daily flame graph can be browsed at https://performance.wikimedia.org/php-profiling/.

Maintainer notes

For information about how to update the PECL release, see how to PECL.

Code stewardship

Further reading

References

  1. Comment on "Excimer: new profiler for PHP", Tim Starling (2018), phabricator.wikimedia.org.
  2. By "web-facing Apache servers" I mean the appserver, api_appserver, and parsoid clusters that run MediaWiki. This notably excludes MediaWiki jobrunners. --~~~~
  3. Application Servers RED metrics, grafana.wikimedia.org.