livesync-bridge가 하루 14번씩 조용히 재시작할 때 — 파일 감시자가 atomic write 임시파일에 걸린다

환경: livesync-bridge(Deno) · Obsidian Self-hosted LiveSync + CouchDB 3.3 · Docker Compose · 라즈베리파이

TL;DR / 빠른 해결

파일을 감시하는 프로세스가 Uncaught NotFound: No such file or directory로 죽고 도커가 계속 되살린다면, 감시 대상 디렉토리에 atomic write(임시파일 쓰고 rename)를 하는 쓰기가 있는지 본다. 감시자가 임시파일 이벤트를 받아 stat하러 가는 사이에 rename으로 그 파일이 사라지면, 예외 처리가 없는 경로에서 프로세스째 죽는다.

애플리케이션 코드의 stat·read를 fail-soft로 바꾸는 것만으로는 절반만 잡힌다. 우리가 손댈 수 없는 의존 패키지 쪽에서 같은 크래시가 남는 것으로 보인다.
livesync-bridge에서 결정타는 설정 한 줄이었다 — dat/config.json의 useChokidar를 false로 두고 Deno 네이티브 워처를 쓰는 것. 소스 주석상 원저자가 primary로 의도한 쪽도 이쪽이다.
위험한 건 크래시 자체가 아니라 크래시 창(window)에 걸린 쓰기다. 파일은 디스크에 남지만 CouchDB에는 안 올라간 채 조용히 누락된다.

증상

이 글은 지금 다시 실행해 재현한 게 아니라, 그때 남긴 운영기록을 바탕으로 내가 다시 정리한 것이다. 시리즈 전체의 배경은 노션 대신 Obsidian 자가호스팅에 정리해뒀다.

동기화는 겉보기에 멀쩡했다. 노트를 고치면 다른 기기로 넘어갔고, 눈에 띄는 실패도 없었다.

그런데 컨테이너 상태를 보니 브리지가 계속 재시작하고 있었다. 하루 평균 약 14회, 12일 동안 169회. 그때 기록에 종료 코드는 0으로 남아 있다 — 잡히지 않은 예외로 죽는데 0으로 끝난 건 지금 봐도 설명이 안 되는 부분이고, 그때 더 파보지 않았다. 어느 쪽이든 restart: unless-stopped는 종료 코드와 무관하게 되살리기 때문에 밖에서는 아무 일도 없어 보였다.

로그에 남는 건 한 줄이었다.

Uncaught NotFound: No such file or directory

여기에 두 가지가 번갈아 따라붙었다.

database is closed
getDBEntryMeta undefined

한 가지 특징이 있었다. 아무것도 안 할 때는 절대 안 죽었다. 브리지가 죽는 건 항상 볼트에 쓰기가 몰릴 때였다 — 봇이 노트를 여러 개 렌더해서 저장하거나, 큰 편집이 한꺼번에 밀려 들어올 때.

오진 배제: 뒤따라오는 에러를 원인으로 본다

처음엔 database is closed와 getDBEntryMeta undefined를 원인으로 봤다. CouchDB 연결이 끊기거나 초기화 순서가 꼬인 문제로 보였고, 실제로 그럴듯했다.

이건 오판이었다. 두 메시지는 프로세스가 죽는 과정에서 나오는 2차 증상이었다. 브리지가 종료되기 시작하면 열려 있던 PouchDB 핸들이 닫히고, 그 시점에 진행 중이던 bulkDocs가 database is closed를 뱉는다. getDBEntryMeta undefined도 초기화가 끝나기 전에 put이 들어와서 나는 것이라, 죽고 되살아나는 사이클의 부산물이다.

방향을 튼 근거는 시점이었다. 이 메시지들은 항상 Uncaught NotFound 뒤에 나왔다. 원인이라면 앞에 나와야 했다.

근본 원인: 감시자가 이미 사라진 임시파일을 stat한다

