Zend_Db_Profilerのバグと、Zend_Db_Profilerでクエリーダンプ
Zend_DbにはZend_Db_Profilerっていうかなり便利な仕組みがあるんだけど、バグがありました。
Zend_Db_Profilerっていうのはそのセッション内で発行されたクエリーの情報(実行にかかった時間やクエリーの情報など)を保存しておく仕組みで、後でそのページでネックになっているクエリーを洗い出したりするのに使えます。
ページの最後に自動的にToytools_Debugで上のようにクエリーのログを自動で吐き出すようにしているのですが、ふと気づきました。
getQueryParams()で取得したパラメータクエリーのバインド情報がおかしい・・
複数の値がバインドされたクエリーで、getQueryParams()で取得できる各パラメータの値が何故か全て一緒の値になってしまっています。
上記問題は以下の修正で可能です。
Zend_Db_Profiler_QueryのbindParamメソッドを
public function bindParam($param, &$variable) { $this->_boundParams[$param] =& $variable; }
から
public function bindParam($param, &$variable) { //$this->_boundParams[$param] =& $variable; $this->_boundParams[$param] = $variable; }
に変更します。
直接フレームワークのソースに手を加えたくないけどこればかりは仕方ないですね。
ちなみに上記のようなログを出すには
<?php $log = new Toytools_Debug( __CLASS__ ); //$dbはZend_Db_Adapter_Abstract $profiler = $db->getProfiler(); if(!$profiler->getQueryProfiles()){ return; } $queryList = array(); $totalTime = $profiler->getTotalElapsedSecs(); $queryCount = $profiler->getTotalNumQueries(); $longestTime = 0; $longestQuery = null; foreach ($profiler->getQueryProfiles() as $query) { if ($query->getElapsedSecs() > $longestTime) { $longestTime = $query->getElapsedSecs(); $longestQuery = $query->getQuery(); } //var_dump( $query->getQueryParams() ); $queryList[] = array( 'TYPE' => $query->getQueryType() , 'QUERY' => $query->getQuery() , 'BIND' => $query->getQueryParams() , 'TIME' => $query->getElapsedSecs() ); } $profile = "\n".'全部で ' . $queryCount . ' 件のクエリが ' . $totalTime . ' 秒で実行されました' . "\n". '平均の所要時間: ' . $totalTime / $queryCount . ' 秒' . "\n". '1 秒あたりのクエリ実行数: ' . $queryCount / $totalTime . "\n". '所要時間の最大値: ' . $longestTime . "\n". "一番時間のかかっているクエリ: \n" . $longestQuery . "\n\n\n"; $log->info( $profile , 'QUERY PROFILE'); $log->info( $queryList , 'QUERY INFO' );
のような感じで可能です。ついでにそのページで一番時間がかかったクエリーなんかも出してくれます。
クラスから抜き出したのでそのままじゃ動かないかも。