Jump to content

Excimer: Difference between revisions

From mediawiki.org
Content deleted Content added
Who uses Excimer?: +Human Made and their WordPress APM
Line 202: Line 202:
* Wikimedia Foundation: [https://techblog.wikimedia.org/2021/03/03/profiling-php-in-production-at-scale/ Profiling PHP in production], [https://techblog.wikimedia.org/2023/06/08/flame-graphs-arrive-in-wikimediadebug/ Flame graphs arrive in WikimediaDebug].
* Wikimedia Foundation: [https://techblog.wikimedia.org/2021/03/03/profiling-php-in-production-at-scale/ Profiling PHP in production], [https://techblog.wikimedia.org/2023/06/08/flame-graphs-arrive-in-wikimediadebug/ Flame graphs arrive in WikimediaDebug].
* [https://docs.sentry.io/platforms/php/profiling/ Sentry for PHP] ([https://github.com/getsentry/sentry-php/pull/1477 source code]), PHP profiling.
* [https://docs.sentry.io/platforms/php/profiling/ Sentry for PHP] ([https://github.com/getsentry/sentry-php/pull/1477 source code]), PHP profiling.
* [https://humanmade.com/ Human Made]: [https://docs.altis-dxp.com/dev-tools/flamegraphs/ Altis Dev Tools] and [https://docs.altis-dxp.com/cloud/dashboard/x-ray/ X-Ray] (WordPress APM).
* [https://moodle.org/plugins/tool_excimer Profiling plugin for Moodle] ([https://github.com/catalyst/moodle-tool_excimer source code]).
* [https://moodle.org/plugins/tool_excimer Profiling plugin for Moodle] ([https://github.com/catalyst/moodle-tool_excimer source code]).



Revision as of 03:13, 17 October 2024

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 (example).

On FreeBSD, Excimer is available in the Ports Collection as devel/pecl-excimer.

PECL

On macOS, it is recommended to install Excimer via pecl, which is included with PHP via Homebrew:

pecl install excimer

See our PECL entry.

MediaWiki-Docker

MediaWiki-Docker uses deb.sury.org for its PHP packages. This requires using an exact versioned package, and must match the current PHP version in your Docker container. Check the docker-compose.yml file in your MediaWiki directory if you're unsure which version you are on.

you:mediawiki$ docker compose exec --user root mediawiki bash
root@docker:/w$ apt-get update && apt-get install php8.1-excimer
root@docker:/w$ exit
you:mediawiki$ docker compose restart

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 or BSD.

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

For more detail, refer to our Profiling PHP in production at scale blog post.

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 perfectly count function calls, but does mean it is suitable for production-wide installation.

PHP provides a vm_interrupt global flag in the PHP engine that its virtual machine checks during code execution. It’s not a very precise feature, but it is checked at least once before the end of any userland function, and on every loop iteration. This check exists in the upstream PHP engine and happens regardless of whether Excimer is installed or used. This is is optimal for measuring or interrupting PHP code and more generally for CPU-intensive tasks.

If an Eximer timer, or profile sample period, elapses while the engine is busy running a C function (such as mysqli_connect), then your callback or profile sample will take place immediately after that function completes, but before your PHP code continues running. Thus the time spent will still be accurately attributed to caller. However, it also means you cannot use Excimer timers to stop (i.e. your callback throws an exception) an expensive operation that takes place as a single C function call (i.e. a single slow request, or a single slow query).

Reference documentation

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

Examples

Per-request flame graph from MediaWiki

Add once to your LocalSettings.php. After making a request with ?forceprofile=1 set, use Speedscope to open the latest Speedscope JSON file from the MediaWiki logs directory.

// Use ?forceprofile=1 to generate a trace log, written to /w/logs/speedscope.json
if ( extension_loaded( 'excimer' ) && isset( $_GET['forceprofile'] ) ) {
	$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( MW_INSTALL_PATH . '/logs/speedscope-' . ( new DateTime )->format( 'Y-m-d_His_v' ) . '-' . MW_ENTRY_POINT . '.json',
				json_encode( $data, JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE ) );
	} );
}

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. When the exception is thrown, the backtrace will report the callback as called from within your 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.

You can drag-n-drop the JSON file directly into www.speedscope.app.

At Wikimedia Foundation, we abstract and automate the below through 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 trace log

In this example, a web request is traced at a high resolution (1ms samples). This can then be viewed in Speedscope (drag and drop), or turned into an interactive flame graph SVG. FlameGraph is presumed to be installed at /usr/local/bin/flamegraph.pl. 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_REAL );
$profiler->start();
register_shutdown_function( function () use ( $profiler ) {
	$profiler->stop();
	file_put_contents( '/tmp/trace.log', $profiler->getLog()->formatCollapsed() );
} );
/usr/local/bin/flamegraph.pl /tmp/trace.log > /tmp/profile.svg

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_REAL );
$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/.

Who uses Excimer?

See also

Code stewardship

Maintainer notes

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

References

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