Dart DevTools: CPU Profiler로 애플리케이션 성능 분석하기

Dart DevTools: CPU Profiler로 애플리케이션 성능 분석하기

Dart로 명령줄 도구를 만드는 백엔드 개발자든, Flutter로 앱을 만드는 UX 엔지니어든, 프로그램 성능은 프로젝트 성공에 중요해요. 명령줄 도구는 지연을 최소화해야 하고, 앱은 프레임을 떨어뜨리지 않으면서 반응이 빠르고 민첩해야 하죠. 개발자로서 우리는 성능 좋은 코드를 쓰려고 최선을 다하지만, 때로는 왜 우리 코드가 기대만큼 성능이 나오지 않는지 명확하지 않을 때가 있어요.

출처: Dart DevTools: Analyzing application performance with the CPU Profiler

본문

코드베이스에서 성능 문제를 추적하는 일은 만만치 않을 수 있어요. Flutter 코드를 필요 이상으로 느리게 만드는 방법은 여러 가지가 있어요. 어떤 것은 뻔히 눈에 띄고, 어떤 것은 교활할 만큼 미묘하죠. 예를 들어 특정 상황에 잘못된 API나 데이터 구조를 사용했을 수도 있어요.

이 글은 느린 Dart 명령줄 인터페이스(CLI) 애플리케이션의 성능을 살펴보는 간단한 사례 연구를 통해 진행돼요. 다음에 대해 배울 수 있어요.

• 일반적인 CPU 프로파일러와 그 중요성
• Dart와 Flutter에 포함되어 제공되는 샘플링 CPU 프로파일러

이렇게 CPU 프로파일링에 대한 새 이해를 바탕으로 프로그램의 성능을 디버깅할게요. Dart DevTools CPU Profiler와 dart:developer의 UserTag 기능으로 비효율적인 코드를 정확히 찾아내면서 말이죠. 다룰 내용이 많으니 시작해 볼게요!

참고: Dart DevTools는 Flutter DevTools라고도 불리지만, Chrome DevTools와는 혼동하면 안 돼요.

사례 연구: Dart로 grep 구현하기

다음과 같은 간단한 Dart CLI 애플리케이션을 생각해 볼게요.

// filename: grep.dart
import 'dart:io';

/// Finds and prints all instances of [pattern] in the [file].
void grep(File file, String pattern) {
  // Open the file and read its contents.
  final lines = file.readAsLinesSync();

  String output = '';
  int lineNum = 1;
  // Check each line to see if it matches `pattern`.
  for (final line in lines) {
    final matcher = RegExp(pattern);
    if (matcher.hasMatch(line)) {
      final foundMessage = '$lineNum:$line';
      output += foundMessage;
    }
    lineNum++;
  }
  stdout.writeln(output);
}

void main(List<String> arguments) {
  if (arguments.length != 2) {
    print('Usage: dart grep.dart <path> <pattern>');
    exitCode = 64;
    return;
  }
  final path = arguments[0];
  final pattern = arguments[1];

  final file = File(path);
  if (!file.existsSync()) {
    stderr.writeln("Error: unable to open file '$path'");
    exitCode = 64;
    return;
  }

  grep(file, pattern);
}

grep.dart 프로그램은 흔한 Unix 도구의 한 버전을 구현해요. 지정된 패턴과 일치하는 문자열이 파일에서 발생하는 것을 검색할 수 있게 해주죠. 예를 들어 names.txt 파일이 이렇게 들어 있다면:

$ cat names.txt
Frank
Bob
Franny
June
Ben
Francis

'Fran' 문자열을 포함한 모든 줄을 찾아볼게요.

$ dart grep.dart names.txt 'Fran'
1:Frank
3:Franny
6:Francis

훌륭해요! grep에서 이 출력을 기대해야 해요. 그런데 말이죠, names.txt는 작은 파일이에요. 더 큰 텍스트 문서에서 'Hummingbird'의 모든 발생을 찾아보려고 해볼게요. 벌새에 관한 437,000줄, 147 MiB짜리 파일에서 같은 프로그램을 실행하면 어떨까요?

$ dart grep.dart hummingbird_encyclopedia.txt 'Hummingbird'

으... 2분이 지나도 완료되지 않아요. Unix grep은 어떻게 동작할까요?

