로깅

기억하지 않는 시스템

새벽 3시에 결제가 실패했다는 신고가 들어왔습니다. 지금 접속해 보면 아무 문제가 없습니다. 그럼 무엇을 볼 수 있을까요?

아무것도 볼 수 없습니다. 그 순간은 이미 지나갔고, 서버는 그때 무슨 일이 있었는지 기억하지 않습니다. 컴퓨터는 방금 한 일을 기록해 두라고 시키지 않으면 기록하지 않습니다.

그래서 우리는 서버에게 일일이 시킵니다. "요청을 받을 때마다, 누가·언제·무엇을 요청했고·결과가 어땠는지 한 줄씩 적어라." 이 한 줄 한 줄이 로그입니다.

로그는 은행 창구의 CCTV와 같습니다. 평소에는 아무도 보지 않습니다. 아무도 보지 않는데도 매일 녹화하는 이유는 단 하나, 사고가 났을 때 그것 말고는 볼 게 없기 때문입니다.

좋은 로그와 쓸모없는 로그

로그를 남긴다고 다 되는 게 아닙니다. "오류 발생"이라고만 적힌 로그는 아무 도움이 되지 않습니다. 나중에 사고를 조사할 사람이 궁금해할 것을 미리 적어둬야 합니다.

• 언제 일어났는가 (정확한 시각)
• 누구의 요청이었는가 (사용자·요청 식별자)
• 무엇을 하려던 중이었는가
• 어떻게 끝났는가 (성공/실패, 실패라면 왜)

특히 중요한 것이 요청 식별자입니다. 요청 하나가 서버 다섯 대를 거쳐 간다면, 다섯 대의 로그에 같은 식별자가 찍혀 있어야 흩어진 기록을 하나로 꿰맬 수 있습니다. 식별자가 없으면 로그는 조각난 문장 더미일 뿐입니다.

여기서 진짜 문제가 시작된다

자, 로그를 남기기로 했습니다. 어디에 적을까요? 서버 한 대의 디스크에 적으면 그 서버가 죽는 순간 기록도 같이 사라집니다. 그러니 바깥의 보관소에 보내야 합니다.

가장 단순한 방법은 이것입니다.

요청 처리 → 로그 한 줄을 보관소에 쓴다 → 쓰기가 끝나면 → 사용자에게 응답

아무 문제 없어 보입니다. 평소에는 그렇습니다. 보관소가 빠르니까요.

창고가 느려지는 날

그런데 어느 날 보관소가 느려집니다. 점검이든, 네트워크 문제든, 다른 팀이 대용량 작업을 돌리든 이유는 많습니다. 로그 한 줄 쓰는 데 0.4초가 걸리기 시작합니다.

이때 무슨 일이 벌어질까요? 서버는 응답을 보내기 전에 로그 쓰기가 끝나기를 기다립니다. 그래서 모든 사용자 요청이 0.4초씩 길어집니다. 서버가 동시에 처리할 수 있는 요청 수는 정해져 있으니, 요청 하나가 자리를 0.4초씩 붙잡고 있으면 처리량이 그만큼 곤두박질칩니다.

결과는 이렇습니다.

로그 창고가 느려졌을 뿐인데 서비스가 죽었습니다.

사고를 조사하려고 달아둔 장치가 사고를 일으켰습니다. 이건 실제로 자주 일어나는 일이고, 그때마다 원인을 찾기가 유난히 어렵습니다. 아무도 "로그 때문"이라고 의심하지 않기 때문입니다.

해법 — 적는 일과 옮기는 일을 나눈다

식당 주방을 생각해 봅시다. 요리사가 주문표를 적을 때마다 창고까지 뛰어가서 철하고 온다면, 창고가 멀어지는 순간 요리가 멈춥니다.

실제 주방은 그렇게 하지 않습니다. 요리사는 주문표를 옆의 통에 툭 던지고 바로 다음 요리를 합니다. 통을 창고로 옮기는 것은 다른 사람의 일입니다.

시스템에서도 똑같이 합니다.

앱 서버 → (로그 한 줄을 큐에 던진다. 여기까지가 앱의 일)
            ↓
          로그 큐  (통)
            ↓
          워커    (옮기는 사람)
            ↓
          보관소  (창고)

큐는 던져 넣기만 하면 즉시 "받았습니다"라고 답하는 통입니다. 앱 서버는 그 대답을 듣고 바로 다음 일을 합니다. 로그가 실제로 보관소에 도착했는지는 앱이 알 바가 아닙니다.

워커는 통에서 로그를 꺼내 보관소로 옮기는 담당자입니다. 보관소가 느려지면 워커가 기다립니다. 워커가 기다리는 동안 사용자는 아무것도 느끼지 못합니다.

공짜는 아니다

대신 잃는 것이 있습니다.

• 기록이 늦게 도착합니다. 통에 쌓여 있는 동안은 보관소에서 검색되지 않습니다.

지금 막 일어난 사고를 실시간으로 보려 하면 로그가 아직 안 왔을 수 있습니다.

• 통이 넘치면 버려집니다. 워커가 오래 못 따라가면 통이 가득 찹니다. 그때부터는

새 로그가 버려집니다. 서비스는 살아 있지만 기록에 구멍이 납니다.

이것이 이 강의의 핵심 교환 조건입니다.

동기: 기록은 확실하다. 대신 창고가 느려지면 서비스가 같이 죽는다. 비동기: 서비스는 안전하다. 대신 기록이 늦거나, 밀리면 일부를 잃는다.

거의 모든 실제 시스템이 후자를 고릅니다. 이유는 단순합니다. 로그 몇 줄을 잃는 것보다 서비스가 멈추는 쪽이 훨씬 비싸기 때문입니다. 회계 감사나 법적 증적처럼 한 줄도 잃으면 안 되는 기록은 로그가 아니라 데이터베이스에 넣습니다. 그건 애초에 로그가 아니라 데이터입니다.

직접 해보세요

아래 과제에는 앱 서버가 로그를 보관소에 직접 쓰는 구조가 준비돼 있습니다. 실행하면 중간에 보관소가 느려지는 사고가 일어납니다. 서비스가 어떻게 무너지는지 먼저 보고, 큐와 워커를 넣어 그 연결을 끊어 보세요.