ทำความเข้าใจ Systrace

systrace เป็นเครื่องมือหลักในการวิเคราะห์ประสิทธิภาพของอุปกรณ์ Android แต่จริงๆ แล้วเครื่องมืออื่นๆ ก็สำคัญกว่า นี่คือ Wrapper ฝั่งโฮสต์ รอบๆ atrace ซึ่งเป็นไฟล์ปฏิบัติการฝั่งเซิร์ฟเวอร์ที่ควบคุมพื้นที่ผู้ใช้ การติดตามและตั้งค่า ftrace รวมถึงกลไกการติดตามหลักใน Linux เคอร์เนล systrace ใช้ Atrace เพื่อเปิดใช้การติดตาม จากนั้นจึงอ่านบัฟเฟอร์ ftrace และ จะรวมทุกอย่างไว้ในโปรแกรมดู HTML แบบในตัว (แม้ว่าเคอร์เนลใหม่ๆ จะรองรับ สำหรับ Linux Enhanced Berkeley PacketFilter (eBPF) เอกสารประกอบต่อไปนี้ ขึ้นอยู่กับเคอร์เนล 3.18 (ไม่มี eFPF) เนื่องจากเป็นภาษาที่ใช้ใน Pixel/Pixel XL)

systrace เป็นของทีม Google Android และ Google Chrome และ แบบโอเพนซอร์สในฐานะส่วนหนึ่งของ Catapult Project ใน นอกจาก Sytrace แล้ว Catapult ยังมียูทิลิตีอื่นๆ ที่มีประโยชน์อีกด้วย ตัวอย่างเช่น ftrace มีฟีเจอร์มากกว่าที่ Sytrace หรือ Atrace จะเปิดใช้ได้โดยตรงและ มีฟังก์ชันการทำงานขั้นสูงบางอย่างที่มีความสำคัญต่อการแก้ไขข้อบกพร่องของประสิทธิภาพ ปัญหา (ฟีเจอร์เหล่านี้ต้องมีสิทธิ์เข้าถึงรูทและมักเป็นเคอร์เนลใหม่)

เรียกใช้ Systrace

เมื่อแก้ไขข้อบกพร่องของ Jitter ใน Pixel/Pixel XL ให้เริ่มด้วยสิ่งต่อไปนี้ คำสั่ง:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

เมื่อใช้ร่วมกับจุดติดตามเพิ่มเติมที่จำเป็นสำหรับ GPU และการแสดงผล กิจกรรมในไปป์ไลน์ ซึ่งจะช่วยให้คุณติดตามจากอินพุตของผู้ใช้ไปยังเฟรมได้ แสดงบนหน้าจอ ตั้งค่าขนาดบัฟเฟอร์เป็นขนาดใหญ่เพื่อไม่ให้สูญหาย เหตุการณ์ (เนื่องจากหากไม่มีบัฟเฟอร์ขนาดใหญ่ CPU บางรายการไม่มีเหตุการณ์หลังจาก จุดใดจุดหนึ่งในการติดตาม)

เมื่อดำเนินการ Systrace โปรดทราบว่าทุกกิจกรรม ที่เกิดจากบางอย่างบน CPU

เนื่องจาก systrace สร้างขึ้นจาก ftrace และ ftrace ทำงานบน CPU สิ่งที่อยู่บน CPU ต้องเขียนบัฟเฟอร์เฟซเทรซที่บันทึกการเปลี่ยนแปลงของฮาร์ดแวร์ ซึ่งหมายความว่าหากคุณสงสัยว่าเหตุใดรั้วจอแสดงผลจึงเปลี่ยนสถานะ คุณได้ สามารถดูสิ่งที่ทำงานอยู่บน CPU ณ จุดที่มีการเปลี่ยนแปลง (มีบางอย่างทำงานบน CPU ซึ่งทริกเกอร์การเปลี่ยนแปลงในบันทึก) ช่วงเวลานี้ ซึ่งเป็นพื้นฐานของการวิเคราะห์ประสิทธิภาพโดยใช้ Systrace

ตัวอย่าง: กรอบการทำงาน