$ grep -n 'Hummingbird' hummingbird_encyclopedia.txt
16:'''Hummingbirds''' are [[bird]]s native to the…
22:Hummingbirds have the highest…
24:Hummingbirds split from their [[Sister taxon|sister group]]…
// Output continues

Unix의 grep은 전체 파일을 검색해 Hummingbird를 포함한 모든 줄을 약 45초 만에 반환했어요. 분명히 우리 코드에 조사해야 할 뭔가 이상한 점이 있어요. 하지만 성능 문제의 원인을 어떻게 파악할 수 있을까요? Dart DevTools에 포함된 CPU Profiler가 시작하기 좋은 곳이에요!

CPU 프로파일러란 무엇인가?

CPU 프로파일링 도구는 프로그램이 실행 중일 때 시간을 어디서 보내는지 추적해요. Dart CLI와 Flutter 애플리케이션을 구동하는 Dart 가상 머신(VM)은 가장 계산 효율적인 CPU 프로파일링 경험을 제공하기 위해 샘플링 CPU 프로파일러를 사용해요. Dart DevTools 같은 도구와 함께 사용하면 Dart 프로그램의 성능 병목을 식별할 수 있어요.

샘플링 CPU 프로파일러는 애플리케이션 성능 데이터를 수집하는 데 통계적 접근을 취해요. 스레드를 일정한 간격으로 인터럽트하고 현재 호출 스택과 기타 관련 실행 상태의 스냅샷을 찍어 샘플을 수집하죠. 이 샘플들을 처리하면 특정 함수를 실행하는 데 대략 얼마나 많은 시간이 소요되는지, 그리고 함수가 서로 다른 호출 스택에 얼마나 자주 나타나는지에 대한 통찰을 얻을 수 있어요.

샘플이 수집되는 빈도를 샘플링 속도(sampling rate) 라고 하며, 초당 샘플 수(헤르츠, Hz라고도 함)로 측정해요. 대부분의 샘플링 프로파일러는 1000 Hz 이상의 샘플링 속도를 가져요. 샘플링 속도가 높을수록 더 상세한 CPU 프로파일을 얻지만, 대상 프로세스에서 샘플링 오버헤드가 더 커지죠. 합리적인 샘플링 속도에서는 샘플링 CPU 프로파일러가 효율적이고, 프로파일링 대상 애플리케이션의 성능 특성에 거의 또는 전혀 영향을 주지 않아요. 게다가 수집된 데이터는 일반적으로 추적(tracing) 프로파일러에 비해 분석을 위한 처리 비용이 더 적어요.

심화: 샘플링 프로파일러는 어떻게 동작하는가?

이 섹션은 Dart VM의 샘플링 CPU 프로파일러가 어떻게 동작하는지 자세히 다뤄요. CPU 프로파일을 분석할 때 이 세부 사항을 알 필요는 없어요. 샘플링 CPU 프로파일러의 세부 사항에 관심이 없다면 이 섹션은 건너뛰어도 돼요.

Dart VM의 샘플링 CPU 프로파일러는 세 가지 중요한 구성 요소로 이루어져 있어요: 스레드 인터럽터(thread interrupter), 샘플 수집기(sample collector), 샘플 프로세서(sample processor).

스레드 인터럽터

스레드 인터럽터는 전용 스레드에서 실행되며, VM이 관리하는 각 스레드에서 CPU 샘플 수집을 트리거해요. 스레드 인터럽터는 일반적으로 비활성 상태로, 샘플링 간격당 한 번씩만 깨어나요. 각 샘플링 간격 후 인터럽터는 스레드 목록을 반복하면서 각 스레드에 멈추고 샘플을 수집하라고 알려요. 스레드 인터럽터는 운영체제별 세부 사항 때문에 플랫폼에 따라 동작이 약간 달라요.

시그널 기반 제어 흐름을 지원하는 대부분의 플랫폼(Android와 Linux)에서는 SIGPROF 신호가 각 스레드로 보내져요. 이는 CPU 프로파일러가 대상 스레드에 등록한 시그널 핸들러를 호출하는 인터럽트를 트리거하고, 핸들러가 작업을 재개하기 전에 CPU 샘플을 수집해요.

신호를 지원하지 않는 다른 플랫폼(Windows와 Fuchsia)이나 SIGPROF를 사용할 때 성능이 나쁜 경우(MacOS와 iOS)에는, 스레드 인터럽터가 시스템 호출로 CPU 샘플 수집 후 각 스레드를 명시적으로 일시 중지하고 재개해요. 이 경우 샘플 수집은 샘플링되는 스레드가 아니라 스레드 인터럽터 스레드에서 이루어져요.

