[PHP] Closureを活用して性能に優しいdebugログを残す工夫をしてみる

概要

この記事では、PHPのClosure（無名関数）機能を、性能改善のトライとして活用する例を紹介します。
無名関数はPHPだけではなく、さまざまな言語で活用されるので、この一例が言語関係なく有用な内容になれば幸いです。

記事は以下の構成となります。

• 1　debugログ記録においての悩み
  • debugログを使う際の課題を話します
• 2　Closureを使ってdebugログの性能最適化を図る
  • Closureの概念を簡単に紹介と、debugログ処理の最適化を図ります
• 3　結論
• APPENDIX. 注意点

※ debugログを残すのが良いのかに関する本質的な話は、今回は深く話しませんので、あらかしめご理解ください。
※ この記事は個人の主観を含めています。もし間違ったところや他の意見がありましたら、コメントいただけると幸いです。

1. debugログ記録においての悩み

1-1. debugログを使いまくってもいいか？

debugログを残す際に、データに何らかの演算を加えて残す場合は要注意
※例：配列のマージ、オブジェクトから特定メソッドを呼び出してデータ取得など

debugログは、賛否両論ではありますが、残しておくと開発はもちろん、アプリケーションの修正や維持補修において、有用な場合も多いと思います。

そのため、実際にdebugレベルのログを残すロジックは実装をして、環境ごとにログレベルの閾値(Log　Level Threshold)を調整して、運用するケースもあると思います。

しかし、debugログという特性上、なるべく多くの情報をダンプする形で残すように場合も多いと思います。また、その場合は、無意識的に、何らかの演算をした結果をdebugログに残すようにする場合もあると思います。

例えば、極端的な例ですが、こういう感じでしょうか。

// array_merge
$logger->debug("request dump", array_merge($request->post, $request->get, $request->headers));

// method call (with calculating)
$logger->debug("processed data", $money->convertCurrencyTo('USD'));

// instance dump
$logger->debug("instance dump", serialize($someObject));

この場合は当然、debugログを閾値から除外下にもかかわらず、無駄な処理がそのまま残り性能に影響を及ぼします。

だとしたら、debugログの記録を残したままにするのは、控えるのだけが正解でしょうか？

1-2. どうすれば良いか？

データ記録に関わる演算を、必要な時だけ実行するようにする

今回は、問いに対する一つの案として、このアプローチをします。
そして、PHPではClosureという概念を使い、それを実現します。

2. Closureを使ってdebugログの性能最適化を図る

2-1. Closureはなに？

PHPにおいてのClosureは、無名関数(Anonymous Function)を表すためのクラスです。
無名関数は、名前を持たないままの関数を、ランタイム時に生成ができる言語仕様です。
PHPでは、callableタイプ変数として定義ができ、パラメータ指定、リターン、ランタイム時に生成・関数実行などができます。

使い方は、PHP公式にシンプルでわかりやすい例があるのでご参考ください。
https://www.php.net/manual/en/functions.anonymous.php

この特性によって、さまざまな活用ができますが、今回は、単純にパラメータで渡して、条件付きで実行する例に絞って話をします。

※ 無名関数は、完璧ではないですが、関数型プログラミングと似た機能を具現できるようにしてくれます。
※ 第一級関数（first-class function）の特性と参考すると、良い深い理解が可能だと思います。

2-2. Debugログ処理の作成

以下のようなイメージで、debugログの記録するメソッドを作成します。

public function debugLog($message, Closure $closureForContext=null)
{
    // skip if logging threshold is upper from DEBUG on environment.
    // self::LOGGING_THRESHOLD refer to global setting of each environments.
    if (self::LOGGING_THRESHOLD !== Logger::DEBUG) {
        return;
    }

    // call Closure as function to get Context Array we need to do logging.
    $context = $closureForContext ? $closureForContext() : null;
    $this->monolog->debug(Logger::DEBUG, $message, $context);
}

2-3. Debugログ記録呼び出しの作成