ตัวอย่างนี้อธิบาย Sytrace สำหรับไปป์ไลน์ UI ปกติ ฟีเจอร์ติดตาม ในตัวอย่าง ให้ดาวน์โหลดไฟล์ ZIP ของการติดตาม (ซึ่งรวมถึงการติดตามอื่นๆ ที่อ้างอิงถึงในส่วนนี้ด้วย) คลายการบีบอัดไฟล์ แล้วเปิดไฟล์ systrace_tutorial.html ในเบราว์เซอร์ รับคำเตือน ว่า systrace นี้เป็นไฟล์ขนาดใหญ่ เว้นแต่ว่าคุณจะใช้ Systrace ในแต่ละวัน การติดตามนี้ก็น่าจะเป็นการติดตาม ที่มีข้อมูลมากกว่าของคุณ อย่างที่ไม่เคยปรากฏมาก่อน

เพื่อภาระงานที่สม่ำเสมอและต่อเนื่อง เช่น TouchLatency, ไปป์ไลน์ UI มีข้อมูลต่อไปนี้

  1. EventThread ใน SurfaceFlinger จะปลุกเทรด UI ของแอปเพื่อส่งสัญญาณว่าได้เวลาแล้ว เพื่อแสดงผลเฟรมใหม่
  2. แอปแสดงเฟรมในเธรด UI, RenderThread และ hwuiTasks โดยใช้ CPU และ ทรัพยากร GPU นี่เป็นปริมาณสูงสุดของความจุที่ใช้สำหรับ UI
  3. แอปจะส่งเฟรมที่แสดงผลไปยัง SurfaceFlinger โดยใช้แฟ้ม จากนั้น SurfaceFlinger เข้าสู่โหมดสลีปแล้ว
  4. EventThread ที่ 2 ใน SurfaceFlinger จะเรียกให้ SurfaceFlinger ทริกเกอร์ การเรียบเรียงเพลงและการแสดงผล หาก SurfaceFlinger ระบุว่าไม่สามารถดำเนินการ ให้ทำได้ มันก็จะกลับสู่โหมดสลีป
  5. SurfaceFlinger จัดการการเรียบเรียงโดยใช้ฮาร์ดแวร์คอมโพสเซอร์ (HWC)/ฮาร์ดแวร์ Composer 2 (HWC2) หรือ GL องค์ประกอบ HWC/HWC2 เร็วขึ้นและพลังงานลดลง แต่มีข้อจำกัดโดยขึ้นอยู่กับระบบในชิป (SoC) โดยปกติขั้นตอนนี้จะใช้เวลาประมาณ 4-6 มิลลิวินาที แต่อาจซ้อนทับกับขั้นตอนที่ 2 เนื่องจาก Android จะมีบัฟเฟอร์ 3 ระดับเสมอ (แม้ว่าแอปจะถูกบัฟเฟอร์ 3 ครั้ง อาจเป็นเฟรมที่รอดำเนินการเพียงเฟรมเดียวใน SurfaceFlinger ซึ่งทำให้ปรากฏขึ้น เหมือนกับการบัฟเฟอร์คู่)
  6. SurfaceFlinger จะส่งผลลัพธ์สุดท้ายไปแสดงผลกับไดรเวอร์ผู้ให้บริการและดำเนินการต่อ กลับเข้าสู่โหมดสลีปเพื่อรอการปลุก EventThread

ลองดูรายละเอียดเฟรมเริ่มต้นที่ 15,409 มิลลิวินาที ดังนี้

ไปป์ไลน์ UI ปกติที่ EventThread ทำงานอยู่
รูปที่ 1 ไปป์ไลน์ UI ปกติ, EventThread กำลังทำงาน

