VPS는 온라인이었지만 Linux는 디스크 읽기에 18초를 기다리기 시작했다

디버깅 이야기에 들어가기 전에 한 가지는 분명히 하고 싶다. 나는 FDCServers에 대해 전반적으로 나쁜 인상을 가지고 있지 않다. 이 글은 FDCServers를 피하라고 말하는 리뷰도 아니고, 그들의 전체 인프라 품질을 평가하려는 글도 아니다. 특정 기간에 내가 사용하던 한 대의 VPS에서 아주 까다로운 문제가 발생했을 뿐이다.

오랫동안 그 VPS는 정상적으로 동작했고 실제 production traffic도 문제없이 처리했다. 그러다 어느 순간 상황이 달라졌다. 평범한 request가 터무니없이 오래 걸리기 시작했고, 페이지는 느리게 열리다가 때로는 아예 열리지 않았다. 반대로 장애를 제대로 확인하기 전에 서버가 다시 정상처럼 보이는 경우도 있었다.

가장 심했을 때 기록한 값은 다음과 같았다.

CPU iowait:       97–100%
I/O PSI full:     ~95–98%
read latency:     up to 18.7 seconds
flush latency:    up to 53.6 seconds
I/O queue depth:  128+

Nginx는 실행 중이었다. backend도 실행 중이었다. VM도 online이었다. 그런데 실제로 유용한 작업은 거의 진행되지 않았다.

Production 장애 자체는 답답했지만 디버깅 과정은 정말 재미있었다. 내가 Linux를 좋아하는 이유 중 하나가 바로 이런 상황이다. 겉으로는 살아 있는 시스템에서도 여러 독립적인 kernel interface를 따라가면 실제 진행이 어느 지점에서 멈췄는지 확인할 수 있다. 이 글은 그 단서를 따라가는 이야기이지 FDCServers가 좋은지 나쁜지 판단하는 글이 아니다.

active (running)은 거의 아무것도 보장하지 않았다

처음에는 당연한 것부터 확인했다.

top
free -h
df -h
systemctl status nginx

정상 상태에서는 대략 이랬다.

D-state processes: 0
CPU iowait:        ~0%
disk latency:      ~2–4 ms
I/O PSI some:      0.04
I/O PSI full:      0.04

이 순간에만 접속했다면 VPS가 정상이라고 결론 내리기 쉬웠을 것이다. 하지만 normal traffic이 돌아오면 상태가 완전히 달라졌다. Intermittent 장애에서는 정상 snapshot만 봐서는 실패 상태를 거의 알 수 없다. 장애가 실제로 발생하고 있을 때 evidence를 수집해야 했다.

조사 방향을 바꾼 iostat 샘플

r_await = 18744 ms
f_await = 53561 ms
aqu-sz  = 128.54
util    ≈ 100%
read    = 88 KB/s

완료된 read는 약 18.7초, flush는 약 53.6초가 걸렸다. 평균 queue는 128을 넘었는데 실제 read throughput은 겨우 88 KB/s였다.

이건 demanding workload를 효율적으로 처리하느라 storage가 바쁜 모습이 아니었다. Virtual block path는 사실상 포화 상태였지만 거의 일을 끝내지 못하고 있었다. Utilization이 높다는 사실만으로 장애라고 할 수는 없다. 하지만 엄청난 latency, 큰 queue, stalled task, 낮은 throughput, 실패하는 request가 함께 나타난다면 전혀 다른 신호다.

iowait만으로 진단하지 않기로 했다

blocked processes: 4–9
CPU iowait:        97–100%
CPU idle:          0%

“CPU가 100%의 시간을 디스크를 기다리는 데 쓰고 있었다”고 정리하고 싶어진다. 직관적으로는 유용하지만 Linux accounting은 그보다 복잡하고 iowait 자체가 디스크의 직접 측정값은 아니다. 그래서 하나의 symptom으로 보고 다른 독립적인 evidence를 찾았다.

PSI는 I/O가 실제 작업을 멈추고 있음을 보여줬다

