「このログはどこのメソッドで吐いてるんだっけ…？」を少しだけ改善した方法


ログ出力をするコードで、よく見かけるのは以下のようなコードかなーと。

```
public static final String TAG = "Hoge"; // クラス名とかアプリ共通の文字列が定義されてる

Log.d(TAG, "call value:" + object.toString()); // っぽい感じでログ出力する
```

開発を進めていく中で、何も考えずにログ出力を書いておくと、出力されていくログが積もりに積もって膨大になり、必要な情報が埋もれて見つけにくい状況に陥りやすいです。


そんな状況になってしまった時、少しログの整理をしようとするも、

```
10-21 15:42:47.579  17406-17472/com.hoge.fuga D/HogeTag﹕ start HttpConnection // なるほど通信開始するんだな
10-21 15:42:47.579  17406-17472/com.hoge.fuga D/FugaTag﹕ ##### START!!! ##### // <- わかってるっつーの
10-21 15:42:47.579  17406-17472/com.hoge.fuga D/FugaTag﹕ POST value:piyo
10-21 15:42:47.579  17406-17472/com.hoge.fuga D/FugaTag﹕ url:http://xxx.xxx.xxx/xxx
10-21 15:44:03.102  17406-17472/com.hoge.fuga D/FugaTag﹕ ##### END!!! ##### // テンション高い
10-21 15:44:03.102  17406-17472/com.hoge.fuga D/FugaTag﹕ status:200
10-21 15:44:03.102  17406-17472/com.hoge.fuga D/FugaTag﹕ response:くぁｗせｄｒｆｔｇｙふじこ // ものっそい長いjsonとかズダーッってなる
10-21 15:44:03.129  17406-17472/com.hoge.fuga D/HogeTag﹕ finish HttpConnection

etc...
```


必要かどうか怪しいログが散乱してたりで、 **「このログはどこのメソッドで吐いてるんだっけ…？」** と１つ１つ見つけては修正して…を繰り返すのは **ヒジョー** につらみを感じます。ログ出力の定義をある程度はチーム内で簡単に共有できればいいのですが、そこまでプライオリティは高く見れず、現実はそう簡単にウマくは行かなくて歯がゆいです。

なら、 **「どのメソッドからログが出力されているのか」** という情報をログ自身から読み取れる Util クラスを作ってそれを使いまわすだけでもなんか良いんじゃね！と思い、調べて試してみました。

## StackTrace

Java にはスタックトレースという、メソッド実行の順序を管理してくれたりする機能があり、それを使ってみました。

```Java:MainActivity.java
@Override
protected void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    setContentView(R.layout.activity_main);

    Logger.d("call"); // 'call' の文字列だけを渡す
}
```

```Java:Logger.java
public static void d(String msg) {
    Log.d(getCallMethodName(), msg);
}

private static String getCallMethodName() {

    StackTraceElement[] elements = Thread.currentThread().getStackTrace();

    /**
     * この時のスタックトレース(ファイル名, クラス名, メソッド名)
     * 0, VMStack.java,      dalvik.system.VMStack,       getThreadStackTrace
     * 1, Thread.java,       java.lang.Thread,            getStackTrace
     * 2, Logger.java,       hoge.fuga.piyo.Logger,       getCallMethodName
     * 3, Logger.java,       hoge.fuga.piyo.Logger,       d
     * 4, MainActivity.java, hoge.fuga.piyo.MainActivity, onCreate
     *
     * etc...
     */

    if(elements.length < 5) return "";

    StackTraceElement element = elements[4];

    /**
     * 'android.os.Looper' のようにパッケージ名込みのクラス名を取得し、更に分割してクラス名だけ取得
     */
    String   className  = element.getClassName();
    String[] classNames = className.split("\\.");
    String   clazz = classNames[classNames.length - 1];

    // メソッド名を取得
    String method = element.getMethodName();

    // スレッドのIDを取得
    long id = Thread.currentThread().getId();

    return clazz + "#" + method + "[" + id + "]";
}
```

ログ出力結果

```
10-21 18:53:38.191   16543-16543/hoge.fuga.piyo D/MainActivity#onCreate[1]﹕ call
```

スタックトレースにより、 `MainActivity` の `onCreate` でログが出力されているという情報を、ログ自身に付与することができました。これで、 **「どのメソッドからログが出力されているか」** を払拭できたと思います。また、`StackTraceElement[]` の配列数はメソッドの構成によっては差があるかもしれません。（`getCallMethodName()` を噛ませずに直接取得したら `getStackTrace()` から取得する要素数は１つ減りますね）

### 匿名クラス

ちなみに、匿名クラスで使うと…

```Java:MainActivity.java
@Override
protected void onStart() {
    super.onStart();

    new Thread(new Runnable() {
        @Override
        public void run() {
            Logger.d("call");
        }
    }).start();
}
```

結果は…

```
10-21 18:57:12.079    7068-7082/hoge.fuga.piyo D/MainActivity$1#run[4818]﹕ call
```

`run` メソッドから呼んでいるので `onStart` とは表示されませんでした。当然といえば当然ですね。

***

また副作用？として、ログ出力元のメソッドが分かるだけでなく、ログ出力コードのタイプ数が少しだけ少なくなったりと、精神衛生的にも良いかなと感じました。

・TAG を毎回書かなくても済む
・出力したい情報だけに意識を集中させることができる

***