รูปที่ 1 คือเฟรมปกติที่ล้อมรอบด้วยเฟรมปกติ ดังนั้นจึงเป็นรูปที่ จุดเริ่มต้นในการทำความเข้าใจวิธีการทำงานของไปป์ไลน์ UI แถวชุดข้อความ UI สำหรับ TouchLatency จะมีสีที่ต่างกันในแต่ละช่วงเวลา แท่งหมายถึง สถานะต่างๆ สำหรับชุดข้อความ:

  • สีเทา การนอนหลับ
  • สีน้ำเงิน เรียกใช้ได้ (เรียกใช้ได้ แต่เครื่องจัดตารางเวลาไม่ทำงาน) ยังไม่ได้เลือกให้แสดง)
  • เขียว ทำงานอยู่ (เครื่องจัดตารางเวลาคิดว่าถึงเวลาแล้ว ทำงานอยู่)
  • แดง การนอนหลับแบบไม่ขาดตอน (โดยทั่วไปจะนอนบนล็อก ในเคอร์เนล) อาจบ่งบอกถึงโหลด I/O มีประโยชน์อย่างยิ่งสำหรับการแก้ไขข้อบกพร่อง ปัญหาด้านประสิทธิภาพ
  • ส้ม การนอนหลับที่ต่อเนื่องเนื่องจากภาระของ I/O

หากต้องการดูเหตุผลของการนอนหลับอย่างไม่ขาดตอน (ดูข้อมูลได้จาก sched_blocked_reason จุดติดตาม) ให้เลือกประเภทเป็นการสำรองสีแดง สลีป

ขณะที่ EventThread ทำงานอยู่ เทรด UI สำหรับ TouchLatency จะเปลี่ยนไป เรียกใช้ได้ หากต้องการดูว่าอะไรปลุก ให้คลิกส่วนสีน้ำเงิน

ชุดข้อความ UI สำหรับ TouchLatency
รูปที่ 2 ชุดข้อความ UI สำหรับ TouchLatency

รูปที่ 2 แสดงให้เห็นว่าเธรด UI ของ TouchLatency ถูกทำให้ทำงานโดย tid 6843 ซึ่ง สอดคล้องกับ EventThread เธรด UI เริ่มทำงาน แสดงผลเฟรม และสร้างคิว เพื่อให้ SurfaceFlinger ใช้งาน

เทรด UI เริ่มทำงาน แสดงผลเฟรม และกำหนดคิวให้ SurfaceFlinger ใช้งาน
รูปที่ 3 เทรด UI ปลุก แสดงผลเฟรม และกำหนดคิว สำหรับ SurfaceFlinger จึงจะใช้งาน

หากเปิดใช้แท็ก binder_driver ในการติดตาม คุณจะเลือก ธุรกรรมการเชื่อมโยงเพื่อดูข้อมูลเกี่ยวกับกระบวนการทั้งหมดที่เกี่ยวข้อง ธุรกรรม

รูปที่ 4 ธุรกรรมการเชื่อมโยง

รูปที่ 4 แสดงให้เห็นว่า Binder:6832_1 ที่ 15,423.65 มิลลิวินาที จะเปลี่ยนสถานะเป็น สามารถเรียกใช้ได้เพราะ tid 9579 ซึ่งเป็น RenderThread ของ TouchLatency นอกจากนี้คุณยัง ดูQueueBuffer ที่ทั้ง 2 ฝั่งของธุรกรรม Binder

ระหว่างQueueBuffer ที่ฝั่ง SurfaceFlinger จำนวนที่รอดำเนินการ เฟรมจาก TouchLatency จะเริ่มจาก 1 ถึง 2

เฟรมที่รอดำเนินการจะเปลี่ยนจาก 1 เป็น 2
รูปที่ 5 เฟรมที่รอดำเนินการจะเปลี่ยนจาก 1 เป็น 2

รูปที่ 5 แสดงการบัฟเฟอร์ 3 ส่วน ซึ่งมีเฟรมที่เสร็จสมบูรณ์สองเฟรมและ แอปกำลังจะเริ่มแสดงผลเป็นภาพที่ 3 เนื่องจากเราได้ยกเลิกแล้ว บางเฟรม ดังนั้นแอปจะเก็บเฟรมที่รอดำเนินการ 2 เฟรมแทนที่จะเป็น 1 เฟรมเพื่อหลีกเลี่ยง เฟรมที่ลดลงเพิ่มเติม

หลังจากนั้นไม่นาน เทรดหลักของ SurfaceFlinger ก็ได้ทำงานด้วย EventThread ที่ 2 เฟรมนั้นจะแสดงเฟรมเก่าที่รอดำเนินการอยู่ได้:

