困った時のログの取り方
システム開発部のうのです。
みなさん、CakePHPでのデバッグやテストはどのようにやりますか? echo してから exit で処理を止める、ですかね。 とりあえず var_dump で書き出してみる、ですかね。
いわゆる「printfデバッグ」、 言い換えると 「ログ」を取ってみる 、ってヤツですね。 これらは分かりやすく、かつ手っ取り早く処理の中身を見る良い方法です。
ですが、これだけではログを取れない、見れない場合があります。 ブラウザ上で確認するという都合上、致命的なエラーが起こったり、そもそもブラウザで結果が見えるコードじゃなかったり。
その場合にも対応できる方法を、いくつか紹介します。
CakePHPでのログの取り方
Cakephpには、ブラウザ以外でログを確認する機能が用意されています。クックブックの「ロギング」のページに全てが書かれています。……ちょっっっと見つけにくいなぁ。でも見えるところには置いてあるんですよ。中身を見てみましょう。
「ロギング」のページによると、 ログをとる時、主にこのように書きます。
$this->log('ログを取ろうね'); //ここでログを書き出す
こう書くと、ログ関数が実行された時に /log/error.log
のファイルが更新されます。
▼このように、実行日時も出してくれる
2020-09-15 18:40:47 Error: ログを取ろうね
これを使って、こまめにログを書き出すようにすれば、 処理の流れを追う事ができます。
例として、 「ネットショップでよくある、商品をカートに入れる処理」 を書いてみました。 ボタンを押すと、画面遷移せずにカートに商品が追加される想定です。
// Controllerのソース
public function addCart(){
if( $this->request->is('ajax') == false ){
$this->log('カートの中にある商品を処理、ここから');
// カートの中の商品を取得
$product_ids = $this->request->getData();
$products = $this->Product->find()
->where([
'id' => $product_ids,
])
;
$this->log('商品ID:' . print_r($product_ids, true));
foreach ($products as $product) {
$product->stock -= 1; // 在庫を減らす
$product->addCart($this->Auth); // ログインユーザーのカートに入れる
$this->Product->save($produst);
$this->log('ID:' . $product->id . ' 在庫: ' . $product->stock);
}
$this->log('カートの中にある商品を処理、ここまで');
} else {
$this->log('不正なリクエスト');
}
}
このソースを実行すると、下のようなログが出力されます。
2020-09-15 18:36:18 Error: 不正なリクエスト
2020-09-15 18:40:47 Error: カートの中にある商品を処理、ここから
2020-09-15 18:40:47 Error: 商品ID:[
1,
5,
88
]
2020-09-15 18:40:47 Error: ID:1 在庫: 99
2020-09-15 18:40:47 Error: ID:5 在庫: 6
2020-09-15 18:40:47 Error: ID:88 在庫: 2
2020-09-15 18:40:47 Error: カートの中にある商品を処理、ここまで
ログを見ると、どんな流れでソースコードが実行されたか分かると思います。この例の場合は、2回リクエストされて、そのうち1回はちゃんとPostされた内容の商品に対して処理が実行されたことがわかります。
CakePHPが用意している関数
ほとんど話してしまったのですが、ロギングのページをよく見ると、もう少し書いてあるので解説します。
ログを取る方法には以下の方法があると書かれています。
Controller内でlog関数を使う
先ほども使った、簡単な方法です。
$this->log('ログを取ろうね');
この方法は、コントローラーの中でしか使えませんが、 特別何かを気にする事はなく、文字を渡すだけでログをとることができます。
ログの保存先は /log/error.log
です。
Logクラスのwrite関数を使う
「ロギング」のページで一番使われている関数です。
use Cake\Log\Log;
Log::write('error', 'ログを取ろうね');
この方法を使えば、モデルやビューでもログを取れます。 エラーの種類を必ず指定することが特徴です。
例えば
Log::write('debug', 'ログを取ろうね');
と変えると、ログの保存先が /log/debug.log
になります。
困った時のログの取り方
デバッグのやり方とひとくちで言っても、 もっと高度で効果の高いものから、 今回の「ログ」ように簡単で、地道なものまで多くあります。
専門的なものの方が取り上げられやすいですが、 日常的に、ちょっと気になったときに、細かく小さく使うテクニックの方が大事な場面も多くあると思います。
こういった細かいものにも目を向けていきたいですね。
うのでした。