ทําความเข้าใจ systrace

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

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

เรียกใช้ Systrace

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

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

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

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

สำหรับภาระงานที่สอดคล้องกันและเป็นระยะๆ เช่น TouchLatency ไปป์ไลน์ UI จะทำตามลำดับต่อไปนี้

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

ตัวอย่างลำดับเฟรมที่เริ่มต้นที่ 15409 มิลลิวินาที

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

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

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

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

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

รูปที่ 2 เธรด UI สำหรับ TouchLatency

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

รูปที่ 3 เธรด UI จะตื่นขึ้น แสดงผลเฟรม และจัดคิวให้ SurfaceFlinger ใช้

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

รูปที่ 4 ธุรกรรมการผูก

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

ในระหว่าง queueBuffer ที่ฝั่ง SurfaceFlinger จำนวนเฟรมที่รอดำเนินการ จาก TouchLatency จะเปลี่ยนจาก 1 เป็น 2

รูปที่ 5 เฟรมที่รอดำเนินการจะเริ่มจาก 1 ถึง 2

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

หลังจากนั้นไม่นาน เทรดหลักของ SurfaceFlinger จะถูกปลุกโดย EventThread ที่ 2 เพื่อให้สามารถแสดงเฟรมที่รอดำเนินการก่อนหน้าได้

รูปที่ 6 EventThread ที่ 2 จะปลุกเทรดหลักของ SurfaceFlinger

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

รูปที่ 7 SurfaceFlinger จะเชื่อมต่อกับบัฟเฟอร์ที่รอดำเนินการที่เก่ากว่าก่อน

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

รูปที่ 8 SurfaceFlinger จะตั้งค่าการคอมโพสิตและส่งเฟรมสุดท้าย

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

รูปที่ 9. mdss_fb0 ตื่นขึ้นใน CPU 0

mdss_fb0 ตื่นขึ้นมา ทำงานในระยะเวลาสั้นๆ เข้าสู่โหมดสลีปที่ขัดจังหวะไม่ได้ แล้วตื่นขึ้นมาอีกครั้ง

ตัวอย่าง: เฟรมที่ไม่ได้ใช้งาน

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

เมื่อเปิด Systrace คุณจะเห็นข้อมูลคล้ายกับรูปที่ 1

รูปที่ 10 TouchLatency ทำงานบน Pixel XL โดยเปิดใช้ตัวเลือกส่วนใหญ่

ในรูปที่ 10 ตัวเลือกส่วนใหญ่เปิดใช้อยู่ รวมถึงจุดติดตาม mdss และ kgsl

เมื่อมองหา Jank ให้ตรวจสอบแถว FrameMissed ใน SurfaceFlinger FrameMissed เป็นการปรับปรุงคุณภาพชีวิตที่ HWC2 มอบให้ เมื่อดู systrace สำหรับอุปกรณ์อื่นๆ แถว FrameMissed อาจไม่ปรากฏหากอุปกรณ์ไม่ได้ใช้ HWC2 ไม่ว่าจะในกรณีใด FrameMissed จะสัมพันธ์กับการที่ SurfaceFlinger พลาดรันไทม์ปกติอย่างใดอย่างหนึ่ง และจำนวนบัฟเฟอร์ที่รอดำเนินการของแอปไม่เปลี่ยนแปลง (com.prefabulated.touchlatency) ที่ VSync

รูปที่ 11 ความสัมพันธ์ของ FrameMissed กับ SurfaceFlinger

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

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

รูปที่ 12 SurfaceFlinger จะปลุกและเข้าสู่โหมดสลีปทันที

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

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

รูปที่ 13 รั้ว mdss_fb0_retire

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

รูปที่ 14 เฟรมก่อนหน้าเฟรมที่ถูกจับได้

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

ตรวจสอบว่ารั้วสิ้นสุดที่ใดเพื่อพิจารณาว่าอะไรเป็นตัวควบคุมรั้ว

รูปที่ 15 ตรวจสอบปลายรั้ว

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

ตรวจสอบเฟรมก่อนหน้าเพื่อดูว่ามีส่วนทำให้เกิดปัญหาหรือไม่ บางครั้งความกระตุก อาจสะสมไปเรื่อยๆ และทำให้พลาดกำหนดเวลาในที่สุด

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

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

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

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