實務效能偵錯範例：ANR

本節將透過範例追蹤記錄，說明如何使用 ProfilingManager 偵錯應用程式無回應 (ANR) 問題。

設定應用程式以收集 ANR

首先，請在應用程式中設定 ANR 觸發條件：

public void addANRTrigger() {
  ProfilingManager profilingManager = getApplicationContext().getSystemService(
      ProfilingManager.class);
  List<ProfilingTrigger> triggers = new ArrayList<>();
  ProfilingTrigger.Builder triggerBuilder = new ProfilingTrigger.Builder(
      ProfilingTrigger.TRIGGER_TYPE_ANR);
  triggers.add(triggerBuilder.build());
  Executor mainExecutor = Executors.newSingleThreadExecutor();
  Consumer<ProfilingResult> resultCallback =
      profilingResult -> {
        // Handle uploading trace to your back-end
      };
  profilingManager.registerForAllProfilingResults(mainExecutor, resultCallback);
  profilingManager.addProfilingTriggers(triggers);
}
ProfilingManagerJavaSnippets.java

擷取並上傳 ANR 追蹤記錄後，請在 Perfetto UI 中開啟。

分析追蹤記錄

由於 ANR 觸發了追蹤記錄，因此當系統偵測到應用程式主執行緒沒有回應時，您就知道追蹤記錄已結束。圖 1 顯示如何前往應用程式的主要執行緒，該執行緒會在 UI 中相應標記。

Perfetto UI 導覽至應用程式主執行緒。
圖 1. 導覽至應用程式的主執行緒。

如圖 2 所示，追蹤記錄的結尾與 ANR 的時間戳記相符。

Perfetto UI 顯示追蹤記錄結尾，並醒目顯示 ANR 觸發位置。
圖 2.ANR 觸發位置。

追蹤記錄也會顯示發生 ANR 時，應用程式執行的作業。具體來說，應用程式在 handleNetworkResponse 追蹤切片中執行程式碼。這個切片位於 MyApp:SubmitButton 切片內。這個函式使用了 1.48 秒的 CPU 時間 (圖 3)。

Perfetto UI 顯示 ANR 發生時，handleNetworkResponse 執行作業耗用的 CPU 時間。
圖 3.發生 ANR 時的執行情況。

如果您目前僅依賴 ANR 發生時的堆疊追蹤進行偵錯，可能會錯誤地將 ANR 完全歸因於 handleNetworkResponse 追蹤切片中執行的程式碼，而該切片在設定檔完成記錄時尚未結束。不過，即使是耗用資源的操作，1.48 秒也不足以觸發 ANR。您需要回溯更久的時間，瞭解這個方法之前是哪些項目封鎖了主執行緒。

如要找出 ANR 的原因，請從 UI 執行緒產生的最後一個影格開始，也就是對應於 Choreographer#doFrame 551275 切片，且在導致 ANR 的 MyApp:SubmitButton 切片開始之前，沒有造成延遲的大型來源 (圖 4)。

Perfetto UI 顯示 ANR 發生前，UI 執行緒轉譯的最後一個影格。
圖 4.ANR 發生前產生的最後一個應用程式影格。

如要瞭解阻塞情形，請縮小畫面，檢查完整 MyApp:SubmitButton 切片。如圖 4 所示，您會發現執行緒狀態中的重要詳細資料：執行緒有 75% 的時間 (6.7 秒) 處於 Sleeping 狀態，只有 24% 的時間處於 Running 狀態。

Perfetto UI 顯示作業期間的執行緒狀態，醒目顯示 75% 的休眠時間和 24% 的執行時間。
圖 5. `MyApp:SubmitButton` 作業期間的執行緒狀態。

這表示 ANR 的主要原因是等待，而非運算。 查看個別睡眠事件，找出睡眠模式。

Perfetto UI 顯示 MyAppSubmitButton 追蹤記錄切片中的第一個休眠間隔。
圖 6. `MyAppSubmitButton` 內的第一次休眠時間。
Perfetto UI：顯示 MyAppSubmitButton 追蹤記錄切片中的第二個休眠間隔。
圖 7. `MyAppSubmitButton` 內的第二個睡眠時間。
Perfetto UI：顯示 MyAppSubmitButton 追蹤記錄切片中的第三個休眠間隔。
圖 8. `MyAppSubmitButton` 內的第三個睡眠時間。
Perfetto UI：顯示 MyAppSubmitButton 追蹤記錄切片中的第四個休眠間隔。
圖 9. `MyAppSubmitButton` 中的第四個睡眠時間。

前三個睡眠間隔 (圖 6 至 8) 幾乎相同，每個間隔約 2 秒。第四次睡眠的離群值 (圖 9) 為 0.7 秒。在運算環境中，2 秒的持續時間很少是巧合。這強烈暗示是程式設計逾時，而非隨機資源爭用。最後一次休眠可能是因為執行緒完成等待，因為等待的作業成功。

這個假設是應用程式多次達到使用者定義的 2 秒逾時時間，最終成功，但延遲時間足以觸發 ANR。

Perfetto UI 顯示 MyApp:SubmitButton 追蹤記錄切片期間的延遲摘要，指出多個 2 秒的休眠間隔。
圖 10.`MyApp:SubmitButton` 切片期間的延遲摘要。

如要驗證這點，請檢查與 MyApp:SubmitButton 追蹤記錄相關聯的程式碼：

private static final int NETWORK_TIMEOUT_MILLISECS = 2000;
public void setupButtonCallback() {
  findViewById(R.id.submit).setOnClickListener(submitButtonView -> {
    Trace.beginSection("MyApp:SubmitButton");
    onClickSubmit();
    Trace.endSection();
  });
}

public void onClickSubmit() {
  prepareNetworkRequest();

  boolean networkRequestSuccess = false;
  int maxAttempts = 10;
  while (!networkRequestSuccess && maxAttempts > 0) {
    networkRequestSuccess = performNetworkRequest(NETWORK_TIMEOUT_MILLISECS);
    maxAttempts--;
  }

  if (networkRequestSuccess) {
    handleNetworkResponse();
  }
}

boolean performNetworkRequest(int timeoutMiliseconds) {
  // ...
}

  // ...
}

public void handleNetworkResponse() {
  Trace.beginSection("handleNetworkResponse");
  // ...
  Trace.endSection();
}
ProfilingManagerJavaSnippets.java

這段程式碼證實了這項假設。onClickSubmit 方法會在 UI 執行緒上執行網路要求，並將 NETWORK_TIMEOUT_MILLISECS 硬式編碼為 2000 毫秒。重要的是，這項作業會在 while 迴圈中執行，最多會重試 10 次。

在這個特定追蹤記錄中，使用者可能網路連線品質不佳。前三次嘗試均失敗，導致三次 2 秒逾時 (總共 6 秒)。第四次嘗試在 0.7 秒後成功，程式碼可繼續執行 handleNetworkResponse。不過，累計等待時間已觸發 ANR。

如要避免這類 ANR，請將延遲時間不一的網路相關作業放入背景執行緒，不要在主執行緒中執行。即使連線品質不佳，UI 仍可保持回應，完全消除這類 ANR。