샘플 수집

스레드가 인터럽트되면 CPU 프로파일러가 해당 스레드의 현재 실행 상태에 대한 샘플을 수집해요. 각 샘플에는 다음과 같은 메타데이터가 포함돼요.

• 스레드와 isolate 식별자
• 스레드의 활성 사용자 태그(user tag)
• 수집 타임스탬프
• 샘플링되는 스레드의 현재 스택 트레이스

수집된 스택 트레이스는 프로그램 카운터(PC) 목록으로 구성되며, 이는 스택에서 발견된 각 Dart 및 네이티브 함수의 반환 주소에 해당해요. 이 PC들은 "스택 워킹(stack walking)"이라는 과정으로 수집돼요. 스택 워크를 수행하는 동안 스택 워커는 최상위 프레임의 프레임 포인터(FP)와 각 스택 프레임의 알려진 레이아웃을 사용해 그 함수와 연관된 PC와 이전 스택 프레임의 FP를 찾아 기록해요. 스택 워커는 이전 프레임의 FP를 시작점으로 삼아 스택 끝에 도달할 때까지 이 과정을 반복해요.

각 수집된 샘플은 VM의 샘플 버퍼(sample buffer)에 저장되는데, 이는 제한된 수의 CPU 샘플을 저장할 수 있는 원형 버퍼(circular buffer)예요. 이렇게 하면 VM이 런타임에 추가 할당을 피할 수 있어요. 추가 할당은 성능에 부정적 영향을 주거나, 시그널 핸들러에서 발생하면 나쁜 일을 일으킬 수 있기 때문이죠.

샘플 버퍼의 크기는 런타임에 고정되어 있고, 가득 차면 프로파일러가 오래된 샘플을 새 샘플로 덮어써요. 샘플 버퍼가 채워지는 속도는 샘플링 속도와 각 샘플의 평균 스택 깊이에 따라 달라져요. 예를 들어 샘플링 속도가 높고 스택이 깊을수록 버퍼가 더 빨리 감겨요. DevTools에서 개발자는 낮음(1000 Hz), 중간(4000 Hz), 높음(20,000 Hz) 샘플링 속도 중에서 선택해 샘플 버퍼가 감기는 속도를 제어할 수 있어요.

샘플 처리

클라이언트가 VM 서비스 프로토콜을 통해 CPU 샘플 프로파일 요청을 보내면, CPU 프로파일러는 클라이언트에 보내기 전에 수집된 샘플을 처리해야 해요. 프로파일러는:

• 샘플 버퍼를 반복하면서 필터를 사용해 클라이언트가 지정한 isolate와 시간 범위에 해당하는 샘플만 검색해요.
• 샘플 집합의 각 스택 프레임을 심볼화(graph) 하거나 PC를 함수 이름에 매핑해요.
• 처리된 전체 샘플 버퍼를 JSON으로 직렬화해요.
• JSON을 클라이언트로 보내요.

프로파일러가 처리한 뒤에도 CPU 샘플 응답은 저수준이라, 유용하게 쓰려면 개발자 도구의 추가 처리가 필요해요. 예를 들어 Dart DevTools는 CPU 샘플 목록을 다양한 구조적 표현으로 변환해 비용이 많이 드는 함수(Bottom Up)와 비용이 높은 호출 경로(Call Tree와 CPU Flame Chart)를 식별하게 해주고, 개별 메서드의 호출자·피호출자 통계(Method Table)를 검사하게 해줘요.

Dart DevTools로 Dart와 Flutter 애플리케이션 프로파일링하기

이제 샘플링 CPU 프로파일러가 무엇이고 어떻게 동작하는지 익숙해졌으니, grep 구현의 성능을 디버깅해 볼게요. --observe 플래그로 코드를 다시 실행하고 Dart DevTools CPU Profiler 탭을 열어볼게요.

참고: DevTools에서 Flutter 앱을 테스트할 때는 --observe 플래그를 쓸 필요가 없어요.

$ dart — observe grep.dart hummingbird_encyclopedia.txt 'Hummingbird'
The Dart VM service is listening on http://127.0.0.1:8181/omxEtsCtW9k=/
The Dart DevTools debugger and profiler is available at: http://127.0.0.1:8181/omxEtsCtW9k=/devtools?uri=ws://127.0.0.1:8181/omxEtsCtW9k=/ws
// At this point, the terminal hangs with no output.

