에러 로그를 열면 내 잘못은 몇 줄일까

서버에 문제가 생기면 에러 로그부터 엽니다. 그런데 평소에 그 파일에 무엇이 쌓이는지는 들여다본 적이 없었습니다. 30일치 아파치 에러 로그 90,151줄을 한 줄씩 갈라 봤습니다. 결과는 예상과 달랐습니다. 내 서버가 잘못해서 남은 줄은 사실상 없었습니다. PHP가 죽거나 경고를 낸 줄은 0줄이고, 90,151줄 중 89,454줄은 밖에서 들어온 요청이 남긴 것이었습니다. 에러 로그라는 이름이 붙어 있지만 실제로는 공격 기록부에 가깝습니다.

90,151줄이 무엇으로 채워져 있나

줄의 내용	줄 수	비율
없는 PHP 파일을 실행하려 함	58,396	64.8%
차단 규칙이 막아 낸 요청	25,539	28.3%
디렉터리 목록을 보려 함	2,638	2.9%
경로를 벗어나려는 요청	1,858	2.1%
내부 리다이렉트 한계 초과	1,023	1.1%
서버 시작·종료 등 그 밖	697	0.8%

가장 많은 것은 없는 PHP 파일을 실행하려다 실패한 기록입니다. 공격자가 심어 둔 파일이 있는지 이름을 돌려 가며 찔러 보는 것이고, 파일이 없으니 아파치가 한 줄씩 남깁니다. 하루 평균 1,946줄입니다. 이 줄들은 서버가 정상으로 동작했다는 증거인데 에러로 기록됩니다.

PHP 오류가 한 줄도 없다는 것

PHP가 치명적 오류나 경고를 낸 줄은 30일 동안 0줄이었습니다. 사이트가 멀쩡하다는 뜻이기도 하지만, 동시에 이 파일에서 내 문제를 찾는 것이 얼마나 비효율적인지를 보여 줍니다. 90,151줄 중 내가 고쳐야 할 줄이 하나라도 섞여 있다면 그것을 찾는 일은 건초더미에서 바늘 찾기입니다. 실제로 장애가 났을 때 에러 로그를 열고 스크롤을 내리다 보면 스캐너 기록만 지나갑니다.

차단 규칙은 일하고 있다

두 번째로 많은 25,539줄은 설정해 둔 차단 규칙이 요청을 막았다는 기록입니다. 무엇을 막았는지 세어 봤습니다.

차단된 대상	줄 수
.env 계열 파일	19,497
.git 폴더	5,488
합계	25,539

.env는 데이터베이스 비밀번호나 API 키가 들어가는 파일이고 .git에는 소스 코드 전체가 들어 있습니다. 둘 다 웹으로 열려 있으면 안 되는 것입니다. 파일 이름을 조금씩 바꿔 가며 찾는데, .env.backup, .env.local, .env.production, .env.bak, .env.old 같은 변형이 계속 나옵니다. 개발자가 원본을 지우면서 사본을 남겨 두는 습관을 노린 것입니다.

요청 대상은 이 서버에 올라와 있는 사이트 16개에 고루 퍼져 있었습니다. 특정 사이트를 겨눈 것이 아니라 아이피 대역을 훑으면서 나오는 모든 도메인에 같은 목록을 던지는 방식입니다. 남의 서버에서 .git 폴더부터 찾는 사람들을 봤을 때와 같은 패턴인데, 이번에는 차단 규칙을 넣은 뒤라 전부 막힌 기록으로 남았습니다. 규칙이 없었다면 이 25,539줄은 에러 로그가 아니라 접속 로그에 200 응답으로 남았을 것입니다.

아파치가 설정 오류라고 말한 1,023줄

여기서 한 번 놀랐습니다. 1,023줄에 “설정 오류로 보인다”는 메시지가 찍혀 있었습니다. 내부 리다이렉트가 열 번을 넘어 아파치가 요청을 포기했다는 뜻이고, 문구 그대로라면 내가 고쳐야 할 문제입니다.

