올해 초, 저는 PicoShare라는 오픈소스 앱을 만들었습니다. 파일을 공유하기 위한 간단한 Golang 웹 앱입니다. 이메일 첨부 파일로 보내기에는 너무 큰 파일을 보낼 때 사용하며, 수신자가 Dropbox나 Google Drive를 거쳐야 하는 번거로움을 겪지 않도록 하기 위해 만들었습니다.

몇 달 전부터 PicoShare 서버가 며칠마다 죽는 현상이 나타나기 시작했습니다. 로그를 확인해 보니 메모리 부족(out of memory) 오류가 있었습니다:

당시에는 크래시를 디버깅할 시간이 없어서 서버 메모리를 512MB에서 1GB로 늘렸습니다. 그래도 계속 크래시가 발생해서 다시 2GB로 늘렸습니다.

단순히 RAM을 더 투입해서 크래시를 해결하는 방식은 만족스럽지 않았습니다. 그래서 지난 2주 동안 크래시를 디버깅하며 트위터에 진행 상황을 공유했습니다.

이제 크래시를 일으키던 모든 문제를 수정했고, 그 과정에서 Go와 SQLite, 디버깅에 대해 유용한 교훈을 많이 얻었습니다.

실시간으로 전개됐던 이야기를 보고 싶다면 트위터 스레드를 확인해 보세요. 정리되고 압축된 버전으로 제가 배운 내용을 보고 싶다면 계속 읽어 주세요.

서문: 저는 SQLite를 이상하게 사용합니다

PicoShare를 만들면서 했던 독특한 아키텍처 결정 중 하나는 모든 파일 데이터를 SQLite에 저장한 것이었습니다. 이는 흔치 않은 선택입니다. 웹 애플리케이션은 보통 파일 업로드를 데이터베이스가 아니라 파일 시스템에 직접 저장하며, 특히 업로드 용량에 제한이 없을 때는 더욱 그렇습니다.

파일 데이터를 SQLite에 쓰는 장점은 PicoShare의 모든 애플리케이션 상태가 하나의 데이터베이스에 담긴다는 점입니다. 그 자체로는 특별할 것 없지만, 저는 PicoShare를 Litestream과 연동되도록 설계했습니다. Litestream은 SQLite 데이터베이스를 클라우드 스토리지에 복제하는 도구입니다. Litestream 덕분에 PicoShare는 사실상 ‘공짜로’ 백업과 복원 기능을 갖게 됩니다. 서버를 완전히 날려버린 뒤 어디든(다른 클라우드 호스팅 업체라도) 재배포해도 PicoShare는 정확히 동일한 상태로 깨어나 같은 파일들을 그대로 제공합니다.

디버깅 과정

오류 재현하기

PicoShare는 며칠에 한 번씩만 크래시가 발생했기 때문에, 가장 먼저 크래시를 더 빠르게 강제하는 방법을 찾아야 했습니다.

RAM이 256MB에 불과한 Fly 인스턴스에 PicoShare를 배포한 뒤 대용량 파일을 업로드하는 방법으로 오류를 재현하는 데 성공했습니다. 고해상도 버전의 단편 영화 Big Buck Bunny를 사용했으며, 용량은 269MB에서 618MB까지였습니다.

618MB 버전 두 개를 동시에 업로드하면 1분 정도 안에 항상 메모리 부족 오류로 PicoShare가 죽었습니다.

프로파일링 도구로 RAM 부풀림 식별하기

조사의 첫 번째 돌파구는 Litestream의 저자이자 최근 Fly 팀에 합류한 Ben Johnson에게서 나왔습니다. Ben은 상세한 풀 리퀘스트를 통해 단 한 줄의 코드가 어떻게 PicoShare의 RAM을 대량으로 소모하게 하는지 설명했습니다.

Ben은 프로파일링 경험이 풍부해서 새로운 단위 테스트를 만들고 테스트 후 메모리를 프로파일링하는 방식으로 문제를 재현할 수 있었습니다. 나중에 Ben이 같은 정보를 더 쉽게 얻는 방법을 알려주었기 때문에 여기서는 그 방법을 소개하겠습니다. Ben이 처음 사용한 방법은 풀 리퀘스트에서 확인할 수 있습니다.

알고 보니 Go 표준 라이브러리에는 웹 애플리케이션의 문제를 디버깅하기 위한 마법 같은 도구가 들어 있습니다. import에 다음 한 줄만 추가하면 됩니다:

