ตัวอย่างการแก้ไขข้อบกพร่องด้านประสิทธิภาพในทางปฏิบัติ: 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);
}

หลังจากบันทึกและอัปโหลดการติดตาม ANR แล้ว ให้เปิดการติดตามใน UI ของ Perfetto

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

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

การนำทาง UI ของ Perfetto ไปยังเทรดหลักของแอป
รูปที่ 1 การไปยังเทรดหลักของแอป

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

UI ของ Perfetto แสดงจุดสิ้นสุดของการติดตาม โดยไฮไลต์ตำแหน่งทริกเกอร์ ANR
รูปที่ 2 ตำแหน่งทริกเกอร์ ANR

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

UI ของ Perfetto แสดงเวลา CPU ที่ใช้โดยการดำเนินการ handleNetworkResponse
 ในช่วงเวลาที่เกิด ANR
รูปที่ 3 การดำเนินการ ณ เวลาที่เกิด ANR

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

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

UI ของ Perfetto แสดงเฟรมสุดท้ายที่เธรด UI แสดงผลก่อนเกิด ANR
รูปที่ 4 เฟรมแอปสุดท้ายที่สร้างขึ้นก่อนเกิด ANR

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

UI ของ Perfetto แสดงสถานะของเธรดระหว่างการดำเนินการ โดยไฮไลต์เวลาที่เธรดอยู่ในสถานะพัก 75%
 และเวลาที่เธรดอยู่ในสถานะทำงาน 24%
รูปที่ 5 สถานะของเทรดระหว่างการดำเนินการ `MyApp:SubmitButton`

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

UI ของ Perfetto แสดงช่วงเวลาที่หยุดทำงานแรกภายใน
 MyAppSubmitButton trace slice
รูปที่ 6 เวลานอนหลับครั้งแรกภายใน `MyAppSubmitButton`
UI ของ Perfetto แสดงช่วงเวลาที่ 2 ของการหยุดทำงานภายใน
 ส่วนการติดตาม MyAppSubmitButton
รูปที่ 7 เวลานอนหลับครั้งที่ 2 ภายใน `MyAppSubmitButton`
UI ของ Perfetto แสดงช่วงเวลาที่ 3 ที่แอปเข้าสู่โหมดสลีปภายใน
 MyAppSubmitButton trace slice
รูปที่ 8 เวลานอนหลับครั้งที่ 3 ภายใน `MyAppSubmitButton`
UI ของ Perfetto แสดงช่วงเวลาที่ 4 ที่แอปเข้าสู่โหมดสลีปภายใน
 ส่วนการติดตาม MyAppSubmitButton
รูปที่ 9 เวลานอนหลับครั้งที่ 4 ภายใน `MyAppSubmitButton`

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

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

UI ของ Perfetto แสดงข้อมูลสรุปของความล่าช้าระหว่างส่วนการติดตาม MyApp:SubmitButton
 ซึ่งบ่งบอกถึงช่วงเวลาหยุดทำงาน 2 วินาทีหลายช่วง
รูปที่ 10 สรุปความล่าช้าระหว่างสไลซ์ `MyApp:SubmitButton`

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


void prepareNetworkRequest() {
  // ...
}

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

โค้ดยืนยันสมมติฐานนี้ เมธอด onClickSubmit จะดำเนินการคำขอเครือข่ายในเทรด UI โดยมี NETWORK_TIMEOUT_MILLISECS ที่ฮาร์ดโค้ดไว้ 2000 มิลลิวินาที ที่สำคัญคือเมธอดนี้ทำงานภายในลูป while ที่ลองใหม่ได้สูงสุด 10 ครั้ง

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

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