gihyo.jpサイトのロゴ

CakePHPで高速Webアプリ開発

第11回CakePHPの「DEBUG値」を極める！

2008-04-18

今回はCakePHPのデバッグに重要な「DEBUG値」を極めます。CakePHPバージョンは1.1系を対象としています。

DEBUG値とは

DEBUG値は、app/config/core.php内で定義するDEBUG定数の値です。

app/config/core.php
/**
 * Set debug level here:
 * - 0: production
 * - 1: development
 * - 2: full debug with sql
 * - 3: full debug with sql and dump of the current object
 *
 * In production, the "flash messages" redirect after a time interval.
 * With the other debug levels you get to click the "flash message" to continue.
 *
 */
    define('DEBUG', 1);

DEBUG定数に設定する値は、0、1、2、3の4種類があります。0から順に解説していきます。

DEBUG値「0」は本番用。エラー出力なし

DEBUG値に「0」を設定すると、CakePHPのエラー画面でコードヒントなどが表示されなくなります。さらにCakePHPコア内で「error_reporting(0);」が実行され、PHPによるすべてのエラーは出力されなくなります（参考：PHP: error_reporting - Manual⁠）⁠。

PHPでは、WarningやFatal Errorを出力するとエラーが発生したファイルのパス名などが画面に出力されます。仮にアプリケーションにセキュリティホールがあったときに、ファイルのパス名などが出力されてしまうと、具体的な攻撃を行うための重要な情報を提供してしまうことになります。CakePHPに限らず、余計な情報は表示させないようにしましょう。

なお、CakePHPでは app/tmp/cache/models以下に、DBのスキーマと連動したモデルのキャッシュファイルが作成されています。このキャッシュファイルはDEBUG値を1以上にしない限り更新されませんので、DBの仕様変更などを行った際には手動で削除するかDEBUG値を1以上にして再作成してください。

本番環境では通常、この設定で運用します。

DEBUG値「1」は通常の開発用。エラー出力あり

DEBUG値に「1」を設定すると、CakePHPコア内では「error_reporting(E_ALL);」と「ini_set('display_errors', 1);」（⁠ini_setが使用可能な場合のみ）が実行され、PHP5においてはE_STRICT以外の全てのエラーが出力されます。

また、HTMLのコメントとして、CakePHPアプリケーションの実行時間（アプリケーションが呼び出されてから結果出力まで）のミリ秒時間が末尾に出力されます。

以下のように末尾に実行時間が出力される
<!-- 0.079s -->

この実行時間出力は、DEBUG値が1以上のときは常に行われます。しかしJSONやバイナリデータなどを出力した場合、このHTMLコメントによってJSONテキストをそのまま処理できなかったり、バイナリデータにゴミが付加されてしまうことになります。

幸いなことに、この時間出力はアプリケーション部分の「app/webroot/index.php」で行われています。必要なときだけ出力すれば良い情報ですので、JSONやバイナリを出力するアプリケーションの場合は「app/webroot/index.php」内の以下のコードをコメントアウトしてしまってもよいでしょう。

app/webroot/index.php
if (Configure::read() > 0) {
  echo "<!-- " . round(getMicrotime() - $TIME_START, 4) . "s -->";
}

デフォルトのDEBUG値はこの「1」が設定されています。

DEBUG値「2」はDBへのクエリーのデバッグ情報が出力される

DEBUG値「2」は、DEBUG値「1」をベースに、末尾にDBへのクエリのデバッグ情報が出力されます。たとえば、本連載で作成したToDoアプリケーションでDEBUG値を「2」にすると、以下のような情報が画面末尾に出力されます。

3 queries took 1 ms
NrQueryErrorAffectedNum. rowsTook (ms)
1DESCRIBE `tasks`551
2SELECT `Task`.`id`, `Task`.`content`, `Task`.`status`, `Task`.`created`, `Task`.`modified` FROM `tasks` AS `Task` WHERE `Task`.`status` = 'yet' ORDER BY `Task`.`created` ASC 330
3SELECT `Task`.`id`, `Task`.`content`, `Task`.`status`, `Task`.`created`, `Task`.`modified` FROM `tasks` AS `Task` WHERE `Task`.`status` = 'done' ORDER BY `Task`.`modified` DESC 110

この情報の各カラムの意味は以下のとおりです。

  • 「* queries took * ms」実行したクエリの数と、合計時間です。
  • 「Nr」実行したクエリーの連番です。
  • 「Query」実行したSQL文です。
  • 「Error」クエリがエラーだった場合、エラー情報が入ります。
  • 「Affected」UPDATEやDELETEの際は、影響した行数が入ります。 SELECTの場合は結果の行数です。
  • 「Nom. rows」結果の行数です。
  • 「Took (ms)」DB上でのクエリの実行時間と考えて差し支えありませんが、CakePHPコア内の処理時間の一部も含まれるため、DB上での実行時間だけとは限りません。APCなどのPHPアクセラレータを導入した際にこの値が短縮されることがあります。

