InstrumentsでのHTTPトラフィックの解析

ようこそ カツパーです Appleのパフォーマンスツール エンジニアです 今日はセルジオと一緒に Instruments 13で利用できる 新しいHTTPトラフィック Instrumentについて解説します Networkテンプレートに含まれる このInstrumentを使用すると アプリケーションから スタックを介して送信された HTTPトラフィックを 検査できます

このアプローチには 利点がいくつもあります すべてのAppleデバイスで 動作します 送信されたトラフィックも含め URLロードシステムが HTTP/3プロトコルまたは VPN経由であっても トラフィック全体が公開されます システムインテグレーションにより トラフィックは実行中の プロセスに属性を付け Apple Networkingフレームワークに 紐付けしているので リクエストはディスク上の キャッシュにヒット もしくはエラーが発生したかなど すべてがご存知の ハイレベルのAPIコンセプトである URLSessionやURLSessionTaskなどで 明らかにされます このツールはAPIの使用が ネットワークリクエストの ライフタイムに どのように反映されているのかを 理解するのに役立ちます このセッションではまず Instruments UIが APIの概念をどのように 反映しているかを 見ていくことにします

ツールの使用方法を 説明する４つのデモで パフォーマンスと 正確さの両方の 懸案事項について 明らかにしていきます Appが問題なく動作して いるように見えても トラフィックを監査 することによって 動作確認する方法に ついて学びます Networking APIが Instrumentsのビジュアルに どのようにマッピングされるかから 始めましょう これはNetworkテンプレートを使って システムトラフィックを記録したときに InstrumentsにHTTPトラフィックの トレースの表示です ナビゲーションはトラック階層を 中心に構成されており まずそれを最初に詳しく 説明します トップレベルにあるHTTP Traffic Instrumentは URLSessionタスクが トレースでいくつ実行されているかの 概要を示すので Appのライフタイムに HTTPトラフィックアクティビティが 増加しているか などをスポット検出する のに最適です 次の階層レベルは プロセスごとのアクティビティの 内訳を示しています デバッグ可能なプロセスからの トラフィックに加えて バックグラウンド トラフィックを検査 できます それぞれのプロセスは そこで使用されるURLSessionであり コードで作成した URLSessionオブジェクトに 一致する形になります このレベルのグラフを 使用するとタスクインターバルを 一望できます セッションオブジェクトと ビジュアライゼーションとのマッピングを 改善するにはインスタンスの sessionDescription プロパティからコードに 名称設定します

最後のレベルでは 要求されたドメインに トラフィックが分類されます このレベルのグラフは タスクに関する詳細を タスクとその状態を 構成する個々の トランザクションを含め 表示します

トランザクションと タスクをよりよく 理解するため例を 分析してみましょう

選択したドメインから データを読み込んだ タスクを次に示します タスクの構造を分析 するために １つに焦点を当てて みます

このインターバルには 多くの情報があります Instrumentsのビジュアライゼーションが APIにどうマッピングされるか より抽象的な方法で 確認できます

トップレベルにはタスク オブジェクトがあります タスクは複数の トランザクションで構成

トランザクションの一つに HTTPリクエストと それに対応する レスポンスのペアがあります

タスクレベルはコードが システムの APIとどのようにインタラクト するかを示したものです タスクを作成して再開を 呼び出すと タスクインターバルが開始 終了するのは 完了ブロックが 呼び出される直前です

各タスクにはプロパティにより セマンティックを 設定して Instrumentsの インターバルに ラベルを付けます またタスクIDをタスクラベルの 一部として表示 他のデータを使用した タスクとの 相互参照に使用できます 完了時のエラーに 関しては デバッグを容易にするため インターバルラベルに その説明が表示されます 前述のとおりタスクは 複数のトランザクションで 構成が可能です 次の話はそれに関するものです apple.comのスタート ページをロードするタスク でもこれは正規のURLでは ありません タスクはapple.comを要求 しますが優先ドメインは www.apple.comです このタスクを作成すると、 URLローディングシステムは 当初apple.comへの リクエストを作成します その後すぐサーバーから リダイレクト応答を 受信します 優先URLは実際には www.apple.comです