브리지는 볼트 디렉토리를 감시하다가 파일이 바뀌면 그 내용을 읽어 CouchDB로 올린다. 문제는 감시 대상 안에서 벌어지는 atomic write였다.

많은 프로그램이 파일을 안전하게 바꾸려고 이렇게 한다. 먼저 임시파일(*.tmp.<pid>.<hex> 같은 이름)에 전부 쓰고, 다 쓰면 rename으로 원래 이름에 덮어씌운다. rename은 원자적이라 읽는 쪽이 반쪽짜리 파일을 보는 일이 없다.

감시자 입장에서는 이 임시파일도 새 파일이 생긴 이벤트다. 그래서 감시자는 그 경로를 stat하러 간다. 그런데 그 사이에 rename이 끝나면 그 이름은 이미 없다. 그러면 Deno.stat이 NotFound를 던지고, 그 호출이 try/catch 없이 감싸여 있으면 프로세스가 통째로 끝난다.

idle에 안 죽고 쓰기 폭주에만 죽던 이유가 이거다. 임시파일이 생겼다 사라지는 창이 짧아서, 이벤트 처리와 rename이 겹치려면 쓰기가 몰려야 했다.

여기서 진짜 위험한 건 재시작 자체가 아니다. 브리지는 재시작할 때 오프라인 변경 스캔으로 스스로를 복구하기 때문에 대부분은 아무 일 없이 지나간다. 그런데 크래시 창에 걸린 쓰기는 디스크에는 남고 CouchDB에는 안 올라간다. 에러도 안 나고 알림도 없다. 그 파일을 나중에 touch로 건드려 이벤트를 다시 내면 그때 올라간다. 즉 자가복구가 이 결함을 오래 가려주고 있었다.

해결 1: 애플리케이션 코드를 fail-soft로 (절반만 잡힌다)

먼저 브리지 소스에서 감시 이벤트 처리 경로의 stat·read를 전부 "파일이 사라졌으면 이벤트를 건너뛴다"로 바꿨다. PeerStorage.ts의 세 함수(get·writeFileStat·isChanged), 편집으로는 네 곳이다.

// before
const stat = await Deno.stat(path);
if (!stat.isFile) {
    return false;
}
 
// after
const stat = await Deno.stat(path).catch(() => null);
if (!stat || !stat.isFile) {
    return false;
}

읽기도 같이 감쌌다. 확인하는 시점과 실제로 사용하는 시점 사이가 벌어지는 TOCTOU 레이스라, 파일은 stat 직후에도 얼마든지 사라질 수 있다.

try {
    if (isPlainText(path)) {
        ret.data = [await Deno.readTextFile(path)];
    } else {
        ret.data = await Deno.readFile(path);
    }
} catch {
    // 파일이 stat 직후 사라짐(atomic rename 레이스) → 이벤트 무시
    return false;
}

여기서 중요한 건 파일이 사라진 걸 "삭제"로 해석하지 않는다는 것이다. 그냥 이벤트를 버린다. 임시파일이 사라진 건 삭제가 아니라 rename이 끝났다는 뜻이고, 진짜 내용은 원래 이름으로 이미 들어와 있다.

이걸로 브리지 자기 코드에서 나는 크래시는 사라졌다. 그런데 재시작이 완전히 멎지는 않았다. 남은 건 우리가 고칠 수 없는 자리에서 나고 있었다. 브리지 코드가 아니라 chokidar 쪽에서 같은 NotFound가 나는 것으로 보였는데, 정확히 어느 지점인지는 확정하지 못했다 — 스택 트레이스를 남겨두지 않았고, 의존 패키지 내부라 우리가 손댈 수 있는 코드도 아니었다.

해결 2(결정타): 감시자를 바꾼다

브리지 설정에 감시자를 고르는 스위치가 있었다. dat/config.json의 storage 피어 항목이다.

{
  "type": "storage",
  "name": "pi-vault",
  "baseDir": "data/vault/",
  "scanOfflineChanges": true,
  "useChokidar": false
}

