Google은 흑인 공동체를 위한 인종 간 평등을 진전시키기 위해 노력하고 있습니다. Google에서 어떤 노력을 하고 있는지 확인하세요.

Systrace 이해

주의: 전에 systrace를 사용해본 적이 없는 경우 systrace 개요부터 읽어보는 것이 좋습니다.

systrace는 Android 기기 성능을 분석하기 위한 기본 도구입니다. 하지만 실질적으로는 다른 도구 주변의 래퍼에 가까우며, 사용자 공간 추적을 제어하고 Linux 커널의 기본 추적 기능인 ftrace를 설정하는 기기 측 실행 파일인 atrace 주변의 호스트 측 래퍼입니다. systrace는 atrace를 사용하여 추적을 사용 설정한 다음 ftrace 버퍼를 읽고 독립형 HTML 뷰어에서 버퍼를 완전히 래핑합니다. 최신 커널은 Linux eBPF(Enhanced Berkeley Packet Filter)를 지원하지만, 다음 문서는 Pixel/Pixel XL에 사용되었던 3.18 커널(eFPF 아님)과 관련된 내용을 다룹니다.

systrace는 Google Android팀과 Google 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 및 디스플레이 파이프라인 작업에 필요한 추가 트레이스 포인트와 결합하면 사용자 입력에서 화면에 표시된 프레임까지 추적할 수 있습니다. 이벤트 손실을 피할 수 있도록 버퍼 크기를 큰 값으로 설정하세요(큰 버퍼가 없으면 보통 트레이스의 특정 시점 이후 일부 CPU에 이벤트가 포함되지 않음).

systrace를 진행할 때는 모든 이벤트가 CPU의 요소에 의해 트리거된다는 점을 기억하세요.

참고: 하드웨어 인터럽트는 CPU로 제어되지 않으며 ftrace에서 작업을 트리거합니다. 하지만 트레이스 로그에 대한 실질적인 커밋은 인터럽트 핸들러에 의해 이루어집니다. 이는 예를 들어 잘못된 일부 다른 드라이버가 인터럽트를 사용 중지한 상태에서 인터럽트가 도착한 경우에 지연되었을 수 있습니다. 중요한 요소는 CPU입니다.

systrace는 ftrace를 기반으로 빌드되고 ftrace는 CPU에서 실행됩니다. 따라서 CPU의 작업이 하드웨어 변경사항을 기록하는 ftrace 버퍼를 작성해야 합니다. 즉, 디스플레이 펜스 상태가 변경된 이유가 궁금한 경우에는 정확한 전환 시점에 CPU에서 무엇이 실행되고 있었는지 확인하면 됩니다(CPU에서 실행 중인 작업이 로그의 해당 변경사항을 트리거함). 이러한 개념이 systrace를 사용한 성능 분석의 기초라고 할 수 있습니다.

예: 작동하는 프레임

이 예시에서는 일반 UI 파이프라인의 systrace를 설명합니다. 예시를 따라해 보려면 트레이스(이 섹션에서 언급되는 다른 트레이스 포함)의 zip 파일을 다운로드하고 파일을 압축 해제한 다음 브라우저에서 systrace_tutorial.html 파일을 여세요. 이러한 systrace는 용량이 큰 파일입니다. 일상적인 작업에서 systrace를 사용하지 않는 이상 이는 보통 어떠한 단일 트레이스보다도 많은 정보를 포함하는 훨씬 더 큰 트레이스입니다.

TouchLatency와 같은 일관적이고 주기적인 워크로드를 위해, UI 파이프라인에는 다음이 포함되어 있습니다.

  1. SurfaceFlinger의 EventThread는 앱 UI 스레드의 절전 모드를 해제하여 새 프레임을 렌더링할 때가 되었음을 알립니다.
  2. 앱은 CPU 및 GPU 리소스를 사용하여 UI 스레드, RenderThread 및 hwuiTasks의 프레임을 렌더링합니다. 이는 UI에 대해 소비된 용량의 대부분을 차지합니다.
  3. 앱은 렌더링된 프레임을 바인더를 통해 SurfaceFlinger로 전송하고 절전 모드에 들어갑니다.
  4. SurfaceFlinger의 두 번째 EventThread는 SurfaceFlinger의 절전 모드를 해제하여 구성 및 디스플레이 출력을 트리거합니다. 수행해야 할 작업이 없다고 판단하면 SurfaceFlinger가 절전 모드에 들어갑니다.
  5. SurfaceFlinger는 HWC/HWC2 또는 GL을 통해 구성을 처리합니다. HWC/HWC2 구성은 더 빠르고 전력이 덜 소비되지만, SOC에 따라 제한사항이 있습니다. 이는 보통 4~6ms가 걸리지만, Android 애플리케이션이 항상 삼중으로 버퍼링되므로 2단계와 겹칠 수 있습니다. 애플리케이션은 항상 삼중 버퍼링되지만 SurfaceFlinger에서는 한 개의 프레임만 대기 중일 수 있습니다. 따라서 이중 버퍼링과 동일해 보일 수 있습니다.
  6. SurfaceFlinger는 공급업체 드라이버를 통해 최종 출력을 디스플레이에 디스패치한 후 절전 모드로 돌아가 EventThread wakeup을 기다립니다.