このようにクエリの合計時間とクエリ1つ1つについての情報が列挙されるので、かなり充実した内容となっています。CakePHPがどんなクエリを発行しているかということと、それぞれのクエリーの実行時間がわかるため、ボトルネック調査のときなどにかなり重宝するでしょう。

個人的にはこの出力はCakePHPの目玉機能の1つではないかと思います。

DEBUG値「3」はコントローラーのオブジェクトを出力する

DEBUG値「3」は、DEBUG値「2」をベースに、CakePHPのコントローラーのオブジェクトを出力します。この値だけは設定するだけでは出力されず、レイアウトかビューに「<?php echo $cakeDebug; ?>」と記述する必要があります。

たとえば、本連載で作成したToDoアプリケーションでDEBUG値を「3」に設定し、レイアウトかビューに「<?php echo $cakeDebug; ?>」を記述すると、以下のように出力されます。

Controller dump:

TasksController Object
(
    [name] => Tasks
    [uses] => Array
        (
            [0] => Task
        )
    [helpers] => Array
        (
            [0] => Javascript
            [1] => Ajax
            [2] => Html
        )
    [here] => /todo/tasks
    [webroot] => /todo/
    [action] => index
    [params] => Array
        (
            [pass] => Array
                (
                )
            [controller] => tasks
            [action] => index
            [form] => Array
                (
                )
            [url] => Array
                (
                    [url] => tasks
                )
            [bare] => 0
            [webservices] => 
            [plugin] => 
        )
…

以下延々とコントローラのオブジェクトに設定されている値が出力されます。情報が多すぎてちょっと見づらいので、個人的にはあまり使うことはありません。

DEBUG値を動的に変更する

DEBUG値によるデバッグ情報出力は非常に便利ですが、Ajax処理やJSONデータの受け渡しなどでデバッグ出力が邪魔になることがあります。そのたびに app/config/core.php を書き換えるのは少々面倒なので、効率的にDEBUG値を変更する手法を紹介します。

Configure::write() で変更する

DEBUG値を変更したい時点で、「⁠Configure::write('debug', DEBUG値);」を実行すると、その時点からDEBUG値が変更されます。

たとえば、開発中のDEBUG値が2のとき、特定のアクションだけDBのデバッグ出力をなくしたいときがあります。そんなときはそのアクション内で「Configure::write('debug', 1);」と書けば、DEBUG値は「1」に設定されます。

ただし、開発中のコードが誤ってそのまま本番に反映されてしまうと、app/config/core.php で設定したDEBUG値が「0」でも、特定のアクションでPHPエラーが出力されてしまうなどの問題が発生します。そこでお勧めなのが、以下の書き方です。

Configure::write('debug', DEBUG ? 1 : 0)

三項演算子を使用し、DEBUG定数が真（今回のケースでは2か3を想定）のときのみ1が設定されます。偽（今回のケースでは0）のときは0が設定され、本番用の設定が保たれます。

隠しパラメータなどで変更する

GETでのアクセスに限りますが、隠しパラメータなどでDEBUG値を動的に設定するのも良いでしょう。

app/config/core.phpでDEBUG定数を設定している部分を、以下のように書き換えます。

app/webroot/index.php
define('DEBUG', isset($_GET['debug']) ? $_GET['debug'] : 0);

こうして「http://example.com/cakeapp/?debug=2」といったURLでアクセスすること、DEBUG値を設定できます。ただし、このコードがそのまま本番環境に反映された場合、誰でもdebug値の変更が可能になってしまいますので、かなり危険です。かといって開発環境と本番環境で app/config/core.php を書き換えていては、本末転倒です。

そこで、たとえば、LAN内からアクセスされた場合のみ変更可能するなどの制限を加えるなどが有効です。以下のコードはクライアントのIPアドレスが「192.」から始まる場合の例です。

app/webroot/index.php
define('DEBUG', isset($_GET['debug']) &&
  preg_match('/^192\./', $_SERVER['REMOTE_ADDR']) ? $_GET['debug'] : 0);

開発環境がLAN内ではなくWAN先で、アクセス元が固定IPの場合は、そのIPアドレスのみ許可する形式でも良いでしょう。

その他にもアイデアいろいろ。基本は同一のコードで

その他にも、Cookieを使ったり、サーバの環境変数を使ったりするなど、さまざまな手法があります。基本方針としては、開発環境でも本番環境でもなるべくアプリケーションのコードを同一にすることです。誤ってアップロードしたりコミットしたりというのは、どんなに注意していても必ず起きます。人間は必ずミスをする生き物ということを前提に、快適にデバッグできるように工夫すると良いでしょう。

おすすめ記事

記事・ニュース一覧