Nodejs 최적화 Tip?

 

 최근에 Javascript의 function calling record 기능을 만들고 이를 Naver Pinpoint 와 연동하여 간단한 NodeJS용 APM을 만들었던 내용을 DEVIEW에서 발표했습니다. 이 기능을 통해 NodeJS에서 Compile되는 함수들을 출력해서 볼 수 있는데, 이를 통해 최근에 페북에서 본 'The V8 Engine and JavaScript Optimization Tips' 의 내용을 공부해보려고 합니다.

 

 

 먼저, 'The V8 Engine and JavaScript Optimization Tips' 글의 내용을 통해 공부하려고 하는 내용을 정의해보려고 합니다. NodeJS는 Javascript Engine으로 v8을 사용합니다. v8은 NodeJS 보다 Chromium에서 사용하고 있어서 더 유명하기도 합니다. v8은 .js 파일 내에 존재하는 함수들을 바로 Parsing하지 않습니다. 입력된 .js 파일을 Toplev이라고 부르며 Toplevel의 Javascript들을 statement로 Parsing하고 파일에 존재하는 함수들은 Declarations들로 분류해놓기만 합니다.

 

 이를 그림으로 표현하면 위와 같습니다.

 이 상태로 v8은 interpreting을 시작합니다. 그러면 interpreter는 find_me_a() 가장 먼저 처리하게 되며, find_me_a 함수를 호출하기 위해, (1) find_me_a라는 이름의 함수가 있는지 검색하고 (2) 실행할 수 있는 상태인지 검사하고 (3) 아직 Parsing도 Compile도 되지 않았으므로 Parsing을 하고 동시에 Compile을 합니다.

 

 이런 과정이 반복적으로 이뤄지는 것이 v8의 interpreting 과정이고, 거의 모든 interpreter들이 공통적으로 동작하는 방식이기도 합니다. 다음의 Javascript code의 실행과정을 한번 확인해보겠습니다.

// eager parse declarations right away
const a = 1;
const b = 2;

const find_me_a = (function(a, b) {
    console.log(a + b);
});

find_me_a(a, b);

위의 Javascript 코드를 '--trace_parse' 옵션을 줘서 실행시키면 다음의 결과를 볼 수 있습니다.

$ nodejs --trace_parse opt.js [parsing script: /home/m/git/uftrace_plugin_nodejs/opt.js - took 0.014 ms] [parsing function: find_me_a - took 0.006 ms] [parsing function: get - took 0.004 ms] [parsing function: log - took 0.009 ms]

Uftrace로 LazyCompile 되는 것을 확인 가능합니다.

 

이렇게 LazyCompile되면 함수의 최초 실행 시간은 당연하게도 지연되게 됩니다.

보시는 것처럼 find_me_a 함수의 최초 호출시 실행 시간은 49ms 정도로 이후 호출에 비해 상대적으로 많은 시간을 소비하는 것을 확인 할 수 있습니다. 단순히 find_me_a만 지연 컴파일되는게 아니라 find_me_a 함수에서 참조하거나 사용하는 모든 함수 및 객체들이 초기화되기 때문에 그에 비례해서 지연 시간은 증가하며, 위의 경우 Nodejs의 라이브러리 Express의 함수를 호출하기 때문에 지연 시간이 꽤 길어진겁니다. 'console.log(a+b);' 한 줄이었으면 당연하게도 이정도로 지연되지는 않겠죠.

 

어쨌든 이렇게 실행 시간에 영향을 주는 Lazy Parsing, Lazy Compile 대신에 실행 시에 Parsing, Compile 되도록 만드는 eager parsing을 강제하는 방법을 'The V8 Engine and JavaScript Optimization Tips'에서 소개하고 있습니다. 다만 예제가 문제가 있어서 다음과 같이 바꿔봤습니다.

// eager parse declarations right away
const a = 1;
const b = 2;

const find_me_a = (function() {
    return (function(a, b) { console.log(a + b); })
})();

// we can use this right away as we have eager parsed
// already
find_me_a(a, b);

 

결과는 예상했던 대로 find_me_a 함수는 Eager Parse 되며, 전체 Parsing에서 제외된 것으로 미뤄 유추해볼 때 js파일이 CreateScript 함수에서 Parsing 될 때, 함께 Parsing 된 것으로 보입니다.

278 [parsing script: /home/m/git/uftrace_plugin_nodejs/eager.js - took 0.013 ms] 279 [parsing function: get - took 0.004 ms] 280 [parsing function: log - took 0.009 ms] 281 [parsing function: format - took 0.060 ms] 282 [parsing function: inspect - took 0.032 $ wc -l eager_parse.log 325 eager_parse.log

278 [parsing script: /home/m/git/uftrace_plugin_nodejs/lazy.js - took 0.012 ms] 279 [parsing function: find_me_a - took 0.004 ms] 280 [parsing function: get - took 0.003 ms] 281 [parsing function: log - took 0.007 ms] 282 [parsing function: format - took 0.059 ms] 283 [parsing function: inspect - took 0.032 ms] $ wc -l lazy_parse.log 326 lazy_parse.log

이를 통해 Lazy Parsing되는 시간을 줄일 수 있는데,  저는 이런걸 분석하는게 좋아서 해보기는 합니다만....

과연 이게 얼마나 도움이 될런지는 의문입니다. 

 

 

Parsing의 시간은 줄일 수 있지만, Eager Parsing을 하더라도 여전히 Compile은 이뤄지며 실질적인 지연시간은 Compile에서 많이 발생하게 됩니다.

 

위 그림을 유심히 보시면 find_me_a 함수가 응답하기 까지 49ms 가 걸린 첫 번째 결과가 보이실겁니다. 이것은 Parsing + Compile 시간이 지연되서 그렇습니다. 앞에서 언급했든 Eager Parsing을 하지 않으면 Lazy Parsing으로 자연스럽게 진행되며, Compile의 경우 Lazy Compile이 진행되어 bytecode를 생성합니다. 여기서 지연 시간이 발생하게 되는 것이죠.

 

 

+@ 추가로 해당 글에서는 fix argument types에 대해서 언급하며, 인자 타입이 4개 보다 많아지면 최적화가 되지 않을거라고 합니다만... 제가 테스트해보니 잘 되는데요? 뭔가 특수한 예제가 필요한 내용일수도 있겠네요.

function find_me_a(a, b) {
	c = a + b;
}


for (var i = 0; i < 40000; i++) {
	find_me_a(1,2);
    find_me_a(3.1415, 1.1415);
    find_me_a("A", "B");
    find_me_a(true, false);
    find_me_a({}, {});
    find_me_a([], []);
}

 

위의 예제코드는 최적화가 되는지 테스트해보기 위한 예제입니다. 버전마다 다르겠지만, 대충 4만번 정도 호출하면 v8에서는 최적화를 합니다 (^^ ;) 최적화가 되는지 여부를 알아보기 위해 다음 명령으로 실행해봤습니다.

 

$ nodejs --print-opt-code type_inference.js > opt.code $ grep "find_me_a" -nR opt.code  -B5 8- 9---- Optimized code --- 10-optimization_id = 0 11-source_position = 81 12-kind = OPTIMIZED_FUNCTION 13:name = find_me_a --

 

네... 최적화 되었네요 (흠털레스팅)