_ "net/http/pprof"

이제 앱을 실행하면 유용한 디버깅 정보가 가득한 /debug/pprof/ 경로가 생깁니다.

이렇게 간단하게 추가할 수 있다는 사실에 놀랐습니다. 이 웹 인터페이스에는 흥미로운 데이터가 많지만, 제가 사용한 것은 heap 이었습니다. 사용 방법은 PicoShare에 대용량 파일을 업로드한 뒤 다음 명령을 실행하는 것이었습니다:

go tool pprof \
  -http=:8081 \
  -alloc_space \
  call_tree \
  http://localhost:4001/debug/pprof/heap

그러면 웹 인터페이스가 뜨면서 다음과 같은 그래프가 렌더링됩니다:

하단을 보면 bytes makeSlice 63.99 MB 라고 표시된 큰 빨간색 블록이 있습니다. PicoShare가 할당한 RAM 중 64MB가 Go의 makeSlice 함수에서 나왔다는 뜻입니다.

makeSlice는 제 코드가 아니라 Go 표준 라이브러리에 있는 함수입니다. 이 메모리 할당을 일으킨 PicoShare 코드를 찾기 위해 그래프를 위로 따라가다 PicoShare 함수를 찾았습니다:

이 체인에서 마지막 PicoShare 함수는 handlers.fileFromRequest이며, Go 표준 라이브러리 함수인 *Request.ParseMultipartForm을 호출합니다. 이 함수는 multipart HTTP 데이터를 파싱하는 역할을 하며, PicoShare가 파일 업로드를 받는 방식이기도 합니다.

ParseMultipartForm은 maxMemory 매개변수를 받으며, 문서는 다음과 같이 설명합니다:

요청 본문 전체가 파싱되며, 파일 파트 중 최대 maxMemory 바이트까지는 메모리에 저장되고 나머지는 임시 파일로 디스크에 저장됩니다.

PicoShare에서의 호출은 이렇게 생겼습니다:

r.ParseMultipartForm(32 << 20) // 32 MB

32MB로 제한을 지정했는데도 Go는 64MB의 RAM을 할당하고 있었습니다.

Ben은 maxMemory 매개변수를 1 << 20(1MB)로 줄여 보았고, ParseMultipartForm으로 인한 RAM 사용량이 2.5MB로 떨어졌습니다:

메모리 사용량이 크게 줄어들어 Ben이 문제를 확실히 해결했다고 생각했습니다.

하지만 Ben의 수정 사항을 적용한 테스트 버전을 배포했는데도 여전히 크래시가 발생했습니다.

Ben의 수정 이후 PicoShare는 크래시 전에 더 많은 부하를 견딜 수 있었으므로 효과는 분명 있었습니다. 그럼에도 세 개의 대용량 파일을 동시에 업로드하면 서버는 같은 메모리 부족 오류로 죽었습니다.

ParseMultipartForm 호출 후 리소스 해제하기

구글링을 통해 ParseMultipartForm에 또 다른 함정이 있다는 것을 알게 되었습니다.

문서에는 경고가 없지만, 호출자는 ParseMultipartForm 실행 중에 Go가 할당한 리소스를 해제하기 위해 r.MultipartForm.RemoveAll()을 호출해야 합니다. 즉, 저는 ParseMultipartForm을 호출할 때마다 메모리를 누수시키고 있었던 셈입니다.

누수를 고치기 위해 multipart 리소스를 정리하도록 코드를 다시 작성했습니다:

multipartMaxMemory := 1 << 20 // 1 MiB
if err := r.ParseMultipartForm(multipartMaxMemory); err != nil {
  return err
}
// Free form resources before returning from function.
defer func() {
  if err := r.MultipartForm.RemoveAll(); err != nil {
    log.Printf("failed to free multipart form resources: %v", err)
  }
}()

Fly에서 리소스를 명시적으로 해제한 뒤 RAM 사용량이 크게 줄어드는 것을 확인했기 때문에 이 수정은 꽤 유망해 보였습니다:

안타깝게도 이 수정을 적용한 뒤에도 크래시는 계속되었습니다.

다운로드 최적화하기

이 시점에서 Dan Wilhelm이 트위터 스레드를 팔로우하기 시작했습니다. Go를 단 하루도 써본 적이 없었지만, 그는 소매를 걷어붙이고 자신의 개발 머신에서 코드를 실험하기 시작했습니다.

