BEAR.Sunday内部のベンチマーク

helloworldベンチマークというフレームワークのミニマムブートストラップを計測するベンチマークがあります。この記事ではBEAR.Sundayでのブートスラップコストをより細かく分割して、それぞれ内部のアクションにどれくらいのいのコストがかかっているかを見ます。

アプリケーションはユーザーのプロジェクトフォルダのbootstrap/bootstrap.phpで、リクエストの最初から最後まで実行されます。

action	意味
load	composerのautoload初期化
$app	ルートオブジェクトグラフの取得(bootstrap.phpのみで使用）
route	webリクエストとオブジェクトリクエストの変換
request	リソースリクエスト
transfer	リソース状態を表現に変換してクライアントへの転送

インストール直後のスケルトンアプリケーションにベンチマーク用の関数t()とその結果を表示するresult()を追加して、それぞれの時間を計測しました。

git clone https://github.com/koriym/BEAR.HelloworldBenchmark.git
cd BEAR.HelloworldBenchmark
composer install --no-dev
composer dump-autoload --no-dev
php -S 127.0.0.1:8080/ bootstrap/bench.php

bootstrap.php

<?php
use BEAR\Package\Bootstrap;
use BEAR\Resource\ResourceObject;

$context = 'prod-app';

apcu_add('i', 0);
apcu_store('i', apcu_fetch('i') + 1);

require dirname(__DIR__) . '/autoload.php';
t('load');

/* @global string $context */
$app = (new Bootstrap)->getApp('MyVendor\MyProject', $context, dirname(__DIR__));
t('app');

$request = $app->router->match($GLOBALS, $_SERVER);
t('route');

try {
    $page = $app->resource->{$request->method}->uri($request->path)($request->query);
    t('request');

    /* @var $page ResourceObject */
    $page->transfer($app->responder, $_SERVER);
    t('transfer');
    if (isset($_GET['result'])) {
        result();
    }

    exit(0);
} catch (\Exception $e) {
    $app->error->handle($e, $request)->transfer();
    exit(1);
}

function t(string $key)
{
    static $i;

    apcu_add($key, 0);
    $i = $i ?: apcu_fetch('i');
    if ($i === 1) {
        return; // first call to create cache
    }
    $time = apcu_fetch($key) + microtime(true) - $_SERVER['REQUEST_TIME_FLOAT'];
    apcu_store($key, $time);
}

function result()
{
    $i = apcu_fetch('i');
    $averageRequestTime = apcu_fetch('transfer') / $i;
    $lastTimer = 0;
    foreach (['load', 'app', 'route', 'request', 'transfer'] as $action) {
        $actionTime = apcu_fetch($action);
        $elapsedTime = number_format($actionTime / $i * 1000, 3);
        $periodTime = number_format(($actionTime - $lastTimer) / $i * 1000, 3);
        $lastTimer = $actionTime;
        $proportion = number_format($periodTime / $averageRequestTime / 1000 * 100, 1);
        printf("| %s | %s | %s | %s%% |\n", $action, $elapsedTime, $periodTime, $proportion);
    }
}

action	経過時間	所要時間	割合
load	1.058	1.058	12.1%
app	7.502	6.443	73.5%
route	7.564	0.062	0.7%
request	8.725	1.161	13.2%
transfer	8.764	0.039	0.4%

composerのautoloadの初期化12%。routeとtransferは無視できるほど小さく、$appオブジェクトのアンシリアライズが約3/4とほとんどを占めています。

次に最適化オプションをつけてautoloadをダンプします。

composer dump-autoload --no-dev -o

action	経過時間	所要時間	割合
load	1.998	1.998	21.6%
app	8.068	6.070	65.6%
route	8.125	0.057	0.6%
request	9.212	1.087	11.8%
transfer	9.251	0.038	0.4%

autoloadの初期化に倍の時間がかかるようになってしまいました。不使用かもしれないクラスマップを読み込んでるためです。初期化コストを払うからわりにランタイムでのオートロードの時のファイルパスを探すのが早くなります。appとrequestに注目してください。僅かに早くなってるのはランタイムでのオートロードコストが低いためと考えられます。$appをアンシリアライズする課程で大量のクラスファイルをロードしないといけないからです。

このベンチマークのようなランタイム中にオートロードの必要の少ないプログラムでは逆に遅くなることになります。その差はこのhello worldが最大と考えていいでしょう。約5%程度です。

composer dump-autoload --no-dev

Polidog.Todo

HTML

次にHTMLアプリケーションを検討します。TwigとAura.Sqlを使ったアプリケーションで実際にデータベースもアクセスしていますす。

-oなし

action	経過時間	所要時間	割合
load	1.221	1.221	3.3%
app	9.841	8.620	23.2%
route	9.937	0.096	0.3%
request	21.521	11.584	31.1%
transfer	37.230	15.710	42.2%

-oあり

action	経過時間	所要時間	割合
load	3.036	3.036	8.2%
app	11.019	7.984	21.6%
route	11.105	0.085	0.2%
request	21.973	10.868	29.4%
transfer	36.921	14.948	40.5%

最適化オプションのあるなし(-o)での違いを見るとやはりhello worldアプリと同じ傾向がみられます。loadの初期化コストとapp+requestがトレードオフの関係にあります。

transferでは毎回Twigのテンプレートをレンダリングしているのでこのようなコストになりました。

API

最後にAPIです。先ほどのTodoアプリと違ってテンプレートのレンダリングはないがDBアクセスを行ってJSONを出力しています。

API -oなし

action	経過時間	所要時間	割合
load	1.247	1.247	7.2%
app	10.085	8.838	50.8%
route	10.183	0.098	0.6%
request	17.341	7.158	41.2%
transfer	17.391	0.051	0.3%

API -oあり

action	経過時間	所要時間	割合
load	5.596	5.596	27.5%
app	13.567	7.971	39.1%
route	13.654	0.088	0.4%
request	20.329	6.675	32.7%
transfer	20.383	0.054	0.3%

helloworldとHTMLの中間ぐらいの数字です。-oオプションをつけないでautolodaerをダンプした方が有利な結果になりました。

BEAR.Sundayのbootstrapの特徴

オブジェクトシリアライズとPHPファクトリーコードの生成により、DIコンテナや各機能コンポーネントの初期化コストが原理的にほぼないことです。モジュール追加で機能追加してもbootstrapコストはほとんど変わりません。

「フレームワークの機能が多いから遅い／少なから速い」ということがありません。

アプリケーションタイプによるコストインパクト

フレームワークのbootstrapコスト(hello wolrdベンチ）のインパクトはアプリケーションや用途によって大きく変わります。

データベースアクセスを用いてHTMLを返すWebアプリケーションでは相対的に低いです。単純なTodoアプリの場合で初期化に27%、リクエスト（データの作成）に32%、TwigでHTMLにするのに42%かかっています。（この場合Helloworldベンチを倍の性能にしても13.5%しか速度向上しません）

DBなどに単純なアクセスをしてJSONを返すようなAPIの場合にはアプリケーションコードよりフレームワークコストのbootstrapコストの方が高くなる場合もあります。（ちょっと納得できかねますが）

dump-autoload -o オプション

実験の結果からは-oオプションはBEAR.Sundayアプリケーションではつけない方が良さそうですが、念のために実際のアプリケーションでベンチをとってみたら良いと思います。

autoload.phpコンパイル

2018/05/19にリリースしたBEAR.Package v1.7.11のautoloadコンパイルのベンチマークも取ってみます。このautoload.phpのようなファイルを削減してautoloadの時のクラスファイルの読み込みコストを大幅に低減します。

コンパイルなし

action	経過時間	所要時間	割合
load	3.015	3.015	39.7%
app	6.856	3.841	50.6%
route	6.917	0.061	0.8%
request	7.582	0.665	8.8%
transfer	7.594	0.012	0.2%

Requests per second: 123.11 [#/sec] mean
Time per request: 81.230 [ms] mean
Time per request: 8.123 [ms] mean, across all concurrent requests

コンパイルあり

action	経過時間	所要時間	割合
load	6.490	6.490	91.3%
app	6.728	0.239	3.4%
route	6.791	0.062	0.9%
request	7.097	0.306	4.3%
transfer	7.109	0.011	0.2%

Requests per second: 135.79 [#/sec] mean
Time per request: 73.642 [ms] (mean
Time per request: 7.364 [ms] (mean, across all concurrent requests

appやrequestなどの各処理の所用時間が減っているのはその時に必要なオートロードがほぼ無しになったためです。$appをアンシリアライズする時間も1/10以下になっています。

大きなオブジェクトのアンシリアライズが遅いのではなく、実はその際に発生するオートロードに時間がかかっていたということが分かりました。（=バイナリシリアライズオプションとか導入しても効果は限定的と思われます）

改めてはっきりしたのはBEAR.Sundayのミニマムブートストラップのうちの90%以上はrequire実行のコストということです。一方、他の処理が十分に最適化されているということも言えるかと思います。