DebugBarを導入してプログラム実行時の情報を身近にする

こんにちは、Garoon開発チームの中田です!

先日のPHPカンファレンス2021にて、「続)改善失敗から学ぶ、レガシープロダクトに立ち向かうチーム作り。」というタイトルで、直近数年でのGaroonへの技術的な取り組みの具体例や開発チームのプロセス改善についてお話ししました。

この発表の中で簡単に触れるのみで詳細をお話しできなかった、DebugBarの導入について本記事にて紹介します。

phpcon.php.gr.jp

fortee.jp

背景

Garoonはリリースから今年で21年目を迎え、長期間に渡って開発されてきた巨大なプロダクトです。 利用している言語はPHPで、4系から始まり今では7系までバージョンアップしており、日々Garoonを継続していくための活動をしています。

しかしながら、Garoonで利用している独自フレームワークの実装についてはリリース当初から今にかけて大きな書き換えはしておらず、まだまだPHP4系の名残があります。 また、フレームワークに深い知見を持つメンバーは(20年も前に開発したので当然ではありますが)既に開発チームから離れていたりと、Garoonの内部処理を把握するのはなかなか困難です。 具体的に把握し辛かった部分としては、実際に実行されてているクエリやSmartyに受け渡されている変数、セッションに保存されている情報などがありました。

私自身、前職でEthnaとLaravelの2つのフレームワークを使った開発を経験していたので、古さで言えばEthnaに近くキャッチアップもそこまで苦労しないんじゃないかと思っていましたが、例に漏れず苦労しました。

DebugBarの導入へ

前職でLaravelを使って開発していたことから、開発時にLaravel DebugBarを使ってクエリやセッション、キャッシュなどを確認していたのを思い出し、似たようなツールがあればGaroonの内部処理を把握しやすくなると思いつきました。 実際の導入には、Laravel DebugBarで統合されているPHP DebugBarを利用することに決め、Garoon向けの拡張を施して導入しました。

github.com

github.com

GaroonでDebugBarを表示する流れ

GaroonでDebugBarを導入するに当たって、以下の流れでデバッグ情報の収集や実際に表示する要素の構築をするようにしました。

  1. リクエストを受け取る
  2. DebugBarのインスタンスを作成する
  3. リクエストされた処理を開始する
  4. 収集対象のプログラムが実行される度にデバッグ情報を記憶する
  5. リクエストされたロジック部分の処理が完了し、テンプレートエンジン側の処理に遷移する
  6. 表示対象のデバッグ情報および記憶しておいた情報を集約する
  7. Garoonの画面表示の有無に応じて2通りに分岐
    • Ajax通信またはリダイレクトする場合、集約した情報を一時的にファイルに出力する
    • 画面表示する場合、集約した情報とファイル出力済みの情報をテンプレートに埋め込む
  8. レスポンスを返す

GaroonがAjax通信やリダイレクトをする場合は、デバッグ情報を表示する画面を一連の処理の中で持たないため、一時的にファイルに出力しておき、その次の画面表示を伴うリクエストのタイミングで結合して表示します。

各種情報を収集する

PHP Debug Barでは、RequestやConfigなどの各種情報を収集するためのCollectorクラスがデフォルトで用意されており、更に必要に応じてMonologやSlimといった収集する情報を選択できます。 また、Collectorクラスを作成することもできるので、今まで正確な情報を把握し辛かったクエリの情報やSmartyの変数を簡単に確認できるように、以下のようなデータも収集するようにしています。

  • MySQLi
  • Smarty
  • Xdebug Profiler

実行クエリのデータを収集する場合は、どのメソッドから呼び出されているか把握できるようにスタックトレースを併せて収集したり、クエリが重複している場合は強調表示するなどしています。

DebugBarで実行されたクエリのログを確認する様子
DebugBarで実行されたクエリのログを確認する様子

テンプレートエンジンへの変数の受け渡しもまた、暗黙的に受け渡している部分や、表示向けにデータの構造を変化させている場合など、変数を想定し辛いケースがあるため、デバッグ情報として収集するようにしました。

また、Xdebug Profilerの結果をDebugBar上から簡単に取得できるようにしています。 GaroonではCIによる性能検証を実施しており、昨日時点や前バージョンとの性能比較の結果から性能改善の要否の検討やプロファイリング結果などを用いた調査をします。 性能劣化が検出された時の調査として手動でプロファイリング結果を取得していたのが、DebugBarの仕組みで簡単に取得できるようになりました。

開発メンバーへの共有

Garoon開発チームヘの共有として、スプリントレビューなどで紹介させてもらい、日々の開発に活用してもらっています。 現在、導入から1年ほど経過しましたが、便利に使っている旨の声も聞こえていて嬉しい限りです。

また実際に使い始めてみると、見栄えや使いにくい部分などについては、開発メンバーが自主的に改良のPRを投げてくださるなど、便利に使っていくためのサイクルが回ったのはとても良かったです。 このような改良により、ダークモードの追加やクエリの実行時間でのソート機能などが追加されました。

ダークモードを有効にした状態のDebugBar
ダークモードを有効にした状態のDebugBar

まとめ

この仕組みにより、今まで暗黙知になっていたり、無意識に「(慣わしとして)●●は▲▲と書くもの」としてコーディングしていた箇所の処理などがより簡単に可視化できるようになり、開発の効率化やバグの混入の抑制、原因の早期発見などができました。

今回の対応でDebugBarに表示した情報は、xdebugなどを使うことで勿論得ることができ、また表示した情報より更に詳細な情報を知りたい場合などは、DebugBarはあまり役立ちません。 それでも、この1年ほどを経てDebugBarを導入したことには十分な価値を感じています。 DebugBarを導入して開発や調査の手がかりになる情報を簡単に得られるようになったことで、能動的にprintデバッグをしたりブレークポイントを設定しなくても、開発者が相応のデバッグ情報を認識できるようになりました。 実際に、機能開発やPHP8.0へのアップグレードのための調査などにも役立っています。

今回はGaroonを開発者にとって魅力的なプロダクトにするための取り組みの一例を紹介しました。 これからも積極的に開発効率上げる取り組みをやっていきます。We're hiring!

修正履歴

2021/12/10 軽微な表現を修正