デフォルトでは リダイレクトに従います そのため301の代わりに URLローディングシステムを使用 新しいトランザクションを 作成して優先URLをロード この第２のトランザクション からの応答が タスクに返されるものです

前述のとおり トランザクションは HTTP要求と応答の 組合せです セッションが内部で行う タスクを処理する HTTPレイヤーの すべての情報は 要求されたURLや 転送データに関する情報 などが含まれます

タスクの場合と同様に トランザクションラベルは トランザクションの 概要を示します 主にリクエストと レスポンスに関する 情報です

トラック階層は 要求された ドメインを示しつつ ラベル自体の パスとクエリも検証 できます

加えてインターバル ラベルは HTTPバージョンに 加え HTTPメソッドや リクエスト承認の如何 またCookieヘッダなどを 表示します これらは認証フローを 一目で理解するのに 役立つものと思います

応答にCookieが含まれて いるか 応答のコンテンツ タイプに関わらず ステータスコードを 取得します リクエストとレスポンスに かかった時間 より詳細なタイミング情報 トランザクションの一部である 他の作業については トランザクション状態によって キャプチャされます 含まれているタスクの コンテキストで 分析してみましょう トランザクションの開始は URLローディングシステムが 実行された時点で このリクエストを実行するための トランザクションを作成 まず有効なキャッシュされた 応答があるかどうかを確認 ない場合は接続時に リクエストの スケジュールを試みます

次にトランザクションは ブロック状態で若干 待機が必要な場合も 考えられます

要求はトランザクションの 開始により送信 最終的に接続によって 処理されます ネットワークへの 要求の最後のバイトを 送信すると終了します 次にトランザクションは アイドル状態になり 応答状態を待ちつつ スパンを追跡する レスポンスがサーバーから受信する 最初のバイトから 最後のバイトまで続きます

トランザクションは 最後のバイトを受信後 URLロードシステムが 応答に成功と 判断された後に 完了します 実際にはGETリクエストの キャッシュルックアップと 送信状態は通常はるかに 短くなるため このように表示される 可能性が高くなります

いくつかの例を 示すために 同僚のセルジオに 譲りたいと思います HTTP Instrumentが どのように 最近開発を開始した Appのパフォーマンスと 正確性を修正したか 説明してもらいます ありがとうカツパー こんにちは セルジオです 犬の愛好家のための Appを開発中です SNSのようなものですが 目的は犬の写真 のみ！ 犬の画像を投稿して 最新アップロードの ストリームを取得 できます！ Appを開くといくつかの 新しい犬の画像が 読み込まれますが ロードされるまで 時間がかかります

この状況を改善する ために新しい HTTP Trafic Instrumentを使用して プロファイルを作成します プロダクトメニューで オプションを 選択してInstrumentsで Appのプロファイルを作成

リリース構成でAppが ビルドされユーザーに対して すべての最適化がオンに なった状態で実行されるように プロファイリングが 実行されます ビルドが完了すると Instrumentsは 自動的に起動します 起動するとInstrumentsの 標準テンプレート セレクタが表示されます

この場合は左下の ネットワークテンプレートを 選択して一般的な ネットワーク接続の情報や 新しいHTTPトレース 機能の情報も 取得可能となります

トラックエリアに Instrumentごとに２つ 下のトラックは既存の ネットワーク接続であり 上のトラックは新しいHTTP Traffic Instrumentです 今日はこの新しい Instrumentに着目 必要な処理は“レコード”を クリックすることだけ これでInstrumentsは Appを起動し記録を開始

このツールを使用する前に ネットワークトラフィックを キャプチャすることの意味を 確認しておく必要が あります 特にすべてのプロセスを 記録する場合は重要です キャプチャされたデータには 送信されたすべてが含まれ 個人情報や機密情報に ログイン情報まで 含まれる場合があります したがって結果のトレース ファイルには十分注意する 必要があります 確認しましょう

Appが起動し 画像の読み込みに 時間がかかっています

記録を停止します

記録したデータを オプションキーを押下し クリックしてドラッグ HTTPトラフィック全体を カバーします

左上の“HTTPトラフィック” トラックの 開示インジケータを クリックして カツパーが前述した トラック階層を 表示させます

