構造化ロギングによるデバッグ

Xcode 15のデバッグココンソールを使い、どのようにロギングを通して、アプリの調査経験を向上させることができるかを学びます。高度なフィルタリングと改善された視覚化を使用して、簡単かつ効率的にログを辿る方法を探ります。また、デバッグ中にコード内の式を評価するためにdwim-print コマンドを使用する方法を紹介します。

リソース

関連ビデオ

ダウンロード

♪ ♪

皆さん　こんにちは私はXCodeデバッガUIチームエンジニアのNathanです本日はXcode 15に搭載される新しいデバッグコンソールを紹介します

このセッションではまずデバッグコンソールについて簡単に説明していきます次にデバッグコンソールの利点を紹介していきましょう私自身のアプリのバグを診断してみますそれからLLDBに導入される改善点を紹介しますそして最後にAppleの統一ログの APIを活用するためのヒントを紹介します

ではまずデバッグコンソールの新機能について説明します私のデバイスでアプリ「Backyard Birds」を起動していますこれは　ユーザーがバックヤードを管理しバーチャルな鳥の世話をするアプリです

アプリケーション起動後デバッグコンソールに多くのログが入力されていますすぐにコンソールにこれまで使っていたメタデータがついていないことに気がつきました代わりにデベロッパが見てもらいたいメッセージに注目しまだ表示を見たい場合にはデバッグコンソールの左下にあるメタデータのボタンを選択しますニーズに最も適したタイプを選択しますこの場合タイプライブラリーサブシステムカテゴリーを選択します

これで　メタデータの設定が有効になりますコンソールの各ログの下に表示されより小さくより目立たないようになっていて意図された出力を妨げないようにするため黄色や赤の背景のログに接することもありますがこれらはより重要度が高くエラーや不具合があることを示すものですすべてのログのメタデータを同時に見たくない場合コンソールを使えば個々のログのメタデータを見ることができるコンソールで　該当するログを選択することでそのログのメタデータを調べることが可能ですこれでポップアップ・ウィンドウが表示され利用可能な全メタデータが表示されるこれにはコールサイトのような情報も含まれていますログを出した元の機能の名前が表示されますこの追加メタデータを確認するのは重要でも新しいデバッグ・コンソールの最大の利点はフィルタリング機能なのですコンソールが重要でないログでいっぱいになりがちだけれど Xcode 15ではフィルタリングがこれまで以上に簡単になったのですこれでコンソールは複雑な条件付きフィルタリングを実行できるようになり簡単に重要なログを見つけることができるようになりましたコンソールはまたこれらのフィルタを様々な作成方法がありもちろん入力可能です

フィルターは　フィルターバーに直接入力もできます

その際自動補完ポップオーバーが表示されて入力しようとしている　フィルタを作成する手助けをしてくれます

さらに　フィルター・メニューは特定の種類のログに素早くアクセスできるので見たい種類のログを選ぶことができます

最後にある程度興味を持ったログを逆クリックするとコンソールには似たようなログを隠したり表示するオプションがありますこのように見たいログに焦点を当てたりあるいは除外もできます

これらのフィルタリング方法によってすべての出力データを迅速かつ効率的に切り分け最も関連性の高いログを探し出すことができますでは　新しいデバッグ・コンソールを使ってアプリケーションの実際の問題を見つけ修正してみましょう一部のユーザーがプロフィールを更新した後　内容が保存されていないことに気づいたという報告を受けました最新のデバッグコンソールを活用して上手なログインの仕方を実践してみましょう私はこのバグの原因を素早く簡単に特定できます

まず　タブバーで「アカウント」を選択してこの問題を再現してみましょう鉛筆を選択してアカウントを編集するを選択します

最後に表示名をかえてみましょう

これでうまくいったように見えましたがページを閉じて自分のアカウントを確認すると変更は消えているようですさて　いくつか思い当たることがありますが新しいデバッグコンソールがこの問題を解決し問題の根源を突き止める手助けをしてくれますこれらの手順を行うとデバッグコンソールに多くの出力が表示されます新しいコンソールで多くのログの中から自分の興味を持ったものを見つけることができますこの場合アカウント管理だけに特化したカテゴリーですこれらに焦点を絞るために、プロジェクトのすべてのカテゴリーにを含むすべてをフィルターに入力しポップアップからカテゴリーフィルターを選択します