15409ms에서 시작하는 프레임을 살펴보겠습니다.

그림 1. 일반 UI 파이프라인, EventThread 실행 중

그림 1은 일반 프레임에 둘러싸인 일반 프레임입니다. 따라서 UI 파이프라인의 작동 방식을 이해하기 위한 좋은 시작점이라고 할 수 있습니다. TouchLatency의 UI 스레드 행에는 서로 다른 시점에 서로 다른 색상이 표시되어 있습니다. 막대는 스레드의 여러 상태를 나타냅니다.

  • 회색. 절전 중입니다.
  • 파란색. 실행 가능합니다(실행 가능하지만 스케줄러에서 아직 실행을 위해 선택하지 않음).
  • 초록색. 실행 중입니다(스케줄러에서 실행 중이라고 판단함).

    참고: 인터럽트 핸들러는 일반적인 CPU별 타임라인에 표시되지 않습니다. 따라서 스레드 런타임의 일부 시간 동안 실제로 인터럽트 핸들러 또는 softirqs를 실행 중일 가능성이 있습니다. 프로세스 0에 속한 트레이스의 irq 섹션을 보고 인터럽트가 표준 스레드 대신 실행되고 있는지 확인하세요.

  • 빨간색. 무중단 절점 모드(보통 커널의 잠금에서 절전 모드 유지)입니다. I/O 로드를 나타낼 수 있습니다. 성능 문제를 디버그하는 데 매우 유용합니다.
  • 주황색. I/O 로드로 인한 무중단 절전 모드입니다.

무중단 절전 모드의 이유(sched_blocked_reason 트레이스 포인트에서 사용 가능)를 보려면 빨간색 무중단 절전 모드 슬라이스를 선택합니다.

EventThread가 실행되는 동안 TouchLatency의 UI 스레드는 실행 가능 상태가 됩니다. 무엇이 TouchLatency 절전 모드를 해제했는지 확인하려면 파란색 섹션을 클릭합니다.

그림 2. TouchLatency의 UI 스레드

그림 2는 TouchLatency UI 스레드가 EventThread에 해당하는 tid 6843에 의해 절전 모드가 해제되었음을 보여 줍니다. UI 스레드의 절전 모드가 해제됩니다.

그림 3. UI 스레드가 절전 모드를 해제하고 프레임을 렌더링한 다음 SurfaceFlinger에서 이를 사용할 수 있도록 대기열에 등록함

binder_driver 태그가 트레이스에 사용 설정된 경우 바인더 트랜잭션을 선택하여 해당 트랜잭션에 사용된 모든 프로세스의 정보를 볼 수 있습니다.

그림 4. 바인더 트랜잭션

그림 4는 SurfaceFlinger의 Binder:6832_1이 15,423.65ms 시점에 실행 가능한 상태로 전환됨을 보여줍니다. 이는 TouchLatency의 RenderThread인 tid 9579에 의해 전환된 것입니다. 또한 바인더 트랜잭션의 양쪽에서도 queueBuffer를 확인할 수 있습니다.

SurfaceFlinger 측의 queueBuffer 중에는 TouchLatency의 대기 중인 프레임 수가 1에서 2로 변합니다.

그림 5. 대기 중인 프레임 수가 1에서 2로 변경됨

그림 5는 삼중 버퍼링을 보여 주는데, 두 개의 프레임이 완료되었으며 앱이 곧 세 번째를 렌더링하기 시작합니다. 이는 몇몇 프레임을 이미 드롭했기 때문입니다. 따라서 앱은 추가적인 프레임 드롭을 피하기 위해 하나가 아닌 두 개의 대기 중인 프레임을 유지합니다.

곧이어 SurfaceFlinger 기본 스레드의 절전 모드가 두 번째 EventThread에 의해 해제되므로, 더 오래된 대기 프레임을 디스플레이에 출력할 수 있습니다.

그림 6. SurfaceFlinger의 기본 스레드가 두 번째 EventThread에 의해 절전 모드가 해제됨

SurfaceFlinger는 우선 더 오래된 대기 버퍼를 래칭하는데, 이로 인해 대기 중인 버퍼 수가 2에서 1로 감소합니다.

