takaiwa.net

Android、Java、Web系、Linux、マラソン等の備忘録

2012/02/19

【PHP】CodeIgniterのログをクラス名やメソッド名や行番号とかも表示してみる

0 件のコメント

環境

CodeIgniter:Version 2.1.0

前置き

表題にCodeIgniterと書きましたが、概念的にはこのフレームワークだからという話ではないです。前回の続きと言うことで。

デフォルトでログは以下のように吐かれます。

DEBUG - 2012-02-18 23:30:43 --> Controller Class Initialized
INFO - 2012-02-18 23:30:43 --> start
INFO - 2012-02-18 23:30:43 --> valid id:hogehoge
INFO - 2012-02-18 23:30:43 --> end


まあ、ざっくりこのログが何を表しているかというと、土曜の夜だというのにデバッグしてるMVCモデルのControllerの部分に要求がきて、その中のメソッドを開始し、idの値判定して結果をログへ出力。正常にメソッドを抜けてendといった感じを表しています。



自分で作り込んでいれば、上記では割愛した前後のログでおよその見当は付くでしょうが、ぱっと見どこの処理かわからないですね。



これにクラス名やメソッド名、行番号が表示されていれば、前後を確認しなくとも1発でどこの処理か判断する事ができるのではないでしょうか。





クラス名やメソッド名、行番号などの情報を取得する方法



PHPには便利な関数があるようで、




・PHP: debug_backtrace - Manual
http://www.php.net/manual/ja/function.debug-backtrace.php




この関数を叩けば、呼び出し元のクラス名やら行番号が参照できます。という事で、前回社畜仕様にカスタマイズしたファイルに埋め込めばOK。はい解決!と行きたいところですが、少し挙動を見てみましょう。



debug_backtrace関数の戻り値を表示させるには、



 var_dump(debug_backtrace());


という記述をしてやります。これを前回で言うところのMY_Log.phpのwrite_logメソッド内に記述し、



呼び出し元となる、テスト用のControllerを作成してやります。



<?php if ( ! defined('BASEPATH')) exit('No direct script access allowed');

class Testcontroller extends CI_Controller {

public function index() {
log_message('debug', 'Hello world');
}
}




ブラウザから呼んで、1回の処理でどれだけ戻り値があるか実験してみます。



WS000424



こんな感じでたくさんの配列の中身が表示されます。これらをコピーしてテキストに保存してサイズを見ると、





WS000422





160KBなかなか大きいサイズじゃないですか。たかだかControllerからHello worldとログに出力するだけでこのサイズの戻り値の文字があるわけです。これが、何行もログを出力し、同時に複数のアクセスがある事を考えると、脇役のログが結構な負荷になるのではないでしょうか?そんなにアクセスないから安心しろ。 とは言え、160KBと言われても、戻り値の配列を文字で表示したサイズですし、PHPの中身がどうなっててメモリをどう使ってるのかわからないので”大きいサイズ”と言いましたが感覚的なものです。。。ブラウザに表示すると重くなるデータサイズはちと見逃せねーなーといった感じです。





パフォーマンス重視で言えば、以下の定数を1個1個Hello worldの部分へ埋め込めば良いでしょう。




・PHP: 自動的に定義される定数 - Manual
http://php.benscom.com/manual/ja/language.constants.predefined.php




しかし、捕らぬアクセスのレスポンス算用を今のうちにして、パフォーマンス重視の見づらいコードになるくらいなら、バグを埋め込まないためにもスッキリさせておきたいので、仲介の関数(ラッパー関数)を間に挟んでみます。



ロガーを仲介する関数を作成する



メソッドからロガーを呼ぶにあたり、以下のようなコードの見栄えでどこからでも直接関数を呼べるよう、



log_message('debug', 'Hello world');


CodeIgniterのヘルパー関数として実装します。




・ヘルパー関数 : CodeIgniter ユーザガイド 日本語版
http://codeigniter.jp/user_guide_ja/general/helpers.html




まず、ヘルパー関数を記述するファイルを作成します。ファイル名の末尾は「_helper.php」となるようにします。




  • application/helpers/mylogwrap_helper.php



<?php
function logger_debug($msg) {
print_r(debug_backtrace());
log_message('debug', $msg);
}
?>


まずは、上記のMY_Log.phpと比較できるよう、print_r(debug_backtrace());を実装しておきます。これをどこからでも呼べるよう、「application/config/autoload.php」に登録します。こちらでは、ファイル名の「_helper.php」は必要ありません。



$autoload['helper'] = array('mylogwrap');


これで先ほどのControllerでこの関数を呼ぶようにして実験をしてみます。