เทรดหลักของ SurfaceFlinger ถูกปลุกด้วย EventThread ครั้งที่ 2
รูปที่ 6 เทรดหลักของ SurfaceFlinger ตื่นมา 1 วินาที ชุดข้อความกิจกรรม

SurfaceFlinger จะยึดบัฟเฟอร์เก่าที่รอดำเนินการอยู่ก่อน ซึ่งทำให้ จำนวนบัฟเฟอร์ที่รอดำเนินการลดลงจาก 2 เป็น 1

SurfaceFlinger จะยึดกับบัฟเฟอร์เก่าที่รอดำเนินการอยู่
รูปที่ 7 SurfaceFlinger ยึดไว้กับอันเก่าที่รอดำเนินการ บัฟเฟอร์

หลังจากสลักบัฟเฟอร์แล้ว SurfaceFlinger จะตั้งค่าองค์ประกอบและส่ง เฟรมสุดท้ายในจอแสดงผล (บางส่วนเหล่านี้มีการเปิดใช้ในฐานะ mdss ของการติดตาม ดังนั้นจุดเหล่านั้นอาจไม่รวมอยู่ใน SoC ของคุณ)

SurfaceFlinger ตั้งค่าองค์ประกอบและส่งเฟรมขั้นสุดท้าย
รูปที่ 8 SurfaceFlinger ตั้งค่าการเรียบเรียงและส่ง เฟรมสุดท้าย

ถัดไป mdss_fb0 ปลุกระบบด้วย CPU 0 mdss_fb0 คือ แสดงเธรดเคอร์เนลของไปป์ไลน์เพื่อแสดงผลเฟรมที่แสดงผลในจอแสดงผล เราจะเห็น mdss_fb0 เป็นแถวของตัวเองในการติดตาม (เลื่อนลงไปยัง มุมมอง)

mdss_fb0 เริ่มทำงานบน CPU 0
รูปที่ 9 mdss_fb0 เริ่มทำงานบน CPU 0

mdss_fb0 ตื่นขึ้น ทำงานเพียงครู่เดียว เข้าสู่การนอนหลับแบบไม่ขาดตอน แล้วปลุกอีกครั้ง

ตัวอย่าง: เฟรมไม่ทำงาน

ตัวอย่างนี้อธิบาย Sytrace ที่ใช้ในการแก้ไขข้อบกพร่อง Jitter ของ Pixel/Pixel XL ถึง ตามด้วยตัวอย่าง ดาวน์โหลดไฟล์ Zip ของการติดตาม (ซึ่งรวมถึงการติดตามอื่นๆ ที่อ้างถึงใน ) แตกไฟล์ และเปิดไฟล์ systrace_tutorial.html ใน เบราว์เซอร์

เมื่อเปิด Systrace คุณจะเห็นดังนี้

TouchLatency ทำงานบน Pixel XL ที่เปิดใช้ตัวเลือกส่วนใหญ่
รูปที่ 10 TouchLatency กำลังทำงานใน Pixel XL (ตัวเลือกส่วนใหญ่ เปิดใช้งาน รวมถึง MDS และ kgsl Trackpoints)

เมื่อค้นหาการกระตุก ให้ตรวจสอบแถว Frame missing ใต้ SurfaceFlinger การพลาดเฟรมคือการปรับปรุงคุณภาพชีวิตโดย HWC2 เมื่อดู Sytrace สำหรับอุปกรณ์อื่น แถว FrameNone อาจไม่แสดงในอุปกรณ์ ไม่ได้ใช้ HWC2 ใน ในกรณีนี้ Frame Missing จะสัมพันธ์กับ SurfaceFlinger ที่ไม่มี รันไทม์ที่สม่ำเสมอมากและจำนวนบัฟเฟอร์ที่รอดำเนินการอยู่ของแอป (com.prefabulated.touchlatency) ที่ vsync

สร้างความสัมพันธ์ที่ไม่ได้รับการจัดเฟรมกับ SurfaceFlinger
รูปที่ 11 สร้างความสัมพันธ์ที่ไม่ได้รับการจัดเฟรมกับ SurfaceFlinger

