Winscope を使用してウィンドウ遷移をトレースする

Winscope は、アニメーションや遷移の最中および終了後における複数のシステム サービスの状態を記録、リプレイ、分析できるウェブツールです。Winscope は、すべての関連するシステム サービスの状態をトレース ファイルに記録します。トレース ファイルと Winscope UI を使用すると、遷移をリプレイ、ステップ実行、デバッグすることで、画面録画の有無にかかわらず、アニメーション フレームごとにこうしたサービスの状態を調べることができます。

サポートされているトレース

Winscope では、システム サービスの状態のさまざまなトレースやシーケンスを収集し、視覚的に表すことができます。これらのトレースは、少ないオーバーヘッドから高度な詳細度まで、特定のユースケースに適合するよう構成できます。次のトレースは Winscope でサポートされています。

  • EventLog: EventLog を使用してシステム診断イベントの記録を収集します。Winscope では、この情報は CUJ マークの特定および表示にのみ使用されます。
  • IME: IMS、IMMS、IME クライアントなどのインプット メソッド エディタ(IME)パイプラインからのイベントをトレースします。
  • Input: 入力イベント パイプラインのさまざまな部分からの入力イベントをトレースします。
  • ProtoLog: システム サービスと、クライアント プロセスで実行しているシステム サービスのコードからの ProtoLog メッセージを収集します。
  • Screen recording: トレースとともに画面録画を収集します。
  • Shell transitions: ウィンドウとアクティビティ遷移システムの詳細情報を記録します。
  • SurfaceFlinger: 位置、バッファ、コンポジションなど、サーフェス(レイヤ)に関する情報を含む SurfaceFlinger トレースを収集します。
  • Transactions: コンポジションについて SurfaceControl を使用して SurfaceFlinger が受け取る一連のアトミックな変更をトレースします。
  • ViewCapture: システム UI やランチャーなど、ViewCapture をサポートするシステム ウィンドウのすべてのビューの幅広いプロパティを取得します。
  • Window Manager: ウィンドウに関する詳細情報(入力イベント、フォーカス イベント、画面の向き、遷移、アニメーション、ポジショニング、変換など)を含む Window Manager の状態をトレースします。

サポートされているダンプ

Winscope は状態ダンプを収集、表示でき、このダンプはユーザーが定義した特定の瞬間をとらえたデバイスの状態のスナップショットです。デバイスの使用中に継続的に収集され、パフォーマンスに影響をおよぼすことがあるトレースとは異なり、ダンプはユーザーが定義した瞬間にのみ取得され、パフォーマンスと詳細度が侵害されないようにします。これにより、特定の時点でのデバイスの状態を集中的かつ効率的に分析できます。Winscope は次のダンプをサポートしています。

  • Window Manager: 1 つの Window Manager の状態をダンプします。
  • SurfaceFlinger: 1 つの SurfaceFlinger スナップショットをダンプします。
  • Screenshot: ダンプとともにスクリーンショットを収集します。

リソース

Winscope のビルドと実行に関する情報は、Winscope を実行するをご覧ください。

トレースの収集に関する情報は、トレースをキャプチャするをご覧ください。

Winscope ウェブ UI を使用してトレースを読み込む方法については、トレースを読み込むをご覧ください。

トレースの分析に関する情報は、トレースを分析するをご覧ください。

以下の例では、フリッカー テストの失敗とユーザーから報告されたバグをデバッグする方法について説明します。

フリッカー テストの失敗

この例では、Winscope を使用してフリッカー テストの失敗をデバッグする方法を示します。

テストの失敗について調べる

