zz log

zaininnari Blog

CakePHP で実行箇所をSQLのコメントに埋め込む

概要

CakePHP + DebugKit で開発しているときに、
「このSQLどこで発行されているの?」となることがあるので、
ActiveRecordのSQLの実行箇所をSQLのコメントに入れる - I sort my thought...
を参考にして簡単なプログラムを作成しました。

但し、DebugKit で使うには、DebugKit の仕様上中途半端になってしまいました。

環境

  • PHP 5.4.11
    • debug_backtrace の 第2引数 limit は 5.4.0 で追加され、このパラメータを使ってスタックフレームの数を制限できます。
    • 今回はこれを利用しているので、PHP5.4以上である必要があります
  • CakePHP 2.4.8
    • 2.4以降なら動作可能
    • 2.3未満は未確認

仕様

  • DboSource::execute を拡張
  • SQLの最後に、debug_print_backtrace の結果を追加
    • 先頭に追加すると、DebugKit で不具合で発生する
      • HtmlToolbarHelper::explainLink で、文頭がSELECTで始まるものだけ、Explain ボタンが生成されるため。
  • データベースは問わない
    • 今回はMySQLで作成

コード

[app/Config/database.php]

Database/Mysql を拡張したDatabase/DebugMysqlで debug が 0より大きい場合にデータソースの書き換えを行います。

<?php

class DATABASE_CONFIG {

    public $default = array(
        // 略
    );

    public $test = array(
        // 略
    );

    public function __construct() {
        $debugDataSources = [
            'Database/Mysql' => 'Database/DebugMysql',
        ];

        if (CakePlugin::loaded('DebugKit') && Configure::read('debug') > 0) {
            $datasource = $this->default['datasource'];
            if (isset($debugDataSources[$datasource])) {
                $config['datasource'] = $debugDataSources[$datasource];
            }
        }
    }
}

[app/Model/Datasource/Database/DebugMysql.php]

execute メソッドを拡張して、SQL文の後ろにバックトレースの内容を追加します。

<?php

App::uses('Mysql', 'Model/Datasource/Database');

class DebugMysql extends Mysql {

    public function execute($sql, $options = array(), $params = array()) {
        ob_start();
        // options
        //     DEBUG_BACKTRACE_IGNORE_ARGS "args" インデックスを無視してすべての関数/メソッドの引数をメモリに格納するかどうか。
        // limit
        //     5.4.0 以降、このパラメータを使ってスタックフレームの数を制限できるようになりました。
        //     デフォルト (limit=0) は、すべてのスタックフレームを返します。
        debug_print_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 10);
        // 最後にある改行コードを削除
        $out = trim(ob_get_clean());

        // 改行コードで分割して配列に変換
        $backtrace = explode("\n", $out);
        // 最後の実行箇所(DebugMysql::execute)は自明なため削除
        array_shift($backtrace);

        // 各要素の最初の文字は`#` で開始されており、
        // これはMySQLではコメントとして解釈されるが、
        // 一般的なコメント構文にする
        // 実行されるファイル名がフルパスなため、冗長な部分を削除する
        foreach ($backtrace as &$line) {
            $line = '-- ' . str_replace(ROOT, '', $line);
        }

        // 既存のSQL分の最後に、バックトレースの結果を追加する
        // "\r\n\r\n" は見やすくするための改行
        // "\r\n" を使用しているのは、
        // DebugKit で、Explain を行う際、
        // セキュリティコンポーネントでPostValidate に引っかからないようにするため
        $sql = trim($sql) . "\r\n\r\n" . join("\r\n", $backtrace);
        return parent::execute($sql, $options, $params);
    }
}

DebugKit で、Explain を行う際、セキュリティコンポーネントでPostValidate に引っかからないようにするために、改行コードを\r\nにしています。これは、\nだけの場合、POST時に改行コードがブラウザで\r\nに強制され、\nハッシュ値と異なってしまい、PostValidate でブラックホールに吸い込まれてしまうのを防ぐためです。

DebugKit上では整形できない見づらい欠点

これでSql Logsのパネルを見ると以下のようになります。 f:id:zainin:20131023214529p:plain 見てわかる通り、整形されていないため見づらいです。
brタグを挿入しても、SQLの表示には、ToolbarHelper::getQueryLogs内で h関数でエスケープ処理されてしまうので、どうすることもできません。 ただ、ファイルに書き出したりする場合は、改行が活きてきます。

DebugKit の仕様上で中途半端になってしまいましたが、実行場所を特定はしやすくはなったと思います。