Örnek olay: ANR'de hata ayıklama

Bu sayfada, örnek bir sistem iziyle ProfilingManager kullanarak Uygulama Yanıt Vermiyor (ANR) hatasında nasıl hata ayıklama yapılacağı açıklanmaktadır.

Uygulamayı ANR'leri toplayacak şekilde ayarlama

Uygulamanızda bir ANR tetikleyicisi ayarlayarak başlayın:

Kotlin

fun addANRTrigger() {
    val profilingManager =
        applicationContext.getSystemService(ProfilingManager::class.java) ?: return
    val triggers = ArrayList<ProfilingTrigger>()
    val triggerBuilder = ProfilingTrigger.Builder(ProfilingTrigger.TRIGGER_TYPE_ANR)
    triggers.add(triggerBuilder.build())
    val callbackExecutor: Executor = Executors.newSingleThreadExecutor()
    val resultCallback = Consumer<ProfilingResult> { profilingResult ->
        // Handle uploading trace to your back-end
    }
    profilingManager.registerForAllProfilingResults(callbackExecutor, resultCallback)
    profilingManager.addProfilingTriggers(triggers)
}

Java

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 callbackExecutor = Executors.newSingleThreadExecutor();
  Consumer<ProfilingResult> resultCallback =
      profilingResult -> {
        // Handle uploading trace to your back-end
      };
  profilingManager.registerForAllProfilingResults(callbackExecutor, resultCallback);
  profilingManager.addProfilingTriggers(triggers);
}

ANR izini yakalayıp yükledikten sonra aşağıdaki adımlarda gösterildiği gibi Perfetto kullanıcı arayüzünde manuel olarak inceleyebilir veya ANR incelemesini bir yapay zeka ajanıyla otomatikleştirebilirsiniz.

İzlemeyi analiz etme

ANR, izlemeyi tetiklediği için sistem, uygulamanızın ana iş parçacığında yanıt vermeme durumu algıladığında (veya başka bir zaman aşımı gerçekleştiğinde) izlemenin sona erdiğini bilirsiniz. Şekil 1'de, uygulamanızın ana iş parçacığına nasıl gidileceği gösterilmektedir. Bu iş parçacığı, kullanıcı arayüzünde uygun şekilde etiketlenmiştir.

Perfetto kullanıcı arayüzünde uygulamanın ana iş parçacığına gitme.
Şekil 1. Uygulamanın ana iş parçacığına gitme.

İzlemenin sonu, Şekil 2'de gösterildiği gibi ANR'nin zaman damgasıyla eşleşir.

Bir izin sonunu gösteren Perfetto kullanıcı arayüzü. ANR tetikleyici konumu vurgulanıyor.
Şekil 2. ANR tetikleme konumu.

ANR gerçekleştiğinde ana iş parçacığı, MyApp:SubmitButton içinde handleNetworkResponse dilimini yürütüyordu ve bu işlem 1,48 saniye CPU süresi tüketti (Şekil 3).

ANR sırasında handleNetworkResponse yürütme işleminin tükettiği CPU süresini gösteren Perfetto kullanıcı arayüzü.
Şekil 3. ANR sırasındaki yürütme.

Yalnızca ANR anında alınan yığın dökümüne güvenmek, donmayı tamamen handleNetworkResponse ile yanlış ilişkilendirebilir. Ancak 1, 48 saniye tek başına ANR'yi tetikleyecek kadar uzun olmadığından, ana iş parçacığını daha önce neyin engellediğini incelemeniz gerekir.

