Excimer
 Release status: stable |
|
|---|---|
| Implementation | PHP |
| MediaWiki | |
| License | Apache License 2.0 |
| Download | GitHub: |
| 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
[edit]Linux package manager
[edit]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
[edit]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
[edit]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
[edit]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
[edit]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
[edit]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
[edit]For now, please see the function stubs in the extension source.
Examples
[edit]Per-request flame graph from MediaWiki
[edit]
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
[edit]$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
[edit]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)
[edit]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
[edit]
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
[edit]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
[edit]
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?
[edit]- Wikimedia Foundation: Profiling PHP in production, Flame graphs arrive in WikimediaDebug.
- Sentry for PHP (source code), PHP profiling.
- Human Made: Altis Dev Tools and X-Ray (WordPress APM).
- Profiling plugin for Moodle (source code).
See also
[edit]- Profiling PHP in production at scale, Timo Tijhof, 2021.
- Browse source code (GitHub mirror)
- Arc Lamp, generate flame graphs for PHP in production using Excimer as sampling profiler.
- Brendan Gregg's Flame Graphs
Code stewardship
[edit]- Maintained by MediaWiki Platform Team.
- Live chat (IRC): #mediawiki-core connect
- Issue tracker: Phabricator Excimer (Report an issue)
Maintainer notes
[edit]For information about how to update the PECL release, see how to PECL.
References
[edit]- ↑ Comment on "Excimer: new profiler for PHP", Tim Starling (2018), phabricator.wikimedia.org.
- ↑ "Web-facing Apache servers" refers to the appserver, api_appserver, and parsoid clusters that run MediaWiki at WMF. This notably excludes MediaWiki jobrunners.
- ↑ Application Servers RED metrics, grafana.wikimedia.org.