Pratik performans hata ayıklama örneği: ANR

Bu bölümde, örnek bir izleme ile ProfilingManager kullanılarak Uygulama Yanıt Vermiyor (ANR) hatasının nasıl ayıklanacağı gösterilmektedir.

Uygulamayı ANR'leri toplayacak şekilde ayarlama

Uygulamanızda ANR tetikleyicisi oluşturarak başlayın:

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);
}

ANR izini yakalayıp yükledikten sonra Perfetto kullanıcı arayüzünde açın.

İzlemeyi analiz etme

ANR, izlemeyi tetiklediğinden izlemenin, sistem uygulamanızın ana iş parçacığında yanıt vermeme durumunu algıladığında sona erdiğini bilirsiniz. Şekil 1'de, uygulamanızın kullanıcı arayüzünde uygun şekilde etiketlenmiş olan ana iş parçacığına nasıl gidileceği gösterilmektedir.

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

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

Bir izlemenin sonunu gösteren Perfetto kullanıcı arayüzü. ANR tetikleyici konumu vurgulanmıştır.
Şekil 2. ANR tetikleme konumu.

İzleme, ANR oluştuğunda uygulamanın çalıştırdığı işlemleri de gösterir. Özellikle uygulama, handleNetworkResponse iz diliminde kod çalıştırdı. Bu dilim, MyApp:SubmitButton diliminin içindeydi. 1,48 saniyelik CPU süresi kullanıldı (Şekil 3).

ANR sırasında handleNetworkResponse yürütmesi tarafından kullanılan CPU süresini gösteren Perfetto kullanıcı arayüzü.
Şekil 3. ANR sırasında yürütme.

Hata ayıklama için şu anda yalnızca ANR anındaki yığın izlemelere güveniyorsanız ANR'yi tamamen, profil kaydı tamamlandığında sona ermemiş olan handleNetworkResponse izleme diliminde çalışan koda yanlış bir şekilde atfedebilirsiniz. Ancak, pahalı bir işlem olmasına rağmen 1, 48 saniye tek başına ANR'yi tetiklemek için yeterli değildir. Bu yöntemden önce ana iş parçacığını neyin engellediğini anlamak için daha geriye bakmanız gerekir.

ANR'nin nedenini aramak için bir başlangıç noktası belirlemek üzere, Choreographer#doFrame 551275 dilimine karşılık gelen kullanıcı arayüzü iş parçacığı tarafından oluşturulan son kareyi incelemeye başlıyoruz. ANR ile sonuçlanan MyApp:SubmitButton dilimi başlatılmadan önce büyük gecikme kaynakları yok (Şekil 4).

ANR&#39;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 çerçevesi.

Engellemeyi anlamak için uzaklaştırarak MyApp:SubmitButton diliminin tamamını inceleyin. Şekil 4'te gösterildiği gibi, iş parçacığı durumlarında önemli bir ayrıntı fark edeceksiniz: İş parçacığı, zamanın% 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, ANR'nin temel nedeninin hesaplama değil, bekleme olduğunu gösterir. Bir düzen bulmak için uyku zamanlarını tek tek inceleyin.

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

İlk üç uyku aralığı (Şekil 6-8) neredeyse aynıdır ve her biri yaklaşık 2 saniye sürer. Aykırı değer olan dördüncü uyku (Şekil 9) 0,7 saniyedir. Tam olarak 2 saniyelik bir süre, bilgi işlem ortamında nadiren tesadüf olur. Bu durum, rastgele kaynak çekişmesinden ziyade programlanmış bir zaman aşımının söz konusu olduğunu gösterir. Son uyku, beklediği işlem başarılı olduğu için ileti dizisinin bekleme işlemini tamamlamasından kaynaklanıyor olabilir.

Bu hipoteze göre uygulama, kullanıcı tarafından tanımlanan 2 saniyelik zaman aşımına birden fazla kez ulaşıyor ve sonunda başarılı oluyordu. Bu durum, ANR'yi tetikleyecek kadar gecikmeye neden oluyordu.

MyApp:SubmitButton izleme dilimi sırasında gecikmelerin özetini gösteren Perfetto kullanıcı arayüzü. Bu özet, 2 saniyelik birden fazla uyku aralığı olduğunu belirtiyor.
Şekil 10. `MyApp:SubmitButton` dilimindeki gecikmelerin özeti.

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

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();
}

Kod, bu hipotezi doğrular. onClickSubmit yöntemi, kullanıcı arayüzü iş parçacığında 2.000 ms'lik sabit kodlanmış bir NETWORK_TIMEOUT_MILLISECS ile ağ isteği yürütür. Önemli olarak, 10 kez yeniden deneme yapan bir while döngüsünde çalışır.

Bu özel izlemede, kullanıcının ağ bağlantısı muhtemelen zayıftı. İlk üç deneme başarısız oldu ve bu nedenle üç 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 işlemine devam etmesine izin verildi. Ancak birikmiş bekleme süresi, ANR'yi zaten tetiklemişti.

Çeşitli gecikme sürelerine sahip ağla ilgili işlemleri ana iş parçacığında yürütmek yerine arka plan iş parçacığına yerleştirerek bu tür ANR'lerden kaçının. Bu sayede, bağlantı zayıf olsa bile kullanıcı arayüzü yanıt vermeye devam eder ve bu tür ANR'ler tamamen ortadan kalkar.