スポンサーリンク

制御しやすい「デバッグ用ロガー」を自作して，サクサク開発 （Javaで，メソッド名を含めログ出力する方法のサンプル）

java ラテン語 小ネタ プログラミング

重要なお知らせ：

この記事で公開した情報は，AndroidのMVCフレームワーク「Android-MVC」の機能の一部として取り込まれました。

より正確な設計情報や，動作可能な全ソースコードを閲覧したい場合，「Android-MVC」の公式ページより技術情報を参照してください。


AndroidのMVCフレームワーク - 「Android-MVC」
http://code.google.com/p/android-mvc-...


開発中，デバッグ用のログ出力機能は，できるだけ役立って欲しい。

プログラマにとって役立つような情報を，最大限のボリュームまで引き出してログ出力したい。


そのために，Javaで簡易ロガーを自作する際，

下記の２つの要素を駆使してみるのはどうか？

  • スタックトレースAPI
  • 独自アノテーション


スタックトレースを使えば，ログ出力しようとしているオブジェクト自身の情報が分かる。*1

つまり，「呼び出し元」のクラス名やメソッド名を，ログに記載できる。

（これは，Log4jをラップする独自ロガークラスなんかを作った時，よく初回で苦戦する罠だろう。）


また，独自アノテーションを定義すれば，

特定のクラスや特定のメソッドに対して，自由に「メタ属性」を付与できる。

その属性を見ることによって，クラスやメソッドの振る舞いを容易に制御できる。

  • 「このクラスはもう十分，単体テスト済みなので，このクラスだけはデバッグログを出さないようにしたい。」

とか。

そうすれば，結合レベルの試験段階で，作業負荷を軽減できる見込みがある。



上記の指針に基づいて，ごくシンプルなクラス設計を行ない，

下記にサンプルコードと実行結果を示す。


※また末尾には，おまけとして，ラテン語の小ネタを掲載する。

サンプルコード

主要な役者となるクラスは，３つ。

  • メイン処理
  • 独自ロガー
  • 独自アノテーション


まず，メインクラス：

Main.java

package logtest;
import logtest.*;

// メインのクラス。
public class Main
{
	public static void main( String[] args )
	{
		// ログを出力するテスト
		
		MyLogger.d("メイン処理を開始します。");
		
		
		MyLogger.d("Lorem ipsum dolor sit amet,");
		MyLogger.d("consectetur adipisicing elit,");
		
		
		// さまざまな処理
		Hoge.a();
		
		Fuga.b();
		
		new Boo(){
			public void c()
			{
				MyLogger.d("Excepteur sint occaecat cupidatat non proident,");
				
				c2();
			}
		}.c();

		MyLogger.d("メイン処理を終了します。");
	}

}


自作ロガークラス：

MyLogger.java

package logtest;
import logtest.*;

// ロガー
public class MyLogger
{
	
	// ログの出力対象となるコールスタックインデックス
	private static final int LOG_STACK_INDEX = 4;


	// ログの抑制対象となるコールスタックインデックス
	private static final int SUPPRESS_STACK_INDEX = 4;


	// ログを出力
	public static void d( String msg )
	{
		// 対象クラスでログの出力が抑制されていたら，出力しない。
		if( mustSuppressLogByAnnotation() )
		{
			// 抑制
			return;
		}

		// １回を２行に分割。呼び出し元を含めるとあまりにも読みづらいから
		String output = getCallerMethodInfoAsString() + " : \n  " + msg;
		
		// 出力
		System.out.println( output );
	}


	// ログを抑制すべきかどうか判定
	private static boolean mustSuppressLogByAnnotation() 
	{
		// 対象クラスを取得
		Class<?> target_class = null;
		try {
			target_class = Class.forName( getTraceInfoByIndex( SUPPRESS_STACK_INDEX ).getClassName() );
		} catch (ClassNotFoundException e) {
			// 起こりえず
		}

		// クラスのアノテーション宣言と値を取得
		SuppressLog ann = target_class.getAnnotation(SuppressLog.class);
		if( ( ann != null ) && ann.value() ) // 宣言されていてtrue指定されていれば
		{
			return true;
		}
		else
		{
			return false;
		}
	}

	
	// ロガーを呼び出したメソッドの情報を返す
	private static String getCallerMethodInfoAsString()
	{
		StackTraceElement trace = getTraceInfoByIndex( LOG_STACK_INDEX );

		String class_name = trace.getClassName();
		String method_name = trace.getMethodName();
			// @see http://koteitan.seesaa.net/article/171393826.html
			// http://okwave.jp/qa/q6341313.html

		return class_name + "#" + method_name;
	}


