로그 파일을 지웠는데 디스크 사용량이 그대로였던 이유
문제 발생
디스크 사용률 알람이 울려서 들어가 보니 애플리케이션 로그 파일 하나가 디스크를 거의 다 채우고 있었습니다. 급한 대로 지웠습니다. 그런데 지웠는데도 df가 1MB도 안 줄었습니다.
$ df -m .
/dev/vda 258020 13937 30413 32% /
$ rm app.log
$ df -m .
/dev/vda 258020 13937 30413 32% /du로 재면 폴더는 1MB로 보이는데 df는 그대로였습니다. 파일 목록에는 없고, 용량은 쓰고 있는 상태였습니다. 위 출력은 300MB짜리 로그로 재현한 것이고, 실제로는 그보다 훨씬 큰 파일이라 더 당황스러웠습니다.
원인 분석
rm은 파일을 지우는 게 아니라 이름을 지웁니다. rm이 부르는 unlink(2) 매뉴얼은 이렇게 설명합니다. unlink()는 파일 시스템에서 이름을 삭제하고, 그 이름이 파일의 마지막 링크이면서 어떤 프로세스도 파일을 열고 있지 않을 때 파일이 삭제된다고요. 이어서 마지막 링크였더라도 어떤 프로세스가 아직 파일을 열고 있으면, 그 파일을 가리키는 마지막 파일 디스크립터가 닫힐 때까지 파일은 계속 존재한다고 적어 둡니다. 애플리케이션이 로그 파일을 열어 둔 채였으니 이름만 사라지고 300MB는 그대로 남은 겁니다. 심지어 프로세스는 그 보이지 않는 파일에 계속 로그를 쓰고 있었습니다.
그래서 du와 df가 다르게 보입니다. du는 디렉터리를 따라가며 이름이 있는 파일을 더합니다. 이름이 없어진 파일은 셀 방법이 없습니다. df는 파일 시스템이 실제로 쓰고 있는 블록을 보고하니 여전히 잡혀 있습니다. 둘의 차이가 크면 이름 없이 열려 있는 파일부터 의심하면 됩니다.
어느 프로세스가 들고 있는지는 /proc에 나옵니다. proc_pid_fd(5) 매뉴얼에 따르면 /proc/PID/fd/에는 프로세스가 연 파일마다 파일 디스크립터 번호를 이름으로 하는 항목이 있고, 각각 실제 파일로 가는 심볼릭 링크입니다. 재현해 보니 지워진 파일은 링크 대상 뒤에 (deleted)가 붙어서 나왔습니다.
$ ls -l /proc/228/fd | grep deleted
l-wx------ 1 root root 64 Oct 17 01:18 3 -> /srv/app/app.log (deleted)lsof는 이걸 전체 프로세스에서 한 번에 찾아 줍니다. 매뉴얼에 따르면 +L1은 링크 수가 1 미만인, 그러니까 이름이 지워진 열린 파일만 고릅니다.
$ lsof +L1
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NLINK NODE NAME
python3 228 root 3w REG 254,0 314572990 0 950473 /srv/app/app.log (deleted)NLINK가 0이고 SIZE/OFF가 300MB입니다. 사라진 용량의 행방이 여기 있었습니다.
해결 방안
- 지금 당장 용량을 돌려받아야 하면
/proc를 통해 비웁니다. 프로세스를 재시작할 수 없을 때 쓰는 방법입니다./proc/PID/fd/N은 그 열린 파일로 이어지니, 이 경로에 빈 내용을 써서 길이를 0으로 만들면 블록이 바로 반환됩니다.
$ : > /proc/228/fd/3
$ df -m .
/dev/vda 258020 13637 30713 31% /재현에서는 이 한 줄로 300MB가 돌아왔고, 프로세스는 아무것도 모른 채 다음 줄을 이어서 썼습니다. 프로세스를 재시작할 수 있다면 그게 제일 깔끔합니다. 마지막 디스크립터가 닫히는 순간 파일이 정말로 삭제됩니다.
-
로그를 비울 때는 지우지 말고 자릅니다. 처음부터
rm대신: > app.log나truncate -s 0 app.log로 길이를 0으로 만들었다면 이런 일이 없었습니다. 이름은 그대로 두고 내용만 비우니 열어 둔 프로세스도 그대로 씁니다. 급하게 디스크를 비울 때 손이rm으로 가는 걸 막는 게 이 글의 절반입니다. -
로그 파일은 append 모드로 엽니다. 2번이 안전하려면 조건이 하나 있습니다.
open(2)매뉴얼에 따르면O_APPEND로 연 파일은 매write(2)전에 파일 오프셋을 파일 끝으로 옮깁니다. 그래서 바깥에서 파일을 0으로 잘라도 다음 쓰기는 0번 위치부터 시작합니다. append 모드가 아니면 프로세스는 자기가 알던 오프셋, 예를 들어 1MB 지점에 계속 쓰고, 파일 앞쪽 1MB는 NUL로 채워진 구멍이 됩니다. 크기는 다시 1MB로 보이는데 열어 보면 앞부분이 깨져 있습니다. 1MB를 쓴 파일을 바깥에서 자른 뒤 한 줄 더 써 보면 이렇게 갈립니다.
mode='w': size=1048596 bytes, blocks*512=4096 bytes
first bytes: \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0 \0
mode='a': size=20 bytes, blocks*512=4096 bytes
first bytes: a f t e r - t r u n c a t e lPython의 logging.FileHandler는 문서대로 mode='a'가 기본이라 괜찮습니다. 조심할 건 Node입니다. fs.createWriteStream()의 flags 기본값은 'w'라서, 이 스트림으로 로그를 쓰고 있었다면 { flags: 'a' }를 꼭 줘야 합니다. 재현에서 기본값으로 연 스트림은 위의 'w'와 똑같이 1MB짜리 구멍을 만들었습니다. logrotate의 copytruncate도 결국 바깥에서 파일을 자르는 방식이라 이 조건이 그대로 적용됩니다.
-
logrotate를 쓴다면 지워지는 파일을 누가 들고 있을지 생각합니다.
copytruncate는 매뉴얼대로 복사와 자르기 사이의 아주 짧은 틈에 로그가 유실될 수 있지만, 열린 파일을 지우지는 않아서 용량이 유령처럼 남지 않습니다. 반대로create방식은 파일 이름을 바꾸고 새 파일을 만드는데, 애플리케이션이 로그를 다시 열지 않으면 이름이 바뀐 옛 파일에 계속 씁니다. 그러다 보관 개수를 넘겨 logrotate가 그 파일을 지우는 날, 이 글의 상황이 그대로 재연됩니다.create를 쓸 거면postrotate에서 신호를 보내 다시 열게 하거나, Python이라면WatchedFileHandler처럼 파일의 device나 inode가 바뀌면 스스로 닫고 다시 여는 핸들러를 씁니다. -
감시는
df와du의 차이, 그리고(deleted)로 합니다.lsof가 없는 최소 이미지에서도/proc만 있으면 찾을 수 있습니다. 이 명령의 결과가 비어 있지 않으면 알림이 오게 해 두면 디스크가 차기 전에 압니다.
$ find /proc/*/fd -lname '*(deleted)' -printf '%p -> %l\n' 2>/dev/null
/proc/228/fd/3 -> /srv/app/app.log (deleted)
댓글0
댓글을 남기려면 로그인이 필요해요. 로그인
아직 댓글이 없어요. 첫 의견을 편하게 남겨 보세요.