Node 24 + better-sqlite3: 빌드 캐시가 가린 크래시

값을 바꿔도 화면에 반영되지 않았습니다. 새로고침하면 보였습니다.

그날 오후 내내 그 화면을 고치고 있었으니 제가 뭔가 잘못 건드린 줄 알았습니다. 상태 갱신을 빠뜨렸거나, 리렌더가 안 걸렸거나. 컴포넌트를 한참 들여다봤는데 이상한 곳이 없었습니다.

브라우저 콘솔을 열어 보니 이런 것이 하나 떠 있었습니다.

Uncaught (in promise) SyntaxError: Unexpected token '<', "<!DOCTYPE "... is not valid JSON

JSON을 받을 자리에 HTML이 왔다는 뜻입니다. 프론트엔드 문제가 아니었습니다.

빗나간 가설 세 개

"값이 안 바뀐다"를 보고 처음 세운 가설들은 이랬습니다.

레이트 리밋을 의심했습니다. 며칠 전 커밋에 레이트 리밋 추가가 있었고, 서른 번쯤에서 막힌다는 것이 모양이 비슷했습니다. 열어 보니 한도가 분당 600이었고 걸리면 429를 줍니다. 아니었습니다.

의존성이 올라갔나 싶었습니다. 그날 아침에 디스크가 꽉 차서 빌드 캐시를 전부 지우고 다시 올린 참이었습니다. package.json이 캐럿 범위였으니 캐시 없이 새로 받으면서 최신으로 바뀌었을 법했습니다. 잠금 파일과 컨테이너 안 버전을 대조했는데 소수점까지 같았습니다. npm ci가 제 일을 하고 있었습니다.

베이스 이미지가 바뀌었나 싶었습니다. node:24-alpine은 떠 있는 태그라 콜드 빌드 때 새 다이제스트를 받을 수 있습니다. 로컬 이미지는 3주 전 것 그대로였고 컨테이너 안 Node 버전도 그대로였습니다.

세 번 다 코드와 설정 파일을 읽어서 세운 가설이었고, 세 번 다 빗나갔습니다. 이쯤 되니 읽어서는 안 나오겠다 싶었습니다.

읽는 대신 세어 봤을 때 나온 것

콘솔의 그 한 줄은 어떤 API가 에러 페이지를 돌려주고 있다는 뜻이었습니다. 엔드포인트를 하나씩 두드려 보니 몇 개가 502를 냈는데, 조금 있다 다시 두드리면 200이었습니다. 간헐적이라 어느 라우트가 범인인지 잡히지 않았습니다.

그래서 한 엔드포인트만 붙잡고 반복해서 부르며 몇 번째에 깨지는지 셌습니다.

33번째에서 502
36번째에서 502
30번째에서 502

요청 간격을 250ms에서 150ms로 줄여도 횟수는 그대로였습니다. 시간이 아니라 횟수에 걸려 있다는 뜻입니다.

그다음에 502가 나기 직전과 직후로 컨테이너 재시작 횟수를 찍었습니다.

전: 재시작 12
후: 재시작 13

여기서 끝났습니다. 502는 게이트웨이 오류가 아니라 프로세스가 죽는 소리였습니다.

로그에 처음부터 있던 한 줄

컨테이너 로그를 그제서야 제대로 봤습니다.

next-server[1]: void node::RemoveEnvironmentCleanupHook(...) at ../src/api/hooks.cc:142
Assertion failed: (env) != nullptr

Node 내부의 네이티브 어서션 실패입니다. 네이티브 애드온을 정리하려는데 그것이 붙어 있던 Environment가 이미 사라졌다는 뜻입니다. 이 앱에 네이티브 애드온은 하나뿐입니다. SQLite 드라이버입니다.

버전을 맞춰 보니 그림이 나왔습니다.

Node	24.19.0
better-sqlite3	11.10.0, engines 필드 없음
better-sqlite3 12.x	node: 20.x || 22.x || 23.x || 24.x
Prisma SQLite 어댑터	better-sqlite3: ^11.9.0 고정

engines 필드가 없다는 것은 그 버전이 Node 24보다 먼저 나왔다는 뜻입니다. Node 24를 명시적으로 지원하는 것은 12.x부터인데, 쓰고 있는 Prisma SQLite 어댑터가 ^11.9.0으로 묶어 두어서 11.x를 벗어날 수 없었습니다. 게다가 Alpine은 이 패키지의 프리빌드 바이너리가 없어서 매번 소스에서 컴파일합니다.

검증된 적 없는 조합이고, 그렇게 만들어진 바이너리가 서른 번쯤마다 터졌습니다.

코드도 버전도 안 바뀌었는데 그날 터진 이유

이 부분이 제일 얄미웠습니다. git log를 아무리 봐도 나올 것이 없었습니다. 이 조합은 5일 전부터 그대로였으니까요.

그날 아침 이야기를 해야 합니다.

같은 날 새벽에 서버가 통째로 내려가 있었습니다.

04:58:23  console.log 쓰기 실패: no space left on device
04:59:01  VM has stopped gracefully

디스크가 꽉 차서(여유 1.2GB) Docker VM 안의 ext4가 읽기 전용으로 넘어갔고, Docker가 스스로 내려갔습니다. 그 위에 있던 컨테이너 서른 개가 같이 멈췄습니다. 채운 것은 빌드 캐시였습니다. 이 오리진 서버는 빌드 러너를 겸하고 있어서 리포지터리 24개가 배포할 때마다 레이어를 쌓는데 아무도 치우지 않았습니다. docker system df를 찍어 보니 빌드 캐시가 765개에 73GB였고 그중 실제로 쓰이는 것은 0개였습니다.

그래서 전부 지웠습니다. 그게 방아쇠였습니다.

