ใช้ ftrace

ftrace คือเครื่องมือดีบักที่ช่วยให้เข้าใจสิ่งที่เกิดขึ้นภายใน เคอร์เนลของ Linux ส่วนต่อไปนี้จะแสดงรายละเอียดฟังก์ชัน ftrace พื้นฐาน, ftrace การใช้ Atrace (ซึ่งรวบรวมเหตุการณ์ของเคอร์เนล) และ ftrace แบบไดนามิก

สำหรับรายละเอียดเกี่ยวกับฟังก์ชัน ftrace ขั้นสูงซึ่งไม่มีให้บริการใน systrace โปรดดูเอกสาร ftrace ที่ <kernel tree>/Documentation/trace/ftrace.txt

บันทึกเหตุการณ์ของเคอร์เนลด้วย Atrace

atrace (frameworks/native/cmds/atrace) ใช้ ftrace เพื่อบันทึก เหตุการณ์ของเคอร์เนล ในทางกลับกัน systrace.py (หรือ run_systrace.py ในเวอร์ชันที่ใหม่กว่าของ Catapult) ใช้ adb เพื่อเรียกใช้แอตทริบิวต์บนอุปกรณ์ แอตทริบิวต์ของแอตทริบิวต์จะดำเนินการดังต่อไปนี้

  • ตั้งค่าการติดตามโหมดผู้ใช้โดยการตั้งค่าพร็อพเพอร์ตี้ (debug.atrace.tags.enableflags)
  • เปิดใช้ฟังก์ชัน ftrace ที่ต้องการโดยการเขียนไปยัง ftrace sysfs โหนด แต่เนื่องจาก ftrace สนับสนุนฟีเจอร์เพิ่มเติม คุณจึงอาจต้องกำหนด บางโหนดของ Sysfs ด้วยตนเองแล้วใช้ Atrace

อาศัยการใช้แอตทริบิวต์เพื่อตั้งค่า ยกเว้นการติดตามเวลาเปิดเครื่อง เป็นค่าที่เหมาะสม ที่พักนี้เป็นบิตมาสก์และไม่มีส่วนดี วิธีกำหนดค่าที่ถูกต้องนอกเหนือจากการดูส่วนหัวที่เหมาะสม (ซึ่งอาจเปลี่ยนแปลงได้ใน Android รุ่นต่างๆ)

เปิดใช้เหตุการณ์ ftrace

โหนด ftrace sysfs อยู่ใน /sys/kernel/tracing และมีการติดตาม กิจกรรมจะถูกแบ่งออกเป็นหมวดหมู่ใน /sys/kernel/tracing/events

หากต้องการเปิดใช้เหตุการณ์ตามหมวดหมู่ ให้ใช้ 

echo 1 > /sys/kernel/tracing/events/irq/enable

หากต้องการเปิดใช้เหตุการณ์แบบทีละเหตุการณ์ ให้ใช้ 

echo 1 > /sys/kernel/tracing/events/sched/sched_wakeup/enable

หากเปิดใช้เหตุการณ์เพิ่มเติมด้วยการเขียนไปยังโหนด Sysfs ระบบจะดำเนินการ ไม่ จะถูกรีเซ็ตโดย Atrace รูปแบบทั่วไป สำหรับการเรียกอุปกรณ์ Qualcomm คือการเปิดใช้ kgsl (GPU) และ mdss (แสดงไปป์ไลน์) ของการติดตามแล้วจากนั้นใช้ Atrace หรือ systrace:

adb shell "echo 1 > /sys/kernel/tracing/events/mdss/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/kgsl/enable"
./systrace.py sched freq idle am wm gfx view binder_driver irq workq ss sync -t 10 -b 96000 -o full_trace.html

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

  1. กำหนดขนาดบัฟเฟอร์ให้มีค่าใหญ่พอสำหรับการติดตาม ดังนี้ 
    echo 96000 > /sys/kernel/tracing/buffer_size_kb
  2. เปิดใช้งานการติดตาม: 
    echo 1 > /sys/kernel/tracing/tracing_on
  3. ทำการทดสอบ แล้วปิดใช้การติดตาม 
    echo 0 > /sys/kernel/tracing/tracing_on
  4. ทิ้งการติดตาม: 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace_output