	// 特定の階層インデックスのトレース情報を返す
	private static StackTraceElement getTraceInfoByIndex( int index )
	{
		return Thread.currentThread().getStackTrace()[ index ];
	}

}


そして，独自アノテーションの定義ファイル：

SuppressLog.java

package logtest;

import logtest.*;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
import java.lang.annotation.ElementType;

// 特定のクラス内でのログ出力を抑止する独自アノテーション。引数は省略可能。

@Retention(RetentionPolicy.RUNTIME) // プログラム全体で有効とする
@Target(ElementType.TYPE) // クラス宣言に対して使用する
public @interface SuppressLog
{
    boolean value() default true; // 引数として真偽値を取る。省略時はtrue
}

// http://d.hatena.ne.jp/vaice/20091227/p1

この自前アノテーションは，下記のような仕様になる。

  • ログが出る場合：
    • アノテーションなし
    • @SuppressLog(false)
  • ログが出ない場合：
    • @SuppressLog
    • @SuppressLog(true)

ここまでが主だったオブジェクト。


あとは，個別にログを吐くだけのダミークラスを３つばかり。

  • Hoge
  • Fuga
  • Boo


Hoge.java

package logtest;
import logtest.*;

// 処理としてログを出すだけのクラス
public class Hoge
{
	public static void a()
	{
		MyLogger.d("sed do eiusmod tempor incididunt ut labore et dolore magna aliqua.");
		MyLogger.d("Ut enim ad minim veniam,");
		
		a2();
	}

	
	public static void a2()
	{
		MyLogger.d("quis nostrud exercitation ullamco laboris nisi");
		MyLogger.d("ut aliquip ex ea commodo consequat.");
	}
}


Fuga.java

package logtest;
import logtest.*;

// 処理としてログを出すだけのクラス

// このクラスはログ出力を抑制するように
// アノテーションで指示
@SuppressLog
public class Fuga
{
	public static void b()
	{
		MyLogger.d("これは，出力されないログです。");
		
		b2();
	}
	
	public static void b2()
	{
		MyLogger.d("これも，出力されないログです。");
	}
}


Boo.java

package logtest;
import logtest.*;

// 処理としてログを出すだけのクラス

@SuppressLog(false)
public class Boo
{
	public void c()
	{
		// Override me
	}
	
	public void c2()
	{
		MyLogger.d("sunt in culpa qui officia deserunt mollit anim id est laborum.");
	}
}

実行してみよう


ここまでのソースを見ると，抑制されるログを除いて，

全部で10回分のログが出力されるはずである。



コンパイルして実行。

どんな結果になるか？