またすべてのインターバルを 表示するためにトラックを高く

最上部に最初の タスクがありますが これはAppの最新 セクションに表示される 画像のリストをサーバーに 照会します

このタスクが完了すると 受け取ったリストのすべての 画像のサムネイルを読み込む 新しいタスクが作成されます

時間枠をカバーする領域を クリックしてドラッグし 画像のリストを取得した その後に 個々の画像を取得するなど 多くのリクエストが続きます

この領域をクリックして ドラッグすると 選択した時間範囲の 期間を示す ツールチップが表示 されます 初期画面の読込みが 完了するまでに ７秒以上かかりました

最初の画像はかなり速く 読み込まれます しかしスクロールすると 後で開始されたタスクの 完了に時間がかかっており 紫色ブロックが増加して いるのが分かります 並行リクエストが 多すぎる 輻輳の問題のようです 後続のタスクの１つを 調べてみましょう

タスクにカーソルを合わせると ツールチップに タスクの期間と ホバリング中の子の インターバルが表示されます このタスクはほとんどの時間 ブロックされていました

ブロックされた理由を 解明するために トラック表示を 切り替えましょう トランザクションビューに 移動します

左側のトラックサイドバーの ドメイン名の下にある 下向きの矢印を クリックして トラック表示を切り替え られます

現在タスクを描いて います 接続別トランザクション 表示に切り替えましょう

このビューにはトランザクション のみが表示され タスクごとにグループ化 する代わりに スケジュールされた 接続を検索できます

トランザクションは使用した 接続ごとにグループ化 トランザクションを処理する ために使用できる 接続は６つありました 接続１で発行された トランザクションを 分析し サムネイル読込みを 調査してみましょう 上から順に各トランザクションの 完了に 時間がかかっている ことがわかります 連続する紫色のブロックが 増加しています 実際ここには明確な 階層パターンが見えます

同じ接続での前の トランザクションが終了するまで 各トランザクションは ブロックされます ここで初めてリクエストを 送信できます 後続のトランザクションごとに このパターンが繰り返されます

これはヘッドオブライン ブロッキングと呼ばれ HTTP/1を使用する際の 問題の１つです

問題はほとんどの時間 これらトランザクションが 何もしていないことです ほとんどの時間 ブロックするか サーバーからの応答を 待つことに費やされます 応答を待っている間に 次のトランザクションが HTTP/1ではサポート されていない 別の要求を前の トランザクションが 待っている可能性が あります ヘッドオブライン ブロッキングは HTTP/1の制限の１つで HTTP/2の主な改善点の １つは多重化によって同じ サーバーへの複数のリクエストの 影響を回避することです

HTTP/2では 最初のリクエストが 応答を待っている間に２番目の リクエストの送信を開始できます App側で何もする必要は ありません すべてのAppleプラットフォームは HTTP/2をサポートしており iOS 15以降と macOS Montereyでは HTTP/3もサポート クライアントはサーバーが サポートする最新の HTTPバージョンを選択 HTTP/1と2の 違いについてもっと 知りたい場合や HTTP/3が提供する メリットについては “HTTP/3とQUICによる ネットワーキングの加速” セッションをご覧ください 私はこのトレースを取得し サーバー担当者に見せて HTTP/2をサポート すべきことを 納得してもらえました それでは新しいサーバーの 強化とともに Appを実行してみましょう

かなり速くなりました これをInstrumentsで 確認しましょう これがHTTP/2の サポートを オンにした後に 記録したトレースです ドメイン固有のトラックでも サムネイルの読込みはなく タスクがブロックされて いることもないようです 良かった もう一度トランザクション ビューに 切り替えましょう

最初に気付くのは接続が １つしかないことです 同時リクエストを送信 するために複数の 接続が不要になり 必要なのが１回の 接続のみになったためです 個々のサムネイル読込み トランザクションを見ると 基本的にブロック状態で 時間が費やされて いないことがわかります 実際時間は非常に 短いため このズームレベルでは 表示されません 最終的にすべての トランザクションは要求の 送信を終了し 応答を待ちます 下にスクロールすると 同時に応答が 進んでいることが わかります