이런! 11.6초 동안 수집된 모든 샘플 중에서 isolate는 CPU 시간의 90% 이상을 _StringBase.+를 실행하는 데 썼어요. 이게 우리 성능 문제와 관련이 있을 가능성이 높지만, grep 함수에서 어떤 코드 블록이 느려짐의 원인인지는 명확하지 않을 수 있어요. 다행히 사용자 태그를 사용해 비용이 많이 드는 _StringBase.+ 호출의 위치를 더 좁힐 수 있어요.

User Tags로 CPU 샘플 분류하기

Dart CPU 프로파일러가 스레드를 인터럽트해 새 샘플을 수집할 때, isolate에 설정된 현재 사용자 태그를 기록해요. dart:developer 라이브러리는 UserTag 클래스를 제공하는데, 이걸로 프로파일링하고 싶은 코드 섹션에 사용자 지정 태그를 지정하고 설정할 수 있어요.

grep 구현에서 시간을 어디에 쓰는지 더 잘 이해하기 위해 함수에 사용자 태그로 계측(instrument)해 볼게요.

// filename: grep.dart
import 'dart:developer';
import 'dart:io';

/// Finds and prints all instances of [pattern] in the [file].
void grep(File file, String pattern) {
  final defaultTag = getCurrentTag();
  final fileReadTag = UserTag('File Read');
  final textMatchTag = UserTag('Text Matching');
  final printTag = UserTag('Print Output');

  // Set the 'File Read' tag as the current user tag.
  fileReadTag.makeCurrent();

  // Open the file and read its contents.
  final lines = file.readAsLinesSync();

  // Set the 'Text Matching' tag as the current user tag.
  textMatchTag.makeCurrent();
  String output = '';
  int lineNum = 1;
  // Check each line to see if it matches `pattern`.
  for (final line in lines) {
    final matcher = RegExp(pattern);
    if (matcher.hasMatch(line)) {
      final foundMessage = '$lineNum:$line';
      output += foundMessage;
    }
    lineNum++;
  }

  // Set the 'Print Output' tag as the current user tag.
  printTag.makeCurrent();
  stdout.writeln(output);

  // Reset the user tag to the tag set when grep was invoked.
  defaultTag.makeCurrent();
}

이제 프로그램을 다시 실행하고 CPU Profiler를 열어볼게요. 분류된 프로파일을 보려면 드롭다운에서 Group by: User Tag 옵션을 선택해요. Text Matching 태그를 펼치면 _StringBase.+ 메서드가 우리의 텍스트 매칭 루프에서 호출된다는 것을 확인할 수 있어요.

이 정보로 코드를 자세히 살펴보고 문제를 파악할 수 있어야 해요.

  // Set the ‘Text Matching’ tag as the current user tag.
  textMatchTag.makeCurrent();
  String output = '';
  int lineNum = 1;
  // Check each line to see if it matches `pattern`.
  for (final line in lines) {
    final matcher = RegExp(pattern);
    if (matcher.hasMatch(line)) {
      final foundMessage = '$lineNum:$line';
      // Ahah! This is our call to _StringBase.+!
      output += foundMessage;
    }
    lineNum++;
  }

바로 그거예요! StringBuffer를 쓰지 않고 String에 여러 번 내용을 추가하는 전형적인 실수를 저질렀어요. String에 내용을 추가하면 _StringBase.+ 메서드의 결과를 저장할 새 문자열이 만들어져요. 그 결과 일치 항목을 찾을 때마다 output + foundMessage를 새 문자열로 복사하죠.

output이 길어질수록 여기에 데이터를 추가하는 비용이 더 커져서, 복사를 수행하는 데 O(m*n)이 소요돼요. 여기서 m은 일치 항목의 평균 문자 수, n은 최종 문자열의 총 문자 수예요. StringBuffer를 사용하면 추가할 때마다 output을 복사하지 않고, 함수 끝에서 일치 항목들을 단일 O(n) 연산으로 이어 붙여요.

이제 앱이 String에 추가하는 대신 StringBuffer.writeln을 사용하니 우리 함수를 살펴볼게요.

// filename: grep.dart
import ‘dart:developer’;
import 'dart:io';