그림 7. SurfaceFlinger가 우선 더 오래된 대기 버퍼를 래칭함

버퍼를 래칭한 후 SurfaceFlinger가 구성을 설정하고 최종 프레임을 디스플레이에 제출합니다. 이 섹션의 일부는 mdss 트레이스 포인트의 일부로 사용 설정되므로 SOC에 없을 수도 있습니다.

그림 8. SurfaceFlinger는 구성을 설정하고 최종 프레임을 제출함

그러면 CPU 0에서 mdss_fb0의 절전 모드가 해제됩니다. mdss_fb0은 렌더링된 프레임을 디스플레이에 출력하기 위한 디스플레이 파이프라인의 커널 스레드입니다. 트레이스에서 mdss_fb0을 하나의 자체 행으로 볼 수 있습니다(보려면 아래로 스크롤).

그림 9. CPU 0에서 mdss_fb0의 절전 모드가 해제됨

mdss_fb0의 절전 모드가 해제되어 잠시 동안 실행된 후 무중단 절전 모드에 들어간 다음, 다시 절전 모드가 해제됩니다.

참고: 이 시점부터는 트레이스가 좀 더 복잡해집니다. 이는 최종 작업이 mdss_fb0, 인터럽트 및 작업 대기열 함수 간에 분할되기 때문입니다. 이러한 수준까지 세부정보가 필요한 경우 SOC 드라이버 스택의 정확한 특성을 참조하세요. Pixel XL의 트레이스가 본인에게 유용하지 않을 수도 있기 때문입니다.

예시: 작동하지 않는 프레임

이 예시에서는 Pixel/Pixel XL 잡음을 디버그하는 데 사용되는 systrace를 설명합니다. 예시를 따라 진행하려면 트레이스(이 섹션에서 언급되는 다른 트레이스 포함)의 zip 파일을 다운로드하고 파일을 압축 해제한 다음 브라우저에서 systrace_tutorial.html 파일을 여세요.

처음으로 systrace를 열면 다음과 같이 표시됩니다.

그림 10. Pixel XL에서 실행되는 TouchLatency(mdss 및 kgsl 트레이스 포인트를 포함한 대부분의 옵션이 사용 설정됨)

버벅거림을 찾을 때는 SurfaceFlinger 아래에서 FrameMissed 행을 확인하세요. FrameMissed는 HWC2(Hardware Composer 2)에서 제공하는 수명 기간 중 품질 개선 기능입니다. 2016년 12월부터는 HWC2가 Pixel/Pixel XL에만 사용됩니다. 다른 기기의 systrace를 볼 때는 FrameMissed 행이 없을 수도 있습니다. 어느 경우든, FrameMissed는 아주 일정한 런타임 중 하나가 누락된 SurfaceFlinger 및 vsync 시 앱(com.prefabulated.touchlatency)의 변경되지 않은 대기 버퍼 수와 상관관계를 지닙니다.

그림 11. FrameMissed와 SurfaceFlinger의 상관관계

그림 11의 경우 15598.29ms에서 프레임이 누락된 것을 볼 수 있습니다. SurfaceFlinger는 vsync 구간에서 잠시 절전 모드가 해제되었으며 어떠한 작업도 수행하지 않고 다시 절전 모드로 전환되었습니다. SurfaceFlinger가 디스플레이에 프레임을 다시 전송할 이유가 없다고 판단한 것입니다. 왜일까요?

이 프레임의 파이프라인이 어떤 방식으로 분류되었는지 이해하려면 먼저 위에 나와 있는 작동하는 프레임 예시를 검토하여 정상적인 UI 파이프라인에 systrace에 표시되는 방식을 확인하세요. 준비가 되면 누락된 프레임으로 돌아가 역순으로 작업합니다. SurfaceFlinger의 절전 모드가 해제되었다가 바로 절전 모드로 돌아갑니다. TouchLatency에서 대기 중인 프레임의 수를 보면 두 개의 프레임이 있는데, 이는 상황 파악을 위한 유용한 단서가 됩니다.

그림 12. SurfaceFlinger의 절전 모드가 해제되었다가 바로 절전 모드에 돌아감

SurfaceFlinger에 프레임이 있으므로 이는 앱 문제가 아닙니다. 또한 SurfaceFlinger의 절전 모드가 정확한 시간에 해제되므로 SurfaceFlinger 문제도 아닙니다. SurfaceFlinger 및 앱 모두 정상으로 보이는 경우, 이는 드라이버 문제일 가능성이 높습니다.