これで　私のコードのアカウント関連から全てのログインが表示されますこのフィルターをセットすれば出力はずっとあつかいやすくなりますこれらのログのいくつかは私が要求した「プロパティを設定する」表示名ですなぜアプリは期待通りに動かなかったのかを検証しますこのコードがある場所をログにカーソルを合わせて右下にあるソースの場所を選択してみます

Xcodeはソースのログに移動するのでこの表示名を設定しますソースコードを確認してみると現在のアカウントでsetDisplayNameを呼び出しているようですこの問題をより詳しく検証するためにアカウント情報の更新を担う関数に移動してみましょうこのコードをさらに見直したらセントラル・アカウント・データベースに変更を送信している間にローカルアカウントのキャッシュを更新するのを忘れていたようですデータベースを更新した後ローカルの表示名を新しいものに設定する必要があります。

ついでにメールアドレスの同じバグにも気づきましたこの問題は同じ方法で修正できます

次の行にブレークポイントを使って疑惑を検証しこれで問題が解決したのかを確認しましょう

アプリケーションを作り直しここで一時停止するために前のステップを再作成しますこの位置まできたら　私の疑念が正しいかどうか確認してみたいそのためにアカウントの現在の状態に "po"と入力してみます想定している古いデータをチェックします

困ったことにこの対象のアドレスだけを受け取ったようですどういうわけでしょうか「po」はごく一般的な表現ではあるが私が実行したい表現ではないことがわかりました私はこのクラスに対して独自のデバッグdescriptionを定義していないのです実際にこのケースでは、"p"を実行したいのですではやってみましょう

まさにこれは私が求めていたものであり表示名はデータベースの更新によって単独で設定された訳ではないという私の疑念を裏付けたものでした追加した行を進み表示名が更新されたことを確認しましょう

バッチリですこの問題は解決したようですこれで鳥に餌をやる時間に戻れます Xcode 15でかなり単純だったものから進歩したLLDBにログインしますあのバグを解決しようとしていたことを思い返すと私は「po」を間違えた場所に入力したことに気が付きました式の実行時間を遅らせてしまうか最悪の場合は CustomStringConvertibleを実行していないと単純にプロパティのアドレスが戻ってきてしまうことですこれにはイライラさせられてしまいもっといい方法があればと思うのですそこで"p"を実行したところ適切な結果が得られましたしかし「expression」のように様々なコマンドがあります「v」「vo」「フレーム変数」その他覚えるべきことがたくさんありますこれは実行するのが　難しそうなのでデベロッパを支援するために Do What I Mean Printを紹介します Do What I Mean Printはひとつのコマンドでコード内のさまざまな式使用して 1つのコマンドで評価することで時間を節約することが可能になります

変数をチェックするたびにこのような長いコマンドを入力するのは面倒でしょうから以前の"p"を「Do What I Mean Print」の略名で実行してみますこれにより大半の使用例で "p"を実行するだけで済みます実際にカスタムオブジェクトの説明を印刷したい場合のために Do What I Mean Print のオブジェクトの説明フラグを付けて実行することができます以前の略名「po」を置き換えて「何をプリントするのか」をカスタムオブジェクトの説明欄で実行するようにしました従来であれば意図した出力を得るために複数の異なるコマンドを実行する必要があった多くの異なる表現に対して 2つのコマンドの片方を実行できるようになります最後に誰もがロギングを最大限に活用しデバッグの経験を向上させより説明します再現が困難な問題やユーザーからの報告に依存する問題を効果的に特定して解決できるようにする方法について説明していきます標準I/OはコマンドラインUIのためのもので　OSLogはデバッグ用だとまずこう言っておきますしたがってプログラム実行中のログを記録するために使うべきではありませんエンドユーザーからの構造化ログ取得は OSLogを使用するほうががはるかに効果的ですデバッグの構造体の保持だけではありませんそれでは　標準I/Oから OSLogへの変換がいかに簡単かいくつかの例を挙げてみましょうこれは単純な関数です。追加ログインをしてみたいと思いますタスクをログに実行したりそれを記録するのもよい習慣になります少しだけ私が知っている最善の方法で補足させてくださいこれでこのコードに従うためのいくつかの簡単な「print」文の追加が完了しましたタスクが完了したらその結果を出力するのと同様にこの関数において今行なっているアクションを表示します。プロジェクトの中でこれを続けているとこのアウトプットすべてがどこからかなのか見つけるのが難しくなるため多くの人と同じように私はマーカーを付け始めましたこれは収拾がつかなくなってきているような気がしますこの追加出力のおかげでコンソールがごちゃごちゃになってしまいましたこの全てのメタデータを手間をかけずに活用できる方法があればいいのですが結論から言うとOSLogは私が望んでいることをやってくれますユニファイドロギングを活用してこの機能のアップデートをしてみますまずはOSLogをプロジェクトにインポートしログハンドルを作成しますこうしてログハンドルを作成しますここでサブシステムとカテゴリを指定しますログが表示されることを望んでいるこれらの文字列のうちでデバッグのフィルタリングを容易にするのがサブシステムのバンドルidentifierを使う方法でクラス名またはコンポーネント名をカテゴリに指定するロガーを作成したら提供された機能を呼び出す必要がありますログレベルを指定し表示したいメッセージを提供しますこの方がはるかに読みやすく結果的に大幅にコードが削減されますコンソールに実行するとどのように表示されるかを見てみましょう