Track_output จะให้การติดตามในรูปแบบข้อความ หากต้องการแสดงภาพโดยใช้ ทำจากหนังสติ๊ก ซื้อ ตัวเร่งปฏิกิริยา ที่เก็บจาก GitHub และเรียกใช้ query2html

catapult/tracing/bin/trace2html ~/path/to/trace_file

โดยค่าเริ่มต้น ระบบจะเขียน trace_file.html เป็น ไดเรกทอรี

เชื่อมโยงเหตุการณ์

การดูการแสดงภาพจาก Catapult และ ftrace มักจะมีประโยชน์ บันทึกพร้อมกัน เช่น เหตุการณ์ ftrace บางเหตุการณ์ (โดยเฉพาะผู้ให้บริการ ไม่แสดงภาพด้วย Catapult แต่การประทับเวลาของ Catapult สัมพันธ์กับเหตุการณ์แรกในการติดตามหรือกับการประทับเวลาที่เฉพาะเจาะจง ถูกส่งออกโดย Atrace ในขณะที่การประทับเวลาแบบ ftrace แบบข้อมูลดิบจะขึ้นอยู่กับ แหล่งที่มาของนาฬิกาแบบสัมบูรณ์ในเคอร์เนลของ Linux

วิธีค้นหาเหตุการณ์ ftrace จากเหตุการณ์ Catapult

  1. เปิดบันทึก ftrace ที่เป็นข้อมูลดิบ การติดตามใน Sytrace เวอร์ชันล่าสุดคือ ที่บีบอัดโดยค่าเริ่มต้น:
    • หากคุณจับภาพ Systrace ด้วย --no-compress แล้ว ไฟล์ HTML ในส่วนที่ขึ้นต้นด้วย BEGIN TRACE
    • หากไม่ ให้เรียกใช้ html2trace จาก ตัวเร่งปฏิกิริยา แผนผัง (tracing/bin/html2trace) เพื่อยกเลิกการบีบอัดการติดตาม
  2. ค้นหาการประทับเวลาแบบสัมพัทธ์ในการแสดงภาพจาก Catapult
  3. ค้นหาบรรทัดที่จุดเริ่มต้นของการติดตามที่มี tracing_mark_sync ซึ่งควรมีหน้าตาเช่นนี้ 
    <5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286

    หากไม่มีบรรทัดนี้ (หรือหากใช้ ftrace โดยไม่มีแอตทริบิวต์) ให้ทำดังนี้ เวลาจะสัมพันธ์กันจากเหตุการณ์แรกในบันทึก ftrace
    1. เพิ่มการประทับเวลาสัมพัทธ์ (เป็นมิลลิวินาที) ไปยังค่าใน parent_ts (เป็นวินาที)
    2. ค้นหาการประทับเวลาใหม่

ขั้นตอนเหล่านี้ควรนำคุณไปยัง (หรืออย่างน้อยก็ใกล้กับ) เหตุการณ์

ใช้ ftrace แบบไดนามิก

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

หากต้องการเปิด ftrace แบบไดนามิก ให้แก้ไข defconfig ของเคอร์เนลดังนี้

  1. ลบ CONFIG_STRICT_MEMORY_RWX (หากมี) หากคุณใช้เวอร์ชัน 3.18 หรือ ใหม่กว่ากับ arm64 ไม่ได้อยู่ตรงนั้นนะ
  2. เพิ่มรายการต่อไปนี้: CONFIG_DYNAMIC_FTRACE=y, CONFIG_FUNCTION_TRACER=y, CONFIG_IRQSOFF_TRACER=y, CONFIG_FUNCTION_PROFILER=y และ CONFIG_PREEMPT_TRACER=y
  3. สร้างและเปิดเครื่องเคอร์เนลใหม่
  4. เรียกใช้รายการต่อไปนี้เพื่อตรวจหาตัวติดตามที่ใช้ได้ 
    cat /sys/kernel/tracing/available_tracers
  5. ยืนยันว่าคำสั่งแสดง function, irqsoff, preemptoff และ preemptirqsoff
  6. เรียกใช้สิ่งต่อไปนี้เพื่อให้แน่ใจว่าฟุตเทรซแบบไดนามิกทํางานอยู่ 
    cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>

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

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

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

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

ถึงตอนนี้เราต้องทราบว่าใครโทรมาที่ ion_client_destroy ดังนั้นจึงได้เวลาใช้เครื่องมือสร้างโปรไฟล์ฟังก์ชันต่อไปนี้

  1. เนื่องจากบางครั้งคอมไพเลอร์เปลี่ยนชื่อฟังก์ชัน ดังนั้นให้ยืนยัน ion_client_destroy อยู่โดยใช้: 
    cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
  2. หลังจากยืนยันว่ามีรหัสแล้ว ให้ใช้เป็นตัวกรอง ftrace ดังนี้ 
    echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
  3. เปิดเครื่องมือสร้างโปรไฟล์ฟังก์ชันโดยทำดังนี้ 
    echo function > /sys/kernel/tracing/current_tracer
  4. ให้เปิดสแต็กเทรซเมื่อมีการเรียกใช้ฟังก์ชันตัวกรอง ดังนี้ 
    echo func_stack_trace > /sys/kernel/tracing/trace_options
  5. เพิ่มขนาดบัฟเฟอร์: 
    echo 64000 > /sys/kernel/tracing/buffer_size_kb
  6. วิธีเปิดการติดตาม 
    echo 1 > /sys/kernel/tracing/trace_on
  7. ทำการทดสอบและรับการติดตาม 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace
  8. ดูการติดตามเพื่อดูสแต็กเทรซจำนวนมากและสแต็กเทรซ 
        cameraserver-643   [003] ...1    94.192991: ion_client_destroy <-ion_release
    cameraserver-643   [003] ...1    94.192997: <stack trace>
 => ftrace_ops_no_ops
 => ftrace_graph_call
 => ion_client_destroy
 => ion_release
 => __fput
 => ____fput
 => task_work_run
 => do_notify_resume
 => work_pending

จากการตรวจสอบตัวขับไอออน เราพบว่า ion_client_destroy ถูกสแปมโดยการปิดฟังก์ชัน userspace fd ไปยัง /dev/ion ไม่ใช่ไดรเวอร์เคอร์เนลแบบสุ่ม โดยการค้นหา ฐานของโค้ด Android สำหรับ \"/dev/ion\" เราพบไดรเวอร์ผู้ให้บริการจำนวนมาก ทำแบบเดียวกันกับตัวขับรูปหกเหลี่ยมและการเปิด/ปิด /dev/ion (การสร้างและการทำลายไคลเอ็นต์ไอออนใหม่) ทุกครั้งที่ผู้ดูแลระบบ ต้องจัดสรรไอออนใหม่ กำลังเปลี่ยนเป็น ใช้ ไคลเอ็นต์ไอออนเดียวตลอดอายุของกระบวนการแก้ไขข้อบกพร่อง

หากข้อมูลจากเครื่องมือสร้างโปรไฟล์ฟังก์ชันไม่เจาะจงมากพอ คุณสามารถรวม ftrace Trackpoints ด้วยเครื่องมือสร้างโปรไฟล์ฟังก์ชัน เหตุการณ์ ftrace สามารถเปิดใช้ได้ใน ด้วยวิธีเดียวกันกับปกติ และจะแทรกสลับกับการติดตามของคุณ ดีมากหากมีการนอนต่อเนื่องนานๆ ครั้งและไม่รบกวนในบางช่วงเวลา ที่ต้องการแก้ไขข้อบกพร่อง: ตั้งค่าตัวกรอง ftrace เป็นฟังก์ชันที่ต้องการ เปิดใช้จุดติดตาม ให้ทำการติดตาม คุณแยกวิเคราะห์การติดตามที่ได้ได้ด้วย trace2html ค้นหาเหตุการณ์ที่ต้องการ แล้วรับสแต็กเทรซใกล้เคียง ในการติดตามดิบ

ใช้ Lockstat

บางครั้ง ftrace อาจไม่เพียงพอ และคุณต้องแก้ไขข้อบกพร่องของสิ่งที่ดูเหมือนจะ การช่วงชิงล็อกเคอร์เนล ยังมีตัวเลือกเคอร์เนลอีก 1 อย่างที่ควรลองใช้ ได้แก่ CONFIG_LOCK_STAT ซึ่งเป็นทางเลือกสุดท้ายเพราะ ทำงานบนอุปกรณ์ Android ได้ยากเพราะวิดีโอจะขยายขนาด เคอร์เนลเกินกว่าที่อุปกรณ์ส่วนใหญ่สามารถจัดการได้

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

ในปัญหานี้ เทรด SCHED_FIFO หยุดทำงานเมื่อแกนประมวลผลทั้งหมดถึงขีดจำกัดสูงสุด โหลดด้วยชุดข้อความที่ไม่ใช่ SCHED_FIFO เรามีร่องรอยที่แสดงให้เห็นล็อกที่สำคัญ การแข่งขัน FD ในแอป VR แต่เราไม่สามารถระบุ FD ที่มีการใช้งานได้อย่างง่ายดาย หากต้องการทำตามตัวอย่างพร้อมๆ กัน ให้ดาวน์โหลดไฟล์ Zip ของการติดตาม (ซึ่งรวมถึงการติดตามอื่นๆ ที่อ้างถึงใน ) แตกไฟล์ และเปิดไฟล์ track_30905547.html ในเบราว์เซอร์

เราสันนิษฐานว่าการติดตามนั้นคือแหล่งที่มาของการช่วงชิงล็อก เมื่อ ชุดข้อความที่มีลำดับความสำคัญต่ำจะเริ่มเขียนไปยังท่อ ftrace จากนั้นจะมี ถูกจองล่วงหน้าก่อนที่จะปลดล็อก นี่เป็นสถานการณ์ที่เลวร้ายที่สุด มึนงงเพราะมีการเขียนชุดข้อความที่มีลำดับความสำคัญต่ำมากรวมกันเพื่อ เครื่องหมาย ftrace พร้อมด้วยเทรดที่มีลำดับความสำคัญสูงกว่าซึ่งหมุนอยู่บน CPU เพื่อ จำลองอุปกรณ์ที่โหลดเสร็จสมบูรณ์

เนื่องจากใช้ ftrace เพื่อแก้ไขข้อบกพร่องไม่ได้ เราจึงทำให้ LOCK_STAT ทำงานได้ จากนั้นจึงปิดการติดตามอื่นๆ ทั้งหมดจากแอป ผลลัพธ์แสดงล็อก ส่วนใหญ่แล้วก็มาจาก ftrace เนื่องจากไม่มีความขัดแย้งปรากฏขึ้นใน การติดตามล็อกเมื่อ ftrace ไม่ทํางาน

หากคุณเปิดเครื่องเคอร์เนลด้วยตัวเลือกการกำหนดค่าได้ การติดตามล็อกจะคล้ายกับ ฟุตเรซ:

  1. เปิดใช้งานการติดตาม: 
    echo 1 > /proc/sys/kernel/lock_stat
  2. ทำการทดสอบ
  3. ปิดใช้การติดตาม: 
    echo 0 > /proc/sys/kernel/lock_stat
  4. ถ่ายโอนการติดตามของคุณ: 
    cat /proc/lock_stat > /data/local/tmp/lock_stat

หากต้องการความช่วยเหลือในการตีความผลลัพธ์ที่ได้รับ โปรดดูเอกสารประกอบของ Lockstat ที่ <kernel>/Documentation/locking/lockstat.txt

ใช้จุดติดตามของผู้ให้บริการ

ใช้จุดติดตามอัปสตรีมก่อน แต่บางครั้งคุณอาจต้องใช้จุดติดตามของผู้ให้บริการ ดังนี้

  { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, {
        { OPT,      "events/mdss/enable" },
        { OPT,      "events/sde/enable" },
        { OPT,      "events/mali_systrace/enable" },
    } },

จุดติดตามขยายได้ด้วยบริการ HAL ซึ่งจะช่วยให้คุณเพิ่มการติดตามเฉพาะอุปกรณ์ได้ คะแนน/หมวดหมู่ Tracepoints จะผสานรวมกับ Perfetto, atrace/systrace และระบบในอุปกรณ์ แอปการติดตาม

API สำหรับการใช้จุด/หมวดหมู่การติดตามมีดังนี้

  • listCategory()สร้าง (หมวดหมู่ vec<TracingCategory>);
  • เปิดหมวดหมู่(vec<string> หมวดหมู่) ที่สร้าง (สถานะสถานะ);
  • disabledAllCategory() สร้าง (สถานะสถานะ);
สำหรับข้อมูลเพิ่มเติม โปรดดูคำจำกัดความ HAL และการใช้งานเริ่มต้นใน AOSP