<?php if ( ! defined('BASEPATH')) exit('No direct script access allowed');

class Testcontroller extends CI_Controller {

public function index() {
logger_debug('Hello world');
}
}


WS000423



約27KBで仲介させた関数の方が約1/6小さい!ということで明らかに効果がありますね。まあ、フレームワーク自体のログが出なくなる事もあり、当たり前ですが。できればByte単位にしたいところですが、コレでいきたいと思います。



で、これを表題の通りに表示させるべく、debug_backtrace関数の戻り値から必要な情報を取得し、関数を修正・整理してみたのが以下です。ただし、クラス名を表示させるので呼び出し元はクラス限定という縛りで。



<?php
function logger_info($msg) {
logger('info', $msg);
}
function logger_debug($msg) {
logger('debug', $msg);
}
function logger_error($msg) {
logger('error', $msg);
}

function logger($level, $msg) {
$arr = debug_backtrace();
// この関数が直接呼ばれた場合と、同ファイル内から呼ばれた場合でバックトレースの取得位置を分岐。
if(stristr($arr[0]['file'], 'mylogwrap_helper') === FALSE) {
// ヘルパーとして呼び出された場合
$filename = $arr[1]['class'] ."::".$arr[1]['function'];
$msg = $filename."[".$arr[0]['line']."] ".$msg;
}
else {
// 同ファイル内からの呼び出された場合
$filename = $arr[2]['class'] ."::".$arr[2]['function'];
$msg = $filename."[".$arr[1]['line']."] ".$msg;
}
// 本家ロガーへ (;_;)/~~~
log_message($level, $msg);
}
?>


パラメータとして記述していたdebugやerrorというレベル値は、その分対応する関数としました。これならNetBeansとかのIDEなら実行前にエラーだとわかるのではないでしょうか?試してないのでわかりませんが。そして、共通的に処理するloggerを設けてます。本当はloggerはプライベートな関数としたいところですが、そうもいかないので、直接呼ばれた場合と同ファイルから呼ばれた場合で分岐させましました。





これを先ほどのControllerから呼ぶと、



DEBUG - 2012-02-19 01:32:45 Controller Class Initialized
DEBUG - 2012-02-19 01:32:45 Testcontroller::index[6] Hello world


これで、どこのHello worldさんか一目瞭然ですね!

【PHP】CodeIgniterのログ出力をサイズ単位にカスタマイズ

0 件のコメント

環境

CodeIgniter:Version 2.1.0

前置き

CodeIgniterは「application\config\config.php」の

/*
|--------------------------------------------------------------------------
| Error Logging Threshold
|--------------------------------------------------------------------------
|
| If you have enabled error logging, you can set an error threshold to
| determine what gets logged. Threshold options are:
| You can enable error logging by setting a threshold over zero. The
| threshold determines what gets logged. Threshold options are:
|
| 0 = Disables logging, Error logging TURNED OFF
| 1 = Error Messages (including PHP errors)
| 2 = Debug Messages
| 3 = Informational Messages
| 4 = All Messages
|
| For a live site you'll usually only enable Errors (1) to be logged otherwise
| your log files will fill up very fast.
|
*/
$config['log_threshold'] = 3;


log_thresholdの値を3(または4)とかにして



log_message('debug', "hello CodeIgniter");


のように書けば「application/logs」ディレクトリへログが出力されますが、ファイル名が



log-2012-02-14.php
log-2012-02-15.php
log-2012-02-16.php
log-2012-02-17.php


という日付単位になっているため、tailコマンド等でログを追っていると日付を超えた瞬間ログが出力されなくなります。日付を超えて作業をしているような社畜にとってはありがたくない仕様です。





せっかくノリノリでコーディングをしていても、ログが出なくなる異変に気付き、今日の日付のファイル名でtailコマンドを打ち直すというちょっとした作業により、毎晩遅くまでご苦労さんwwと日付が変った事を思い知らせてくれるドS仕様にやる気をくじかれるわけです。これはいかんという事で、ログファイル名は固定で、あるサイズを超えるとアーカイブを作る(リネーム)するように変更したいと思います。





とは言え、CodeIgniterでログをカスタマイズするのはググればたくさん出てくると思うので、そちらを参考にしてもらう方が良いかもしれませんが、ファイルサイズをチェックしてリネームするかどうとか、config.phpいじるとか一連の流れを覚えておきたいのでメモしておきます。





カスタマイズ用のファイルを作成



このログのファイル名を決定している 諸悪の根源 実装はsystemディレクトリ内にある「system/libraries/Log.php」というファイルです。これを直接編集すれば直ちに動作も変るわけですが、systemディレクトリ内のファイルは触りたくないという事で、CodeIgniterのこちらのガイドに従い、