以下の2つのログを分けてこのメタデータがどこから来ているのかを検証してみましょう指定したログアウトプットには出力しようとしたメッセージと指定した追加メタデータが有効になっていればその下に表示されますこのメタデータの一部はメッセージやレベルなどの最初に the initial log 作成した所から収集されたものですその他のものはサブシステムやカテゴリーなどの繰り返しを省くために　ログハンドルを作成したとき収集しましたいくつかは　バックグラウンドで処理されるこれらにはタイムスタンプライブラリ名　プロセスID スレッドID などが含まれますこれらの情報は必要なときに大いに役立ちますが必要性に関係なくすべてのログに出力すると膨大なスペースを取ってしまいます幸いに新しいデバッグコンソールをカスタマイズできるので思う存分使うことができます最後に　ログインを最大限に活用するためにアプリケーションを構築する際にこの事をよく考えておいてください様々なコンポーネントにそれぞれのログハンドルを作成する必要があります根本的なメタデータにアプリケーションのセクションに適切な検索条件を設定できます最も適切なログをより迅速に見つけることができますさらにOSLogStoreを活用すれば現場でアプリケーションに問題が発生した場合貴重な診断データを収集します最後に OSLogはトレース機能ですつまりInstrumentsなどのツールを使ってアプリケーションの複雑なパフォーマンス分析が可能ですこの例では　ロギング・プロファイリング・テンプレートを使ってアプリケーションのパフォーマンスを分析していますさて先ほどの内容を振り返ってみて自分のプログラミング経験をどのように向上させていくのかを考えていきましょうログインに関するあらゆるニーズに対応するため多くの改良を重ねたXcode 15の新しいデバッグコンソールを活用する必要があると思います次にコードを標準I/OからOSLogに移行する新しいデバッグ・コンソールが提供するすべての新機能を利用できるようにする必要がありますぜひLLDBの新しい何をプリントするのかまたは "p"のコマンドを試してみてください様々な点検をする場合は必ずこれを使用するようにしてください最後にAppleの統合ログAPIについて過去のセッションをご参照ください「Measuring Performance Using Logging」そして「Explore logging in Swift」ログ付けを楽しんで! ご覧いただきありがとうございました

5:17 - Calling setDisplayName from Edit Account page

.onSubmit {
    logger.info("Requesting to change displayName to \(displayName)")
    accountViewModel.setDisplayName(displayName)
}

5:34 - Account Data Setters (Before Fix)

public func setDisplayName(_ newDisplayName: String) {
    logger.info("Sending Request to update DisplayName")

    Database.setValueForKey(Database.Key.displayName, value: newDisplayName, forAccount: account.id)

    logger.info("Updated DisplayName to '\(newDisplayName)'")
}

public func setEmailAddressName(_ newEmailAddress: String) {
    logger.info("Sending Request to update EmailAddress")

    Database.setValueForKey(Database.Key.emailAddress, value: newEmailAddress, forAccount: account.id)

    logger.info("Updated EmailAddress to '\(newEmailAddress)'")
}