Donmadan önce oluşturulan son kullanıcı arayüzü karesini (Choreographer#doFrame 551275) bularak başlayın. Bu kare, MyApp:SubmitButton diliminden hemen önce gelir (Şekil 4).

ANR'den önce kullanıcı arayüzü iş parçacığı tarafından oluşturulan son kareyi gösteren Perfetto kullanıcı arayüzü.
Şekil 4. ANR'den önce oluşturulan son uygulama karesi.

Engellemeyi anlamak için MyApp:SubmitButton diliminin tamamını incelemek üzere uzaklaştırın. Şekil 5'te manuel olarak seçilen aralık için iş parçacığı durumlarında önemli bir ayrıntı fark edeceksiniz: İş parçacığı, zamanın yaklaşık %75'ini (6,7 saniye) Sleeping durumunda, yalnızca %24'ünü ise Running durumunda geçiriyor.

Bir işlem sırasında iş parçacığı durumlarını gösteren Perfetto kullanıcı arayüzü. Uyku süresinin %75, çalışma süresinin %24 olduğu vurgulanıyor.
Şekil 5. MyApp:SubmitButton işlemi sırasında iş parçacığı durumları.

Bu durum, ANR'nin birincil nedeninin hesaplama değil, bekleme olduğunu gösterir. Bir kalıp bulmak için her bir uyku durumunu inceleyin.

MyAppSubmitButton izleme dilimindeki ilk uyku aralığını gösteren Perfetto kullanıcı arayüzü.
Şekil 6. MyApp:SubmitButton içindeki ilk uyku zamanı.
MyAppSubmitButton izleme dilimindeki ikinci uyku aralığını gösteren Perfetto kullanıcı arayüzü.
Şekil 7. MyApp:SubmitButton içinde ikinci uyku süresi.
MyAppSubmitButton izleme dilimindeki üçüncü uyku aralığını gösteren Perfetto kullanıcı arayüzü.
Şekil 8. MyApp:SubmitButton içinde üçüncü uyku zamanı.
MyAppSubmitButton izleme dilimindeki dördüncü uyku aralığını gösteren Perfetto kullanıcı arayüzü.
Şekil 9. MyApp:SubmitButton içinde dördüncü uyku zamanı.

İlk üç uyku aralığı (Şekil 6-8) yaklaşık 2 saniye, dördüncü aralık (Şekil 9) ise 0,7 saniyedir. Tekrarlanan 2 saniyelik duraklamalar, dördüncü denemede başarılı olmadan önce üç kez yeniden denenen programlanmış bir zaman aşımını güçlü bir şekilde gösterir. Bu da ANR'yi tetikleyecek kadar gecikmeye neden olur (Şekil 10).

MyApp:SubmitButton izleme dilimi sırasında gecikmelerin özetini gösteren Perfetto kullanıcı arayüzü. Birden fazla 2 saniyelik uyku aralığı gösteriliyor.
Şekil 10. MyApp:SubmitButton dilimi sırasındaki gecikmelerin özeti.

Kodda temel nedeni belirleme

Bu hipotezi doğrulamak için MyApp:SubmitButton izleme bölümüyle ilişkili kodu inceleyin:

Kotlin

fun setupButtonCallback() {
    findViewById<View>(R.id.submit).setOnClickListener {
        trace("MyApp:SubmitButton") {
            onClickSubmit()
        }
    }
}

fun onClickSubmit() {
    prepareNetworkRequest()

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

    if (networkRequestSuccess) {
        handleNetworkResponse()
    }
}

fun performNetworkRequest(timeoutMilliseconds: Int): Boolean {
    // ...
}

fun prepareNetworkRequest() {
    // ...
}

fun handleNetworkResponse() {
    trace("handleNetworkResponse") {
        // ...
    }
}

companion object {
    private const val NETWORK_TIMEOUT_MILLISECS = 2000
}

Java

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) {
  // ...
}


void prepareNetworkRequest() {
  // ...
}

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

Kod bu hipotezi doğrular. onClickSubmit yöntemi, kullanıcı arayüzü iş parçacığında 2.000 ms'lik sabit kodlu bir NETWORK_TIMEOUT_MILLISECS ile ağ isteği yürütür. En önemlisi, 10 defaya kadar yeniden deneme yapan bir while döngüsü içinde çalışır.

Bu özel izlemede, kullanıcının ağ bağlantısı muhtemelen zayıftı. İlk üç deneme başarısız oldu ve üç kez 2 saniyelik zaman aşımı yaşandı (toplam 6 saniye). Dördüncü deneme 0,7 saniye sonra başarılı oldu ve kodun handleNetworkResponse'a geçmesine izin verildi. Ancak birikmiş bekleme süresi, ANR'yi zaten tetiklemişti.

ANR'yi düzeltme

Farklı gecikme sürelerine sahip ağla ilgili işlemleri ana iş parçacığında yürütmek yerine arka plan iş parçacığına taşıyarak bu tür ANR'leri önleyebilirsiniz. Bu sayede, bağlantı zayıf olsa bile kullanıcı arayüzü duyarlı kalır ve bu ANR sınıfı ortadan kalkar.