Dan은 파일을 다운로드할 때 RAM 사용량이 급증한다는 것을 발견했습니다. 다운로드가 많은 RAM을 소모해서는 안 되므로 이상한 일이었습니다. multipart 폼을 파싱하는 것은 복잡해서 RAM 부풀림의 요인이 많을 수 있지만, 파일을 제공하는 일은 꽤 단순합니다.

PicoShare는 모든 파일 데이터를 SQLite에 328KB 청크 단위로 저장합니다. 청크 몇 개를 RAM으로 읽어 클라이언트에 전송한 뒤 메모리를 해제하면 되므로 RAM을 많이 쓸 이유가 없습니다.

Dan은 데이터베이스에서 PicoShare의 파일 데이터를 읽는 코드에서 버그를 발견했습니다. 어디인지 찾아보세요:

func (fr *fileReader) populateBuffer() error {
  if fr.offset == int64(fr.fileLength) {
    return io.EOF
  }

  startChunk := fr.offset / int64(fr.chunkSize)
  stmt, err := fr.db.Prepare(`
      SELECT
        chunk
      FROM
        entries_data
      WHERE
        id=? AND
        chunk_index>=?
      ORDER BY
        chunk_index ASC
      `)
  if err != nil {
    log.Printf("reading chunk failed: %v", err)
    return err
  }
  defer stmt.Close()

  var chunk []byte
  err = stmt.QueryRow(fr.entryID, startChunk).Scan(&chunk)
  if err != nil {
    return err
  }

  // Move the start index to the position in the chunk we want to read.
  readStart := fr.offset % int64(fr.chunkSize)

  fr.buf = bytes.NewBuffer(chunk[readStart:])
  fr.offset += int64(len(chunk)) - readStart

  return nil
}

버그가 있는 곳은 SQL 쿼리의 WHERE 절입니다:

WHERE
    id=? AND
    chunk_index>=?

이 쿼리는 파일 데이터의 단일 청크 하나만 가져오도록 되어 있습니다. 하지만 실제로는 대상 청크와 그 이후의 모든 데이터를 읽고 있었습니다.

수정 방법은 단순히 >=를 =로 바꾸는 것이었습니다:

WHERE
    id=? AND
    chunk_index=?

Dan의 수정은 다운로드 쪽이었기 때문에 업로드 중에 보던 크래시가 해결되리라고 기대하지는 않았습니다. 실제로도 해결되지 않았지만, 다운로드 제공 성능은 극적으로 개선되었습니다. 특히 동영상이나 오디오 같은 스트리밍 콘텐츠에서 파일의 다른 위치로 이동할 때 PicoShare가 훨씬 더 반응이 빨라졌습니다.

SQLite 트랜잭션 제거하기

트위터 스레드에서 여러 사람이 PicoShare의 SQLite 트랜잭션이 RAM 부풀림의 원인일 가능성이 높다고 제안했습니다.

PicoShare가 파일 데이터를 SQLite에 쓸 때 트랜잭션 안에서 수행했습니다. 데이터베이스가 항상 일관된 상태를 유지하도록 하기 위해서였습니다.

트랜잭션을 사용함으로써 SQLite는 일부 쓰기가 실패하더라도 파일의 일부만 데이터베이스에 남는 상태에 도달하지 않도록 보장했습니다. 또한 파일 메타데이터만 쓰고 파일 내용을 빠뜨리거나, 그 반대로 실수하는 일을 방지할 수 있었습니다.

검색해 보니 큰 SQLite 트랜잭션이 메모리 부풀림의 원인이 될 수 있다는 정보가 있어서 시도해 볼 만하다고 생각했습니다. 트랜잭션을 사용하는 대신 변경 사항을 즉시 커밋해 보았지만 여전히 RAM이 부풀었습니다. 트랜잭션이 별 차이를 만들지 않는 것처럼 보였습니다.

RAM 부풀림은 괜찮지만 크래시는 문제다

이 시점에서 저는 세 가지 다른 각도에서 RAM 사용량을 측정하고 있었는데, 그 결과가 모두 서로 달랐습니다:

• Go 디버그 메트릭이 보여주는 할당된 메모리 양
• VM 내부의 htop
• VM 호스트에서 제공하는 Fly의 RAM 메트릭