/// Finds and prints all instances of [pattern] in the [file].
void grep(File file, String pattern) {
  final defaultTag = getCurrentTag();
  final fileReadTag = UserTag(‘File Read’);
  final textMatchTag = UserTag(‘Text Matching’);
  final printTag = UserTag(‘Print Output’);

  // Set the ‘File Read’ tag as the current user tag.
  fileReadTag.makeCurrent();

  // Open the file and read its contents.
  final lines = file.readAsLinesSync();

  // Set the ‘Text Matching’ tag as the current user tag.
  textMatchTag.makeCurrent();
  final output = StringBuffer();
  int lineNum = 1;
  // Check each line to see if it matches `pattern`.
  for (final line in lines) {
    final matcher = RegExp(pattern);
    if (matcher.hasMatch(line)) {
      final foundMessage = '$lineNum:$line';
      // Add the match to the buffer without creating a copy.
      output.writeln(foundMessage);
    }
    lineNum++;
  }

  // Set the ‘Print Output’ tag as the current user tag.
  printTag.makeCurrent();
  // output.toString() concatenates each entry in the buffer
  // into a new String, only performing a single allocation of
  // size `output.length`.
  stdout.writeln(output);

  // Reset the user tag to the tag set when grep was invoked.
  defaultTag.makeCurrent();
}

개선이 있는지 다시 테스트해 볼게요.

$ dart grep.dart hummingbird_encyclopedia.txt 'Hummingbird'
16:'''Hummingbirds''' are [[bird]]s native to the…
22:Hummingbirds have the highest…
24:Hummingbirds split from their [[Sister taxon|sister group]]…
// Output continues

StringBuffer를 사용하면 'Hummingbird'의 모든 발생을 약 45초 만에 찾을 수 있어요. 훨씬 나아졌고 Unix grep 구현과 거의 같죠! 성능을 더 개선할 수 있을지 CPU 프로파일러를 다시 살펴볼게요.

프로파일을 잠깐 보면 대부분의 시간을 일치 항목을 출력하는 데 쓰고, 실제 매칭은 약 200ms밖에 걸리지 않는다는 것을 알 수 있어요. 'Print Output' 태그에 해당하는 코드에 집중해야 해요.

  // Set the ‘Print Output’ tag as the current user tag.
  printTag.makeCurrent();
  // output.toString() concatenates each entry in the buffer
  // into a new String, only performing a single allocation of
  // size `output.length`.
  stdout.writeln(output);

핵심 dart:io 라이브러리 멤버인 stdout.writeln 호출을 하나만 하고 있어서 우리가 할 수 있는 일은 많지 않아 보여요. 프로파일러의 CPU flame chart를 보면 이 코드가 SDK에 속한 것이고, 우리 코드에서는 더 이상 성능을 개선할 여지가 없음을 알 수 있어요.

그걸로 끝났어요!

정리

이 글을 시작한 이후로 많은 것을 해냈어요.

• Dart로 간단한 grep 도구를 작성했어요.
• 프로그램의 성능이 나쁘다는 것을 식별했어요.
• CPU 프로파일러에 대해 배우고 Dart VM의 샘플링 CPU 프로파일러를 탐구했어요.
• Dart DevTools의 CPU Profiler를 사용해 프로그램의 성능 문제를 식별하고 고쳤어요.

성능 도구를 잘 이해하는 것은 중요한 기술이고, 이 글에서 보여주듯이 코드에서 미묘한 성능 문제를 식별하는 데 도움을 줄 수 있어요. CPU Profiler는 Dart DevTools에 포함된 많은 도구 중 하나일 뿐이며, Dart CLI와 Flutter 애플리케이션의 동작과 성능을 더 잘 이해하는 데 도움이 돼요.

앞으로의 글에서는 Dart DevTools로 앱을 디버깅하고 최적화하는 다른 방법을 탐구할 거예요.

• Memory 화면으로 메모리 사용량 분석
• Performance 화면으로 실행 타임라인 검사
• Network 화면으로 HTTP 트래픽 검사

그때까지, 즐거운 해킹 되세요! 관심이 있다면 GitHub에서 저를 팔로우해서 Flutter와 Dart 가상 머신에서의 작업은 물론 다른 펫 프로젝트도 확인해 보세요.

더 알아보기

• Dart DevTools 개요 — DevTools에 포함된 다양한 도구와 화면.
• dart:developer 라이브러리 — UserTag와 기타 개발자 도구 API.
• Performance 화면 — 실행 타임라인 검사 도구.