全体として ３秒以内にすべての リクエストが完了します これは以前の２倍の 速さです サーバー担当者と話して HTTP/1.1から HTTP/2に切り替えたので 画像の読込みがはるかに 速くなっています Appを再起動して 他に何ができるかを見ます 画像をタップするとAppは フル解像度をロード この写真が撮られた 距離を示しています 右上にはその写真を お気に入りに追加できる ハートのアイコンも あります そのためには アカウントが必要です アカウントなしでAppを 使用して写真を閲覧することを 許可しますが お気に入りの画像を保存したり デバイス間で同期したり 新しい写真をアップロード するにはアカウントが必要です ここでログインします

別の写真にいいね させてください 実にかわいい犬だ お気に入りに追加したい ログインしたばかりなのに 再度ログイン？ そんなはずありません このAppは私のログインを 保持しているはずです 以前は機能していました ログイン画面を閉じます 再度ログインしたく ないので

問題を再現した後 以前の トレースファイルを 記録しました 記録を分析するため インスツルメントで開きます 左側にはお気に入りの ボタンを初めて押したときに 対応するタスクがあります

右側には最新のタブに 戻って 画像のストリームが 更新された後 発行されたタスクがあります

次にフル解像度の画像を 別の犬の写真をタップした後 ロードするタスクが あります

右端にはお気に入りを２回 タップしたときに 対応するタスクが あります

最初のタスクインターバルには ２つのトランザクション込み

最初のトランザクションは 401ステータスを受理 ログインしていないので これは想定内です トランザクションは オレンジ色なので HTTPレベルで成功して いないことを示しています

次にタスクに大きな空の 領域があります これはユーザー名と パスワードの入力に 費やされた時間を表します

クレデンシャルの入力が 完了するとすぐに トランザクションを 再試行します インターバルの緑色と 201コードで 今回は成功したことが 分かります 認証チャレンジやパスワードの 入力および トランザクションの再試行の インタラクションには URLローディングシステムが 処理する別のケースであるため ２つのトランザクションは同じ タスクオブジェクトに属します

ズームアウトすると右側の 画像を優先する ２番目の試行が 表示されます タスクオブジェクトは ログイン画面が灰色で 表示されたため タスクがキャンセルされ ラベルにも反映されて います サーバーから401応答を 再度受理したため インターバルはオレンジ色で 表示されます このタスクは別の犬の写真に いいねしようとして 再度ログインするよう 要求された後に 発生しました 簡単なログイン システムを使用し ユーザー情報を初回のみ 取得しますが サーバーがクレデンシャルを 確認すると 次の要求でユーザー情報を 提供する必要がないよう ユーザー識別のCookieを 設定します タスクにより適切なCookieが 送信されたことを期待しますが そのとおりになったかどうか 判断しましょう カツパーに説明してもらった ようにメソッドの横に このトランザクションでCookie ヘッダが送信されたことを示す 小さなCookieアイコンが あるはずです そのようなアイコンはないので Cookieは送信されていません この部分は機能しませんでした 問題はサーバーがCookieを 設定しなかったのか それともクライアントが あったのに提供 しなかったのかという ことになります 調べるには前の トランザクションで サーバーからCookieを 取得したかどうか 調査確認する必要が あります これが以前のログイン要求 から成功した 最初のトランザクションです トランザクションラベルの応答 部分にCookieアイコンが あるのでサーバーがCookieを 送信していたことになります 興味深い ではなぜ次のトランザクションで Cookieが送信されなかったか このトランザクションの詳細を 取得しCookieを 詳細に調査するには 下部の 詳細ビューの “トランザクション” リストに切り替えます

タイムカーソルがトラック ビューのトランザクション内に 配置されているため トランザクションは選択済です

右下の拡張 詳細ビューに 現在選択されている トランザクションの 要求ヘッダと 応答ヘッダが表示

これが期待される Set-Cookieヘッダです 一見このクッキーは 問題ないようです この有効期限が 見えますか？ 2020年３月です 過去の日付けだ！ サーバーは期限切れの Cookieを 送信していたのです 期限切れのクッキーが 好きな人はいません セッションでまだ有効な Cookieのみを 送信するように 設定します