useChokidar를 false로 두면 chokidar 대신 Deno 네이티브 Deno.watchFs를 쓴다. 이쪽은 루트 디렉토리 하나만 재귀로 감시하고 파일마다 watch를 걸지 않는다. 즉 사라진 임시파일에 watch를 거는 상황 자체가 안 생긴다.

그리고 이건 우리가 발견한 우회가 아니라 소스가 원래 그렇게 하라고 적어둔 쪽이었다. PeerStorage.ts의 start()에 이렇게 달려 있다.

// For addressing Deno's and chokidar's compatibility issues (especially on Windows),
// we use Deno's fs watcher as the primary watcher.
if (!this.config.useChokidar) {
    await this.startDenoFsWatch();
    return;
}

즉 네이티브 워처가 primary이고 chokidar가 옵션인데, 우리 설정이 반대로 켜져 있었던 것이다.

왜 그렇게 됐는지도 짐작이 간다. 상류 저장소가 서로 다른 말을 한다. readme의 예시 설정은 "useChokidar":false에 "이제 Deno.watch를 쓴다, 리눅스에서 문제가 있으면 켜라"는 주석이 붙어 있는데, 정작 함께 배포되는 dat/config.sample.json은 리눅스용 storage 피어 예시에 "useChokidar": true를 박아뒀다. 샘플을 복사해서 시작하면 chokidar가 켜진 채로 출발한다. 그리고 readme는 "리눅스에서 문제가 있으면 켜라"고 안내하는데, 여기서 겪은 건 정확히 그 반대였다.

한 가지 실무적인 함정. dat/config.json은 bind-mount라 이미지 리빌드가 필요 없지만, 여기서는 restart로 반영되지 않았다. 브리지가 단순 재시작을 넘겨 들고 가는 상태가 있는 것 같은데 그게 뭔지까지는 확인하지 못했고, 컨테이너를 새로 만들자 적용됐다.

docker compose up -d --force-recreate livesync-bridge

검증

두 가지를 확인했다.

같은 파일에 6번 연속으로 쓰기를 몰아넣고 재시작 0회. 그전까지는 이런 쓰기 버스트가 정확히 크래시 조건이었다.
호스트 쪽에서 파일을 편집해도 네이티브 워처가 정상 감지. bind-mount된 디렉토리를 컨테이너 밖에서 고쳐도 이벤트가 잡히는지가 이 스택에서는 필수 조건이라 따로 봤다.

남은 잔재도 적어둔다. CouchDB에 임시파일 이름으로 만들어진 유령 문서가 6건 남아 있었다. 전부 deleted:true 삭제 표식이라 어느 기기에도 그 이름의 파일로는 나타나지 않았고, 남는 건 스캔 로그의 노이즈뿐이었다.

지우는 건 보류했다. 얻는 게 로그 정숙뿐인데, 동기화 DB를 손으로 건드렸다가 비싸게 배운 편이 이 시리즈에 이미 하나 있다. 얻는 것에 비해 걸 게 크다.

교훈 / 체크리스트

재시작 정책은 죽음을 감춘다. unless-stopped는 종료 코드와 무관하게 되살리므로 죽는 것도 되살아나는 것도 조용하다. 컨테이너 재시작 횟수를 세보기 전엔 아무 일도 없어 보인다.
에러가 여러 줄 나오면 시간 순서를 먼저 본다. 늘 뒤에 오는 메시지는 원인이 아니라 죽는 과정의 부산물일 가능성이 높다.
파일 감시자를 쓰는 프로그램은 atomic write와 사이가 나쁘다. 감시 대상 안에서 임시파일이 생겼다 사라지는 쓰기가 있으면, 감시자가 그 짧은 창에 걸린다. 이벤트 처리에서 파일이 없는 건 정상 상황으로 다뤄야 한다.
자가복구가 있는 시스템은 결함을 오래 숨긴다. 재시작으로 알아서 복구되니 겉으로는 멀쩡한데, 복구되지 않는 소수의 쓰기가 조용히 누락된다. 증상이 안 보인다고 없는 게 아니다.