cat /proc/pressure/io

심한 구간에서는 다음과 같았다.

some avg10=99.14
full avg10=95.55

이후 재현에서는 full이 98% 가까이 올라갔다. I/O pressure에서 some은 일부 non-idle work라도 I/O 때문에 stalled된 시간을, full은 모든 non-idle task가 동시에 I/O 때문에 stalled된 시간을 뜻한다. 100%에 가까운 값은 단순히 “디스크가 바쁘다”는 의미가 아니다. workload가 진행할 기회 자체를 거의 잃고 있다는 뜻이다.

D-state를 보자 하나의 process만 탓할 수 없었다

ps -eo state,pid,ppid,etime,wchan:50,comm,args | awk 'NR==1 || $1 ~ /^D/'

process 하나가 잠깐 D-state에 들어갔다고 storage 장애가 증명되는 것은 아니다. 중요한 것은 어떤 process들이 동시에 막혀 있었느냐였다. jbd2, systemd-journald, Nginx worker, Nginx cache process, 기타 filesystem activity처럼 서로 관련 없는 구성요소들이 함께 block돼 있었다.

backend만 멈추면 backend를 본다. Nginx만 멈추면 Nginx를 본다. 하지만 Nginx, system journal, EXT4 journal thread가 함께 진행하지 못한다면 개별 process보다 공통 dependency가 더 중요하다. 이 경우 공통점은 filesystem과 그 아래의 storage path였다.

Kernel stack이 다음 layer를 보여줬다

EXT4 journal thread는 다음 path에서 보였다.

wait_on_buffer
jbd2_log_wait_commit
jbd2_journal_commit_transaction

Nginx worker는 일반적인 filesystem read path에 있었다.

folio_wait_bit_common
filemap_read
generic_file_read_iter
ext4_file_read_iter
vfs_read
pread64

한 번은 kernel이 다음과 같이 보고했다.

INFO: task nginx blocked for more than 122 seconds.

systemctl status nginx는 여전히 active (running)이라고 표시할 수 있었다. 둘 다 사실이다. process는 존재하지만 Nginx task가 2분 넘게 유용한 작업을 끝내지 못할 수 있다. Running process와 healthy service는 같은 의미가 아니다.

가장 깔끔한 비교 실험은 약 3밀리초였다

Nginx를 통한 request는 실패했다.

HTTP=000
SSL connection timeout

그다음 Nginx를 우회해 local backend에 직접 요청했다.

connect = 0.000423 s
TTFB    = 0.003063 s
total   = 0.003139 s

약 3 ms였다. 이 테스트에서는 정확한 HTTP status가 중요하지 않았다. backend는 connection을 받고 request를 실행한 뒤 거의 즉시 response를 돌려줬다. 거의 같은 시점에 Nginx worker는 EXT4 read path 안에서 기다리고 있었다.

application execution       → progressing normally
filesystem-backed web path  → not progressing normally

조사를 계속할수록 application-level 원인이라는 설명은 점점 설득력을 잃었다.

같은 VPS가 약 30초 만에 무너질 수 있었다

한 재현 직전에는:

HTTP:          200
D-state:       0
CPU iowait:    3%
r_await:       ~1.18 ms
I/O PSI full:  ~2.95%

약 30초 뒤:

D-state:       4
CPU iowait:    91%
CPU idle:      0%
I/O PSI some:  86.11%
I/O PSI full:  78.02%
r_await:       236.50 ms
HTTP:          000

더 악화되면:

CPU iowait:    96–100%
I/O PSI full:  ~98%
HTTPS queue:   512
HTTP:          000

workload를 제거하면 반대 변화도 빠르게 일어났다.

D-state:      0
CPU iowait:   6%
r_await:      ~0.98 ms
queue depth:  ~0.07
HTTP:         200

이런 이유로 intermittent infrastructure 장애는 어렵다. 10분 뒤 같은 VM을 검사한 사람이 sub-millisecond latency를 보고해도 틀렸다고 할 수 없다. 그 사람은 단지 다른 state를 보고 있는 것이다.

