iOS14から登場したNew Logger API vs OSLog

こんにちは、 ２１日目はiOSエンジニアの paper_and_paper です。

アプリを開発されている皆さんは、自分のデバイスでは再現しないようなエラーや不具合ってどれくらいございますか？

おそらくユーザが数100万人規模になると、ユーザからのお問い合わせや不具合報告だけでもかなり頻度と数が上がってくるかと思います。しかし、実際にフタを空けてみたとしても、最初から手順や条件が確立していたり、高頻度で再現できるものは多くはなく、大半の不具合やエラーは開発端末でも再現しにくいため、何かともどかしい思いをします。

今年のWWDC2020では、そんな再現性が低いときの心強い見方、ロギング のAPIが新たに発表されました。今回は、それについて少し触れたいと思います。

ロギングの役割

ユーザはバグが生じない高品質なアプリケーションを期待します。しかし、ソフトウェアにはどうしてもバグは付き物で、日々開発を進めていると大小様々な不具合と対峙しなければなりません。その中でも一番厄介なのは、すぐに再現できないバグです。

再現が難しいバグを検出し、修正するのにログは有用なツールとなります。バグを再現することなく、バグを把握するための手がかりを提供してくれる。また、ログは再現不可能なバグに対する理解を助けてくれるという意味では他に方法ありません。（もしかすると私が知らないだけかもしれません...）

非常に稀にしか生じないエラーだと、そもそもデバッガーで再現ができません。アプケーションにロギングを追加すれば、エラーを再現せずとも把握できます。

従来のロギングは...

import os.log

let log = OSLog.init(subsystem: "jp.iridge.test.logger", category: "main")
os_log("Start network call", log: log)

現在のAppleの標準的な統一ロギングシステムは、iOS10から使用できるようになりました。
詳しくはUnified Logging and Activity Tracing - WWDC2016を参照下さい。

subsystemにはアプリを識別するユニークなバンドルIDを指定し、categoryにはモジュールを指定することができました。

New logging API in Xcode12

Xcode12では統合ログとして使用できる新しいSwift APIが導入されたことはご存知でしょうか？

このAPIでは、従来のロギングよりも以下の点が強調されました。(※OSバージョンはiOS14から)

• アプリケーション実行時に発生する重要なイベントを記録ができる。
• オペレーションシステムによりアーカイブされるため、後でデバイスから取得できる。
• 非常に効率的で、アプリケーションの動作遅延を招くことなく広範囲で使用できる。

ロギング

新しいロギングAPIを使用するには、まず os_log と同様に import os.log を記述する必要ですが、syntaxに関しては従来とはかなり異なります。

import os

// Logger型のインスタンスを生成する
// バンドル識別子と "main"をカテゴリを持つLoggerを作成する
let logger = Logger(subsystem: "jp.iridge.test.logger", category: "main")

func beginTask(url: URL, handler: (Data) -> Void) {
    launchTask(with: url) {
        handler($0)
    }
    logger.log("Started a task")
}

Loggerでは文字列補間が非常に良くサポートされており。さらに以前のC言語スタイル寄りだったフォーマットも、よりSwiftっぽいスタイルへと変貌を遂げました。

New

let count = 0
let logger = Logger(subsystem: "jp.iridge.test.logger", category: "main")
logger.debug(“Start \(count) network call”)

Old

let count = 0
let log = OSLog(subsystem: "jp.iridge.test.logger", category: "main")
os_log("Start %d network call", log: log, type: OSLogType.debug, count)

Logデータの取得

1. Macにデバイスを接続する
2. デバイスオプションを指定して、 log collectコマンドを実行する
3. アーカイブログをダブルクリックする （コンソールが起動する）

コマンド例

$ log collect --device --start '2020-12-21 10:00:00 --output hoge.logarchive' 

ログが必要なタイミングを開始時刻として指定します。（通常はバグを最初に確認した数分前を指定すれば良いかと思います） また、もし出力ファイルに任意の名前を付けたい場合、アーカイブログを格納するためのファイル名も指定することもできます。

