Ví dụ thực tế về gỡ lỗi hiệu suất: ANR

Phần này trình bày cách gỡ lỗi Ứng dụng không phản hồi (ANR) bằng ProfilingManager kèm theo một dấu vết ví dụ.

Thiết lập ứng dụng để thu thập lỗi ANR

Bắt đầu bằng cách thiết lập một điều kiện kích hoạt lỗi ANR trong ứng dụng:

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

Sau khi ghi lại và tải dấu vết ANR lên, hãy mở dấu vết đó trong Giao diện người dùng Perfetto.

Phân tích dấu vết

Vì lỗi ANR đã kích hoạt dấu vết, nên bạn biết dấu vết kết thúc khi hệ thống phát hiện thấy luồng chính của ứng dụng không phản hồi. Hình 1 cho thấy cách chuyển đến luồng chính của ứng dụng được gắn thẻ tương ứng trong giao diện người dùng.

Thời gian kết thúc dấu vết trùng với dấu thời gian của lỗi ANR, như trong Hình 2.

Dấu vết này cũng cho thấy các thao tác mà ứng dụng đang chạy khi xảy ra lỗi ANR. Cụ thể, ứng dụng đã chạy mã trong lát theo dõi handleNetworkResponse. Lát này nằm trong lát MyApp:SubmitButton. Thao tác này mất 1,48 giây thời gian CPU (Hình 3).

Nếu chỉ dựa vào dấu vết ngăn xếp tại thời điểm xảy ra lỗi ANR để gỡ lỗi, bạn có thể nhầm lẫn khi cho rằng lỗi ANR hoàn toàn là do mã đang chạy trong lát cắt dấu vết handleNetworkResponse chưa kết thúc khi hồ sơ hoàn tất quá trình ghi. Tuy nhiên, 1,48 giây là không đủ để tự kích hoạt lỗi ANR, mặc dù đây là một thao tác tốn nhiều tài nguyên. Bạn cần xem xét khoảng thời gian trước đó để hiểu rõ điều gì đã chặn luồng chính trước phương thức này.

Để nắm bắt điểm bắt đầu tìm nguyên nhân gây ra lỗi ANR, chúng ta bắt đầu tìm kiếm sau khung hình cuối cùng do luồng giao diện người dùng tạo ra, tương ứng với lát Choreographer#doFrame 551275 và không có nguồn gây ra độ trễ lớn nào trước khi bắt đầu lát MyApp:SubmitButton kết thúc bằng lỗi ANR (Hình 4).

Để hiểu rõ hơn về tình trạng tắc nghẽn, hãy thu nhỏ để kiểm tra toàn bộ lát cắt MyApp:SubmitButton. Bạn sẽ nhận thấy một chi tiết quan trọng trong trạng thái của luồng, như minh hoạ trong Hình 4: luồng đã dành 75% thời gian (6,7 giây) ở trạng thái Sleeping và chỉ 24% thời gian ở trạng thái Running.

Điều này cho thấy nguyên nhân chính gây ra lỗi ANR là do chờ đợi, chứ không phải do tính toán. Xem xét từng lần ngủ để tìm ra một quy luật.

3 khoảng thời gian ngủ đầu tiên (Hình 6 – 8) gần như giống hệt nhau, mỗi khoảng thời gian khoảng 2 giây. Giấc ngủ thứ tư bất thường (Hình 9) là 0,7 giây. Thời lượng chính xác là 2 giây hiếm khi là một sự trùng hợp ngẫu nhiên trong môi trường điện toán. Điều này cho thấy rõ ràng là đã có thời gian chờ được lập trình thay vì xảy ra tình trạng tranh chấp tài nguyên ngẫu nhiên. Lần ngủ gần đây nhất có thể là do luồng đã hoàn tất quá trình chờ vì thao tác mà luồng đang chờ đã thành công.

Giả thuyết này cho rằng ứng dụng đã đạt đến thời gian chờ do người dùng xác định là 2 giây nhiều lần và cuối cùng thành công, gây ra đủ độ trễ để kích hoạt lỗi ANR.

Để xác minh điều này, hãy kiểm tra mã được liên kết với phần dấu vết 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

Mã này xác nhận giả thuyết này. Phương thức onClickSubmit thực thi một yêu cầu mạng trên luồng giao diện người dùng với NETWORK_TIMEOUT_MILLISECS được mã hoá cứng là 2000 mili giây. Điều quan trọng là vòng lặp này chạy trong vòng lặp while và thử lại tối đa 10 lần.

Trong dấu vết cụ thể này, người dùng có thể có kết nối mạng kém. Ba lần thử đầu tiên không thành công, dẫn đến 3 lần hết thời gian chờ 2 giây (tổng cộng là 6 giây). Lần thử thứ tư thành công sau 0,7 giây, cho phép mã chuyển sang handleNetworkResponse. Tuy nhiên, thời gian chờ tích luỹ đã kích hoạt lỗi ANR.

Tránh loại lỗi ANR này bằng cách đưa các thao tác liên quan đến mạng có độ trễ khác nhau vào một luồng nền thay vì thực thi chúng trong luồng chính. Điều này giúp giao diện người dùng vẫn phản hồi ngay cả khi kết nối kém, hoàn toàn loại bỏ lớp ANR này.