특히 Fly의 메트릭은 Go와 htop이 거의 사용하지 않는다고 표시할 때도 RAM이 가득 찬 것으로 자주 나타났습니다. 더 깊이 파고들수록 RAM 측정값이 실제 크래시 동작과 점점 더 벌어졌기 때문에 디버깅이 매우 답답했습니다.

상황을 바꾼 결정적인 통찰은 Andrew Ayer에게서 나왔습니다. 그는 RAM 부풀림이 아마도 잘못된 단서일 가능성이 높다고 지적했습니다:

Fly의 CEO인 Kurt Mackey가 스레드에 나타나 Andrew의 가설을 확인해 주었습니다:

즉, Fly의 메모리 메트릭에는 페이지 캐시가 포함되어 있었지만, 실행 중인 애플리케이션에 필요하면 VM이 해당 RAM을 회수해야 했습니다.

이것은 큰 깨달음이었습니다. 메모리 부족 크래시를 일으키기가 어려웠기 때문에 저는 RAM 부풀림을 크래시의 근사치로 사용해 왔던 것입니다. 하지만 VM이 프로세스를 계속 실행할 만큼 충분한 메모리를 가지고 있다면 RAM 부풀림 자체는 문제가 되지 않습니다.

이제 모든 것을 재평가해야 했습니다. 제가 다른 수정들을 기각했을 때, 그것이 무해한 RAM 부풀림 때문이었을까요? 아니면 실제 크래시를 관찰했기 때문이었을까요?

SQLite 트랜잭션 다시 살펴보기

Andrew Ayer가 RAM 부풀림에 대해 말한 것을 듣고 PicoShare의 SQLite 트랜잭션을 다시 살펴보았습니다. 트랜잭션 없는 구현을 시도했을 때 크래시를 봤던 걸까, 아니면 단순한 RAM 부풀림이었을까? 기억이 나지 않았습니다.

트랜잭션 없는 구현을 다시 실행해 보았습니다. 역시 RAM은 부풀었지만 PicoShare는 계속 실행되었습니다. 618MB 파일 세 개를 동시에 업로드했는데도 모든 업로드가 성공했고 PicoShare는 계속 HTTP 요청을 처리했습니다.

성공했습니다! 마침내 성능 문제의 근본 원인을 찾은 것 같았습니다.

그렇게 생각했습니다…

서버를 밤새 켜 두었는데 다음 날 아침 확인해 보니 같은 메모리 부족 크래시로 실패해 있었습니다.

SQLite VACUUM 제거하기

밤새 발생한 크래시가 SQLite VACUUM 명령과 관련이 있다고 즉시 의심했습니다. 이 명령은 데이터베이스 파일을 압축해 사용되지 않는 디스크 공간을 회수합니다.

크래시가 발생했을 때 PicoShare 서버를 사용하는 사람은 아무도 없었지만, PicoShare의 예약된 데이터베이스 유지 관리 시점과 일치했습니다. 7시간마다 PicoShare는 만료된 항목을 데이터베이스에서 제거하고 VACUUM을 수행해 사용되지 않는 디스크 공간을 회수합니다.

서버에서 VACUUM 명령을 실행해 테스트해 보니 실제로 메인 .db 파일의 크기는 줄어들었지만 SQLite 쓰기 전 로그(write-ahead log)의 크기가 증가하고 있었습니다.

이 시점에서 Ben은 왜 애초에 VACUUM이 필요한지 물었습니다:

그러게요, 왜 하고 있었던 걸까요?

PicoShare를 처음 출시했을 때 사용자들은 파일을 삭제한 뒤에도 디스크 공간이 반환되지 않는다고 불만을 제기했습니다. 저는 고정된 디스크 볼륨을 가진 Fly VM에서 PicoShare를 운영하므로 디스크를 얼마나 쓰든 저에게는 영향이 없었습니다. 하지만 주기적인 VACUUM을 추가하는 것은 그리 어렵지 않아서 추가했습니다.

고민 끝에 PicoShare의 동작을 변경하여 VACUUM을 기본적으로 끄고, 사용자가 필요하면 명령줄 플래그로 켤 수 있도록 하기로 했습니다.

dbPath := flag.String("db", "data/store.db", "path to database")
vacuumDb := flag.Bool("vacuum", false, "vacuum database periodically to reclaim disk space")
flag.Parse()

성공: 256MB RAM에서 실행되는 PicoShare

VACUUM을 기본적으로 비활성화하고 다른 성능 수정을 모두 적용한 뒤, PicoShare는 마침내 낮은 RAM에서도 안정적으로 실행되었습니다.