6:04 - Account Data Setters (After Fix)

public func setDisplayName(_ newDisplayName: String) {
    logger.info("Sending Request to update DisplayName")

    Database.setValueForKey(Database.Key.displayName, value: newDisplayName, forAccount: account.id)

    account.displayName = newDisplayName

    logger.info("Updated DisplayName to '\(newDisplayName)'")
}

public func setEmailAddressName(_ newEmailAddress: String) {
    logger.info("Sending Request to update EmailAddress")

    Database.setValueForKey(Database.Key.emailAddress, value: newEmailAddress, forAccount: account.id)

    account.emailAddress = newEmailAddress

    logger.info("Updated EmailAddress to '\(newEmailAddress)'")
}

6:35 - po account
```
(lldb) po account
```
6:39 - po account (with result)
```
(lldb) po account
<Account: 0x60000223b2a0>
```
7:00 - p account
```
(lldb) p account
```

7:04 - po account (with result)

(lldb) p account
(BackyardBirdsData.Account) =0x000060000223b2a0 {
	id = 3A9FC684-8DFC-4D7D-B645-E393AEBA14EE
	joinDate = 2023-06-05 16:41:00 UTC
	displayName = "Sample Account"
	emailAddress = "sample_account@icloud.com"
	isPremiumMember = true
}

7:18 - p account (after fix)

(lldb) p account
(BackyardBirdsData.Account) =0x000060000223b2a0 {
	id = 3A9FC684-8DFC-4D7D-B645-E393AEBA14EE
	joinDate = 2023-06-05 16:41:00 UTC
	displayName = "Johnny Appleseed"
	emailAddress = "johnny_appleseed@icloud.com"
	isPremiumMember = true
}

9:43 - Login Method Skeleton

func login(password: String) -> Error? {
    var error: Error? = nil

    //...

    loggedIn = true
    return error
}

9:56 - Login Method with Print Statements

func login(password: String) -> Error? {
    var error: Error? = nil
    print("Logging in user '\(username)'...")

    …

    if let error {
        print("User '\(username)' failed to log in. Error: \(error)")
    } else {
        loggedIn = true
        print("User '\(username)' logged in successfully.")
    }
    return error
}

10:18 - Login Method with Extended Print Statements

func login(password: String) -> Error? {
    var error: Error? = nil
    print("🤖 Logging in user '\(username)'... (\(#file):\(#line))")

    //...

    if let error {
        print("🤖 User '\(username)' failed to log in. Error: \(error) (\(#file):\(#line))")
    } else {
        loggedIn = true
        print("🤖 User '\(username)' logged in successfully. (\(#file):\(#line))")
    }
    return error
}

10:40 - Login Method with Partial OSLog Transition

import OSLog

let logger = Logger(subsystem: "BackyardBirdsData", category: "Account")

func login(password: String) -> Error? {
    var error: Error? = nil
    print("🤖 Logging in user '\(username)'... (\(#file):\(#line))")

    //...

    if let error {
        print("🤖 User '\(username)' failed to log in. Error: \(error) (\(#file):\(#line))")
    } else {
        loggedIn = true
        print("🤖 User '\(username)' logged in successfully. (\(#file):\(#line))")
    }
    return error
}

11:00 - Login Method with OSLog Statements

import OSLog

let logger = Logger(subsystem: "BackyardBirdsData", category: "Account")

func login(password: String) -> Error? {
    var error: Error? = nil
    logger.info("Logging in user '\(username)'...")

    //...

    if let error {
        logger.error("User '\(username)' failed to log in. Error: \(error)")
    } else {
        loggedIn = true
        logger.notice("User '\(username)' logged in successfully.")
    }
    return error
}

11:16 - Example Logging Statements

let logger = Logger(subsystem: "BackyardBirdsData", category: "Account")
logger.error("User '\(username)' failed to log in. Error: \(error)")
logger.notice("User '\(username)' logged in successfully.")

特定のトピックをお探しの場合は、上にトピックを入力すると、関連するトピックにすばやく移動できます。

構造化ロギングによるデバッグ

関連する章

リソース

関連ビデオ

WWDC23

WWDC20

WWDC18