ANR incelemesini yapay zeka ajanıyla otomatikleştirme

Perfetto kullanıcı arayüzünde zaman çizelgelerini ve uyku aralıklarını manuel olarak incelemek yerine, ANR izini sorgulamak ve kod tabanınızla ilişkilendirmek için Perfetto yapay zeka becerisi ile yapılandırılmış bir yapay zeka kodlama temsilcisini kullanabilirsiniz:

Analyze the Perfetto system trace at </path/to/trace.perfetto-trace>, which
corresponds to an ANR trace, and find the root cause of the ANR using the
Perfetto AI skill. The codebase is located at </path/to/codebase>.

Temsilci, trace_processor ile izi sorgular ve izlemenin sonundaki tamamlanmamış handleNetworkResponse dilimi tarafından yanıltılmadan manuel incelemeyle aynı sonuca ulaşır. MyApp:SubmitButton, ana iş parçacığını 9,2 saniyeden uzun süre engellediğini tespit eder, performNetworkRequest içindeki üç adet 2 saniyelik ağ zaman aşımını ve 0,7 saniyelik dördüncü denemeyi, prepareNetworkRequest ve handleNetworkResponse içindeki CPU meşgul bekleme döngüleriyle birlikte yeniden oluşturur ve her aşamayı ProfilingManagerJavaSnippets.java ile eşleyerek onClickSubmit'i kullanıcı arayüzü iş parçacığından kaldırmanızı önerir:

# Perfetto ANR Root-Cause Analysis Report

* **Source Code:** `ProfilingManagerJavaSnippets.java`
* **Target Process:** `com.example.sampleapp` (`pid = 32579`, `upid = 27`)
* **Blocked Thread:** Main UI thread `ample.sampleapp` (`tid = 32579`, `utid = 760`)
* **Collection Mechanism:** Android `ProfilingManager` (`ProfilingTrigger.TRIGGER_TYPE_ANR`)

---

## 1. Executive Summary

> **Important:** The ANR in `com.example.sampleapp` is caused by executing **synchronous, blocking network retry logic (`Thread.sleep`) and heavy CPU busy-wait loops (`cpuIntensiveComputation`) directly on the main UI thread** inside the submit button click listener (`MyApp:SubmitButton` -> `onClickSubmit()`).

When the user taps the submit button at `7,967.78 ms` into the trace (`ts = 80459171444519`), the main UI thread is blocked continuously for **more than `9,281.30 ms`** (still unfinished when the trace ends at `17,249.08 ms`):

1. **`prepareNetworkRequest()`** runs a CPU busy-wait loop on the main thread for **`~1,019 ms`**.
2. **`performNetworkRequest(2000)`** executes in a synchronous `while` retry loop on the main thread. Each attempt begins with **`20 ms`** of CPU busy-waiting followed by a `Thread.sleep()`. The request times out (`2,000 ms` sleep) **3 times in a row** and succeeds on the **4th attempt** (`~701 ms` sleep), blocking the main thread for **`~6,764 ms`** across the 4 attempts (`6,703.18 ms` sleeping + `~60 ms` CPU).
3. **`handleNetworkResponse()`** begins at **`+7,783.44 ms`** after the button click and runs another `2,000 ms` CPU busy-wait loop on the main thread (`1,497.86 ms` captured before the trace ends).

    [Touch UP & Click (t = +0 ms)]
      -> prepareNetworkRequest() (~1,000 ms CPU Busy-Wait)
      -> Attempt #1 (Timeout: 20 ms CPU + 2,001 ms Sleep)
      -> Attempt #2 (Timeout: 20 ms CPU + 2,001 ms Sleep)
      -> Attempt #3 (Timeout: 20 ms CPU + 2,001 ms Sleep, crosses 5s ANR threshold)
      -> Attempt #4 (Success: 20 ms CPU + 701 ms Sleep)
      -> handleNetworkResponse() (1,498 ms CPU, unfinished at trace end)
## 2. PerfettoSQL Trace Analysis

### 2.1 Open Main-Thread Slices at Trace End

Querying `thread_or_process_slice` on the main thread (`utid = 760`) around and after the touch event shows that `MyApp:SubmitButton` and its nested slice `handleNetworkResponse` both have `dur = -1` (still open when the trace completed):

