ตัวอย่างการแก้ไขข้อบกพร่องด้านประสิทธิภาพในทางปฏิบัติ: ANR

ส่วนนี้แสดงวิธีแก้ไขข้อบกพร่องของแอปพลิเคชันไม่ตอบสนอง (ANR) โดยใช้ ProfilingManager พร้อมตัวอย่างการติดตาม

ตั้งค่าแอปเพื่อรวบรวม 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 แล้ว ให้เปิดใน UI ของ Perfetto

วิเคราะห์การติดตาม

เนื่องจาก ANR ทริกเกอร์การติดตาม คุณจึงทราบว่าการติดตามสิ้นสุดลงเมื่อระบบ ตรวจพบว่าแอปไม่ตอบสนองในเทรดหลัก รูปที่ 1 แสดงวิธี ไปยังเธรดหลักของแอปซึ่งมีการติดแท็กตามนั้นภายใน UI

จุดสิ้นสุดของการติดตามตรงกับการประทับเวลาของ ANR ดังที่แสดงในรูปที่ 2

นอกจากนี้ การติดตามยังแสดงการดำเนินการที่แอปกำลังเรียกใช้เมื่อเกิด ANR ด้วย กล่าวโดยละเอียดคือ แอปเรียกใช้โค้ดในhandleNetworkResponse Trace Slice โดยสไลซ์นี้อยู่ภายในสไลซ์ MyApp:SubmitButton โดยใช้เวลา CPU 1.48 วินาที (รูปที่ 3)

หากคุณอาศัยสแต็กเทรซเพียงอย่างเดียวในขณะที่เกิด ANR เพื่อการแก้ไขข้อบกพร่อง คุณอาจระบุสาเหตุของ ANR ผิดพลาดทั้งหมดให้กับโค้ดที่ทำงานภายในhandleNetworkResponseสไลซ์การติดตามซึ่งยังไม่สิ้นสุดเมื่อโปรไฟล์บันทึกเสร็จ อย่างไรก็ตาม เวลา 1.48 วินาทีไม่เพียงพอที่จะทําให้เกิด ANR ด้วยตัวเอง แม้ว่าจะเป็นการดําเนินการที่มีค่าใช้จ่ายสูงก็ตาม คุณต้องย้อนเวลากลับไปดูเพื่อทำความเข้าใจว่าอะไร บล็อกเทรดหลักก่อนหน้านี้

หากต้องการหาจุดเริ่มต้นในการหาสาเหตุของ ANR เราจะเริ่มมองหา หลังจากเฟรมสุดท้ายที่สร้างโดยเทรด UI ซึ่งสอดคล้องกับ สไลซ์ Choreographer#doFrame 551275 และไม่มีแหล่งที่มาขนาดใหญ่ที่ทำให้เกิดความล่าช้าก่อน ที่จะเริ่มสไลซ์ MyApp:SubmitButton ที่สิ้นสุดด้วย ANR (รูปที่ 4)

หากต้องการทำความเข้าใจการอุดตัน ให้ซูมออกเพื่อตรวจสอบMyApp:SubmitButton ชิ้นเต็ม คุณจะเห็นรายละเอียดที่สำคัญในสถานะของเธรด ดังที่แสดงใน รูปที่ 4: เธรดใช้เวลา 75% (6.7 วินาที) ในสถานะ Sleeping และใช้เวลาเพียง 24% ในสถานะ Running

ซึ่งบ่งชี้ว่าสาเหตุหลักของ ANR คือการรอ ไม่ใช่การคำนวณ ตรวจสอบการนอนหลับแต่ละครั้งเพื่อหารูปแบบ

ช่วงการนอนหลับ 3 ช่วงแรก (รูปที่ 6-8) แทบจะเหมือนกัน โดยแต่ละช่วงยาวประมาณ 2 วินาที การนอนหลับครั้งที่ 4 ที่อยู่นอกค่าผิดปกติ (รูปที่ 9) คือ 0.7 วินาที ระยะเวลา 2 วินาทีตรงๆ นั้นแทบจะไม่ใช่เรื่องบังเอิญในสภาพแวดล้อมการประมวลผล ซึ่งบ่งชี้อย่างชัดเจนว่าเป็นการหมดเวลาที่ตั้งโปรแกรมไว้ ไม่ใช่การแย่งชิงทรัพยากรแบบสุ่ม การหยุดทำงานครั้งล่าสุดอาจเกิดจากเทรดที่สิ้นสุดการ รอเนื่องจากการดำเนินการที่รออยู่สำเร็จ

สมมติฐานนี้คือแอปถึงระยะหมดเวลาที่ผู้ใช้กำหนดไว้ที่ 2 วินาทีหลายครั้งและในที่สุดก็สำเร็จ ซึ่งทำให้เกิดความล่าช้ามากพอที่จะทําให้เกิด ANR

หากต้องการยืนยัน ให้ตรวจสอบโค้ดที่เชื่อมโยงกับส่วนร่องรอย 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 ครั้ง

ในการติดตามนี้ ผู้ใช้น่าจะมีการเชื่อมต่อเครือข่ายที่ไม่ดี ความพยายาม 3 ครั้งแรกไม่สำเร็จ ทำให้เกิดการหมดเวลา 2 วินาที 3 ครั้ง (รวมเป็น 6 วินาที) ความพยายามครั้งที่ 4 สำเร็จหลังจากผ่านไป 0.7 วินาที ทำให้โค้ดดำเนินการต่อไปยัง handleNetworkResponse ได้ อย่างไรก็ตาม เวลารอที่สะสมไว้ได้ทริกเกอร์ ANR แล้ว

หลีกเลี่ยง ANR ประเภทนี้โดยใส่การดำเนินการที่เกี่ยวข้องกับเครือข่ายซึ่งมีความหน่วงแปรผัน ไว้ในเทรดเบื้องหลังแทนที่จะดำเนินการในเทรดหลัก ซึ่งจะช่วยให้ UI ตอบสนองได้แม้การเชื่อมต่อจะไม่ดี และช่วย ขจัด ANR ประเภทนี้ออกไปโดยสิ้นเชิง