$ log -h

usage:
    log <command>

global options:
    -?, --help
    -q, --quiet
    -v, --verbose

commands:
    collect         gather system logs into a log archive
    config          view/change logging system settings
    erase           delete system logging data
    show            view/search system logs
    stream          watch live system logs
    stats           show system logging statistics

further help:
    log help <command>
    log help predicates

ログレベル

メッセージの重要度を表すため、5つのログレベルが用意されています。

Debug				// デバッグレベルは有用なメッセージに対してデバッグ時に限りなく使われる
Info				// トラブルシューティングエラーに有用である。不可欠ではないメッセージに使われる
Notice (Default)	// トラブルシューティングに不可欠なメッセージ使われる
Error				// 実行中に発生するエラーを記録するために使用される
Fault				// プログラム内の潜在的なバグが原因で発生する状況を記録するために使われる予定

iOS14以前の場合だと、OSLogType型の引数typeをもつ os_log を宣言していました。

Old

let count = 0
let log = OSLog(subsystem: "jp.iridge.test.logger", category: "main")
os_log("Start %d network call", log: log, type: OSLogType.debug, count)

iOS14になると、以下のように先にLogger APIが用意してくれます。

メッセージの持続性

メッセージに持続性があるか否かはログレベルによって異なります。
メソッドの重要度が高いほど、持続性が高くなります。

Debug				// 持続性なし
---
Info				// log collect コマンドまでは持続する
---
Notice (Default)	// 
Error				// ストレージの限界まで持続性あり
Fault				// 

Debugレベルのメッセージは持続性がなく、アプリケーションが終了した後に取得することはできません。情報レベルのメッセージの大半は持続性がありませんが、ログ収集コマンドまでの短時間に生成されたメッセージだけは例外となります。通知レベル、エラーレベル、障害レベルでロギングされたメッセージは持続性があり、後に取得することができます。もちろんアーカイブするメッセージ数には容量制限があり、制限を超えると古いメッセージから削除されて閲覧ができなります。エラー・障害メッセージは通知レベルのメッセージよりも長く保持されるようです。

型の範囲

• Int, Doubleなどの数値型
• Objective-C オブジェクト
• CustomStringConvertible プロトコルに準拠する任意の型

独自の型を対応させたい場合は CustomStringConvertibleプロトコルに準拠するだけというのが非常にシンプルですね。

ログメッセージの可視性

メッセージをロギングする場合、物理的にデバイスにアクセスさえできれば、中身を覗き見ることができてしまいます。そのため、敏感な情報を公開できるかどうかは気にかかるところです。

従来の os_log では、以下のようにフォーマットオプションで可視性が設定できて、デフォルトのままだと動的な値が private となります。例えば、文字列で表されるユーザの銀行口座番号が含まれているメッセージをロギングした場合、出力ログでは口座番号は個人情報として編集されます。

Old

let log = OSLog(subsystem: "jp.iridge.test.logger", category: "main")
os_log("Bank account number %{private}s, ", log: log, type: .info, 00011112222)

Loggerでも同様、可視性のオプションが設定できますが、さらにカスタマイズオプションが追加されています。os_logと同様に動的な変数はデフォルトではprivateとなっており、そこで詳細なことも パラメータ .public or .private で詳細な設定ができます。

New

logger.log("Bank account number \(XXXXXXXX, privacy: .private)")

New

logger.log("Bank account number \(XXXXXXXX, privacy: .private(mask: .hash))")

機密情報を扱わないデータの場合はログで可視化することもできます。実行時間データをロギングする場合は 値 .public をオプションパラメータ個人情報に渡します。

New

logger.log("Ordered smoothies \(smoothieName, privacy: .public)")

これでログのデータが表示されるようになります。

以上です。

ありがとうございました。

References

• logging - Apple Developer
• Explore logging in Swift - WWDC2020
• Unified Logging and Activity Tracing - WWDC2016
• Migrating to Unified Logging: Console and Instruments - Raywenderlich.com