Latency가 0이라고 항상 좋은 소식은 아니다

시스템이 명백히 비정상인데도 iostat에서 r_await = 0인 구간이 있었다. 동시에 높은 iowait, D-state process, outstanding I/O, 거의 없는 completed read, 거의 0에 가까운 throughput이 나타났다.

완료된 operation을 기준으로 하는 평균값은 sampling interval 동안 거의 아무것도 완료되지 않을 때 의미가 줄어든다. 0이라는 값이 read가 즉시 끝났다는 뜻은 아니다. stuck operation을 설명할 만한 completion 자체가 부족할 수 있다.

이 incident 이후에는 latency, IOPS, throughput, queue depth, in-flight I/O, D-state, PSI, 실제 request completion을 함께 본다.

한 incident가 긴 support 조사로 이어졌다

첫 번째 심각한 사건은 원래 인프라의 scheduled backup과 겹쳤고 FDCServers도 backup이 실행 중이었다고 확인했다. 처음에는 합리적인 설명 후보였다. 하지만 backup 종료 후, 원래 backup window 밖에서도 같은 유형의 storage stall을 다시 재현했다.

문제는 여러 날에 걸쳐 다시 발생했다. 한 incident에서는 service log 기준 VPS가 이후 4시간 41분 15초 동안 사용할 수 없었다. storage stall 자체가 VM을 그 state로 만들었다고는 증명할 수 없다. 그 결론에는 내가 볼 수 없는 host-side 정보가 필요하다.

application
    ↓
Linux VFS
    ↓
EXT4
    ↓
virtual block device
    ↓
?

물음표 뒤에는 virtualization, host queue, storage network, distributed storage, physical media, scheduler 등 guest가 볼 수 없는 layer가 존재할 수 있다. 나는 failure가 드러나는 경계까지만 볼 수 있었고 physical root cause는 볼 수 없었다.

FDCServers는 문제를 내부 escalation했고 결국 VPS를 다른 node로 migration했다. 그 후에도 guest에서 심각한 storage stall을 다시 기록했다. 이것이 모든 FDCServers node에 storage 문제가 있었다는 뜻은 아니다. 내 관점에서 내 VPS에 영향을 주던 문제가 사라지지 않았다는 뜻일 뿐이다.

그래도 이것을 FDCServers에 대한 부정적인 이야기라고 생각하지 않는다

Infrastructure incident 하나를 provider 전체에 대한 verdict로 만드는 것은 쉽다. 나는 그렇게 하고 싶지 않다.

정상적인 operating model 자체가 내 workload와 맞지 않는 service와, intermittent하고 재현하기 어렵고 isolate하는 데 오래 걸리는 infrastructure problem은 다르다. FDCServers에서 겪은 경험은 후자에 가까웠다.

incident 전에는 VPS가 정상적으로 동작했고 실제 production traffic도 처리했다. Support는 조사했고 문제를 해결하려고 했다. 결국 나는 충분한 evidence를 모았고 그 VPS에 production을 계속 의존하지 않기로 결정했다.

service cancel과 refund를 요청했고, FDCServers는 환불해 주었다. 이것은 전체적인 인상을 평가할 때 중요한 부분이다.

현재 인프라를 다시 테스트하지 않았기 때문에 오늘날 FDCServers VPS가 어떻게 동작하는지는 말할 수 없다. 내 instance에서 발생한 일이 fleet 전체를 대표했다는 evidence도 없다. Infrastructure는 계속 바뀐다. 한 VPS의 어려운 incident를 provider 전체에 대한 영구적인 평가로 만들 생각은 없다. 여기서 FDCServers를 추천하는 것도 아니다. 단지 내게 일어난 일을 기록할 뿐이다.

가장 재미있었던 것은 Linux 자체였다

Downtime은 답답했지만 investigation은 재미있었다. 문제의 경계를 찾아가는 과정 자체가 좋았다.