・コアシステムクラスの作成 : CodeIgniter ユーザガイド 日本語版

http://codeigniter.jp/user_guide_ja/general/core_classes.html



コアシステムのクラスをユーザバージョンのクラスと置き換えたり、コアシステムのクラスを拡張したりすることもできます。




Log.phpはライブラリのファイルですが置き換えたいと思います。以下手順を2つ




  1. system/libraries/Log.php をコピー


  2. application/libraries/MY_Log.phpとして配置



この頭の「MY_」が置き換えの味噌のようです。で早速MY_Log.phpのクラス名を以下のように修正。

class My_Log extends CI_Log {

これでカスタマイズ用のファイルが完成です。あら簡単。



コンフィグからファイル名とファイルサイズ上限を取ってくる



前仕様では日付をファイル名にしてるので、Log.phpはログを出力するパスだけ知ってれば良かったのですが、ファイル名を指定してやりたいのでconfig.phpから取得させるようにしたいと思います。冒頭のコンフィグのコードが書かれてる下あたりに記述してやればOKでしょう。



$config['log_file_name'] = 'hogehoge.php';
$config['log_file_size'] = 921600;


サイズは適当に900KBにしています。根拠は特にありません。



ログファイルをサイズ単位で出力するようにする



MY_Log.phpのwrite_logメソッド内の85行目~98行目あたりを修正しました。



$config =& get_config();
$filepath = $this->_log_path.$config['log_file_name'];
$message = '';
$openmode = FOPEN_WRITE_CREATE;

if ( file_exists($filepath))
{
// ファイルサイズチェック
if( filesize($filepath) > $config['log_file_size'] ) {
// サイズオーバーなので、コピー退避
$new_file = $this->_log_path.date('Y-m-d_His').'.php';
copy($filepath, $new_file);
// モード:書き出しのみでオープン
$openmode = FOPEN_WRITE_CREATE_DESTRUCTIVE;
}
}
else {
$message .= "<"."?php if ( ! defined('BASEPATH')) exit('No direct script access allowed'); ?".">\n\n";
}

if ( ! $fp = @fopen($filepath, $openmode))
{
return FALSE;
}


これでサイズの敷地を越えると、tailに



tail: hogehoge.php: ファイルが切り詰められまし


と表示されますが、再度コマンドを打つ事なくログを追う事ができます。



付け足すとするなら、前仕様でもそうですが、永遠とログを吐き続けるので運用段階では古いファイルを削除するような実装も欲しいですね。ログのバックアップを取って消すというトリガーでも良いかもしれませんが。



これで今夜から快適なログ出力ライフにのぞめます。

2012/02/06

[JavaScript]プロトタイプ定義したメソッド内でsetTimeoutを使って自身を呼び 出す方法

0 件のコメント

コメント欄で思いがけず見つけたので、メモ。

prototype定義したメソッド内でsetTimeoutで自身を呼び出す方法

・JavaScript’s setTimeout and how to use it with your methods » Klevo blog
http://klevo.sk/javascript/javascripts-settimeout-and-how-to-use-it-with-your-methods/

If you are using the prototype javascript, you can take advantage of its general purpose early-binding function, bind (see http://alternateidea.com/blog/articles/2007/7/18/javascript-scope-and-binding).
The solution using prototype’s bind function is:

setTimeout(this.methodToCall.bind(this), time);

上記赤文字の通りに使えば良いのですが、メソッド自身を繰り返し呼んでブラウザに時計のように表示するサンプルを以下に。

<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01//EN"
"http://www.w3.org/TR/html4/strict.dtd">
<html xmlns="http://www.w3.org/1999/xhtml" lang="en">
<head>
<meta http-equiv="Content-Type"
content="text/html; charset=utf-8" />
<title>BrowserTimer</title>
<meta name="author" content="takaiwa29" />

<script type="text/javascript">
var BrowserTimer = function() {}
BrowserTimer.prototype = {
timerMethod: function () {
// 現在時刻を取得
var nowtime = new Date();

var display = document.getElementById("display");
// 現在時刻を表示
display.innerHTML = nowtime.toString();

// 1秒後に同メソッドを呼ぶ
setTimeout(this.timerMethod.bind(this),1000);
}
}

function init() {
var hoge = new BrowserTimer();
hoge.timerMethod();
}
</script>
</head>
<body onLoad="init()">
<!-- タイマー表示場所 -->
<div id="display"></div>
</body>
</html>


実行結果はこんな感じ



 



WS000408