RAM이 256MB에 불과한 Fly VM에서 PicoShare를 24시간 동안 크래시 없이 실행했습니다.

그 밖에 배운 교훈들

위에서 배운 것들 외에도 이번 디버깅 과정에서 몇 가지 유용한 부수적인 교훈을 얻었습니다.

빌드-테스트 루프 최적화하기

좀 더 일찍 했으면 좋았을 것 중 하나는 빌드-테스트 루프를 최적화하는 것이었습니다. 가설 하나를 테스트하기 위한 과정은 다음과 같았습니다:

1. 변경 사항을 Fly에 배포하기(2~3분)
2. 대용량 파일 업로드하기(1~2분)
3. Fly의 RAM 메트릭이 따라잡을 때까지 기다리기(30~60초)

즉, 하나의 변경 사항을 테스트하는 데만 최대 6분이 걸렸고, 각 단계마다 수작업이 필요했습니다. 게다가 코드를 수정하는 시간은 포함하지도 않은 수치입니다.

처음에는 제한된 RAM으로 Docker 컨테이너에서 PicoShare를 실행해 보았지만 한 번도 크래시가 발생하지 않았습니다.

RAM_LIMIT="64m"
PORT=3001
PS_SHARED_SECRET="somesecretpass"

docker run \
  --memory "${RAM_LIMIT}" \
  --env "PORT=${PORT}" \
  --env "PS_SHARED_SECRET=${PS_SHARED_SECRET}" \
  --publish "${PORT}:${PORT}/tcp" \
  --name picoshare \
  mtlynch/picoshare:1.1.7

$ docker stats
CONTAINER ID   NAME        CPU %     MEM USAGE / LIMIT   MEM %     NET I/O         BLOCK I/O        PIDS
1ababd398113   picoshare   3.82%     63.68MiB / 64MiB    99.50%    278MB / 208MB   6.09GB / 7.1MB   21

왜 PicoShare가 실제 VM과 Docker에서 다르게 동작하는지 아직도 이해하지 못했지만, 제 추측으로는 Docker가 VM만큼 RAM 사용을 엄격하게 제한하지 않기 때문인 것 같습니다.

Dan Wilhelm이 PicoShare를 로컬에서 실행하며 RAM 사용량을 관찰해 얼마나 많은 진전을 이뤘는지 보고했을 때, 매번 Fly에 배포하면서 얼마나 많은 시간을 낭비하고 있었는지 깨달았습니다. 집에 있는 VM 서버에서 PicoShare를 실행해 보았지만 Fly에서처럼 크래시나 RAM 부풀림이 전혀 발생하지 않았습니다.

결국 효과가 있었던 방법은 Fly에 자체 개발 환경을 만드는 것이었습니다. Dockerfile을 작성해 PicoShare 소스와 몇 가지 개발 도구를 포함시켜 Fly에 배포했습니다. 그 뒤로는 fly ssh console로 서버에 셸을 열고 코드 변경 사항을 빠르게 테스트할 수 있었습니다.

Fly의 RAM 메트릭이 업데이트되기까지 약 30초의 지연이 있어서 엄청나게 빠른 것은 아니었지만, 매번 변경 사항을 처음부터 배포해야 했던 것에 비하면 큰 개선이었습니다.

서술적인 git 브랜치와 커밋 메시지로 기록 남기기

이번 조사 과정에서 발견한 유용한 기법 중 하나는 각 가설을 별도의 git 브랜치에서 테스트한 뒤 그 결과를 커밋 메시지로 기록하는 것이었습니다:

여러 가설이 난무하는 상황에서는 각 아이디어를 테스트했을 때 코드가 어떤 상태였는지 기억하기 어려웠습니다. 예를 들어 한때는 디버깅 중에 제가 새로 만든 버그 때문에 크래시가 발생하기도 했습니다.

코드가 어떤 상태였고 무엇을 테스트했는지에 대한 기록이 있었기에 생각을 정리하고 중복 작업을 피할 수 있었습니다.

Go 측정 도구는 cgo에서의 메모리 할당을 볼 수 없다

가장 초기에 시도한 디버깅 단계 중 하나는 runtime.ReadMemStats의 RAM 메트릭 일부를 보여주는 페이지를 PicoShare에 추가한 것이었습니다(나중에 net/http/pprof가 이를 더 잘 해준다는 것을 알게 되었습니다).

