systrace เป็นเครื่องมือหลักในการวิเคราะห์ประสิทธิภาพของอุปกรณ์ Android แต่จริงๆ แล้วเป็นเครื่องมือสำหรับรวมเครื่องมืออื่นๆ ซึ่งเป็นเครื่องมือบรรทัดคำสั่งฝั่งโฮสต์สำหรับ atrace ซึ่งเป็นไฟล์ปฏิบัติการฝั่งอุปกรณ์ที่ควบคุมการติดตามพื้นที่ผู้ใช้และตั้งค่า ftrace รวมถึงกลไกการติดตามหลักในเคอร์เนล Linux โดย systrace จะใช้ atrace เพื่อเปิดใช้การติดตาม จากนั้นจะอ่านบัฟเฟอร์ ftrace และรวมข้อมูลทั้งหมดไว้ในโปรแกรมดู HTML แบบสแตนด์อโลน (แม้ว่าเคอร์เนลเวอร์ชันใหม่จะรองรับตัวกรองแพ็กเก็ต Berkeley ที่ปรับปรุงแล้ว (eBPF) ของ Linux แต่เอกสารประกอบต่อไปนี้เกี่ยวข้องกับเคอร์เนล 3.18 (ไม่มี eFPF) เนื่องจากเป็นเวอร์ชันที่ใช้ใน Pixel/Pixel XL)
systrace เป็นของทีม Google Android และ Google Chrome และเป็นโอเพนซอร์สโดยเป็นส่วนหนึ่งของโปรเจ็กต์ Catapult นอกจาก systrace แล้ว Catapult ยังมียูทิลิตีอื่นๆ ที่มีประโยชน์ด้วย ตัวอย่างเช่น ftrace มีฟีเจอร์มากกว่าที่ systrace หรือ atrace เปิดใช้ได้โดยตรง และมีฟังก์ชันขั้นสูงบางอย่างที่สําคัญต่อการแก้ไขข้อบกพร่องด้านประสิทธิภาพ (ฟีเจอร์เหล่านี้ต้องใช้สิทธิ์เข้าถึงระดับรูทและมักจะต้องใช้เคอร์เนลใหม่)
เรียกใช้ systrace
เมื่อแก้ไขข้อบกพร่องของภาพกระตุกใน 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 จึงต้องเขียนบัฟเฟอร์ ftrace ที่บันทึกการเปลี่ยนแปลงฮาร์ดแวร์ ซึ่งหมายความว่าหากสงสัยว่าทำไมรั้วการแสดงผลจึงเปลี่ยนสถานะ คุณสามารถดูสิ่งที่ทํางานบน CPU ณ จุดเปลี่ยนสถานะนั้นๆ ได้ (สิ่งที่ทํางานบน CPU ทริกเกอร์การเปลี่ยนแปลงในบันทึก) แนวคิดนี้เป็นพื้นฐานของการวิเคราะห์ประสิทธิภาพโดยใช้ Systrace
ตัวอย่าง: เฟรมที่ทำงานอยู่
ตัวอย่างนี้อธิบาย Systrace สําหรับไปป์ไลน์ UI ปกติ หากต้องการทําตามตัวอย่าง ให้ดาวน์โหลดไฟล์ ZIP ของร่องรอย (ซึ่งรวมถึงร่องรอยอื่นๆ ที่กล่าวถึงในส่วนนี้ด้วย) แตกไฟล์ และเปิดไฟล์ systrace_tutorial.html ในเบราว์เซอร์ โปรดทราบว่าไฟล์ Systrace นี้เป็นไฟล์ขนาดใหญ่ เว้นแต่คุณจะใช้ Systrace ในการทำงานประจำวัน ไฟล์นี้อาจเป็นการติดตามที่ใหญ่กว่ามากและมีข้อมูลมากกว่าที่คุณเคยเห็นในการติดตามครั้งเดียวมาก่อน
สำหรับภาระงานที่สม่ำเสมอเป็นระยะ เช่น TouchLatency ไปป์ไลน์ UI จะมีข้อมูลต่อไปนี้
- EventThread ใน SurfaceFlinger จะปลุกเธรด UI ของแอป ซึ่งบ่งบอกว่าถึงเวลาแสดงผลเฟรมใหม่แล้ว
- แอปจะแสดงผลเฟรมใน UI Thread, RenderThread และ hwuiTasks โดยใช้ทรัพยากร CPU และ GPU ซึ่งนี่เป็นความจุส่วนใหญ่ที่ใช้สําหรับ UI
- แอปจะส่งเฟรมที่ผ่านการจัดการแสดงผลไปยัง SurfaceFlinger โดยใช้ Binder จากนั้น SurfaceFlinger จะเข้าสู่โหมดสลีป
- EventThread ที่ 2 ใน SurfaceFlinger จะปลุก SurfaceFlinger ให้ทริกเกอร์การจัดองค์ประกอบและแสดงผลเอาต์พุต หาก SurfaceFlinger พิจารณาว่าไม่มีงานให้ทำ ก็จะเข้าสู่โหมดสลีปอีกครั้ง
- SurfaceFlinger จะจัดการการคอมโพสโดยใช้ Hardware Composer (HWC)/Hardware Composer 2 (HWC2) หรือ GL องค์ประกอบ HWC/HWC2 จะเร็วกว่าและใช้พลังงานน้อยลง แต่มีข้อจำกัดโดยขึ้นอยู่กับระบบในชิป (SoC) ซึ่งโดยปกติจะใช้เวลาประมาณ 4-6 มิลลิวินาที แต่อาจซ้อนทับกับขั้นตอนที่ 2 ได้เนื่องจากแอป Android มีการบัฟเฟอร์ 3 ชั้นเสมอ (แม้ว่าแอปจะใช้บัฟเฟอร์ 3 ชั้นเสมอ แต่อาจมีเฟรมที่รอดำเนินการเพียงเฟรมเดียวใน SurfaceFlinger ซึ่งทำให้ดูเหมือนบัฟเฟอร์คู่)
- SurfaceFlinger จะส่งออกผลลัพธ์สุดท้ายไปยังจอแสดงผลด้วยไดรเวอร์ของผู้ให้บริการและกลับไปอยู่ในโหมดสลีปเพื่อรอการตื่นขึ้นของ EventThread
มาดูเฟรมที่เริ่มต้นที่ 15409 ms กัน
รูปที่ 1 เป็นเฟรมปกติที่ล้อมรอบด้วยเฟรมปกติ จึงเหมาะเป็นจุดเริ่มต้นในการทำความเข้าใจวิธีการทำงานของไปป์ไลน์ UI แถวเธรด UI สำหรับ TouchLatency มีสีแตกต่างกันในแต่ละช่วงเวลา แถบแสดงสถานะต่างๆ ของชุดข้อความ ดังนี้
- สีเทา การนอนหลับ
- น้ำเงิน ทำงานได้ (ทำงานได้ แต่ตัวจัดตารางยังไม่ได้เลือกให้ทำงาน)
- เขียว ทำงานอยู่ (ตัวจัดกำหนดเวลาคิดว่ากำลังทำงานอยู่)
- สีแดง สลีปแบบไม่หยุดชะงัก (โดยทั่วไปจะอยู่ในสถานะสลีปเมื่อล็อกในเคอร์เนล) อาจเป็นตัวบ่งชี้ของภาระงาน I/O มีประโยชน์อย่างยิ่งในการแก้ไขข้อบกพร่องด้านประสิทธิภาพ
- Orange สลีปแบบไม่ขาดตอนเนื่องจากภาระ I/O
หากต้องการดูสาเหตุของการหยุดทำงานแบบต่อเนื่อง (ดูได้จากsched_blocked_reasonจุดตรวจ) ให้เลือกส่วนการหยุดทำงานแบบต่อเนื่องสีแดง
ขณะที่ EventThread ทำงานอยู่ เทรด UI สำหรับ TouchLatency จะทำงานได้ หากต้องการดูสิ่งที่ทำให้อุปกรณ์ตื่น ให้คลิกส่วนสีน้ำเงิน
รูปที่ 2 แสดงว่า tid 6843 เรียกใช้ชุดข้อความ UI ของ TouchLatency ซึ่งสอดคล้องกับ EventThread เทรด UI จะตื่นขึ้น แสดงผลเฟรม และจัดคิวให้ SurfaceFlinger ใช้งาน
หากเปิดใช้แท็ก binder_driver ในการติดตาม คุณจะเลือกธุรกรรม Binder เพื่อดูข้อมูลเกี่ยวกับกระบวนการทั้งหมดที่เกี่ยวข้องกับธุรกรรมนั้นได้
รูปที่ 4 แสดงให้เห็นว่าที่ 15,423.65 ms Binder:6832_1 ใน SurfaceFlinger กลายเป็นรันไทม์ได้เนื่องจาก tid 9579 ซึ่งเป็น RenderThread ของ TouchLatency นอกจากนี้ คุณยังดู queueBuffer ทั้งสองด้านของธุรกรรม Binder ได้ด้วย
ในระหว่าง queueBuffer ทางด้าน SurfaceFlinger จำนวนเฟรมที่รอดำเนินการจาก TouchLatency จะเพิ่มขึ้นจาก 1 เป็น 2
รูปที่ 5 แสดงบัฟเฟอร์ 3 ชั้น โดยมีเฟรมที่เสร็จสมบูรณ์ 2 เฟรมและแอปกำลังจะเริ่มแสดงผลเฟรมที่ 3 เนื่องจากเราได้ทิ้งเฟรมบางส่วนไปแล้ว แอปจึงเก็บเฟรมที่รอดำเนินการ 2 เฟรมแทน 1 เฟรมเพื่อพยายามหลีกเลี่ยงการทิ้งเฟรมเพิ่มเติม
หลังจากนั้นไม่นาน EventThread ที่ 2 จะปลุกเทรดหลักของ SurfaceFlinger เพื่อให้แสดงเฟรมที่รอดำเนินการเก่าไปยังจอแสดงผลได้
SurfaceFlinger จะล็อกบัฟเฟอร์ที่รอดำเนินการรายการเก่าก่อน ซึ่งจะทำให้จำนวนบัฟเฟอร์ที่รอดำเนินการลดลงจาก 2 เป็น 1
หลังจากล็อกบัฟเฟอร์แล้ว SurfaceFlinger จะตั้งค่าการคอมโพสและส่งเฟรมสุดท้ายไปยังจอแสดงผล (ส่วนเหล่านี้บางส่วนจะเปิดใช้เป็นส่วนหนึ่งของmdssจุดติดตาม ดังนั้นจึงอาจไม่รวมอยู่ใน SoC)
ถัดไป mdss_fb0 จะตื่นขึ้นบน CPU 0 mdss_fb0 คือเธรดเคอร์เนลของไปป์ไลน์การแสดงผลสำหรับการแสดงผลเฟรมที่ผ่านการจัดการแสดงผล
เราเห็น mdss_fb0 เป็นแถวของตัวเองในการติดตาม (เลื่อนลงเพื่อดู)
mdss_fb0 ตื่นขึ้น ทำงานเป็นระยะเวลาสั้นๆ เข้าสู่โหมดสลีปแบบไม่หยุดชะงัก แล้วตื่นขึ้นอีกครั้ง
ตัวอย่าง: เฟรมที่ไม่ทำงาน
ตัวอย่างนี้อธิบาย Systrace ที่ใช้ในการแก้ไขข้อบกพร่องของ Pixel/Pixel XL ที่มีการกระตุก หากต้องการทําตามตัวอย่าง ให้ดาวน์โหลดไฟล์ ZIP ของร่องรอย (ซึ่งรวมถึงร่องรอยอื่นๆ ที่กล่าวถึงในส่วนนี้) จากนั้นแตกไฟล์และเปิดไฟล์ systrace_tutorial.html ในเบราว์เซอร์
เมื่อเปิด Systrace คุณจะเห็นข้อมูลลักษณะนี้
เมื่อมองหาการกระตุก ให้ตรวจสอบแถว FrameMissed ในส่วน SurfaceFlinger
FrameMissed เป็นการปรับปรุงคุณภาพชีวิตที่ HWC2 มอบให้ เมื่อดู systrace สําหรับอุปกรณ์อื่นๆ แถว FrameMissed อาจไม่ปรากฏหากอุปกรณ์ไม่ได้ใช้ HWC2 ไม่ว่าในกรณีใด FrameMissed จะสัมพันธ์กับ SurfaceFlinger ที่ขาดรันไทม์ปกติอย่างสุดขั้วรายการใดรายการหนึ่งและจำนวนบัฟเฟอร์ที่รอดำเนินการซึ่งไม่เปลี่ยนแปลงสําหรับแอป (com.prefabulated.touchlatency) ที่ vsync
รูปที่ 11 แสดงเฟรมที่ขาดหายไปที่ 15598.29&nbps;ms SurfaceFlinger ตื่นขึ้นเป็นระยะเวลาสั้นๆ ในช่วง vsync แล้วกลับไปนอนหลับโดยไม่ทำงานใดๆ ซึ่งหมายความว่า SurfaceFlinger พิจารณาแล้วว่าไม่คุ้มค่าที่จะพยายามส่งเฟรมไปยังจอแสดงผลอีกครั้ง เหตุผล
หากต้องการทําความเข้าใจว่าไปป์ไลน์แบ่งออกเป็นส่วนๆ อย่างไรสําหรับเฟรมนี้ ให้ตรวจสอบตัวอย่างเฟรมที่ทํางานด้านบนก่อนเพื่อดูว่าไปป์ไลน์ UI ปกติปรากฏใน Systrace อย่างไร เมื่อพร้อมแล้ว ให้กลับไปที่เฟรมที่พลาดไปและเล่นย้อนกลับ โปรดทราบว่า SurfaceFlinger ตื่นขึ้นและเข้าสู่โหมดสลีปทันที เมื่อดูจํานวนเฟรมที่รอดำเนินการจาก TouchLatency จะมี 2 เฟรม (เป็นเบาะแสที่ดีในการช่วยหาสาเหตุของปัญหา)
เนื่องจากเรามีเฟรมใน SurfaceFlinger จึงไม่ใช่ปัญหาของแอป นอกจากนี้ SurfaceFlinger ยังตื่นขึ้นในเวลาที่ถูกต้อง จึงไม่ใช่ปัญหาของ SurfaceFlinger หากทั้ง SurfaceFlinger และแอปดูปกติ แสดงว่าปัญหาอาจเกิดจากไดรเวอร์
เนื่องจากมีการเปิดใช้การติดตามจุด mdss และ sync เราจึงได้รับข้อมูลเกี่ยวกับรั้ว (แชร์ระหว่างโปรแกรมควบคุมจอแสดงผลและ SurfaceFlinger) ที่ควบคุมเวลาที่ส่งเฟรมไปยังจอแสดงผล
รั้วเหล่านี้จะแสดงอยู่ใน mdss_fb0_retire ซึ่งบ่งบอกว่ามีเฟรมแสดงอยู่ รั้วเหล่านี้เป็นส่วนหนึ่งของsyncหมวดหมู่การติดตาม เฟนซที่สอดคล้องกับเหตุการณ์หนึ่งๆ ใน SurfaceFlinger จะขึ้นอยู่กับ SOC และกองซ้อนไดรเวอร์ ดังนั้นให้ทำงานร่วมกับผู้ให้บริการ SOC เพื่อทําความเข้าใจความหมายของหมวดหมู่เฟนซในการติดตาม
รูปที่ 13 แสดงเฟรมที่แสดงเป็นเวลา 33 ms ไม่ใช่ 16.7 ms ตามปกติ เมื่อเล่นไปครึ่งทางของส่วนนั้น เฟรมดังกล่าวควรถูกแทนที่ด้วยเฟรมใหม่ แต่ไม่ได้ ดูเฟรมก่อนหน้าและมองหาสิ่งต่างๆ
รูปที่ 14 แสดง 14.482 ms ต่อเฟรม ส่วนที่เป็น 2 เฟรมที่ขาดหายไปมีระยะเวลา 33.6 มิลลิวินาที ซึ่งใกล้เคียงกับที่เราคาดไว้สำหรับ 2 เฟรม (เราแสดงผลที่ 60 Hz, 16.7 มิลลิวินาทีต่อการเรนเดอร์ 1 เฟรม ซึ่งใกล้เคียงกัน) แต่ 14.482 ms ไม่ได้ใกล้เคียงกับ 16.7 ms เลย ซึ่งหมายความว่ามีปัญหาเกิดขึ้นกับไปป์การแสดงผล
ตรวจสอบจุดสิ้นสุดของรั้วเพื่อดูว่ามีอะไรควบคุมรั้ว
workqueue มี __vsync_retire_work_handler ซึ่งทำงานเมื่อรั้วมีการเปลี่ยนแปลง เมื่อดูซอร์สเคอร์เนล คุณจะเห็นว่าไฟล์ดังกล่าวเป็นส่วนหนึ่งของโปรแกรมควบคุมจอแสดงผล ดูเหมือนว่าอยู่ในช่วงสําคัญของไปป์ไลน์ Display จึงต้องทํางานโดยเร็วที่สุด ทำงานได้นานประมาณ 70 us (ไม่ใช่ความล่าช้าในการกําหนดเวลานาน) แต่เนื่องจากเป็นงานคิว จึงอาจได้รับการกําหนดเวลาอย่างไม่ถูกต้อง
ตรวจสอบเฟรมก่อนหน้าเพื่อดูว่าเฟรมดังกล่าวมีส่วนทำให้เกิดปัญหาหรือไม่ เนื่องจากบางครั้งการกระตุกอาจเพิ่มขึ้นเมื่อเวลาผ่านไปและทำให้พลาดกำหนดเวลา
คุณจะไม่เห็นบรรทัดที่ใช้ทำงานได้ใน kworker เนื่องจากเครื่องมือดูจะเปลี่ยนบรรทัดนั้นให้เป็นสีขาวเมื่อเลือก แต่สถิติจะบอกเรื่องราวทั้งหมด: ความล่าช้าของเครื่องมือจัดตารางเวลา 2.3 มิลลิวินาทีสำหรับส่วนหนึ่งของเส้นทางที่สำคัญของไปป์ไลน์การแสดงผลนั้นไม่ดี
ก่อนดำเนินการต่อ ให้แก้ไขความล่าช้านี้ด้วยการย้ายส่วนนี้ของเส้นทางที่สำคัญของไปป์ไลน์การแสดงผลจาก workqueue (ซึ่งทำงานเป็นSCHED_OTHERเธรด CFS) ไปยัง SCHED_FIFOkthread โดยเฉพาะ ฟังก์ชันนี้ต้องการการรับประกันเวลาซึ่งเวิร์กคิวไม่สามารถ (และไม่ได้มีไว้เพื่อ) ให้
Is this the reason for the jank? เป็นเรื่องยากที่จะสรุป นอกเหนือจากกรณีที่วินิจฉัยได้ง่าย เช่น การแย่งกันใช้ล็อกเคอร์เนลที่ทำให้เธรดสําคัญต่อการแสดงผลหยุดทำงาน โดยทั่วไปแล้วร่องรอยจะไม่ระบุปัญหา ความผันผวนนี้อาจเป็นสาเหตุของเฟรมที่หลุดหรือไม่ แน่นอน เวลาที่กั้นเฟรมควรเป็น 16.7 มิลลิวินาที แต่ไม่ได้ใกล้เคียงกับค่านั้นเลยในเฟรมที่นำไปสู่การทิ้งเฟรม เมื่อพิจารณาว่าไปป์ไลน์การแสดงผลทำงานร่วมกันอย่างใกล้ชิดเพียงใด จึงเป็นไปได้ว่าความผันผวนของเวลารอบการจำกัดเฟรมอาจส่งผลให้เฟรมถูกทิ้ง
ในตัวอย่างนี้ โซลูชันเกี่ยวข้องกับการเปลี่ยน __vsync_retire_work_handler จาก workqueue เป็น kthread โดยเฉพาะ ส่งผลให้การกระตุกลดลงอย่างเห็นได้ชัดและลดการกระตุกในการทดสอบลูกบอลกระดอน การติดตามที่ตามมาจะแสดงการกําหนดเวลาของรั้วที่ใกล้เคียงกับ 16.7 ms