これはサーバー側の バグです トレースファイルを サーバー担当者に送信 問題を調査解決して もらうことにします Cookieの問題が修正 されたのでログインを 求められることなく写真を お気に入りに追加できます 最新タブに加えて ユーザーがお気に入りにした すべての犬の画像のリストを 表示する“お気に入り” タブもあります そのタブに切り替えましょう

昨日追加したお気に入りが いくつかありますが 何らかの理由で最近の お気に入りが非表示です やり直してみましょう お風呂を楽しんでいる この犬を選んで お気に入りにしてみます お気に入りに戻ってそれが 表示されるか確認しましょう

まだありませんね もう一度Instrumentsを 使用して調査します トレースファイルはすでに 用意しました トラックビューでお気に入りの リストをロードするタスクを 見つけたいところですが すぐには表示されません サーバードメインのトラックを 選択して そのドメインに発行された リクエストのみを表示します 次にこのドメインのすべての タスクのリストを含む 下部の詳細ビューに 移動できます

かなりの数のリクエストが あります 左下の詳細フィルターを 使用して お気に入り関連の リクエストを検索し 要求が受理されたかを 確認します

フィルタすると結果は お気に入りのリストをここに ロードするためのリクエストを 送信したことを示しています トラックビューを見て みましょう

詳細ビューで選択した タスクの開始時に 上のトラックビューでそれを 見つけるための カーソル配置で簡単です ズームインして再確認 しましょう

Appの最初の起動時に お気に入りのリストを 読み込んだのはこれが 初めてでした そこは問題ありません

ここで新しい画像を お気に入りに追加した後 お気に入りを再度ロード

タスクインターバルがあるものの 非常に短いものです

GETリクエストは数ミリ秒しか かかっていません サーバーの応答を取得 するには短すぎます 詳細を取得するため トランザクションビューに 再度切り替えて みましょう

まず気付いたのはこの トランザクションが 接続ではなくローカル キャッシュで実行されたこと リクエストが ネットワーク上ではなく ローカルキャッシュからロード されたことを示しています トランザクションがサーバーを 待機しなかったために 応答待ち状態が発生しない 理由も説明しています

ここが問題です リクエストはキャッシュされ 常にキャッシュされた応答を 受理するので サーバーに問い合わせません 修正する方法の１つは サーバーに応答を キャッシュしないための ヘッダーの設定です ユーザーがお気に入りタブに 移動し新しい画像が 追加されるたびに画像を 再読込みする必要があります 変更がなかった場合は リスト全体を ロードする必要は ありません トレードオフはサーバーに 質問すること “何か変わったことは？” “あったら知らせて” それはリクエストに キャッシュポリシーを 設定することで達成 できます

コードを更新するには タスクビューに戻って 問題のタスクを 選択します

ここで実行された URLSessionタスクごとに

タスクで再開が 呼び出された右側に バックトレースを 表示します

画像収集タイプの メソッドsyncで これが再開されました これをXcodeで開いて 変更を加えます

このURLRequestで キャッシュポリシーを 設定します

必要なキャッシュポリシーは リロードキャッシュデータです これはローカルキャッシュを 無視することを意味し サーバーにリクエストを 送信して キャッシュが有効かを 確認します 有効ならサーバーは304 応答コードを送信して ローカルキャッシュを 使用することを通知します そうでない場合は 新しいデータを返信 ではやってみましょう

現在のお気に入りの 画像で お風呂に入っている 犬が追加されました もう１つ追加します

お気に入りタブを確認 しましょう お気に入りの画像が 正しく表示されました 良かった 無事修正されました カツパーからAppと 依存関係が期待どおりに 動作するかの確認方法に ついて説明してもらいます お気に入りタブを クリックすると ログインせずに ログインビューが 表示されます Appleでサインイン を追加し ログイン体験を シームレスにしました ペットをテーマにした Appがありますが 別チームが共有ログイン SDKに取り組んでおり ユーザーはApp間で自分の アカウントを再利用できます このSDKは現在開発中であり 別のチームから 従来のログイン画面を 置換えることは 可能かどうか 尋ねられました xcframeworkとして配布 されているPetsという SDKバイナリは すべてのプラットフォームで 使用できるものと なっています Xcodeプロジェクトに統合 するのは埋め込みや フレームワークセクションに ドラッグするなど簡単です あとは既存のビューに ボタンを追加するだけ LoginViewのソース コードに移動します