Physical root cause를 확인할 만큼 visibility가 없었다. 내가 원한 답은 더 단순했다. 어느 layer에서 useful work가 완료되지 않는가?

backend는 약 3ms에 응답했다. Nginx는 active라고 표시됐지만 kernel stack에서는 EXT4 read 안에서 기다리고 있었다. vmstat은 blocked process와 극단적인 I/O wait를 보여줬다. PSI는 I/O stall이 workload 거의 전체를 잡아먹고 있음을 보여줬다. iostat은 엄청난 latency와 queueing을 보여줬고, D-state는 관련 없는 process들이 함께 기다리는 모습을 보여줬다. Kernel은 Nginx task가 122초 넘게 block됐다고 보고하기도 했다.

어떤 단일 metric도 incident를 해결하지 못했다. 여러 signal이 같은 방향을 가리킨 것이 결정적이었다. 이것이 내가 Linux를 좋아하는 이유 중 하나다. “사이트가 가끔 열리지 않는다” 같은 애매한 현상에서 시작해 useful work가 멈추는 layer까지 정확하게 좁혀갈 수 있다.

지금 사용하는 디버깅 workflow

top
free -h
df -h

date -u
uptime
cat /proc/pressure/io
cat /proc/pressure/memory
cat /proc/pressure/cpu
vmstat 1 10
iostat -x 1 10
ps -eo state,pid,ppid,etime,wchan:50,comm,args | awk 'NR==1 || $1 ~ /^D/'
ss -lntp
journalctl -k --since "30 min ago" --no-pager

가능하면 request path도 layer별로 따로 테스트한다.

public request
      ↓
reverse proxy
      ↓
direct backend
      ↓
filesystem
      ↓
block device

이제 단순히 “왜 서버가 느린가?”라고만 묻지 않는다. 어느 layer에서 useful work의 completion이 멈추는가? 이 질문이 훨씬 좋은 실험을 만든다.

마지막 규칙: reboot 전에 evidence를 수집한다

Reboot가 production에 꼭 필요한 조치일 수 있다. 하지만 가장 가치 있는 diagnostic state를 지워버릴 수도 있다.

Before reboot:
D-state:     high
I/O PSI:     ~97%
iowait:      ~100%
queues:      large
requests:    failing

After reboot:
D-state:     0
latency:     milliseconds
requests:    healthy

Availability와 business impact가 허용한다면 먼저 UTC timestamp, PSI, vmstat, iostat, D-state, wchan, kernel message, socket queue, request timing을 기록한다. 그다음 machine을 복구한다.

Server는 실행 중이었다. Workload는 아니었다.

최종적으로 어떤 host-side component가 incident를 일으켰는지는 알지 못했다. 특정 SSD가 고장 났다고 말할 수도 없고, 특정 storage node를 지목할 수도 없으며, virtual block device 뒤에서 정확히 무엇이 일어났는지도 증명할 수 없다.

그래도 Linux 안에서 확인한 사실만으로 충분했다.

read latency:       up to 18.7 s
flush latency:      up to 53.6 s
I/O PSI full:       almost 100%
iowait:             almost 100%
I/O queue:          128+
Nginx:              blocked in filesystem reads
EXT4/jbd2:          blocked waiting for I/O
direct backend:     ~3 ms
HTTP through Nginx: timing out

Application과 실패한 layer를 분리하고 운영 결정을 내리기에 충분했다. FDCServers는 VPS 비용을 환불했고, 나는 다른 환경으로 옮겼다. 한 번의 어려운 infrastructure incident를 provider 전체에 대한 verdict로 삼지는 않는다.

더 유용하게 남은 교훈은 이것이다. process는 running일 수 있고, service는 active일 수 있고, VM은 online일 수 있으며, ping도 성공할 수 있다. 그런데도 machine은 거의 아무런 useful work도 완료하지 못할 수 있다.

Linux에는 그 차이를 확인할 충분한 evidence가 있다. Failure가 남아 있을 때 올바른 질문을 하면 된다.