Exemple pratique de débogage des performances : ANR

Cette section explique comment déboguer une erreur Application Not Responding (ANR) à l'aide de ProfilingManager avec un exemple de trace.

Configurer l'application pour collecter les ANR

Commencez par configurer un déclencheur ANR dans votre application :

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

Après avoir capturé et importé une trace ANR, ouvrez-la dans l'interface utilisateur de Perfetto.

Analyser la trace

Étant donné que l'ANR a déclenché la trace, vous savez que la trace s'est terminée lorsque le système a détecté un manque de réactivité dans le thread principal de votre application. La figure 1 montre comment accéder au thread principal de votre application, qui est tagué en conséquence dans l'UI.

La fin de la trace correspond au code temporel de l'ANR, comme illustré sur la figure 2.

La trace indique également les opérations que l'application exécutait lorsque l'ANR s'est produite. Plus précisément, l'application a exécuté du code dans la tranche de trace handleNetworkResponse. Cette tranche se trouvait dans la tranche MyApp:SubmitButton. Il a utilisé 1,48 seconde de temps CPU (figure 3).

Si vous vous fiez uniquement aux traces de pile au moment de l'ANR pour le débogage, vous risquez d'attribuer à tort l'ANR entièrement au code s'exécutant dans la tranche de trace handleNetworkResponse qui n'était pas terminée lorsque l'enregistrement du profil a pris fin. Toutefois, 1,48 seconde ne suffit pas à déclencher un ANR à elle seule, même s'il s'agit d'une opération coûteuse. Vous devez remonter plus loin dans le temps pour comprendre ce qui a bloqué le thread principal avant cette méthode.

Pour trouver la cause de l'ANR, nous commençons à chercher après le dernier frame généré par le thread UI, qui correspond à la tranche Choreographer#doFrame 551275. Il n'y a pas de grandes sources de retard avant le début de la tranche MyApp:SubmitButton qui s'est terminée par l'ANR (figure 4).

Pour comprendre le blocage, effectuez un zoom arrière afin d'inspecter l'intégralité de la tranche MyApp:SubmitButton. Vous remarquerez un détail essentiel dans les états des threads, comme illustré à la figure 4 : le thread a passé 75 % du temps (6,7 secondes) dans l'état Sleeping et seulement 24 % du temps dans l'état Running.

Cela indique que la cause principale de l'ANR était l'attente, et non le calcul. Examinez les occurrences de sommeil individuelles pour identifier une tendance.

Les trois premiers intervalles de veille (figures 6 à 8) sont presque identiques et durent environ deux secondes chacun. La quatrième période de sommeil aberrante (figure 9) est de 0,7 seconde. Dans un environnement informatique, une durée de deux secondes exactement est rarement une coïncidence. Cela suggère fortement un délai d'expiration programmé plutôt qu'une contention de ressources aléatoire. Le dernier état de veille peut être dû au fait que le thread a terminé son attente, car l'opération qu'il attendait a réussi.

L'hypothèse est que l'application a atteint plusieurs fois un délai d'inactivité de deux secondes défini par l'utilisateur et a fini par réussir, ce qui a entraîné un délai suffisant pour déclencher une ANR.

Pour le vérifier, inspectez le code associé à la section de trace 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

Le code confirme cette hypothèse. La méthode onClickSubmit exécute une requête réseau sur le thread UI avec un NETWORK_TIMEOUT_MILLISECS codé en dur de 2 000 ms. Il est important de noter qu'il s'exécute dans une boucle while qui effectue jusqu'à 10 nouvelles tentatives.

Dans cette trace spécifique, l'utilisateur avait probablement une mauvaise connectivité réseau. Les trois premières tentatives ont échoué, ce qui a entraîné trois délais avant expiration de deux secondes (soit six secondes au total). La quatrième tentative a réussi après 0,7 seconde, ce qui a permis au code de passer à handleNetworkResponse. Toutefois, le temps d'attente cumulé a déjà déclenché l'ANR.

Pour éviter ce type d'ANR, placez les opérations liées au réseau dont la latence varie dans un thread d'arrière-plan au lieu de les exécuter dans le thread principal. L'UI reste ainsi réactive même en cas de mauvaise connectivité, ce qui élimine complètement cette catégorie d'ANR.