```sql
INCLUDE PERFETTO MODULE slices.with_context;

SELECT
  id,
  ts,
  (ts - trace_start()) / 1e6 AS rel_ts_ms,
  dur,
  IIF(dur = -1, trace_end() - ts, dur) / 1e6 AS effective_dur_ms,
  depth,
  name
FROM thread_or_process_slice
WHERE utid = 760 AND ts >= 80459169800000
ORDER BY ts;
```

| Slice ID | Slice Name | Start (`ts` ns) | Offset from Trace Start | Raw `dur` | Effective Duration (to trace end) | Depth |
| :--- | :--- | :--- | :--- | :--- | :--- | :--- |
| `40070` | `dispatchInputEvent MotionEvent UP` | `80459169801575` | `7,966.14 ms` | `190,633 ns` | `0.19 ms` | `0` |
| `40156` | **`MyApp:SubmitButton`** | `80459171444519` | `7,967.78 ms` | `-1` | **`9,281.30 ms`** | `0` |
| `97500` | **`handleNetworkResponse`** | `80466954886580` | `15,751.23 ms` | `-1` | **`1,497.86 ms`** | `1` |

---

### 2.2 Aggregate Main-Thread State (`thread_state`) During `MyApp:SubmitButton`

Aggregating `thread_state` for `utid = 760` from the start of `MyApp:SubmitButton` (`ts >= 80459171444519`) to the end of the trace reveals that the main thread spent **72.3%** of the time sleeping (`S`) and **27.6%** actively spinning on CPU (`Running`):

```sql
SELECT
  state,
  COUNT(*) AS cnt,
  SUM(dur) / 1e6 AS total_dur_ms,
  MIN(dur) / 1e6 AS min_dur_ms,
  MAX(dur) / 1e6 AS max_dur_ms
FROM thread_state
WHERE utid = 760 AND ts >= 80459171444519
GROUP BY state
ORDER BY total_dur_ms DESC;
```

| Thread State | Interval Count | Total Duration | Min Duration | Max Duration | Cause in Code |
| :--- | :--- | :--- | :--- | :--- | :--- |
| **`S` (Sleeping)** | `4` | **`6,703.18 ms`** | `700.78 ms` | `2,000.82 ms` | 4 `Thread.sleep()` calls in `performNetworkRequest()` |
| **`Running` (On CPU)** | `20` | **`2,559.81 ms`** | `0.00 ms` | `578.77 ms` | Busy-wait `while` loops in `cpuIntensiveComputation()` |
| **`R` (Runnable)** | `20` | **`2.11 ms`** | `0.01 ms` | `1.21 ms` | Scheduler wakeups and brief preemptions |

---

### 2.3 Phase-by-Phase Reconstruction (`thread_state` Intervals)

Querying individual `thread_state` intervals (`dur > 2 ms`) shows the exact sequence of CPU bursts and sleeps on the main thread:

```sql
SELECT
  ts,
  (ts - 80459171444519) / 1e6 AS ms_since_submit,
  dur / 1e6 AS dur_ms,
  state
FROM thread_state
WHERE utid = 760 AND ts >= 80459171444519 AND dur > 2e6
ORDER BY ts;
```