D:\temp>javac logtest/*.java

D:\temp>java logtest/Main
logtest.Main#main :
  メイン処理を開始します。
logtest.Main#main :
  Lorem ipsum dolor sit amet,
logtest.Main#main :
  consectetur adipisicing elit,
logtest.Hoge#a :
  sed do eiusmod tempor incididunt ut labore et dolore magna aliqua.
logtest.Hoge#a :
  Ut enim ad minim veniam,
logtest.Hoge#a2 :
  quis nostrud exercitation ullamco laboris nisi
logtest.Hoge#a2 :
  ut aliquip ex ea commodo consequat.
logtest.Main$1#c :
  Excepteur sint occaecat cupidatat non proident,
logtest.Boo#c2 :
  sunt in culpa qui officia deserunt mollit anim id est laborum.
logtest.Main#main :
  メイン処理を終了します。

D:\temp>

全部で10回分の出力。


出したいログは，ちゃんと出た。

抑制したいログは，ちゃんと消えてくれている。
制御方法がアノテーションなので，気軽に付けたり外したりできる。



ただし，Mainクラス中でBooを匿名クラスとして定義しているが，

その部分のログは「Boo」というクラス名情報が出ず，

「Main$1」という無名クラスが出したログとして扱われる。


それもそのはず。

コンパイルの時点で，Main.classやBoo.classとは別に，

「Main$1.class」というバイナリがフォルダ上に存在するようになるからだ。

これが匿名クラスの仕様。

Java FAQ : 内部クラス - inner class
http://javafaq.jp/S016.html

  • コンパイラによって生成される匿名クラスのクラスファイルは「外側のクラス名$＜数字＞.class」という名前になる

あと，MyLoggerの中で各クラス情報の調査を毎回個別に行なっているけども，

本当はどこかに情報をキャッシュしておいた方がパフォーマンスを悪化させないで済むだろう。


それでも，スタックトレースを毎度取得するのは結構な負荷なので，

ここで取り上げたロギングの仕組みを実際に使えるのは，

開発中のデバッグ用途ぐらいだと思われる。



あるいは，nano sec・milli sec単位で何かを計測するようなプログラムだと，

単体テストの実行時点で，既に上記のロガーがネックになり，

プログラムの動作がまずくなるだろう。


そういうケースでは，そもそもログに対する要件が異なるので，

そのプロジェクトに応じたログ要件に沿った別のアプローチが必要となる。


参照：

[log4j]ログ出力クラスでのメソッド名出力方法
http://oshiete.goo.ne.jp/qa/6341313.html


ログ用にファイル名、クラス名、メソッド名、行番号などを取得
http://d.hatena.ne.jp/fumokmm/2007072...

  • Throwableを使う手もある

補足

本稿のサンプルログの出力内容について：

Lorem ipsum
http://ja.wikipedia.org/wiki/Lorem_ipsum

  • 出版、ウェブデザイン、グラフィックデザインなどの諸分野において使用されている典型的なダミーテキスト
  • 「lorem ipsum」は古典ラテン語に非常によく似ているが、実際には全く意味を持たない。グリーキング。


内容の解説
http://www.geocities.jp/futoshiki/ess...
ラテン語風だが、ラテン語では無い。
実際に使われそうな文章だと、ダミーだか本物だか分からなくなって、ウッカリ実際の印刷に回されかねない。
なるたけもっともらしいウソ文書、それも「あ、こりゃダミーだね」と分かる奴がよろしい。
"Lorem ipsum..."はこういう用途のために、欧州の印刷業者が採用し、長年愛用されてきた文章なのである。


なんと，Google翻訳は「ラテン語」に対応している。

※http://translate.google.co.jp/#la|ja|

さっそく「羅和（ラテン語→日本語）」の自動翻訳にかけてみよう。　


実行結果：

「Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident, sunt in culpa qui officia deserunt mollit anim id est laborum.」

↓

「これは単に精神的な焦点のダミーテキストですが、時折の状況は、いくつかの大きな喜び、その労苦と痛みが発生するため。簡単な例を取るために、私たちのこれは、これまでに下記の選定からだけでなく、骨の折れる運動を行っています。あなたのリンクは、ページ内で障害を見つけるために、痛みの喜びを楽しむために送信されます。ない製品はありません、彼らは特別な宝石のニーズであるとに簡単に歓迎されるべきである。」

このように，笑える結果となった。

Google翻訳なので，この文章がWeb上で引用されるシチュエーションが如実に反映されている・・・。


ぜひ，他のさまざまな古代語やマイナーな言語も，自動翻訳に対応して頂きたいものだ。



しかし「Lorem ipsum」が正式なラテン語ではなく，意味不明の文章に加工されていたとは。


どうりで，手元の辞書を引きながらこの文章を理解しようとしても，できないわけだ。

そもそも出だしの「Lorem」という単語からして，まず適切な単数主格が見つからなかった。


それも当然，原典では「dolorem」なのだから。わかるわけない。

ダミーテキスト化するために，単語の一部を削除したという事になる。

わかる人にとっては，冒頭からして明らかにダミー文章だとわかる。という事に。

Latin Dictionary and Grammar Aid（ラテン語のオンライン辞書）
http://www.archives.nd.edu/cgi-bin/lo...

  • dolor -oris m. [pain] , physical or mental; esp. [disappointment, resentment].
  • つまり「悲しみ」。


名詞の子音型格変化
http://www.lingua-latina.org/LL_2A_1d...

  • dolorは子音型格変化の，「-, -is（流音幹）」：語幹変化なし のサンプルとして取り上げられている。
  • 単数対格が "dolorem"。訳は「悲しみを」。
  • ※「しいんがたかくへんか」をIMEで変換すると，一発目は「死因が高く変化」になった。…


　

*1:JavaScriptでいうと，arguments.callee.callerみたいなものだ。残念ながらJSでは，Functionオブジェクトの名前までは取得できないし，関数のレシーバを参照するすべも無いが…。

language_and_engineering 読者になる

広告を非表示にする
スポンサーリンク
スポンサーリンク