รูปที่ 11 แสดงเฟรมที่ไม่ได้รับที่ 15598.29&nbps มิลลิวินาที SurfaceFlinger ตื่นเป็นเวลาสั้นๆ เวลา ช่วง vsync และกลับเข้าสู่โหมดสลีปโดยไม่ดำเนินการใดๆ ซึ่งหมายความว่า SurfaceFlinger ระบุว่าไม่คุ้มค่าที่จะพยายามส่งเฟรมไปยังจอแสดงผล อีกครั้ง เหตุผล

หากต้องการทําความเข้าใจว่าไปป์ไลน์มีการแตกรายละเอียดอย่างไรสําหรับเฟรมนี้ ก่อนอื่นให้ตรวจสอบ ตัวอย่างเฟรมการทำงานด้านบนเพื่อดูว่าไปป์ไลน์ UI ปกติจะปรากฏใน Sytrace อย่างไร เมื่อพร้อมแล้ว ให้กลับไปยังเฟรมที่พลาดไปและทำงานย้อนหลัง โปรดสังเกตว่า SurfaceFlinger ตื่นและเข้าสู่โหมดสลีปทันที เมื่อดูจำนวน เฟรมที่รอดำเนินการจาก TouchLatency มี 2 เฟรม (มีข้อมูลที่ดี ดูว่าเกิดอะไรขึ้น)

SurfaceFlinger ตื่นและเข้าสู่โหมดสลีปทันที
รูปที่ 12 SurfaceFlinger ตื่นขึ้นและไปที่ การนอนหลับ

เนื่องจากเรามีเฟรมใน SurfaceFlinger ปัญหานี้ไม่ใช่ปัญหาของแอป นอกจากนี้ SurfaceFlinger ตื่นในเวลาที่ถูกต้อง จึงไม่ใช่ SurfaceFlinger ปัญหา หากทั้ง SurfaceFlinger และแอปดูปกติ นั่นอาจเป็นเพราะ ปัญหาไดรเวอร์

เนื่องจากมีการเปิดใช้จุดติดตาม mdss และ sync ทำให้เราสามารถหาข้อมูลเกี่ยวกับรั้วได้ (ซึ่งแบ่งปันระหว่างไดรเวอร์จอแสดงผลกับ SurfaceFlinger) ที่ควบคุมว่าจะส่งเฟรมไปยังจอแสดงผลเมื่อใด รั้วเหล่านี้อยู่ภายใต้ mdss_fb0_retire ซึ่ง หมายถึงเมื่อมีเฟรมอยู่บนจอแสดงผล รั้วเหล่านี้มีลักษณะดังนี้ ของหมวดหมู่การติดตาม sync รั้วที่สอดคล้องกับ บางเหตุการณ์ใน SurfaceFlinger จะขึ้นอยู่กับ SOC และสแต็กไดรเวอร์ของคุณ ทำงานร่วมกับผู้ให้บริการ SOC เพื่อทำความเข้าใจความหมายของหมวดหมู่รั้วใน การติดตาม

MDss_fb0_retire รั้ว
รูปที่ 13. mdss_fb0_reremove fences

รูปที่ 13 แสดงเฟรมที่แสดงผลเป็นเวลา 33 มิลลิวินาที ไม่ใช่ 16.7 มิลลิวินาทีตามที่คาดไว้ เมื่อผ่านไปครึ่งทางแล้ว เฟรมนั้นควรถูกแทนที่ด้วยเฟรมใหม่ แต่ไม่ได้ทำ ดูเฟรมก่อนหน้าและมองหาอะไรก็ได้

เฟรมก่อนหน้าไปยังเฟรมที่แตก
รูปที่ 14 เฟรมก่อนหน้าไปยังเฟรมที่แตก

รูปที่ 14 แสดงเฟรม 14.482 มิลลิวินาที กลุ่มแบบ 2 เฟรมที่เสียหายคือ 33.6 มิลลิวินาที ซึ่งใกล้เคียงกับที่คาดไว้สำหรับ 2 เฟรม (เราแสดงผลที่ 60 Hz หรือ 16.7 มิลลิวินาที ต่อเฟรม ซึ่งใกล้เคียงกัน) แต่ 14.482 มิลลิวินาทีกลับไม่ใกล้เคียงกับ 16.7 มิลลิวินาทีเลย แสดงว่ามีสิ่งผิดปกติอย่างมากกับท่อแสดงผล