| Phase | Offset from Submit (`ms_since_submit`) | State | Duration (`dur_ms`) | Corresponding Code Execution |
| :--- | :--- | :--- | :--- | :--- |
| **1. Request Prep + Attempt #1 CPU** | `+0.63 ms` -> `+1,019.36 ms` | `Running` | **`1,018.68 ms`** *(across 5 slices)* | `prepareNetworkRequest()` (`1,000 ms` CPU) + Attempt #1 `cpuIntensiveComputation(20)` |
| **2. Network Attempt #1 (Timeout)** | `+1,019.36 ms` -> `+3,020.18 ms` | `S` (Sleep) | **`2,000.82 ms`** | `performNetworkRequest(2000)` -> `Thread.sleep(2000)` (`return false`) |
| **3. Network Attempt #2 (CPU)** | `+3,020.23 ms` -> `+3,040.24 ms` | `Running` | **`20.00 ms`** | Attempt #2 `cpuIntensiveComputation(20)` |
| **4. Network Attempt #2 (Timeout)** | `+3,040.24 ms` -> `+5,041.01 ms` | `S` (Sleep) | **`2,000.78 ms`** | `performNetworkRequest(2000)` -> `Thread.sleep(2000)` (`return false`) -- **5s input ANR threshold crossed** |
| **5. Network Attempt #3 (CPU)** | `+5,041.06 ms` -> `+5,061.30 ms` | `Running` | **`20.11 ms`** *(8.05 + 7.93 + 4.14 ms)* | Attempt #3 `cpuIntensiveComputation(20)` |
| **6. Network Attempt #3 (Timeout)** | `+5,061.30 ms` -> `+7,062.09 ms` | `S` (Sleep) | **`2,000.80 ms`** | `performNetworkRequest(2000)` -> `Thread.sleep(2000)` (`return false`) |
| **7. Network Attempt #4 (CPU)** | `+7,062.15 ms` -> `+7,082.38 ms` | `Running` | **`20.22 ms`** | Attempt #4 `cpuIntensiveComputation(20)` |
| **8. Network Attempt #4 (Success)** | `+7,082.38 ms` -> `+7,783.16 ms` | `S` (Sleep) | **`700.78 ms`** | `performNetworkRequest(2000)` hits `Math.random() < 0.2`, sleeps `~700 ms`, `return true` |
| **9. Handle Response (CPU)** | `+7,783.21 ms` -> `+9,281.30 ms` | `Running` | **`1,479.68 ms`** *(across 6 slices)* | `handleNetworkResponse()` (`Trace.beginSection("handleNetworkResponse")` at `+7,783.44 ms`) runs `cpuIntensiveComputation(2000)` until trace ends |

---

## 3. Code Mapping (`ProfilingManagerJavaSnippets.java`)

In `ProfilingManagerJavaSnippets.java` (lines `38` and `158-221`), the `OnClickListener` for `R.id.submit` runs `onClickSubmit()` directly on the main UI thread:

```java
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() {
  // 1. Blocks main thread on CPU for 1,000 ms
  prepareNetworkRequest();

  // 2. Synchronous retry loop on main thread (up to 10 attempts * 2,020 ms = 20.2 seconds!)
  boolean networkRequestSuccess = false;
  int maxAttempts = 10;
  while (!networkRequestSuccess && maxAttempts > 0) {
    networkRequestSuccess = performNetworkRequest(NETWORK_TIMEOUT_MILLISECS);
    maxAttempts--;
  }

  // 3. Blocks main thread on CPU for another 2,000 ms
  if (networkRequestSuccess) {
    handleNetworkResponse();
  }
}

boolean performNetworkRequest(int timeoutMilliseconds) {
  cpuIntensiveComputation(20);
  try {
    if (Math.random() < 0.2) {
      // Simulate performing a network request by waiting a random period of time
      int networkRequestTimeMs = (int) (Math.random() * timeoutMilliseconds);
      Thread.sleep(networkRequestTimeMs);
      return true;
    } else {
      // Simulate a timeout
      Thread.sleep(timeoutMilliseconds);
    }
  } catch (InterruptedException e) {
  }
  return false;
}

void cpuIntensiveComputation(int durationMs) {
  long start = System.currentTimeMillis();
  while (System.currentTimeMillis() - start < durationMs) {
  }
}

void prepareNetworkRequest() {
  cpuIntensiveComputation(1000);
}

public void handleNetworkResponse() {
  Trace.beginSection("handleNetworkResponse");
  cpuIntensiveComputation(2000);
  Trace.endSection();
}
```

---

## 4. Recommended Remediation

> **Tip:** Never perform network I/O, `Thread.sleep()`, or multi-hundred-millisecond CPU computations on the Android main UI thread.

1. **Offload `onClickSubmit()` to a Background Thread / Coroutine:**
   * In Java, dispatch `prepareNetworkRequest()`, the `performNetworkRequest()` retry loop, and heavy response processing in `handleNetworkResponse()` to a background `ExecutorService` (e.g., `Executors.newSingleThreadExecutor()`), then marshal only lightweight UI updates back to the main thread via `runOnUiThread(...)` or `View.post(...)`.
   * In Kotlin, use `lifecycleScope.launch(Dispatchers.IO)` (for network waiting) and `withContext(Dispatchers.Default)` (for CPU-intensive preparation/parsing).
2. **Use Non-Blocking / Asynchronous Retries with Backoff:**
   * Avoid holding threads with `Thread.sleep()` inside tight retry loops; use asynchronous HTTP client timeouts/retries or `WorkManager` for deferrable background network tasks.