mdsssync 트레이스 포인트가 사용 설정되었으므로 프레임이 실제로 디스플레이에 제출되는 시점을 제어하는 펜스(디스플레이 드라이버 및 SurfaceFlinger 간에 공유됨)에 대한 정보를 가져올 수 있습니다. 주의 깊게 봐야 하는 펜스는 mdss_fb0_retire에 나와 있으며, 이는 프레임이 실제로 디스플레이에 표시되는 시점을 보여 줍니다. 이러한 펜스는 sync 트레이스 카테고리의 일부로 제공됩니다. 어떤 펜스가 SurfaceFlinger의 특정 이벤트에 해당하는지는 SOC 및 드라이버 스택에 따라 다릅니다. 따라서 SOC 공급업체에 문의하여 트레이스에 있는 펜스 카테고리의 의미를 이해해야 합니다.

그림 13. mdss_fb0_retire 펜스

그림 13은 예상처럼 16.7ms가 아닌 33ms에 표시된 프레임을 보여줍니다. 해당 슬라이스의 절반에 도달했을 시점이면 해당 프레임이 새 프레임으로 대체되었어야 하지만 대체되지 않았습니다. 이전 프레임을 보고 흥미로운 사실이 있는지 찾아봅니다.

그림 14. 버스트된 프레임의 이전 프레임

그림 14에는 14.482ms 동안 하나의 프레임이 표시되어 있습니다. 버스트된 2프레임 세그먼트는 33.6ms였습니다. 이는 2개의 프레임에 대해 예상되는 대략적인 수치입니다(이에 근접한 60Hz, 프레임당 16.7ms에서 렌더링됨). 하지만 14.482ms는 16.7ms에 전혀 근접한 수치가 아니며, 이는 디스플레이 파이프에 큰 문제가 있음을 나타냅니다.

펜스가 정확히 끝나는 위치를 조사하여 무엇이 이를 제어하고 있는지 확인합니다.

그림 15. 펜스 끝 조사

작업 대기열에는 펜스가 변경될 때 실행되는 __vsync_retire_work_handler가 포함됩니다. 커널 소스를 살펴보면 커널 소스가 디스플레이 드라이버의 일부임을 알 수 있습니다. 이는 확실히 디스플레이 파이프라인의 중요한 경로에 있는 것으로 보이므로 최대한 빨리 실행되어야 합니다. 이는 대략 70us 동안 실행 가능하지만(긴 스케줄링 지연은 아님) 작업 대기열이므로 정확하게 예약되지 않을 수도 있습니다.

이전 프레임을 확인하여 이전 프레임에 원인이 있는지 파악합니다. 간혹 시간이 지나면서 잡음이 추가될 수 있으며, 이로 인해 결국 시간 제한을 초과하게 되기도 합니다.

그림 16. 이전 프레임

kworker에서 실행 가능한 행이 보이지 않는 이유는 선택되었을 때 뷰어에 의해 흰색으로 바뀌었기 때문입니다. 하지만 통계가 그 이유를 알려줍니다. 디스플레이 파이프라인 주요 경로의 일부에 대한 2.3ms의 스케줄러 지연이 잘못된 것입니다. 우선은 디스플레이 파이프라인 중요 경로의 일부를 SCHED_OTHER CFS 스레드로 실행되는 작업 대기열에서 전용 SCHED_FIFO kthread로 이동하여 해당 문제를 해결해야 합니다. 이 함수에는 작업 대기열에서 제공할 수 없는(원래 기능이 아님) 타이밍 보장이 필요합니다.

이것이 버벅거림의 이유일까요? 확정적으로 말하기는 쉽지 않습니다. 디스플레이에 중요한 스레드가 절전 모드로 전환되도록 하는 커널 잠금 경합과 같이 진단이 쉬운 사례를 제외하면, 트레이스는 보통 무엇이 문제인지를 직접적으로 알려 주지 않습니다. 이러한 잡음이 프레임 드롭의 원인이었을까요? 물론입니다. 펜스 시간은 16.7ms여야 하지만 프레임에서는 전혀 근접하지 못했고 결국 프레임 드롭으로 이어졌습니다(19ms 펜스에 이어 14ms 펜스가 있었음). 디스플레이 파이프라인이 얼마나 밀접하게 연결되어 있는지를 감안한다면 펜스 타이밍에서의 잡음이 결국에는 프레임 드롭으로 이어졌을 가능성이 아주 높습니다.

이 예시에서는 문제 해결을 위해 __vsync_retire_work_handler를 작업 대기열에서 전용 kthread로 전환했으며, 결과적으로는 잡음이 눈에 띄게 개선되었고 공 튕기기 테스트의 버벅거림이 감소했습니다. 후속 트레이스에서는 16.7ms를 근접하게 웃도는 펜스 타이밍을 보입니다.