以下の手順に沿って問題の種類を特定し、テストのエラー メッセージを調べます。

  1. テスト名とクラス名を調べて、問題の種類を特定します。

    テスト名とクラス名:

    FlickerTestsNotification com.android.server.wm.flicker.notification.OpenAppFromLockscreenNotificationColdTest#appLayerBecomesVisible[ROTATION_0_GESTURAL_NAV]
    

    問題の種類:

    • この CUJ は、ロック画面の通知からアプリを起動することを指します(OpenAppFromLockscreenNotificationColdTest)。

    • このテストでは、アプリが表示されることが予想されます(#appLayerBecomesVisible)。

  2. テストのエラー メッセージを調べます。このメッセージには、以下のとおり失敗についての包括的な情報が含まれています。

    • 予想されていた結果と実際に表示される結果の比較
    • エラーの発生時期を特定するためのタイムスタンプ
    • エラーに関連するアーティファクトまたはファイルの名前
    • エラーの理解とデバッグに関連する追加のコンテキスト情報
    android.tools.flicker.subject.exceptions.IncorrectVisibilityException: com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity# should be visible
    
    Where?
        Timestamp(UNIX=2024-05-10T11:04:14.227572545(1715339054227572545ns), UPTIME=37m21s184ms79178ns(2241184079178ns), ELAPSED=0ns)
    
    What?
        Expected: com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity#
        Actual: [e636ecd com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity#3457: Buffer is empty, Visible region calculated by Composition Engine is empty, com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity#3458: Visible region calculated by Composition Engine is empty]
    
    Other information
        Artifact: FAIL__OpenAppFromLockscreenNotificationColdTest_ROTATION_0_GESTURAL_NAV.zip
    
    Check the test run artifacts for trace files
    
        at android.tools.flicker.subject.layers.LayerTraceEntrySubject.isVisible(LayerTraceEntrySubject.kt:187)
        at android.tools.flicker.subject.layers.LayersTraceSubject$isVisible$1$1.invoke(LayersTraceSubject.kt:151)
        at android.tools.flicker.subject.layers.LayersTraceSubject$isVisible$1$1.invoke(LayersTraceSubject.kt:150)
        at android.tools.flicker.assertions.NamedAssertion.invoke(NamedAssertion.kt:32)
        at android.tools.flicker.assertions.CompoundAssertion.invoke(CompoundAssertion.kt:42)
        at android.tools.flicker.assertions.AssertionsChecker.test(AssertionsChecker.kt:79)
        at android.tools.flicker.subject.FlickerTraceSubject.forAllEntries(FlickerTraceSubject.kt:59)
        at android.tools.flicker.assertions.AssertionDataFactory$createTraceAssertion$closedAssertion$1.invoke(AssertionDataFactory.kt:46)
        at android.tools.flicker.assertions.AssertionDataFactory$createTraceAssertion$closedAssertion$1.invoke(AssertionDataFactory.kt:43)
        at android.tools.flicker.assertions.AssertionDataImpl.checkAssertion(AssertionDataImpl.kt:33)
        at android.tools.flicker.assertions.ReaderAssertionRunner.doRunAssertion(ReaderAssertionRunner.kt:35)
        at android.tools.flicker.assertions.ReaderAssertionRunner.runAssertion(ReaderAssertionRunner.kt:29)
        at android.tools.flicker.assertions.BaseAssertionRunner.runAssertion(BaseAssertionRunner.kt:36)
        at android.tools.flicker.legacy.LegacyFlickerTest.doProcess(LegacyFlickerTest.kt:59)
        at android.tools.flicker.assertions.BaseFlickerTest.assertLayers(BaseFlickerTest.kt:89)
        at com.android.server.wm.flicker.notification.OpenAppTransition.appLayerBecomesVisible_coldStart(OpenAppTransition.kt:51)
        at com.android.server.wm.flicker.notification.OpenAppFromNotificationColdTest.appLayerBecomesVisible(OpenAppFromNotificationColdTest.kt:64)
    

    この出力サンプルにより、以下のことがわかります。

    • この問題が発生したのは 2024-05-10T11:04:14.227572545

    • NotificationActivity が表示されるはずだったが、実際には表示されていない。

    • デバッグ用のトレースが含まれているアーティファクト ファイルの名前は FAIL__OpenAppFromLockscreenNotificationColdTest_ROTATION_0_GESTURAL_NAV

デバッグ

以下の手順に沿って、ちらつきの原因を特定します。

  1. トレース ファイルをダウンロードして Winscope に読み込みます。Winscope が開き、SurfaceFlinger が自動選択されます。

    SurfaceFlinger ビューが表示された Winscope のランディング ページ

    図 1. SurfaceFlinger ビューが表示された Winscope のランディング ページ。

  2. 例外メッセージからタイムスタンプをコピーしてタイムスタンプ フィールドに貼り付け、問題が発生したタイムスタンプに移動します。タイムスタンプは、人が読める形式(2024-05-10T11:04:14.227572545)でコピーして最初のフィールドに貼り付けるか、ナノ秒単位(1715339054227572545ns)でコピーして 2 番目のフィールドに貼り付けてください。

    タイムスタンプ ダイアログ

    図 2. タイムスタンプ ダイアログ。

  3. 左矢印キーを押して前のフレームに移動します。この状態では、動画内の NotificationActivity アプリは正しく表示されています。アプリとスプラッシュ画面のサーフェスが確認でき、いずれも 3D ビューでは緑色の矩形で、階層要素では V チップで示されています。

    アプリとスプラッシュ画面のサーフェス名は以下のとおりです。

    com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity#3458`
    
    Splash Screen com.android.server.wm.flicker.testapp#3453
    

    これにより、画面が黒くなったときにアプリが起動していたこと、また依然としてスプラッシュ画面が表示されていることから、このイベントはアプリの起動中に発生していることがわかります。

    アプリの起動時

    図 3. アプリの起動時。

  4. 右矢印キーを押して、ちらつきが発生している次のフレームに戻ります。矩形ビューでは、アプリではなく NotificationShade が画面に表示されます。このフレームには以下のサーフェスが表示されています。

    • 画面装飾オーバーレイ(上部および下部)
    • ナビゲーション バー
    • ポインタの位置(画面の録画から)

      ちらつきの発生

      図 4. ちらつきの発生。

  5. 階層ビューでアプリのアクティビティを選択します。見つからない場合は、[Show only V] をオフにしてから、プロパティ ビューを調べてください。

    アプリのサーフェス名は以下のとおりです。

    com.android.server.wm.flicker.testapp/com.android.server.wm.flicker.testapp.NotificationActivity#3458`
    

    アプリ プロパティ

    図 5. アプリ プロパティ。

    アプリのアクティビティは「表示」および「不透明」に設定されていますが、Invisible due to: null visible region エラーにより、サーフェスが表示されていません。コンポジション中、別の不透明なサーフェスが前面に配置されると、このような状況が発生します。この仮説の根拠として、3D ビューで NotificationShade 矩形が NotificationActivity 矩形の前面に位置していることと、表示されている(緑色の)NotificationShade が選択されたレイヤである可能性が高いことが挙げられます。

  6. この仮説を検証するには、現在のフレームで表示されている NotificationShade サーフェスを選択し、そのプロパティを確認します。フラグは OPAQUE|ENABLE_BACKPRESSURE (0x102) に設定されています。NotificationShade サーフェスの名前は NotificationShade#3447 です。次に、左矢印を押して(ちらつきが発生する)前のフレームに戻り、再度 NotificationShade サーフェスのプロパティを調べます。サーフェスには OPAQUE がなく、ENABLE_BACKPRESSURE (0x100) フラグのみが設定されていることがわかります。これにより、アプリが完全に起動する前に NotificationShade が不透明になることが確認できます。NotificationShadeNotificationActivity の前面にあるため、アプリは表示されません。NotificationShade が黒色であるため画面が一時的に黒くなり、ちらつきが発生します。

  7. NotificationShade が不透明になるのが早すぎる原因をコードで特定します。

ユーザーから報告されたバグ

ユーザーから報告されたバグは、詳細な情報が不足していることが多いため、デバッグが難しい可能性があります。具体的なタイムスタンプ、要素の詳細、画面録画が提供されるフリッカー テスト失敗と異なり、一般的に、ユーザーから報告されたバグには問題の簡単な記述しか含まれていません。

このケーススタディでは、提供された情報は「Screen flickered when reopening app from split screen」というタイトルと「Apr 18, 2024 3:51 PM GMT-04:00」というおおよそのタイムスタンプのみです。

ユーザーから報告されたバグをデバッグする手順は次のとおりです。

  1. Winscope でトレース ファイルを読み込みます。SurfaceFlinger が自動選択された状態で Winscope が開きます。

    SurfaceFlinger ビューが表示された Winscope のランディング ページ

    図 6. SurfaceFlinger ビューが表示された Winscope のランディング ページ。

  2. ユーザーから報告されたおおよそのタイムスタンプ(このケースでは 3:50 PM GMT-04:00)に移動するため、人が読めるタイムスタンプ フィールドに「15:50:00」と入力します。

    タイムスタンプ ダイアログ

    図 7. タイムスタンプ ダイアログ。

  3. 矩形ビューを使用して、画面に何が描画されていたかを特定します。見やすくするため、Rotation スライダーを使用して矩形の視点を変えます。階層ビューで [Show only V] と [Flat] を指定すると、壁紙、画面の装飾オーバーレイ、レターボックス、ランチャー、連絡先、電話アプリのサーフェスが表示されます。

    パッケージの名前は次のとおりです。

    • ランチャー: com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity#40602

    • 連絡先: com.google.android.contacts/com.android.contacts.activities.PeopleActivity#40565

    • 電話アプリ: com.google.android.dialer/com.google.android.dialer.extensions.GoogleDialtactsActivity#40564

    表示可能なサーフェス(緑色の矩形)のほかに、表示エリアのサーフェスを表すグレーの矩形(Unknown display)も表示されます。見やすくするため、ScreenDecorHwcOverlay#64 サーフェスの横にある(表示アイコン)をクリックして対応する矩形を非表示にして、後ろにあるサーフェスが表示されるようにします。オーバーレイはユーザーには見えず、アニメーションがちらつく問題として報告されないため、分析から除外します。

    ユーザーの報告

    図 8. ユーザーの報告。

  4. どのサーフェスが関わっているかを分割画面ビューで特定したら、Transitions トレースを使用して、さまざまなユーザー アクションをステップ実行し、ちらつきを探します。Winscope で [Transitions] タブをクリックすると、再生された遷移のリストが表示されます。

    遷移

    図 9. 遷移。

    このフレーム中に再生された遷移は青色でハイライト表示されています。このケースでは、遷移フラグに、ユーザーが recents 画面に入っていることを示す TRANSIT_FLAG_IS_RECENTS が含まれます。

  5. [Dispatch Time] 列のリンク(このケースでは 2024-04-18, 15:50:57.205)をクリックしてその時点に移動し、[Surface Flinger] タブで矩形を確認します。右矢印キーで遷移をステップ実行して矩形を調べることで、遷移時におけるデバイスの状態の正確さを確認します。

    ランチャーは 15:50:57.278 に表示されますが、その後でアニメーションが開始していません。分割画面のアプリ間には何も描画されていないため(分割線)、壁紙はすでに見えています。1 つ前のフレーム(15:50:57.212)では壁紙は見えず、分割線が表示されています。これがアニメーションがない場合の分割画面の様子です。

    ちらつきの前の画面

    図 10. ちらつきイベントの前の画面。

  6. 次の遷移を確認するため、タイムラインを直接クリックします。SurfaceFlinger の状態は水色のブロックの行で表されています。遷移はピンク色のブロックの行で表されています。

    1 つ目の遷移の終わり

    図 11. 1 つ目の遷移の終わり。

    次の遷移の開始位置で SurfaceFlinger の行をクリックします。図 11 で、カーソルの垂直方向は細い青色の線で示されています。SurfaceFlinger の行の水色の背景はカーソルの水平方向を示します。右矢印キーで遷移をステップ実行して、ちらつきが発生するかどうかを確認します。デバイスでこの遷移が正しく表示されることを確認します。

  7. 次の遷移は期間が非常に短く、ちらつきが含まれている可能性が低いため、スキップします。代わりに、その次の長い遷移の開始位置(次の画像内のカーソル位置)で SurfaceFlinger の行のタイムラインをクリックします。

    2 つ目の遷移の終わり

    図 12. 2 つ目の遷移の終わり。

    この遷移中の 15:51:13.239 で、連絡先アプリと電話アプリの両方のアプリに対する Splash Screen レイヤは画面の同じ側にあります。

    スプラッシュ画面

    図 13. スプラッシュ画面。

  8. どちらのアプリの位置が間違っているかを明らかにします。後でこのフレームに戻れるよう、[ns] 入力フィールドの横にあるフラグアイコンをクリックして現在の位置にブックマークを追加します。

    ブックマークを追加する

    図 14. ブックマークを追加する。

  9. タイムラインを直接クリックして、遷移の終わりのフレーム(たとえば、15:51:13.859)に移動します。ここで、電話アプリは左側、連絡先アプリは右側で、2 つのアプリは最終的な位置になっています。

    最終的な分割画面

    図 15. 最終的な分割画面。

  10. タイムラインにあるブックマークのフラグをクリックして、ちらつきがあるフレームに戻ります。

    タイムラインのブックマーク

    図 16. タイムラインのブックマーク。

    どちらのアプリも右側にあるため、電話アプリの位置が間違っていることがわかります。

  11. 電話アプリのスプラッシュ画面をクリックしてプロパティを表示します。キュレートされた Properties ビューで、変換のプロパティを具体的に調べます。

    変換のプロパティ

    図 17. 変換のプロパティ。

    計算された変換がこのサーフェスに適用されていますが、設定されているのはこのレベルではありません。計算された列とリクエストされた列の値が異なるため、変換は親サーフェスからの継承であることがわかります。

  12. 階層ビューで [Flat] の選択を解除して階層ツリー全体を表示し、Calculated 変換と Requested 変換の両方が同一になり、Surface(name=Task=7934)/@0x1941191_transition-leash#40670 サーフェスに「リクエスト」された変換が表示されるまで、アプリ サーフェスの親ノードに移動します。

  13. 変換が最初に設定されたときと、そのときの値を確認します。タイトルの横にあるアイコンをクリックして、キュレートされたプロパティを閉じます。

    キュレートされたプロパティを閉じる

    図 18. キュレートされたプロパティを閉じる。

  14. Proto Dump ビューで [Show diff] を選択し、このフレームで変更されているプロパティをハイライト表示します。テキスト検索フィールドに「transform」と入力してプロパティをフィルタします。

    Show diff

    図 19. Show diff。

    このフレームで transition-leash に対し変換が IDENTITY から SCALE|TRANSLATE|ROT_270 に設定されています。

    この情報から、分割画面の電話アプリのアニメーション リーシュに変換が適用されたときにちらつきが発生したことがわかります。

    ちらつきの特定

    図 20. ちらつきの特定。

  15. この変換が分割画面の遷移リーシュに設定された理由をコードで特定します。