그전까지는 5일 전에 만들어진 deps 레이어가 계속 재사용되고 있었습니다. 그때 컴파일한 바이너리는 멀쩡했고, Docker가 그 레이어를 캐시에서 꺼내 쓰는 한 다시 컴파일할 일이 없었습니다. 캐시를 비우자 처음으로 지금 툴체인에서 새로 컴파일됐고, 5일 동안 덮여 있던 조합이 그대로 드러났습니다.

디스크 정리는 방아쇠였지 원인이 아닙니다. 안 치웠으면 다음 콜드 빌드까지 그대로 있었을 뿐이고, 그때는 무엇을 만졌는지 기억도 안 났을 겁니다. 차라리 그날 터진 편이 나았다고 생각하기로 했습니다.

반나절을 잡아먹은 것은 버그가 아니라 침묵

버그 자체는 깊지 않습니다. 어렵게 만든 것은 아무도 말을 안 했다는 사실이고, 그것이 세 겹이었습니다.

먼저 Docker가 1초 만에 되살렸습니다. 재시작 정책이 unless-stopped라 프로세스가 죽으면 바로 다시 뜹니다. docker ps는 언제나 Up이었습니다. 흔적이라고는 RestartCount뿐인데 그것을 습관적으로 보는 사람은 없습니다.

다음으로 프론트엔드가 502를 삼켰습니다. 목록 새로고침이 API 열한 개를 Promise.all로 부르는데, 하나가 HTML을 내면 .json()이 터지고 전체가 reject됩니다.

const get = (path) => fetch(path).then((x) => x.json());
const [a, b, c, ...] = await Promise.all([get("/api/a"), ...]);

void reload()로 부르고 있었으니 그 reject는 어디로도 가지 않았습니다. 화면은 낡은 값을 아무 말 없이 계속 보여줬고, 그래서 저는 프론트엔드 버그라고 확신하고 반나절을 엉뚱한 곳에서 보냈습니다.

마지막으로 배포 헬스체크가 통과시켰습니다. 이 앱은 인증 게이트 뒤에 있어서 오리진 직접 접근이 401을 내는 것이 정상입니다. 그래서 헬스체크가 401을 한 번 받으면 성공으로 끝냈습니다. 서른 번마다 죽는 컨테이너도 첫 요청은 401을 줍니다.

셋 중에 하나만 말을 해 줬어도 몇 분이면 끝났을 일입니다.

고친 것

베이스를 Node 22 LTS로 내렸습니다. better-sqlite3 11.x가 원래 검증된 자리입니다. 한 줄 바꾸고 200번 연속으로 두드려서 재시작 0인 것을 확인했습니다.

Node 24로 가려면 Prisma를 메이저 업그레이드해서 어댑터가 12.x를 쓰게 해야 하는데, 서버가 죽고 있는 와중에 할 일은 아니었습니다. 대신 Dockerfile 맨 위에 왜 24로 올리면 안 되는지를 사고 경위째로 길게 적어 뒀습니다. 이런 주석이 없으면 반년 뒤에 누군가 아무 생각 없이 되돌립니다. 십중팔구 저입니다.

get은 이렇게 바꿨습니다.

const get = async (path) => {
  const r = await fetch(path, { cache: "no-store" });
  if (!r.ok) throw new Error(`${path} 가 ${r.status} 를 냈습니다`);
  try { return await r.json(); }
  catch { throw new Error(`${path} 가 JSON 이 아닌 것을 냈습니다`); }
};

Unexpected token '<'는 사람에게 아무것도 알려주지 않습니다. /api/folders 가 502 를 냈습니다는 진단의 절반입니다.

화면 위에는 배너를 뒀습니다. 낡은 값을 지우지는 않습니다. 있는 값이라도 보는 편이 낫습니다. 대신 낡았다는 말은 합니다.

화면이 낡았습니다. 목록을 다시 받지 못했습니다. 아래 값은 마지막으로 성공한 것입니다. [다시 시도]

자동 복구에는 짝이 필요합니다

SQLite 드라이버의 호환 범위 같은 것은 사실 별로 남지 않습니다. 한 줄 고쳤고 다시 볼 일이 없습니다.

남는 것은 자동 복구 이야기입니다. restart: unless-stopped는 맞는 설정입니다. 그것 덕분에 서비스가 계속 떠 있었습니다. 그런데 그것만 있으면 죽었다 살아났다는 사실이 아무 데도 남지 않습니다. 자동 복구에는 몇 번 복구했는지 말해 주는 짝이 필요한데 그것이 없었습니다.

빌드 캐시도 다시 보게 됐습니다. 그동안 캐시를 그냥 빠른 빌드라고만 생각했는데, 캐시된 레이어는 사실 그때 그 환경에서 나온 산출물이고 지금 다시 만들면 같은 것이 나온다는 보장이 없습니다. 캐시가 살아 있는 동안에는 그 차이가 보이지 않습니다. 야간에 캐시 없이 한 번 빌드해 보는 것을 CI에 넣을까 고민 중입니다. 그랬으면 5일이 아니라 하루 만에, 그것도 배포 중이 아니라 새벽에 터졌을 겁니다.

그리고 조용히 낡은 것이 시끄럽게 깨진 것보다 나쁘다는 것을 다시 배웠습니다. 502를 삼킨 코드는 짤 때는 방어적으로 짠 것이었는데 실제로는 사용자에게 거짓말을 하고 있었습니다. 화면에 값이 있으면 사람은 그것이 지금 값이라고 믿습니다.

결국 이 문제를 푼 것은 코드를 더 읽어서가 아니라 두 번 재본 것이었습니다. 몇 번째에 죽는지 세고, 죽기 전후로 재시작 횟수를 찍고. 가설이 세 번 연속 빗나갔을 때 진작 그랬어야 했습니다.