💭console.log()는 왜 느릴까? 에 대한 궁금증 시작
시간초과 나는 console.log(), 왜 느릴까?
오늘은 지금까지 외웠던 큐를 직접 구현해 보며 코딩테스트를 풀이하였다. 문제는 백준 10845번이었고 분명 맞는 풀이라고 생각하였는데, 시간초과가 발생하였다.
코테를 풀며 가장 유명한 대사인 `맞왜틀?(맞는데 왜 틀림?)`을 생각하며 코드를 점검하고 내가 놓친 부분이 있는지 확인했지만, 어디가 틀렸는지 감이 잡히지 않았다.
그러던 중 질의응답에서 console.log()가 느리기에 시간초과가 발생한다는 질의응답 글을 발견했다.
이상했다. 왜 console.log()가 느릴까?
의아했지만, 일단 해당 답변을 참고하여 기존에 반복문을 순회하며 console.log()로 바로 결과를 출력하는 코드 로직을 배열에 담아서 마지막에 console.log()를 사용하는 형태로 변경해 주었다.
// ====================기존 코드===========================
const queue = new Queue();
const N = Number(input.shift());
for (let i = 0; i < N; i++) {
const cur = input.shift().split(" ");
switch (cur[0]) {
case "push":
queue.enqueue(cur[1]);
break;
case "pop":
console.log(queue.isEmpty() ? -1 : queue.dequeue());
break;
case "size":
console.log(queue.queueSize());
break;
case "empty":
console.log(queue.isEmpty() ? 1 : 0);
break;
case "front":
console.log(queue.isEmpty() ? -1 : queue.head.data);
break;
case "back":
console.log(queue.isEmpty() ? -1 : queue.tail.data);
break;
}
}
// ====================변경 후 코드===========================
const queue = new Queue();
const answer = [];
const N = Number(input.shift());
for (let i = 0; i < N; i++) {
const cur = input.shift().split(" ");
switch (cur[0]) {
case "push":
queue.enqueue(cur[1]);
break;
case "pop":
answer.push(queue.isEmpty() ? -1 : queue.dequeue());
break;
case "size":
answer.push(queue.queueSize());
break;
case "empty":
answer.push(queue.isEmpty() ? 1 : 0);
break;
case "front":
answer.push(queue.isEmpty() ? -1 : queue.head.data);
break;
case "back":
answer.push(queue.isEmpty() ? -1 : queue.tail.data);
break;
}
}
console.log(answer.join("\n"));해당 부분을 변경해 주니, 위에 있었던 사진처럼 바로 정답처리 되었다.
📑console.log()에 대한 궁금증 정리
그런데 사실 console.log()로 인해서 시간초과를 겪은 경험은 이번이 처음이 아니다.
이전에도 코테를 왕성하게 풀던 시기에 이런 경험을 몇 번 했었고 최근에도 그런 경험을 종종 했다. 그때마다 왜 이래? 하고 넘어갔지만, 이번에는 이게 도대체 왜 이럴까를 찾아보고 싶었다.
그렇게 시작된 나의 궁금증은 아래와 같이 귀결되었다.
1. console.log()는 왜 느린가?
2. console.log()를 실행하면 어떤 동작이 발생하는가?
3. console.log()는 어떤 로직으로 실행되는가?
총 3가지의 궁금증을 갖게 되었고 이를 해결하기 위해 키워드별로 구글링을 하고 자료를 수집하였다.
🐌console.log()가 느린 이유
첫 번째 질문에 대한 해답은 어느 정도 예측가능하기도 했고, 자료도 굉장히 빠르게 찾을 수 있었다. 관련 블로그를 인용하자면 우리가 console.log()를 실행하게 되면 브라우저 환경에서는 웹 API의 console.log()를, Node환경에서는 V8 엔진에 내장되어 있는 console.log() 메서드를 실행하게 된다면 다음과 같은 과정을 거친다.
1. console.log()함수에 객체를 인수로 전달하면, 해당 객체가 문자열로 변환된다.
2. 이 변환 과정을 `직렬화`라고 하며 문자열 표현으로 변환하는 작업을 진행한다.
3. 이 직렬화 과정 속에서 메모리 내부에 새로운 문자열을 생성하고 객체 데이터를 해당 문자열에 복사한다.
4. 이후 변환된 문자열을 콘솔에 출력한다. 이때 console.log()가 별개로 호출된 상태라면 새로운 출력줄이 만들어진다. 즉, 메모리가 추가적으로 사용된다.
즉 console.log()가 느린 이유는 직렬화하는 과정에서 발생하는 새로운 메모리 할당과 변환 작업이 추가적으로 있었기에 느린 것이었다.
흔히 접할 수 있는 C언어의 `printf`와 아는대로 간단하게 비교해 봤다.
| 특징 | `printf` (C언어) | `console.log()` (JavaScript) |
| 기본 설명 | 포맷된 문자열을 콘솔에 출력 | 브라우저 콘솔 혹은 Node.js 콘솔에 출력 |
| 동작 방식 | 네이티브 코드로 직접 실행 | JavaScript 엔진과 브라우저/Node.js 환경에서 실행 |
| 성능 | 매우 빠름(네이티브 코드) | 상대적으로 느림(직렬화 및 엔진 처리) |
| 메모리 사용 | 메모리 사용 적음 | 객체 직렬화 시 메모리 사용 증가 |
| 비동기 처리 | 동기적 처리 | 비동기적 처리 가능 |
| 예시 | `printf("Hello, $s!\n", name);` | `console.log(′Hello, ${name}!′);` |
즉 다른 언어와 비교했을 때 직렬화의 문제와 상황에 따른 외부 환경에서 실행하는 API 형태로 동작을 하기에 console.log()는 느린 것이었다. 이렇게 첫 번째 궁금증을 어느 정도 해소할 수 있었다.
그렇다면 console.log()를 실행하면 어떤 코드가 실행될까?
⛏️console.log()는 어떻게 동작할까? - 로직 파헤치기
일단 크롬이나 Nodejs에서 동작하는 V8엔진이 C++ 환경에서 구성된다는 것을 알았고, 해당 소스들은 깃허브에 공개되어 있어서 이를 우선적으로 찾아보았다.
음... 어려웠다. src에서 이것저것 파일을 뒤져봤는데 console에 대한 정보가 많이 없었다. 여러 사이트에서 확인해 본 결과 V8 엔진의 C++ 코드 중에서도 console.log()과 같은 내장 JavaScript 함수의 실제 구현은 V8 엔진의 내부에 있으며, 이는 대개 공개되지 않는다는 얘기가 있었다. 그래서 내가 원하는 실제 로직을 찾기에는 한계가 있었던 것 같다.
그래도 일단 소스코드가 공개되어 있는 V8엔진에서 정보를 얻고자 해당 깃허브를 찾았다.
검색창을 통해서 `console`을 검색하니 아래와 같은 결과가 나왔다.
tq확장자에 대하여 간단히
위 결과 중 tq확장자는 V8에서 사용되는 Torque라는 저수준 언어로,
JavaScript의 빌트인(built-in) 객체들의 구현과 V8의 자체적인 런타임 코드를 작성하는 데 사용된다고 한다. 자세한 내용은 요기서
가장 내가 원하는 결과는 맨 아래 D8Console::D8Console 에 해당하는 C++ 코드 부분이었다. 해당 코드에서 어떻게 console.log()가 동작하는지 알 수 있었다.
여기서 D8은 V8 엔진을 사용하여 JavaScript 코드를 실행할 수 있는 독립 실행형 도구이다. 명령줄 인터페이스를 통해 JavaScript 코드를 실행하고 테스트할 수 있다.
즉, 내가 이해한 바로는 V8 정확한 내부 원리는 알 수 없지만, 그 흐름은 D8을 통해서 유추할 수 있다는 것 같았다.
그리고 맨 아래 결과는 그런 C++ 코드를 제공해주고 있었다.
그럼 이제 코드로 확인을 해보자. 자세한 내용은 코드 내부에 주석으로 달았다.
// D8Console 클래스의 Log 메소드 정의이다.
// JavaScript에서 console.log()를 호출할 때 실행된다.
void D8Console::Log(const debug::ConsoleCallArguments& args,
const v8::debug::ConsoleContext&) {
// WriteToFile 함수
// 이 함수는 로그 메시지를 파일이나 표준 출력(stdout) 등에 쓰는 역할을 맡는다.
// 첫 번째 인자는 파일이 없으므로 nullptr로 지정
// 두 번째 인자는 stdout을 지정하여 표준 출력으로 로그 메시지를 보내고 싶음을 나타낸다.
// 세 번째 인자는 현재 작업 중인 V8 isolate를 넘겨준다. 현재 JavaScript 환경의 정보를 얻을 수 있다.
// 마지막 인자는 console.log()로 전달된 인자들이다. 인자들을 처리하여 로그 메시지로 변환 후 출력한다.
WriteToFile(nullptr, stdout, isolate_, args);
}여기서 V8 isolate는 자바스크립트 코드가 실행되는 독립된 환경을 말한다. 자바스크립트 엔진이 코드를 실행할 때 메모리와 리소스를 격리하여 여러 개의 isolate를 사용하며 서로 다른 자바스크립트 코드를 독립적으로 실행할 수 있다고 한다.
즉, 이러한 특성 때문에 console이 하나라면 하나의 isolate 환경만 실행되지만 여러 개의 console이 존재한다면 그 수에 대응하는 isolate가 생성되고 그만큼 메모리와 리소스를 차지하는 것이다.
그렇다면 이제 WriteToFile에 동작원리에 대해 자세히 알아보자.
// WriteToFile 함수는 주어진 인자들을 파일에 기록하는 역할을 한다.
// prefix: 로그 메시지 앞에 추가할 접두사 문자열이다 접두사가 필요 없으면 nullptr을 전달할 수 있다.
// file: 로그 메시지를 기록할 파일의 파일 포인터이다.
// isolate: 현재 실행 중인 V8 JavaScript 실행 환경(Isolate)의 포인터이다.
// args: JavaScript에서 console.log에 전달된 인자들의 목록이다.
void WriteToFile(const char* prefix, FILE* file, Isolate* isolate,
const v8::debug::ConsoleCallArguments& args) {
// prefix가 nullptr이 아니면, 주어진 접두사와 ": "를 파일에 기록한다.
if (prefix) fprintf(file, "%s: ", prefix);
// console.log에 전달된 모든 인자들에 대해 반복한다.
for (int i = 0; i < args.Length(); i++) {
// 현재 Isolate에서 메모리 할당을 관리하는 HandleScope 객체를 생성한다.
// 이는 V8 엔진의 가비지 컬렉션에 사용될 임시 객체들을 관리한다.
HandleScope handle_scope(isolate);
// 첫 번째 인자가 아닌 경우, 인자들 사이에 공백을 추가하여 구분한다.
if (i > 0) fprintf(file, " ");
// 현재 인자를 가져온다.
Local<Value> arg = args[i];
Local<String> str_obj;
// 인자가 Symbol 타입인 경우, 해당 Symbol의 설명(description)을 사용한다.
if (arg->IsSymbol()) arg = Local<Symbol>::Cast(arg)->Description(isolate);
// 인자를 문자열로 변환한다. 변환에 실패하면 함수를 빠져나간다.
if (!arg->ToString(isolate->GetCurrentContext()).ToLocal(&str_obj)) return;
// 변환된 문자열을 UTF-8 형식으로 가져온다.
v8::String::Utf8Value str(isolate, str_obj);
// UTF-8 문자열을 파일에 기록한다.
// 기록된 바이트 수를 검사하여 실패했는지 확인한다.
int n = static_cast<int>(fwrite(*str, sizeof(**str), str.length(), file));
// 기록을 시도한 바이트 수와 실제 기록된 바이트 수가 다르면 오류를 출력하고 프로세스를 종료한다.
if (n != str.length()) {
printf("Error in fwrite\n");
base::OS::ExitProcess(1);
}
}
// 모든 인자에 대한 기록을 완료했으면, 줄 바꿈 문자를 추가하여 로그 메시지를 구분한다.
fprintf(file, "\n");
// 버퍼에 남아 있는 데이터를 파일에 즉시 출력하도록 fflush 함수를 호출한다.
fflush(file);
}주석을 달아봤는데 조금 더 이해하기 쉽게 예시도 같이 준비해 봤다.
`console.log('hello', 1, 2, 3)`을 호출해 보자
1. console.log로 전달된 인자들 'hello', 1, 2, 3이 args 배열에 저장되어 WriteToFile 함수로 전달된다. 그리고 각 원소를 순회하는 반복문을 실행한다.
2. 각 반복마다 메모리를 할당을 관리하는 HandleScope 객체가 생성된다.
3. 첫 번째 인자 'hello'를 제외하고는 구분하기 위한 공백을 추가한다.
4. 'hello'는 문자열 그대로 파일에 기록되고, 1,2,3은 ToString메서드를 통해 문자열로 변환하여 파일에 기록한다.
5. 문자열로 변환된 인자들을 UTF-8 문자열로 변환한다.
6. 이후 파일에 해당 문자열을 기록한다. 이때 요청과 실제 변환 바이트수가 다르면 오류를 반환한다.
7. 모든 인자가 파일에 추가되면 줄 바꿈 문자를 추가해 준다.(console.log()에서 줄 바꿈이 발생하는 이유)
8. fflush를 통해 모든 데이터를 즉시 출력한다.
우리가 JavaScript에서 사용하는 console.log()는 위와 같은 내부 로직을 통해 동작한다..!
---
번외
function consoleTest() {
let count = 0;
for (let i = 0; i < 10000; i++) {
count++;
// console.log(count); // 필요하다면 이 줄의 주석을 해제하세요.
}
return count;
}
// 메모리 사용량을 기록하기 전 호출
let start = new Date(); // 시작
const startMemoryUsage = process.memoryUsage().heapUsed;
// console.log를 대량의 객체로 호출
console.log("count : ", consoleTest());
// consoleTest();
// 메모리 사용량을 기록한 후 호출
const endMemoryUsage = process.memoryUsage().heapUsed;
// console.log 호출에 의해 사용된 대략적인 메모리 계산
const usedMemory = endMemoryUsage - startMemoryUsage;
console.log(`메모리 사용량:`, usedMemory, "byte"); // 단위는 바이트입니다.
let end = new Date(); // 종료
console.log(end - start, "ms"); // 경과시간(밀리초)참조한 블로그에서 메모리 사용량을 실제로 검출하는 코드가 있었다. JS에서도 메모리 사용량을 볼 수 있다는 사실을 처음 알았는데 위 코드를 사용해서 10000번의 반복문 모두 console.log()를 활용하는 경우와 마지막 return값만 console.log()를 사용하는 경우를 비교해 보았다.
시간초까지 추가해 보았다. 굉장히 많은 차이가 났고, 확실히 console.log()를 무의미하게 사용하는 일을 많이 자제해야 할 것 같다.
위 코드에 백준에서 자주 나오는 정답유형을 모아서 출력하는 형식으로도 테스트해보았다.
// 각자 콘솔을 출력하는 케이스
function consoleTest() {
let count = 0;
for (let i = 0; i < 10000; i++) {
count++;
console.log(count);
}
return count;
}
// 배열에 담아 한번에 출력하는 케이스
function consoleTest() {
const answer = [];
for (let i = 1; i <= 10000; i++) {
answer.push(i);
}
console.log(answer.join("\n"));
return answer[9999];
}
생각보다 드라마틱한 차이는 없는 것을 확인할 수 있다.
더 테스트해보다 보니 한 가지 한계점이 존재한다. 오히려 배열의 길이가 2만 줄 ~ 3만 줄을 넘기니 더 느려졌다. 왜인지 찾아보니 배열의 크기가 커졌을 경우, JavaScript의 join 결합 알고리즘의 한계로 오히려 시간이 더 걸리는 경우가 발생할 수 있다는 것이었다.
위 한계점만 기억한다면 좋을 것 같다.
그래도 보통 백준 답변은 10000개 이내이므로 웬만하면 답변을 join('\n') 문으로 감싸서 출력하자.
📝마치며
사실 console.log()가 느린 이유를 끝으로 포스팅을 마무리하고 싶었다. 왜냐하면 정말 정보가 너무나도 안 나왔다.
각종 AI 툴을 다 사용해 보고 외국 블로그와 포럼을 뒤져봤는데 간단한 설명정도는 있지만 자세한 내용을 다루는 블로그가 너무 없었다.
하지만...
의지의 한국인으로서 나름 타당한 결론은 얻고 싶었고, 궁금증을 최대한 결론까지 도출해내고 싶었다.
console.log()를 공부하면서 Console 객체 자체에 대해서도 많이 알 수 있었다. 개발하면서 여러 Console 객체를 잘 응용해 보아야겠다. 그리고 개발과정에서 console.log()를 잘 활용하되 배포단계에서는 잘 제거해 주도록 하자. 애초에 배포환경에서 console.log()를 그대로 두어 데이터가 노출되는 것도 이상하긴 하다.
이번 포스팅에서 얻게 된 것을 가치별로 정리하면 다음과 같다.
1. console.log()가 왜 느린지 알 수 있었다.
2. console.log()를 실행하면 어떤 원리로 실행되는지 알 수 있었다.
3. JS의 console 객체에 대해 더 많이 알 수 있었다.
3-1. console을 더욱 다양하게 써봐야겠다.
4. 각 엔진들에 대한 추가적인 궁금증이 생겼다. 각각의 엔진은 어떤 역할을 할까?
5. process객체를 통해서 메모리 사용량을 확인하는 방법을 알 수 있었다. + 실행 시간 측정 방법
참고 문서
'개발 > Javascript' 카테고리의 다른 글
| GitHub README에 기술 블로그 최근 글 자동으로 업데이트 시키기 (1) | 2024.05.22 |
|---|---|
| 백준 JS 코테 파일을 자동 생성 스크립트로 만들어보자! (0) | 2024.05.07 |
| JS를 이용해서 HTML 태그를 반복 출력해야하는 상황일 때 내장함수 map()을 이용해서 출력하는 법 (0) | 2023.10.17 |