V8, flatstr에게 통수를 맞다

100~200MB 정도의 로그 파일 30 ~ 100개에서 특정 문자열을 찾아 분석해야 해서, 다음과 같은 코드를 적당히 짰다.

const { resolve } = require('path');
const { writeFile, readFile, readdir } = require('fs').promises;

const walkDir = (fn, startingDir = '.') => {
        const _walkDir = (currentDir) => readdir(currentDir, { withFileTypes: true }).then((children) => Promise.all(
                children.map((child) => {
                        const res = resolve(currentDir, child.name);
                        if (child.isDirectory()) return _walkDir(res);
                        return Promise.resolve(fn(res));
                })
        ));
        return _walkDir(startingDir);
};

// https://github.com/davidmarkclements/flatstr/blob/master/index.js
const flatten = (str) => {
        str | 0;
        return str;
};

// Out Of Memory! mem usage 97~99%
const extractErrors = async () => {
        const filenames = [];
        await walkDir((filename) => {
                if (!filename.toLowerCase().endsWith('-log.xml')) return;
                filenames.push(filename);
        });

        let errors = [];
        for (const filename of filenames) {
                console.log(filename);
                const text = await readFile(filename, { encoding: 'utf-8' });
                errors = errors.concat(
                        (text.match(/<error><!\[CDATA\[(.+?)\]\]><\/error>/g) || [])
                                .filter(str => !str.includes(' '))
                                .map(str => str.slice(16, -11))
                                // .map(flatten)
                );
        }
        await writeFile('errors.txt', JSON.stringify([...new Set(errors)]));
};

setTimeout(extractErrors, 0 * 1000);

노드로 실행시켰더니 메모리 초과가 떴다. 여러분은 문제가 어디인지 보이는가? 3분 정도 코드를 쳐다보고 추측해본 뒤, 나의 삽질 기록을 읽어본다면 더욱 재밌게 읽을 수 있을 것 같다.

---

시간 순으로 나열한다.

1. 가장 유력한 문제 원인으로 slice를 고려했고, 얘때문에 GC가 안 도는구나 싶어 flatten 함수를 추가했다.
   • 기존에 알려져 있던 대로라면, str | 0 혹은 Number(str) 처럼 하면 문자열이 flatten되어 slice에 대한 참조가 해제되어야 한다. #1 #2
2. 문제는 여전했다. flatten이 잘못되었나 싶어 다른 방법으로 좀 수정해보거나((str += ' ') | 0 등), slice를 지워봤다. 차이는 없었다.
3. node --inspect로 연결해 확인해 보니 toString에서 메모리의 98%를 차지했다. UTF-8에서 UCS-2로의 변환이 문제거나 뭔가 내부적으로 비효율적인 게 아닐까 추측했다.
4. stream을 활용하거나, 최대 메모리를 --max-old-space-size 플래그로 늘리는 걸 고려해보았다. 하지만 근본적인 문제가 해결되지 않는 방법이었다.
5. 진전이 없었다. 질문 글을 올렸다. #
6. 한동안 댓글에 달리는 추측을 실험해 보았고, 시도할 수록 더더욱 미궁에 빠졌다.
7. 답변을 얻기 위해 상황 재현을 위한 로그 제네레이터를 짜서 올렸다.
8. GC가 왜 안 도나 싶어 삽질을 해보던 도중, errors의 길이를 제한하니 원하는 답은 (당연히) 안 구해지지만 돌아가긴 했다. toString 등 변환 과정이 아니라 어디선가 참조가 해제되지 않고 있다는 생각으로 다시 기울었다.
9. flatten 함수와 slice에 대한 자체검증을 마친 상태였기에, 해당 부분은 문제되지 않을 것이라 생각했다. 그런데 저기를 빼고 보니 문제될 부분이 없었다. 여전히 답은 보이지 않았다.
10. 정규식 match에서도 참조가 생긴다는 댓글이 달렸는데, 일단은 앞서 했던 예상 범위 내였다. flatten 함수로 해결되지 않고 있었으니, 좀 다른 부분이 문제일 것이라 생각했다.
11. 해당 댓글에 다른 사람이 이게 문제가 맞고, 여기 있는 방법을 적용했더니 된다는 답글이 달렸다.
12. 뭐지 싶어서 기존에 안 되던 코드에서 flatten 함수의 str | 0 부분만 str = (' ' + str).slice(1) 로 바꿨다. 진짜 됐다.
13. 범인은 믿고 있던 flatten이었다...!!! 노드가 버전업돼서 그런지 아무 일도 일어나지 않았고, 내부적으로 slice에 대한 참조 역시 해제되지 않아 GC가 문자열을 수집하지 못하는 것이었다...!

배운 점:

1. V8의 특징을 이용한 최적화는 버전이나 환경, 상황에 따라 언제든 무력화될 수 있다.
2. slice 같이 직접적으로 문자열의 일부분을 반환하는 함수뿐만 아니라, match 등의 함수도 문자열의 slice를 반환해 참조를 만든다.
3. node --inspect로 항상 문제 원인을 정확히 알아낼 순 없다. 참고자료로만 활용하자.
4. 인터넷에 올라와 있는 글, 라이브러리 등을 너무 맹신하지 말자. 틀릴 수도 있고, 맞았지만 최근에 바뀐 내용일 수도 있다.
5. 이런 거 할 땐 고언어나 쓰자