contentTracing 모듈로 Electron 브라우저 윈도우 프로파일링하기 | [object Object]

May 28, 2017

contentTracing 모듈로 Electron 브라우저 윈도우 프로파일링하기

Electron의 메인 프로세스는 브라우저 윈도우의 디버깅 및 성능 측정을 위한 모듈 몇 가지를 제공하고 있는데 그 가운데 하나가 contentTracing 모듈이다. contentTracing은 Chromium의 Trace 이벤트 프로파일러 api의 바인딩으로 브라우저 윈도우의 성능 및 세부 동작을 쉽게 측정 할 수 있게 해 준다. LighthouseSpeedracer처럼 웹 페이지의 성능을 측정하는 모듈들이 내부적으로 이 Trace 프로파일러를 사용한다.

contentTracing 간단히 들여다보기

크롬 브라우저에서 about://tracing (버전에 따라 chrome://tracing) 페이지를 열면 크롬 브라우저에서 제공하는 Trace 이벤트 프로파일러의 UI가 보인다. 이 프로파일러의 UIcontentTracing이 내부적으로 호출하는 프로파일링 api가 동일하기 때문에 contentTracing을 이용해 얻은 결과는 크롬 브라우저 Trace 프로파일링과 대부분 동일하다. Electron 문서의 예제가 가장 기본적인 프로파일링 결과를 얻는 방법을 잘 설명하고 있다.

import { app, contentTracing } from 'electron';

if (!app.isReady()) {
  throw new Error('cannot record trace until application is ready');
}

//기본 프로파일링 옵션
const options = {
  categoryFilter: '*',
  traceOptions: 'record-until-full, enable-sampling'
};

contentTracing.startRecording(options, () => {
  console.log('Tracing started');

  setTimeout(() => {
    contentTracing
      .stopRecording('', (path) => console.log(`Trace recorded at ${path}`));
  }, 5000);
});

이 예제는 기본 범주 (categoryFilter: '*'로 가능한 범주를 모두 선택)를 이용해 5초간 프로파일링한 후 결과를 저장하고 저장된 파일의 위치를 전달받는다. Electron은 결과를 확인할 수 있는 UI를 별도로 제공하고 있지 않으므로 저장된 파일을 크롬의 about://tracing 페이지에서 불러오면 아래와 같이 브라우저 윈도우 프로세스의 프로파일링 결과를 확인 가능하다.

Trace 결과. 실행 중인 프로세스 전부를 측정하고 기록한다.

기본 범주가 아닌 다른 범주를 사용해서 측정해 보면 크롬에서 측정한 결과와 대부분 같지만 일부 정보는 포함되지 않는다. 이는 Trace에서 지원하는 범주와 contentTracing이 지원하는 범주가 완전히 동일하지 않기 때문이다. Electron은 현재 사용 가능한 범주를 contentTracing.getCategories를 통해 알려준다.

devTools에서 Trace 이벤트 불러오기

contentTracing과 크롬 Trace 프로파일러가 생성하는 파일은 Trace Event Format 에 따라 작성된 JSON 구조체이다. 그리고 크롬 브라우저의 개발자 도구 중 Timeline(최근 버전은 Performance)탭의 프로파일러 또한 같은 구조의 JSON을 이용해 프로파일링 결과를 저장한다. 최근 버전의 Choromium 소스를 보면 개발자 도구의 프로파일러도 내부적으로는 Trace 프로파일러와 같은 api를 이용하고 있다. 즉, 크롬 개발자 도구의 타임라인에서 contentTracing으로 기록한 파일을 특별한 변환 없이 바로 불러오는 것이 가능하다.

그런데 기록을 불러오는데는 문제가 없지만 불러온 결과물을 보면 개발자 도구를 통해 기록된 프로파일링 결과와 조금 다른 부분들이 있다. 먼저 눈에 띄는 부분은 작성된 어플리케이션이 여러 개의 브라우저 윈도우를 가지고 있을 경우 원하는 프로세스의 결과가 나타나지 않을 수 있다는 점이다. 그리고 두 번째로는 프로파일링 결과에 자바스크립트 스택이 제대로 기록되지 않아서 작성한 코드의 성능을 실제로 확인하기는 다소 어렵다는 문제가 있다.

기본 범주만으로 프로파일링한 결과. 코드 스택이 대부분 표시되지 않는다.

첫 번째 문제는 크롬의 Trace 프로파일러의 동작방식이 실행 중인 모든 프로세스에 대해 프로파일링을 수행하기 때문에 나타나는 현상이다. 개발자 도구의 프로파일러는 연결된 프로세스 하나만을 대상으로 하는 까닭에 여러 개의 프로세스를 표시하거나 선택하는 기능이 없어서, 불러오기 전에 프로파일링 결과 중 원하는 프로세스의 정보만을 표시할 수 있도록 처리 과정을 거쳐야 한다. 위에서 언급한 Trace Event Format 을 살펴 보면 각각의 Trace는 아래와 같은 형태의 구조체로 작성되어 있음을 확인할 수 있다.