最初にフレームワークを インポートしてから Appleでサインイン のすぐ下にある SwiftUIVStackに ボタンを追加します

SwiftUIプレビューを 更新しましょう

ありました “ペットでサインイン”ボタンが プレビューに表示 されました とても簡単に統合 できました この新しいログイン方法が どれ程速いかを確認してみます これを測定するために製品 プロフィールアクションを 使用してInstrumentsで Appのプロファイルを作成

ネットワーク テンプレートを選択 ツールバーのレコード ボタンを クリックしてAppを 起動します

Appが起動しました これでログインビューに 切り替えられます インスツルメントはその間に 発生するすべての トラフィックを 表示しています これを展開してAppの URLセッションを調べます

ありました ちょっと待って メインAppのセッション だけがあるはずですが 統合したばかりの フレームワークが ログインボタンを クリックしなくても 独自のセッションから リクエストしています これは想定外です 調査のため記録を 停止しましょう

いくつかのリクエストに ズームインして オプションクリックで ドラッグします

分析エンドポイントに リクエストが多数 詳細を確認するには “ペットサインオン”を クリックして詳細ビューに すべてを一覧 表示します

すべてPOSTリクエストのため １つをクリックすると 右側にリクエストがコードの どこから発生したかを示す バックトレースが 表示されます

リクエストは予想どおり Petsによって呼び出された CFNetworkを 経由しているようです しかしさらに深く ナビゲートすると CoreLocationが関与 しているようです トリガーするための アクションを 実行していないので なおさらです 位置がサーバーに返されている 可能性があり それがCoreLocationと CFNetworkが同じバック トレースにある理由です

これらのタスクに対応する トランザクションを調べる ことでそれを確認します それにはタスクのリストから トランザクションのリストに 詳細を切り替え そこから１つ選択します

右下の詳細を見ると このリクエストには 標準的なヘッダがいくつか 含まれているだけである ことがわかります でもリクエストの本文は どうでしょうか 位置座標が 含まれているようです 好ましくない事態だ この情報を送信すると プライバシーが侵害されます ユーザーの同意や正当な 理由なしに位置情報を 収集するのは得策では ありません これまでのところAppは ユーザー体験を 向上させる正当な目的でのみ この許可を要求しています この時点では このSDK統合については 一時中止です 代わりにバグレポートを 提出して この容認できない事象 について 担当者に調査して もらうことにします またこのInstruments トレースを使用して バグレポートに必要な情報を 生成することも可能です まずデスクトップに 保存します

名称を“プライバシー違反” として “保存”をクリックします

Instrumentsの コマンドラインxctraceで このトレースを エクスポートして HTTPトラフィック情報を エクスチェンジするための 業界標準であるアーカイブ 形式に変換します これにはトレースの入力と HARフラグを使用 xctraceexportコマンドを 実行するだけです

実行してみます

このコマンドはバグレポートに 添付できる ファイルを生成します HARをサポートしている ツールを持っていなくても マシンにInstrumentsが インストールされていなくとも 記録された情報を 検査できます

HAR自体はJSONベースの フォーマットなので テキストエディタで開いたり スクリプトを使用して 簡単に処理したり することもできます Instruments固有の 詳細は 含まれていなくとも セッションやバックトレース のように他のチームが 問題を調査するには 十分なものです

これが HTTPトラフィック インスツルメントを使用した 実行時のApp処理を 確実に制御するための トラフィックのソースと コンテンツを診断する 方法です これでInstrumentsの 概要が分かったので 今日お見せしたのと 同じようなAppの問題を 検出していただける ものと思います デバッグを簡素化 コンテキストを持たせるために セッションとタスクに 名前を付けます

常に最新のネットワーク プロトコルを採用してください Appのパフォーマンスや 不具合が見つからない 場合でも 送信データ量によって 発生しかねない 不要なトラフィックを 除去するために お役立てください 本日はご覧いただき ありがとうございます Appのトラフィック追跡が 楽しいものになりますよう [アップビートな音楽]