질문은 거의 언제나 같습니다. 밤에는 사이트가 응답하는 데 이십 초가 걸렸는데 아침이 되니 저절로 괜찮아졌다는 것입니다. 이제는 들여다볼 것이 남아 있지 않습니다 — top은 지금 이 순간에 대해 답하는데, 물음은 새벽 세 시에 관한 것이기 때문입니다. 아래에서는 부하 수치가 실제로 무엇을 뜻하는지, 그중 어떤 것을 짝으로 읽어야 하는지, 그리고 한 번의 측정이 도움이 되기보다 오해를 낳는 경우가 더 많은 이유를 다룹니다.
Load average: 세 개의 숫자와 흔한 오해 하나
uptime
cat /proc/loadavg
nproc
세 숫자는 1분, 5분, 15분 평균입니다. 이 값은 0과 비교할 것이 아니라 nproc이 알려 주는 코어 수와 비교해야 합니다. 8코어 머신에서 8이라는 값은 가득 찼지만 건강한 부하입니다. 서버가 처리할 수 있는 만큼의 일이 딱 있는 상태입니다. 1코어 VPS에서 2라는 값은 처리 능력의 두 배 길이인 대기열이며, 모든 요청이 자기 순서를 기다립니다.
세 숫자의 상호 관계는 방향을 알려 줍니다. 1분 값이 15분 값보다 뚜렷하게 높다면 부하는 지금 이 순간 올라가고 있습니다. 반대라면 정점은 이미 지났고 보이는 것은 그 꼬리입니다.
이제 이 수치를 가장 자주 잘못 읽게 만드는 오해입니다. 리눅스의 load average는 「CPU 사용률」이 아닙니다. 다른 유닉스 계열과 달리 리눅스는 여기에 실행 중이거나 실행 준비가 된 프로세스만 세지 않고, D 상태에 있는 프로세스 — 중단할 수 없는 대기 상태 — 까지 함께 셉니다. 즉 디스크나 네트워크 파일 시스템을 기다리는 프로세스입니다. 부하는 12인데 CPU는 거의 놀고 있는 서버가 여기서 나옵니다. 일이 진행되지 않고 모두가 줄을 서 있는 것입니다.
CPU인가 디스크인가
이 두 경우를 갈라내는 것이 먼저 해 볼 만한 일입니다.
vmstat 1 5
iostat -x 1 3
vmstat 출력에서는 세 열이 중요합니다. r는 CPU를 기다리며 줄 서 있는 프로세스 수, b는 입출력을 기다리다 막힌 프로세스 수이고, wa는 CPU가 아무 일도 하지 않고 디스크를 기다린 시간의 비율입니다. us와 sy가 낮은데도 wa가 10~15 % 위에 계속 머문다면 서버는 디스크에 걸려 있는 것입니다. 코어를 더해도 소용이 없습니다. 있는 코어도 이미 비어 있으니까요.
어떤 프로세스가 기다리고 있는지는 이름으로 뽑아 볼 수 있습니다.
ps -eo state,pid,comm,wchan:30 | awk '$1 ~ /^D/'
우리 경험에서 나온 예입니다. 기본 설정 그대로의 Suricata는 서른 종류쯤의 이벤트를 기록하면서 그에 대한 로테이션은 전혀 설정하지 않습니다. 운영 중인 서버에서 이것이 이틀 만에 15 GB의 로그를 만들었습니다. 그때 부하는 바쁜 CPU가 아니라 바로 I/O wait로 나타났습니다. 시스템은 쉬지 않고 쓰고 있었고 나머지 전부가 그 뒤에 줄을 서 있었습니다. 해법은 더 큰 요금제가 아니라 짧아진 이벤트 목록과 설정된 로테이션입니다.
반대의 경우는 순전히 CPU 쪽 문제이고 훨씬 눈에 띄지 않습니다. 어떤 웹 페이지가 PHP-FPM이 실행되는 사용자 계정으로 apt를 호출하고 있었습니다. root는 /var/cache/apt/pkgcache.bin에 바이너리 캐시를 두는데 — 저장소가 열 개 남짓인 호스트에서는 70 MB입니다 — 이를 비용 없이 메모리에 매핑합니다. 일반 사용자는 그 디렉터리에 쓸 수 없어 호출마다 캐시를 처음부터 다시 만듭니다. 같은 머신에서 측정한 값은 root로 0.01초의 CPU 시간, 권한 없는 사용자로 4.2초였습니다. 같은 명령에 사백 배의 차이가 페이지가 열릴 때마다 곱해지고 있었던 셈입니다.
두 경우의 결론은 같습니다. 부하는 측정하는 것이지 짐작하는 것이 아닙니다. 의심스러운 명령을 하나씩 따로 계측하는 데 삼십 분이 들지만, 대개 처음 의심했던 곳과는 다른 지점을 가리킵니다.
메모리: free는 보이는 대로를 보여 주지 않는다
free -h
used 열 하나만으로는 알 수 있는 것이 매우 적고, free 열은 아예 오해를 부릅니다. 리눅스는 쓰지 않는 메모리를 페이지 캐시에 넘기고 요청이 들어오면 곧바로 응용 프로그램에 돌려주기 때문입니다. 읽어야 할 열은 available — swap으로 내려가지 않고 얼마를 차지할 수 있는지입니다. buff/cache가 큰 것은 문제가 아니라 시스템이 제대로 돌아간다는 표시입니다.
swap에서 중요한 것은 현재 값이 아니라 모양입니다. 올라갔다가 0으로 돌아왔다면 짧은 정점이 있었던 것입니다. 한 번 올라가서 그대로 머물렀다면 정점은 이미 지났고, 밀려난 페이지를 아무도 되돌려 놓지 않는다는 뜻입니다. 서버는 조용해 보여도 어느 순간 메모리가 부족했던 것입니다. 교환이 지금 일어나고 있는지는 vmstat의 si와 so 열이 보여 줍니다. 거기서 0이 아닌 값은 사용자가 가장 뚜렷하게 느끼는 형태의 느려짐입니다.
밤중의 침체 동안 어떤 프로세스가 그냥 사라졌다면 설명은 보통 여기에 있습니다.
journalctl -k --since yesterday | grep -i "out of memory"
dmesg -T | grep -i "killed process"
Out of memory: Killed process 1234 (mysqld) 같은 한 줄은 어떤 그래프보다도 문제를 잘 끝냅니다. 데이터베이스가 「스스로 넘어진」 것이 아니라, 메모리가 다 떨어져 커널이 멈춰 세운 것입니다.
누가 그러고 있는가
ps aux --sort=-%cpu | head -10
ps aux --sort=-%mem | head -10
한 가지 유보 사항: ps의 %CPU는 프로세스 전 생애의 평균이므로 짧은 급등은 그 목록에서 묻혀 버립니다. 그것을 보려면 구간으로 측정하는 top이나 pidstat 1 5이 필요합니다.
부하가 보안 문제가 되는 때
밤새 평탄하게 유지되는 100 %의 CPU 사용률에, 이름이 아무 의미 없고 작업 디렉터리가 /tmp나 /dev/shm인 프로세스가 함께 있다면 이는 사이트가 커진 모습이 아니라 채굴기의 전형적인 그림입니다. 인바운드 트래픽의 급증이 로그 기록 증가와 함께 나타나면 진행 중인 비밀번호 공격입니다. 로그 용량이 갑자기 뛰는 것은 대개 어떤 필터의 오탐 폭풍입니다.
보호 도구 자체도 별개의 범주입니다. 우리 서버 중 한 대에서는 방문자가 한 명도 없는데 부하가 3 근처에 머물렀고, 누적 CPU 시간으로 본 ps의 맨 위에는 사이트도 데이터베이스도 아니라 CrowdSec, fail2ban, Falco, Suricata가 있었습니다. 이는 고장도 아니고 끌 이유도 아니지만, 보호의 대가는 숫자로 알아 두는 것이 좋습니다. 작은 VPS에서는 체감이 됩니다.
관찰이 필요한 이유
위의 모든 것은 「지금 무슨 일이 일어나고 있는가」라는 질문에 답합니다. 아침의 질문 — 새벽 세 시에 무슨 일이 있었는가 — 은 이 명령들로 덮이지 않습니다. 아무도 기록하지 않았다면 지나간 밤에 대한 데이터는 없습니다. 그렇다고 VPS 한 대를 위해 Prometheus와 Grafana를 세우는 것도 의심스럽습니다. 관찰하는 쪽 스택이 관찰되는 서버보다 무거워지기 때문입니다.
5분마다 데이터베이스에 한 줄, 그리고 그것으로 최근 24시간을 그려 주는 한 페이지면 충분합니다. load average, CPU 사용률과 별도의 I/O wait, 메모리와 swap, 디스크 읽기와 쓰기, 파티션 사용률, inode, 파일 디스크립터, 연결 수. 같은 시간축에 놓으면 짝을 이루는 지표들이 맨눈으로 읽힙니다. CPU는 조용한데 wa가 높은 상태, 0으로 끝내 돌아오지 않은 swap, 한계에 다가가는 디스크립터 — 다가올 too many open files 오류가 발생 몇 시간 전부터 보이게 됩니다. 이것들이 한데 모이면 어떤 모습인지는 아래 데모 페이지에서 확인할 수 있습니다.