어느 주소에서 났는지 확인하려고 그 시각의 접속 로그를 맞춰 봤습니다. 같은 초에 한 아이피가 보낸 요청은 이랬습니다. 테마 폴더 안의 존재하지 않는 관리용 파일, 플러그인 폴더의 업로드 스크립트, 루트의 정체불명 PHP 파일, 그리고 침입 도구 이름이 그대로 들어간 경로였습니다. 참조 페이지에는 검색 엔진 주소가 적혀 있었지만 형식이 어긋나 있었고, 브라우저 이름은 철자가 틀려 있었습니다. 사람이 만든 요청이 아닙니다.

즉 이 1,023줄은 설정 오류가 아니라 스캐너가 만든 착시였습니다. 없는 경로를 두드리면 리다이렉트 규칙이 연쇄로 걸리고, 그 끝에서 아파치가 설정을 의심하는 문구를 남깁니다. 이 문구만 보고 설정 파일을 뒤졌다면 찾을 것이 없는 곳에서 시간을 썼을 것입니다. 로그가 알려 주는 원인이 항상 맞는 것은 아닙니다.

디렉터리 목록 요청 2,638줄

세 번째 덩어리는 디렉터리 목록을 보여 달라는 요청입니다. 이 중 1,438줄이 한 경로에 몰려 있었습니다. 아파치를 설치하면 기본으로 생기는 빈 문서 폴더인데, 그 안에 첫 화면으로 쓸 파일이 없어서 목록을 보여 주려다 막힌 것입니다. 사이트를 전부 가상 호스트로 따로 두고 나면 이 기본 폴더는 쓰이지 않는데, 도메인 없이 아이피로 직접 들어오는 요청은 여기로 떨어집니다.

나머지는 업로드 폴더와 관리자 화면의 리소스 폴더였습니다. 목록이 막혀 있으니 결과는 같지만, 설정 파일이 겹쳐 로그가 두 번 쌓이던 때처럼 기본값을 그대로 두면 쓰지 않는 곳에서도 기록이 계속 생깁니다.

그래서 에러 로그를 어떻게 볼 것인가

이번 측정으로 정한 것은 두 가지입니다. 첫째, 장애가 났을 때 에러 로그를 통째로 열지 않습니다. 스캐너가 남긴 세 가지 문구를 먼저 걸러 내면 남는 줄이 1% 아래로 줄어듭니다. 90,151줄이 697줄이 됩니다. 둘째, 아파치가 설정 오류라고 말하더라도 그 요청이 어디서 왔는지부터 봅니다. 접속 로그에서 같은 시각 같은 아이피를 찾으면 대개 답이 나옵니다.

반대로 손대지 않기로 한 것도 있습니다. 에러 로그에 쌓이는 스캐너 기록 자체는 막지 않습니다. 이 줄들은 차단 규칙이 작동하고 있다는 증거이고, 지워 버리면 공격이 늘었는지 줄었는지 알 방법이 없어집니다. 한 달에 9만 줄, 용량으로는 크지 않습니다.

측정 방법

아파치 에러 로그 파일 다섯 개를 합쳐 90,151줄을 읽었습니다. 기간은 8월 30일 0시부터 9월 28일 15시 27분까지 30일입니다. 줄의 내용은 아파치가 남기는 고정 문구로 갈랐고, 한 줄에 두 문구가 함께 들어가는 경우는 한 번만 셌습니다. 디렉터리 목록 요청이 그런 경우로, 첫 화면 파일이 없다는 문구와 목록 표시가 금지돼 있다는 문구가 같은 줄에 붙습니다.

한계가 둘 있습니다. 첫째, 이 서버는 사이트 열여섯 개를 함께 올려 둔 곳이라 줄 수에 다른 사이트 몫이 섞여 있습니다. 사이트를 하나만 올린 서버라면 절대 수는 줄겠지만 구성 비율이 크게 달라질 것 같지는 않습니다. 스캐너는 도메인을 가리지 않기 때문입니다. 둘째, 에러 로그에 남지 않는 문제는 이 측정으로 보이지 않습니다. 느리게 응답하거나 잘못된 내용을 정상 코드로 돌려주는 종류는 접속 로그와 응답 시간을 따로 봐야 합니다.