James Tucker는 이러한 측정이 cgo를 통해 할당한 리소스는 제외할 것이라고 지적했습니다:

실제로 저는 cgo를 통해 SQLite를 사용하고 있었습니다. PicoShare는 Go에서 가장 인기 있는 SQLite 라이브러리인 mattn/go-sqlite3을 사용합니다.

그리고 cgo를 사용하면 Go가 정확한 성능 메트릭을 보여줄 수 없다는 점은 납득이 갑니다. 외부 C 코드를 호출하기 위해 Go를 사용하는 경우, Go는 외부 코드의 리소스를 추적할 수 없습니다.

이를 우회하기 위해 순수 Go로 구현된 SQLite인 modernc.org/sqlite를 사용해 보았습니다. 하지만 어떤 이유에서인지 순수 Go 코드에서도 리소스 누수를 확인할 수 없었습니다.

Fly의 디스크 성능은 미칠 듯이 빠르다

한때 트위터 댓글에서 디스크 쓰기로 인해 RAM이 고갈되는 것일 수 있다는 의견이 있었습니다. PicoShare가 Fly VM의 디스크에 실제 물리적 매체에 기록되는 속도보다 더 빠르게 쓰고 있다면 데이터가 RAM에 대기열로 쌓일 수 있다는 것이었습니다.

이 가설을 테스트하기 위해 한 번도 써본 적 없는 fio 디스크 벤치마킹 유틸리티를 사용했습니다. 쓰기 속도가 3353MB/s로 나와서 도구를 잘못 사용하고 있다고 생각했습니다. 클라우드 VM치고는 불가능할 정도로 빠른 속도였기 때문입니다. 참고로 이는 집에 있는 NAS 서버에서 같은 테스트를 했을 때보다 약 30배 빠른 수치입니다.

Kurt Mackey는 Fly의 로컬 디스크가 엔터프라이즈 NVMe 드라이브이기 때문에 측정값이 맞을 가능성이 높다고 확인해 주었습니다:

막다른 길들

조사가 오로지 앞으로만 나아가는 과정이었으면 좋겠지만, 저는 여러 번 잘못된 방향으로 돌아가고 어디로도 이어지지 않는 가설들을 쫓았습니다. 다음은 그러한 막다른 길 중 일부입니다.

Litestream 의심하기

디버깅의 첫 번째 규칙은 문제가 자신의 코드에 있다고 가정하는 것입니다. 하지만 저는 이 규칙을 어겼습니다. 부분적으로는 이러한 버그들을 쫓는 데 얼마나 많은 작업이 필요할지 두려웠기 때문입니다.

그렇다고 해도 Litestream을 의심할 만한 정당한 이유도 있었습니다. PicoShare가 SQLite를 이상하게 사용하긴 하지만, SQLite에 1GB 데이터를 저장하는 것 자체는 그렇게까지 이상한 일은 아닙니다. Litestream은 비교적 새로운 도구이고 SQLite를 참신한 방식으로 사용하므로 크래시가 Litestream에서 비롯되었다고 상상하는 것이 큰 비약은 아니었습니다.

Litestream을 의심하면서도 유지 관리자인 Ben Johnson에게 더 많은 일을 안기고 싶지는 않았습니다. PicoShare가 Litestream의 흔치 않은 사용 사례라는 것을 알고 있었고, 문제를 격리할 간단한 재현 방법도 없었습니다.

그러다 5월에 Fly가 Litestream을 인수하고 Ben을 유지 관리자로 고용했습니다. Litestream과 Fly 모두와 관련된 문제였기 때문에 지금이 Ben에게 이 문제를 문의하기에 완벽한 시점처럼 보였습니다!

저는 Litestream에 버그를 등록해 시도해 본 것과 왜 문제가 Litestream과 관련이 있다고 생각하는지를 설명했습니다. 그리고 15분 뒤 Litestream을 비활성화한 상태에서도 PicoShare를 크래시시키는 데 성공해서 버그를 닫았습니다.

그렇지만 Litestream에 이슈를 등록한 것은 유용했습니다. 상세한 버그 리포트를 작성할 만큼 문제를 엄밀하게 접근하도록 만들었기 때문입니다. 또한 Ben의 호기심을 자극해 Litestream이 원인이 아님이 분명해진 뒤에도 Ben이 많은 유용한 조언을 해주는 계기가 되었습니다.

