systrace는 Android 기기 성능을 분석하기 위한 기본 도구입니다. 그러나 사실상 다른 도구의 래퍼입니다. atrace의 호스트 측 래퍼이고, 사용자 공간 추적을 제어하고 ftrace를 설정하는 기기 측 실행 파일이며, Linux 커널의 기본 추적 메커니즘입니다. systrace는 atrace를 사용하여 추적을 사용 설정하고 ftrace 버퍼를 읽은 후 독립적인 HTML 뷰어에 모두 래핑합니다. 최신 커널은 Linux eBPF(Enhanced Berkeley Packet Filter)를 지원하지만, 다음 문서는 Pixel/Pixel XL에 사용되었던 3.18 커널(eFPF 아님)과 관련된 내용을 다룹니다.
systrace는 Google Android팀과 Chrome팀의 소유이며, Catapult 프로젝트의 일부로 오픈소스입니다. Catapult에는 systrace 이외에 다음과 같은 유용한 유틸리티도 포함됩니다. 예를 들어 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 및 디스플레이 파이프라인 활동에 필요한 추가 tracepoint와 결합하면 사용자 입력에서 화면에 표시된 프레임까지 추적할 수 있습니다. 버퍼 사이즈를 큰 값으로 설정하여 이벤트 손실을 방지합니다. 큰 버퍼가 없으면 트레이스의 특정 시점 이후 일부 CPU에 이벤트가 포함되지 않기 때문입니다.
systrace를 진행할 때는 모든 이벤트가 CPU의 요소에 의해 트리거된다는 점을 기억하세요.
systrace는 ftrace를 기반으로 빌드되고 ftrace는 CPU에서 실행됩니다. 따라서 CPU의 작업이 하드웨어 변경사항을 기록하는 ftrace 버퍼를 작성해야 합니다. 즉, 디스플레이 펜스가 상태를 변경한 이유가 궁금하다면 정확한 전환 시점에 CPU에서 무엇이 실행되고 있었는지 확인하면 됩니다(CPU에서 실행되는 작업이 로그에서 변경을 트리거함). 이러한 개념이 systrace를 사용한 성능 분석의 기초라고 할 수 있습니다.
예: 작동하는 프레임
이 예시에서는 일반 UI 파이프라인의 systrace를 설명합니다. 예시를 따라 하려면 트레이스(이 섹션에서 언급한 다른 트레이스도 포함)의 zip 파일을 다운로드하고 파일의 압축을 푼 후 브라우저에서 systrace_tutorial.html 파일을 엽니다. 이 systrace는 용량이 큰 파일입니다. 일상적으로 systrace를 사용하지 않는다면 전에 단일 트레이스에서 본 것보다 훨씬 많은 정보가 포함된 매우 큰 트레이스일 수 있습니다.
TouchLatency와 같은 일관적이고 주기적인 워크로드를 위해, UI 파이프라인에는 다음이 포함되어 있습니다.
- SurfaceFlinger의 EventThread는 앱 UI 스레드의 절전 모드를 해제하여 새 프레임을 렌더링할 때라고 알립니다.
- 앱이 CPU와 GPU 리소스를 사용하여 UI 스레드, RenderThread, hwuiTasks에서 프레임을 렌더링합니다. 이는 UI에 소비된 용량의 대부분입니다.
- 앱은 바인더를 사용하여 렌더링된 프레임을 SurfaceFlinger로 전송하고 SurfaceFlinger는 절전 모드로 전환됩니다.
- SurfaceFlinger의 두 번째 EventThread는 SurfaceFlinger의 절전 모드를 해제하여 구성 및 디스플레이 출력을 트리거합니다. SurfaceFlinger가 할 작업이 없다고 판단하면 다시 절전 모드로 전환됩니다.
- SurfaceFlinger는 Hardware Composer(HWC)/Hardware Composer 2(HWC2) 또는 GL을 사용하여 구성을 처리합니다. HWC/HWC2 구성은 더 빠르고 전력이 덜 소비되지만 단일 칩 시스템(SoC)에 따라 제한사항이 있습니다. 이는 보통 4~6ms가 걸리지만, Android 앱이 항상 삼중 버퍼링되므로 2단계와 중복될 수 있습니다. 앱은 항상 삼중 버퍼링되지만 SurfaceFlinger에는 프레임 한 개만 대기 중일 수 있어서 이중 버퍼링과 동일하게 보일 수 있습니다.
- SurfaceFlinger는 공급업체 드라이버와 함께 표시할 최종 출력을 전달하고 절전 모드로 다시 전환되어 EventThread wakeup을 대기합니다.
15,409ms에서 시작하는 프레임을 살펴보겠습니다.
그림 1은 일반 프레임에 둘러싸인 일반 프레임입니다. 따라서 UI 파이프라인의 작동 방식을 이해하기 위한 좋은 시작점이라고 할 수 있습니다. TouchLatency의 UI 스레드 행에는 서로 다른 시점에 서로 다른 색상이 표시되어 있습니다. 막대는 스레드의 여러 상태를 나타냅니다.
- 회색. 절전 중입니다.
- 파란색. 실행 가능합니다(실행 가능하지만 스케줄러에서 아직 실행을 위해 선택하지 않음).
- 녹색. 실행 중입니다(스케줄러에서 실행 중이라고 판단함).
- 빨간색. 무중단 절전 모드(보통 커널의 잠금에서 절전 모드 유지)입니다. I/O 로드를 나타낼 수 있습니다. 성능 문제를 디버그하는 데 매우 유용합니다.
- 주황색. I/O 로드로 인한 무중단 절전 모드입니다.
무중단 절전 모드의 이유(sched_blocked_reason tracepoint에서 사용 가능)를 보려면 빨간색 무중단 절전 모드 슬라이스를 선택합니다.
EventThread가 실행되는 동안 TouchLatency의 UI 스레드는 실행 가능 상태가 됩니다. 무엇이 TouchLatency 절전 모드를 해제했는지 확인하려면 파란색 섹션을 클릭합니다.
그림 2는 TouchLatency UI 스레드가 EventThread에 상응하는 tid 6843에 의해 절전 모드가 해제되었음을 보여 줍니다. UI 스레드가 절전 모드를 해제하고 프레임을 렌더링하여 SurfaceFlinger에서 사용할 수 있도록 대기열에 추가합니다.
binder_driver 태그가 트레이스에 사용 설정된 경우 바인더 트랜잭션을 선택하여 트랜잭션에 사용된 모든 프로세스의 정보를 볼 수 있습니다.
그림 4는 SurfaceFlinger의 Binder:6832_1이 15,423.65ms 시점에 실행 가능한 상태로 전환됨을 보여 줍니다. 이는 TouchLatency의 RenderThread인 tid 9579에 의해 전환된 것입니다. 또한 바인더 트랜잭션의 양쪽에서도 queueBuffer를 확인할 수 있습니다.
SurfaceFlinger 측의 queueBuffer 중에는 TouchLatency의 대기 중인 프레임 수가 1에서 2로 변합니다.
그림 5는 삼중 버퍼링을 보여 주며 여기에는 완료된 프레임이 두 개 있고 앱이 세 번째 프레임의 렌더링을 시작하려고 합니다. 이는 몇몇 프레임을 이미 드롭했기 때문입니다. 따라서 앱은 추가적인 프레임 드롭을 피하기 위해 하나가 아닌 두 개의 대기 중인 프레임을 유지합니다.
곧이어 SurfaceFlinger 기본 스레드의 절전 모드가 두 번째 EventThread에 의해 해제되므로, 더 오래된 대기 중인 프레임을 디스플레이에 출력할 수 있습니다.
SurfaceFlinger는 우선 더 오래된 대기 중인 버퍼를 래칭하는데, 이로 인해 대기 중인 버퍼 수가 2에서 1로 감소합니다.
버퍼를 래칭한 후 SurfaceFlinger가 구성을 설정하고 최종 프레임을 디스플레이에 제출합니다. 이 섹션 중 일부는 mdss tracepoint의 일부로 사용 설정되므로 SoC에 포함되지 않을 수 있습니다.
그러면 CPU 0에서 mdss_fb0의 절전 모드가 해제됩니다. mdss_fb0은 렌더링된 프레임을 디스플레이에 출력하기 위한 디스플레이 파이프라인의 커널 스레드입니다.
트레이스에서 mdss_fb0을 하나의 자체 행으로 볼 수 있습니다(보려면 아래로 스크롤).
mdss_fb0의 절전 모드가 해제되어 잠시 실행되고 무중단 절전 모드에 들어간 후 다시 절전 모드가 해제됩니다.
예시: 작동하지 않는 프레임
이 예시에서는 Pixel/Pixel XL 잡음을 디버그하는 데 사용되는 systrace를 설명합니다. 예시를 따라 하려면 트레이스(이 섹션에서 언급한 다른 트레이스도 포함)의 zip 파일을 다운로드하고 파일의 압축을 푼 후 브라우저에서 systrace_tutorial.html 파일을 엽니다.
systrace를 열면 다음과 같이 표시됩니다.
버벅거림을 찾을 때는 SurfaceFlinger 아래에서 FrameMissed 행을 확인하세요.
FrameMissed는 HWC2에서 제공하는 중요한 개선사항입니다. 다른 기기의 systrace를 볼 때 기기에서 HWC2를 사용하지 않으면 FrameMissed 행이 표시되지 않을 수 있습니다. 어느 경우든, FrameMissed는 아주 일정한 런타임 중 하나가 누락된 SurfaceFlinger 및 vsync 시 앱(com.prefabulated.touchlatency)의 변경되지 않은 대기 버퍼 수와 상관관계를 지닙니다.
그림 11은 15598.29ms에서&nbps;누락된 프레임을 보여 줍니다. SurfaceFlinger는 vsync 구간에서 잠시 절전 모드가 해제되었다가 어떠한 작업도 실행하지 않고 다시 절전 모드로 전환되었습니다. 즉, SurfaceFlinger는 디스플레이에 프레임을 다시 전송할 가치가 없다고 판단한 것입니다. 이유가 무엇인가요?
이 프레임의 파이프라인이 어떤 방식으로 분류되었는지 이해하려면 먼저 위에 나와 있는 작동하는 프레임 예시를 검토하여 일반 UI 파이프라인이 systrace에 표시되는 방식을 확인하세요. 준비가 되면 누락된 프레임으로 돌아가 역순으로 작업합니다. SurfaceFlinger의 절전 모드가 해제되었다가 바로 절전 모드로 돌아갑니다. TouchLatency에서 대기 중인 프레임의 수를 보면 두 개의 프레임이 있는데, 이는 상황 파악을 위한 유용한 단서가 됩니다.
SurfaceFlinger에 프레임이 있으므로 이는 앱 문제가 아닙니다. 또한 SurfaceFlinger의 절전 모드가 정확한 시간에 해제되므로 SurfaceFlinger 문제도 아닙니다. SurfaceFlinger와 앱이 모두 정상으로 보이는 경우 드라이버 문제일 수 있습니다.
mdss 및 sync tracepoint가 사용 설정되었으므로 프레임이 디스플레이에 제출되는 시점을 제어하는 펜스(디스플레이 드라이버와 SurfaceFlinger 간에 공유됨)에 관한 정보를 가져올 수 있습니다.
이러한 펜스는 프레임이 디스플레이에 표시되는 시점을 나타내는 mdss_fb0_retire 아래에 나열됩니다. 이러한 펜스는 sync 트레이스 카테고리의 일부로 제공됩니다. 어떤 펜스가 SurfaceFlinger의 특정 이벤트에 상응하는지는 SOC 및 드라이버 스택에 따라 다르므로 SOC 공급업체에 문의하여 트레이스에 있는 펜스 카테고리의 의미를 파악하세요.
그림 13은 예상처럼 16.7ms가 아닌 33ms에 표시된 프레임을 보여 줍니다. 슬라이스의 절반에 도달했을 시점이면 프레임이 새 프레임으로 대체되었어야 하지만 대체되지 않았습니다. 이전 프레임을 보고 아무것이나 찾아보세요.
그림 14는 프레임당 14.482ms를 보여 줍니다. 깨진 2프레임 세그먼트는 33.6ms였고 이는 2프레임에 예상하는 대략적인 값입니다(이에 근접한 60Hz, 프레임당 16.7ms에서 렌더링됨). 그러나 14.482ms는 16.7ms에 전혀 근접한 수치가 아니므로 디스플레이 파이프에 큰 문제가 있음을 나타냅니다.
펜스가 정확히 끝나는 위치를 조사하여 무엇이 이를 제어하고 있는지 확인합니다.
작업 대기열에는 펜스가 변경될 때 실행되는 __vsync_retire_work_handler가 포함되어 있습니다. 커널 소스를 살펴보면 디스플레이 드라이버의 일부임을 확인할 수 있습니다. 디스플레이 파이프라인의 중요한 경로에 있는 것으로 보이므로 최대한 빨리 실행되어야 합니다. 이는 대략 70us 동안 실행 가능하지만(긴 스케줄링 지연은 아님) 작업 대기열이므로 정확하게 예약되지 않을 수도 있습니다.
이전 프레임을 확인하여 이전 프레임에 원인이 있는지 파악합니다. 간혹 시간이 지나면서 잡음이 누적될 수 있으며, 이로 인해 결국 기한을 초과하게 되기도 합니다.
kworker에서 실행 가능한 행이 보이지 않는 이유는 선택되었을 때 뷰어에 의해 흰색으로 바뀌었기 때문입니다. 하지만 통계가 그 이유를 알려줍니다. 디스플레이 파이프라인 주요 경로의 일부에 관한 2.3ms의 스케줄러 지연이 잘못된 것입니다.
계속하기 전에 디스플레이 파이프라인 중요 경로의 이 부분을 SCHED_OTHER CFS 스레드로 실행되는 작업 대기열에서 전용 SCHED_FIFO kthread로 이동하여 지연 문제를 해결합니다. 이 함수에는 작업 대기열에서 제공할 수 없는(원래 기능이 아님) 타이밍 보장이 필요합니다.
이것이 버벅거림의 이유인가요? 확정적으로 말하기는 쉽지 않습니다. 디스플레이에 중요한 스레드가 절전 모드로 전환되도록 하는 커널 잠금 경합과 같이 진단이 쉬운 사례를 제외하면, 트레이스에서는 일반적으로 문제를 지정하지 않습니다. 이 잡음이 프레임 드롭의 원인이었을 수 있나요? 물론입니다. 펜스 시간은 16.7ms여야 하지만 프레임에서는 전혀 근접하지 못했고 결국 프레임 드롭으로 이어졌습니다. 디스플레이 파이프라인이 얼마나 긴밀하게 결합되어 있는지 감안하면 펜스 타이밍에서의 잡음으로 인해 프레임 드롭이 발생할 수 있습니다.
이 예시에서는 문제 해결을 위해 __vsync_retire_work_handler를 작업 대기열에서 전용 kthread로 전환했으며, 결과적으로는 잡음이 눈에 띄게 개선되었고 공 튕기기 테스트의 버벅거림이 감소했습니다. 후속 트레이스에서는 16.7ms에 매우 근접한 펜스 타이밍을 보입니다.