使う場合は、以下のようにパラメータとして、無名関数を渡します。
use()構文は、該当無名関数のスコープから、渡した変数を参照できるようにしてくれます。

$exampleLogger->debugLog(
    "request dump", 
    function () use ($request) {
        return array_merge($request->post, $request->get, $request->headers);
    }
);

2-4. 解説

デバッグログのために必要なデータの演算をClosureで無名関数かし、必要なタイミングのみ演算が行われるようになります。

環境ごとのログ閾値の判断と、データ提供ロジックをClosureにするだけで、本番環境では不要な演算を選択的にしないようにでき、性能面でのロスを減らすことが可能です。

2-5. 簡単な性能チェック

少し端的な例ではありますが、大幅に実行時間に差があることがわかります。
すごく簡単な工夫で、大きい効果を得られる可能性があるという結果でもあると思います。

実行条件

• PHP Symfony&Monologのログ閾値からDEBUGを除外
• microtime(true)で、コード実行開始・終了の差分を測定
• 同一環境で1,000,000回ループ実行を３回行った時間合計の平均
• ログにコンテキストとして、array_merge演算をした結果を設定
  • array_merge($request->headers, $request->query, $request->post)

実行時間結果

-	simply logging with context	with Closure
1 time	1.0609450340271	0.11742901802063
2 time	1.056135892868	0.12697911262512
3 time	1.2411420345306	0.11956310272217
average	1.11 sec	0.12 sec

※ もっと綿密な性能チェックには、プロファイラなどを使って分析するのも良いかもしれません。

3. 結論

Closure(無名関数)の特性を利用すると、特定演算の実行タイミングを制御し、アプリケーション性能向上を図れる

が、今回の結論でしょうか。
もっと奥深に考えたい方は、 遅延実行（Lazy Execution） に対して、参考にしても良いかもしれません。

また、無名関数という特性をよく理解した上で、いくつか注意点を気にしながら取り組む必要はありますが、性能だけではなく、ロジック改善やモジュール開発でも幅広い活用ができ、緩い依存性と再活用性を高め、開発生産性にも役に経つ場合が多いです。

今回は、ごく一部の簡単な例を説明していますが、無名関数の多様な活用を身につけると、いろんなプログラミング環境と、機能具現においての課題解決の知見が広まると思いますので、そのきっかけに成れれば幸いです。

Appendix. 注意点

記事の内容の上で、誤解の余地がある部分を、補足します。

A-1. DEBUGレベルのログを残すのは、必ずしも最善とは言えません

個人の意見としては、いくつかルールをもうけた上でなら、DEBUGレベルのログが残るようにし、開発中のデバッグや本番でのトラブルシューティングに活用するのが理想的だとは思います。
ただし、チーム開発でこのルールが守られるのはかなりハードルが高いとも思っており、その部分は、アプリケーションの性能や、逆に不要な情報を残し続けるという結果を生む可能性があるので、ケースバイケースで慎重な判断をし、適切に取る組むべきだと思います。

A-2. Closure（無名関数）は、必ずしも良いものではありません

例えば、debugログで、演算なしで既に存在する配列を渡すだけなら、Closureはむしろ性能浪費になります。
その理由としては、Closureをインスタンスの生成によるメモリーアロケーション、Closureを呼ぶ時に発生するCallStack追加・消滅とコンテキストスウィッチングが発生などなど、いろんなことが起こります。ただし、array_mergeみたいに、明らかに重くて、よく使う演算に対しては、大きな効果が期待できます。

また、PHPのClosureを含め、無名関数の濫用は、とあるケースでは、コード解釈を難しくするかもしれません。

ともあれ、適材適所に使うことが大事です。

A-3. これは、PHPに限られる活用案ではありません

無名関数は、いろんな言語でサポートしている機能とも言えます。
名称と特徴は多少違いはあるかもですが、無名関数の活用というコンセプトは、そんなに変わらないと思うので、是非、他の言語での活用も試してください。