Fly 의심하기

로컬 VM이나 Docker에서는 크래시를 재현할 수 없게 되자 Fly 쪽에 문제가 있는 것이 아닐까 의심하기 시작했습니다. 저는 그다지 특이한 작업을 하고 있지 않았기 때문에 가능성이 낮아 보였습니다. 만약 그렇다면 Fly의 다른 사용자들이 RAM 고갈로 배포가 죽는 현상을 알아차리지 못했다는 것이 이상할 테니까요.

그래도 Fly라는 가능성을 배제하고 싶었습니다. 그래서 PicoShare를 Amazon의 관리형 Docker 컨테이너 서비스인 Lightsail에 배포했습니다. Lightsail에는 256MB RAM 옵션이 없어서 512MB 인스턴스에 배포했습니다. 몇 분 안에 거기서도 크래시를 재현할 수 있었고, Fly가 범인이 아니라는 점을 확인할 수 있었습니다.

/tmp는 RAM 디스크가 아니다

트위터 스레드에서 몇몇 댓글 작성자들은 Fly가 임시 디렉터리를 RAM 디스크로 마운트하고 있을 수도 있다고 제안했습니다. Go의 ParseMultipartForm 함수는 파일 업로드를 임시 디렉터리에 보관하므로, Fly가 임시 디렉터리를 RAM 디스크로 마운트했다면 일반적인 파일 업로드가 RAM을 고갈시키는 이유를 설명할 수 있습니다.

하지만 lblk를 실행해 보니 /tmp나 다른 임시 디렉터리가 RAM 디스크라는 징후는 전혀 보이지 않았습니다. 시스템에는 그냥 일반적인 디스크만 있는 것처럼 보였습니다:

$ lsblk
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINTS
vda  254:0    0  128M  0 disk
vdb  254:16   0    8G  0 disk /
$ du -h /tmp/*
149.3M /tmp/multipart-338465586
7.66 /tmp/test1

손수 만든 multipart 폼 리더 작성하기

Go 표준 라이브러리의 ParseMultipartForm 함수가 문서화된 제한보다 더 많은 메모리를 소모하는 것처럼 보이는 것은 위험 신호였습니다. 또한 ParseMultipartForm을 호출하고 바이트를 버려도 RAM이 가득 차는 것을 확인했습니다.

ParseMultipartForm의 문제를 우회할 수 있는지 확인하기 위해 제 특정 시나리오에 맞춰 직접 만든 장인 스타일의 multipart 리더를 작성해 보았습니다.

안타깝게도 제가 만든 multipart 리더는 표준 라이브러리보다 나은 성능을 내지 못했지만, 더 낮은 수준에서 multipart 데이터를 다뤄보는 것은 재미있었습니다.

업로드 속도 제한하기

데이터를 더 천천히 업로드하면 RAM에 어떤 영향을 미칠지 궁금했습니다. Chrome에서 3G 속도를 시뮬레이션하도록 설정해 클라이언트 쪽에서 업로드를 제한해 보았지만 PicoShare는 같은 동작을 보였습니다.

디스크에 쓰는 속도를 줄이기 위해 서버 쪽에서도 속도를 제한해 보았지만 역시 아무 효과도 없었습니다.

다만 Go에서 I/O 속도를 제한하는 것이 얼마나 쉬운지는 배웠습니다. io.Reader 인터페이스를 사용하고 있다면 다음과 같이 Reader를 속도 제한 리더로 감싸기만 하면 됩니다:

import "github.com/juju/ratelimit"

...

throttleRate := 1 << 20 // 1 MB
bucket := ratelimit.NewBucketWithRate(float64(throttleRate), throttleRate)
throttledReader := ratelimit.Reader(reader, bucket)

w := file.NewWriter(tx, metadata.ID, d.chunkSize)
if _, err := io.Copy(w, throttledReader); err != nil {
  return err
}

PicoShare 1.2.0

주말 동안 저는 이번 조사를 통해 발견한 모든 성능 문제를 수정한 PicoShare의 1.2.0 릴리스를 공개했습니다.

감사의 글

이 문제를 조사하는 데 도움을 주신 모든 분께 큰 감사를 드리며, 특히 남다른 도움을 주신 몇 분께 특별히 감사드립니다:

• Ben Johnson
• Dan Wilhelm
• Andrew Ayer
• James Tucker
• Kurt Mackey
• Andrew Johnston
• Phil Eaton