{"name": "Asub", "cat": "PERF", "ph": "B", "pid": 22630, "tid": 22630, "ts": 829}

여기서 pid가 이 trace가 작성된 프로세스의 id이다. 생성된 JSON 구조체 가운데 원하는 프로세스의 pid와 메인 프로세스의 pid를 제외한 나머지를 삭제하고 개발자 도구에서 다시 불러보면 원하는 프로세스의 프로파일링 결과를 확인 가능하다.

다음으로 자바스크립트 스택 문제는 프로파일링 환경 설정과 관계가 있다. Trace 프로파일러의 기본 범주 설정은 * 와일드 카드로 지정되어 가능한 모든 프로파일링 기록을 남긴다. 다만 이 와일드 카드는 disable-by-default에 속하는 프로파일링 범주에 대해서는 적용되지 않는데 스택 프로파일링은 바로 이 범주에 속한다. 개발자 도구의 프로파일링 UI에서의 Trace api 호출을 살펴보면 이 범주들을 명시적으로 포함하고 있음을 발견할 수 있으며, 이를 contentTracing에서도 그대로 설정하여 사용이 가능하다.

//timeline에서 스택을 보기 위한 프로파일링 카테고리 설정
const defaultTraceCategories: Readonly<Array<string>> = [
    '-*', 'devtools.timeline', 'disabled-by-default-devtools.timeline',
    'disabled-by-default-devtools.timeline.frame', 'toplevel', 'blink.console',
    'disabled-by-default-devtools.timeline.stack',
    'disabled-by-default-v8.cpu_profile', 'disabled-by-default-v8.cpu_profiler',
    'disabled-by-default-v8.cpu_profiler.hires'
];

const traceOptions = {
    categoryFilter: defaultTraceCategories.join(','),
    traceOptions: 'record-until-full',
    options: 'sampling-frequency=10000'
};

contentTracing.startRecording(traceOptions, ....);

위 범주를 사용하여 프로파일링한 결과는 개발자 도구에서 수동으로 프로파일링한 것과 거의 동일하게 상세한 자바스크립트 스택까지 표시하게 된다.

범주를 변경하고 원하는 프로세스를 지정한 결과 상세한 추적이 가능해졌다.

CPU 사용량 측정과 연동해 보기

1.6.9 버전부터 Electron은 어플리케이션 상태를 알 수 있는 방법을 조금 더 자세하게 제공한다. 그 중 하나인 process.getCPUUsage는 호출할 때 마다 마지막 호출 이후부터 프로세스의 CPU 사용량을 알려 준다. 이 함수를 이용해 프로파일링을 수행하는 간단한 예제를 구현해 보았다.

// 주어진 시간 동안 CPU 사용랑을 측정
const getPercentCPUUsageForPeriod = (period: number) =>
  Observale.of(0, period)
    .mergeMap((x) => Observable.of(x).delay(x))
    .map(process.getCPUUsage)
    .pluck('percentCPUUsage')
    .takeLast(1);

// 주어진 시간 동안 프로파일링을 수행하고 저장된 경로를 반환
const getTraceRecord = (recordDuration: number,
                        recordOptions: { categoryFilter: string }) => {
  const start = Observable.bindCallback(contentTracing.startRecording);
  const stop  = Observable.bindCallback(contentTracing.stopRecording);

  return Observable.concat(
    start(recordOptions),
    stop().delay(recordDuration)
  ).takeLast(1);
};

const traceOptions = { categoryFilter: '*' };

// 10초동안 CPU점유율이 15%이상일 경우 3초간 프로파일링 후 경로 기록
getPercentCPUUsageForPeriod(10000)
    .filter((threshold) => threshold > 15)
    .mergeMap(() => getTraceRecord(3000, traceOptions))
    .subscribe((path) => console.log(`Trace recorded at ${path}`));

getPercentCPUUsageForPeriod는 주어진 시간을 주기로 process.getCPUUsage를 호출하여 시간 동안의 CPU 점유율을 반환하는 함수이고, getTraceRecord는 일정 시간 동안 직접 프로파일링을 수행하는 함수이다. 그리고 마지막으로 두 함수를 연결하여 CPU 점유율이 일정 이상일 경우 (예제에서는 10초간, 15%이상) 프로파일링 후 경로를 기록한다. 실제로 구현할 때는 일정 주기로 측정을 자동화하거나, contentTracing.startMonitoring과 같은 함수를 이용해 결과를 선택적으로 저장하는 등의 방법을 고려해 볼 수 있다.

OJ Kwon