ให้ตรวจสอบว่ารั้วสิ้นสุดลงตรงไหนเพื่อกำหนดว่าจะให้อะไรควบคุม

ตรวจสอบจุดสิ้นสุดของรั้ว
รูปที่ 15 ตรวจสอบจุดสิ้นสุดของรั้ว

คิวงานประกอบด้วย __vsync_retire_work_handler ซึ่งก็คือ ทำงานเมื่อรั้วเปลี่ยนไป เมื่อดูแหล่งที่มาของเคอร์เนลแล้ว คุณจะเห็นว่า เป็นส่วนหนึ่งของไดรเวอร์จอแสดงผล ดูเหมือนว่าจะอยู่ในช่วงวิกฤต สำหรับไปป์ไลน์การแสดงผล เส้นทางจึงต้องทำงานโดยเร็วที่สุด ตอนนี้ ประมาณ 70 USD โดยประมาณ (ความล่าช้าในการกำหนดเวลาที่นาน) แต่เป็นคิวงานและ อาจไม่ได้รับการกำหนดเวลาอย่างถูกต้อง

ตรวจสอบเฟรมก่อนหน้าเพื่อพิจารณาว่ามีส่วนนั้นหรือไม่ รบกวนบางครั้ง อาจเพิ่มขึ้นเมื่อเวลาผ่านไปและอาจทำให้ส่งไม่ทันก็ได้

เฟรมก่อนหน้า
รูปที่ 16 เฟรมก่อนหน้า

บรรทัดที่เรียกใช้ได้บน kworker ไม่ปรากฏเนื่องจากผู้ชมหมุน สีขาวเมื่อเลือกเส้นตั้งเวลา แต่สถิติจะแสดงถึง: 2.3 มิลลิวินาที ของตัวจัดตารางเวลา การหน่วงเวลาในเส้นทางที่สำคัญของไปป์ไลน์โฆษณาแบบดิสเพลย์บางส่วนไม่ดี ก่อนดำเนินการต่อ ให้แก้ไขความล่าช้าที่ด้วยการย้ายส่วนนี้ของ แสดงเส้นทางวิกฤตของไปป์ไลน์จากคิวงาน (ซึ่งทำงานเป็น SCHED_OTHER ชุดข้อความ CFS) ไปยัง SCHED_FIFO เฉพาะ kthread ฟังก์ชันนี้ต้องใช้การกำหนดเวลาเพื่อรับประกันว่าคิวงานจะทำไม่ได้ (และไม่ได้ ที่มีจุดมุ่งหมาย)

นี่เป็นสาเหตุของการกระตุกหรือไม่ ยากที่จะบอกข้อสรุปได้ยาก นอก กรณีที่วินิจฉัยได้ง่าย เช่น การช่วงชิงล็อกเคอร์เนล ที่ก่อให้เกิดการแสดงผลที่ร้ายแรง เทรดที่จะเข้าสู่โหมดสลีป การติดตามมักจะไม่ระบุปัญหา ความกระตุกนี้อาจเป็นสาเหตุของเฟรมที่ตกลงมาหรือไม่ แน่นอน เวลาของรั้วควรเป็น 16.7 มิลลิวินาที แต่ไม่ใกล้เคียงกับเวลาดังกล่าวเลยในเฟรม ที่จะนำไปยังเฟรมที่ตกลงมา โดยพิจารณาจากความเชื่อมโยงระหว่างไปป์ไลน์การแสดงผล อาจเป็นไปได้ว่าสัญญาณรบกวนรอบรั้วทำให้กราฟตกลง เฟรม

ในตัวอย่างนี้ต้องใช้โซลูชันการแปลง __vsync_retire_work_handler จากคิวงานไปยัง kthread ซึ่งส่งผลให้มีการปรับปรุง Jitter อย่างเห็นได้ชัดและลดการกระตุกใน ที่กระเด้งลูกบอล การติดตามที่ตามมาจะแสดงเวลาของรั้วที่วางอยู่ใกล้ๆ มาก ถึง 16.7 มิลลิวินาที