Androidデバッグログの小ネタ

Androidではデバッグログ、Logcatへの出力をする　`android.util.Log`　クラスがありますが、これを直接使うことはあまりせず、独自のログ出力クラスを作る場合も多いかと思います。
そういった場合に使える、Androidでデバッグログ出力を行う上での小ネタをいくつか説明しようと思います。
最近では[Timber](https://github.com/JakeWharton/timber)を使っているプロジェクトが多いと思いますが、ライブラリプロジェクトでTimberを使うわけにはいかない状況があったり、独自の出力方法を作った方が都合がよい場合などもあります。

# コードジャンプ

Android Studio の Logcat View でスタックトレースの出力を見ると、以下のように「`ファイル名:行数`」の箇所がリンク風に表示されており、コードジャンプとして機能しますよね。

![](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/155171/d8b5d133-1215-c819-254a-1fb2a31c3756.png)

これはスタックトレースが特別扱いされている訳ではなく、単に「`ファイル名:行数`」の出力があればコードジャンプとして機能します。

そのため、極端な話以下のような手書きの出力でもコードジャンプが機能します。

```MainActivity.kt
Log.e("XXXX", "MainActivity.kt:12")
```

![](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/155171/1065484c-c9cb-1bf9-3d79-c1faa8453229.png)

ちなみに、スタックトレースの「`at <FQCN>.<methodName>()`」の部分はコードジャンプ機能と関係がありません。
別パッケージに同名のファイルがある場合、FQCNで示されたパッケージのものが表示される、ということはなく、単に選択肢が表示されます。

## ログ出力に呼び出し箇所へのコードジャンプを追加する

「`ファイル名:行数`」の出力さえしてしまえばコードジャンプができると分かったので、ログ出力に自動的に呼び出し元へのコードジャンプを追加することを考えてみましょう。
ファイル名や行数はスタックトレースから取得できます。スタックトレースはThrowableのインスタンスを作ることで取得可能です。
以下のようなLog出力クラスを作ることで自動的に付与することができますね。

```Logcat.kt
object Logcat {
    fun e(message: String) {
        val element = Throwable().stackTrace.getOrNull(1) ?: return
        Log.e("XXXX", "${element.fileName}:${element.lineNumber} | $message")
    }
}
```

そして

```MainActivity.kt
Logcat.e("Hello, world!")
```

とすると、以下のように出力されます

![](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/155171/01f4df09-b6d1-c5b6-678a-c0f08b99db3e.png)

スタックトレースの一つ目の要素は　Throwable　のコンストラクタを呼び出した箇所になるので、　`Logcat.e（）`　を呼び出した箇所を指し示す　StackTraceElement　は2つ目に入っているので、ここでは `getOrNull(1)` にしています。
さらに処理をまとめた別のメソッドに処理を委譲する場合は、メソッド呼び出しの階層に併せてインデックスを調整する必要があります。また、呼び出し経路によって階層が違っていたり、リファクタリングなどによって階層が変わったり、といったことを考えると固定値とするよりは多少コストは上がりますが、以下のようにログ出力関係クラス以外が現れる最初の位置とした方が良いかもしれません。

```Logcat.kt
object Logcat {
    fun e(message: String) {
        val ignoreClassName = this::class.java.name
        val element = Throwable().stackTrace
            .firstOrNull { it.className != ignoreClassName } ?: return
        Log.e("XXXX", "${element.fileName}:${element.lineNumber} | $message")
    }
}
```

関係クラスが複数ある場合は以下のようにすれば良いですね

```Logcat.kt
object Logcat {
    private val ignoreClassNames = setOf(
        Logcat::class.java.name,
        Debug::class.java.name,
    )

    fun e(message: String) {
        val element = Throwable().stackTrace
            .firstOrNull { it.className !in ignoreClassNames } ?: return
        Log.e("XXXX", "${element.fileName}:${element.lineNumber} | $message")
    }
}
```

# 呼び出し元クラス名をTAGに自動設定

AndroidのLogcatの第一引数tagは

> Used to identify the source of a log message. It usually identifies the class or activity where the log call occurs.

とあるように、呼び出し元クラス名の定数を渡すのが一般的で、TAGという定数にクラス名を定義しておいて、それを渡すというスタイルが多いです。が、これはクラスごとに行わないといけない。また、クラス名をリネームしたときにリネームを忘れるなど何かと管理が面倒です。
これを自動化できれば管理する必要がなくなり、コードをシンプルにできます。
こちらはTimberがやってくれていることですね。

## 拡張関数を利用する

Kotlinでは拡張関数が使えるので、ログ出力メソッドをAnyをレシーバーとする拡張関数として実装することで、呼び出し元の `this` をレシーバーとしてメソッド側で受け取るという方法が考えられます。

```kotlin
fun Any.error(message: String) {
    Log.e(javaClass.simpleName, message)
}
```

しかし、thisが変化する状況がいろいろあり、意図しない出力になってしまう場合が多々ありそうで、あまり良い方法ではなさそうです。

## スタックトレースを利用する

スタックトレースを使えば呼び出し元クラス名を取得することが可能です。Timberもこの方法を使っています。
StackTraceElement の `className` はFQCNになっていて長いこと、また、tagは23文字までという制約がある<sup>※</sup>ことも考えると、simpleNameに相当するものを抽出したいですね。
> <sup>※</sup>蛇足ですが、24文字以上のtagを渡しても省略されるだけです。しかし、 `Log#isLoggable()` はAPI 25まで24文字以上のtagを渡すと `IllegalArgumentException` を投げていました。 23文字って中途半端な印象ですが、`"log.tag."+tag` のデータサイズを終端文字を含めて32byte以下にするため、23文字という制限らしいです。

StackTraceElement の `className` は通常、`com.example.myapplication.MainActivity`という値ですが、ラムダの中の場合、`com.example.myapplication.MainActivity$onCreate$action$1`のような値が入っています。

以下のようにすることで呼び出し元のクラス名をtagに設定することができます。

```kotlin
fun e(message: String) {
    val element = Throwable().stackTrace
        .firstOrNull { it.className !in ignoreClassNames } ?: return
    val tag = element.className.extractSimpleClassName()
    Log.e(tag, message)
}

private fun String.extractSimpleClassName(): String {
    val startIndex = lastIndexOf('.').let { if (it == -1) 0 else it + 1 }
    val endIndex = indexOf('$', startIndex).let { if (it == -1) length else it }
    return substring(startIndex, endIndex)
}
```

# ログメッセージの生成を遅延させる

動的に出力内容を変更できるようにしている場合、出力しないにもかかわらず、その出力文字列を作成する処理を走らせるのは無駄となります。そういった無駄を減らすために、メッセージ生成の処理を遅延させたくなります。

## フォーマット引数で受け取る

Timberが使っているアプローチですね。 `String.format()` の引数に相当するものを受け取って、必要な時にformatを実行するというものです。

```kotlin
fun e(message: String, vararg args: Any?) {
    if (!isEnable) return
    val m = if (message.isEmpty() || args.isEmpty()) {
        message
    } else {
        message.format(*args)
    }
    Log.e("XXXX", m)
}
```

こうすると、formatはログ出力が有効な場合のみとなります。

引数に相当する値を作る処理は出力処理の外になるため、そのコストは変わらずかかりますし。文字列結合やKotlinの文字列テンプレートを使った結合はStringBuilderによる結合であり、そこまで高いコストがかかっている訳ではない。`String.format()`は文字列結合よりコストが高い。などと考えるとどれだけの意味があるのかは微妙なところかなという気もしてきます。

## ラムダを渡す

メッセージを返すラムダを渡すという方法もありますね。

```kotlin
fun e(messageSupplier: () -> String) {
    if (!isEnable) return
    Log.e("XXXX", messageSupplier())
}
```

こうしておけば、messageに表示するための各データの取得処理も含めて必要な時のみ実行されるようになります。
一方で、ラムダはインラインクラスのインスタンスになるので、そのインスタンスを作るコストは発生してしまいます。
inlineメソッドとして実装すればそのコストは発生しませんが、少なくとも出力の有無判定に必要なところまで（上記例ではisEnabled）がpublicである必要があります。

inlineメソッドにして、 `BuildConfig.DEBUG` で囲むなどして、リリースビルド時にデッドコードになるような書き方をした場合、Proguardがコードからまるっと削除してくれるというメリットもあります。

```kotlin
inline fun e(messageSupplier: () -> String) {
    if (!BuildConfig.DEBUG) return
    Log.e("XXXX", messageSupplier())
}
```

このアプローチは、ライブラリプロジェクトの場合、デバッグ用とリリース用の2種類のバイナリを提供しないといけなくなる可能性もあるので、ユースケースによって適切な方法は変ってきます。
マルチモジュールやライブラリプロジェクトの場合は、inlinenにしないで、proguardを使って削除した方が良いかもしれません。

# レベルを引数で指定する

`Log` クラスを直接使う場合、 `e` `v`といった、レベルごとのメソッドを呼び出しますが、ログ出力クラスを作る場合は、レベルを引数で指定できないと同じようなメソッドをたくさん作ることになったり、分岐処理を書いたりが必要になります。
当然それらも用意されていて、以下のようなメソッドがあります。

```kotlin
public static int println(@Level int priority, @Nullable String tag, @NonNull String msg)
```

なので、以下のようにレベルを引数で渡すことで、共通処理を綺麗に書くことができますね。

```kotlin
object Logcat {
    fun v(tag: String, message: String) {
        println(Log.VERBOSE, tag, message)
    }
    fun d(tag: String, message: String) {
        println(Log.DEBUG, tag, message)
    }
    fun i(tag: String, message: String) {
        println(Log.INFO, tag, message)
    }
    fun w(tag: String, message: String) {
        println(Log.WARN, tag, message)
    }
    fun e(tag: String, message: String) {
        println(Log.ERROR, tag, message)
    }
    
    private fun println(level: Int, tag: String, message: String) {
        ...
        Log.println(level, tag, message)
    }
}
```

通常利用するメソッドのように、Throwableを渡すインターフェースは用意されていない（hide指定）ため、スタックトレースも必要であれば、それらをまとめたStringとして渡す必要があります。

# スタックトレース文字列を取得する

というわけで、ログ出力クラスを自作する場合、Throwableのスタックトレース内容はStringとして取得したい場合があります。
`Throwable.printStackTrace()` は `System.err` へ出力されます。
Stringとして取得したい場合は、引数に `PrintStream` もしくは `PrintWriter` を渡して、そこに出力をして、その内容をStringとして取得する必要があります。

```kotlin
val stackTraceString =
    StringWriter().also {
        throwable.printStackTrace(PrintWriter(it))
    }.toString()
```

とすることで、Stringとして取得することができますね。
この機能も `Log` クラスに用意されています。 `Log.getStackTraceString(throwable)`を使うことでStringとしてスタックトレースが取得できます。

以下のように使います。

```kotlin
fun e(throwable: Throwable, message: String) {
    Log.e("XXXX", "$message\n${Log.getStackTraceString(throwable)}")
}
```

# ログ出力クラス

以下のようにするとTimberを置換できて最低限の動作をするぐらいのクラスが作れます。

```kotlin
object Logcat {
    private var isEnabled = false
    
    fun setEnabled(enabled: Boolean) {
        isEnabled = enabled
    }
    
    fun v(message: String, vararg args: Any?) {
        println(Log.VERBOSE, null, message, args)
    }

    fun v(t: Throwable?, message: String, vararg args: Any?) {
        println(Log.VERBOSE, t, message, args)
    }

    fun v(t: Throwable?) {
        println(Log.VERBOSE, t, "", emptyArray())
    }

...
    private val ignoreClassNames = setOf(
        Logcat::class.java.name,
    )

    private fun println(level: Int, t: Throwable?, message: String, args: Array<out Any?>) {
        if (!isEnabled) return
        val element = Throwable().stackTrace
            .firstOrNull { it.className !in ignoreClassNames } ?: return
        val tag = element.className.extractSimpleClassName()
        val m = if (message.isEmpty() || args.isEmpty()) {
            message
        } else {
            message.format(*args)
        }
        if (t == null) {
            Log.println(level, tag, m)
        } else {
            Log.println(level, tag, "$m\n${Log.getStackTraceString(t)}")
        }
    }

    private fun String.extractSimpleClassName(): String {
        val startIndex = lastIndexOf('.').let { if (it == -1) 0 else it + 1 }
        val endIndex = indexOf('$', startIndex).let { if (it == -1) length else it }
        return substring(startIndex, endIndex)
    }
}
```

どういう機能が必要なのかは、それぞれのプロダクトごとに決めれば良いと思います。
例えば出力するレベルを動的に変更する機能を追加したりも簡単にできそうですよね。

デフォルトの状態をどうするかも議論の余地はあると思いますが、少なくともライブラリプロジェクトの場合は、何もしなければ出力しない、出力したい場合は明示的に指定が必要としたほうが、リリース時に意図しない出力が行われてしまうみたいな問題が起こらなくて良いのではと思います。

以上です。