디버그 로그가 범인을 잘못 지목할 때

워드프레스가 “치명적인 오류가 발생했습니다”라는 한 줄만 남기고 멈추면 그 화면으로는 아무것도 알 수 없습니다. 무엇이 멈췄는지는 디버그 로그를 켜야 보입니다. 그런데 로그를 켜서 읽는다고 끝나는 것도 아닙니다. 로그는 오류가 터진 자리를 알려 줄 뿐이고, 그 자리가 원인인 곳과 다를 때가 있습니다. 실제로 로그가 특정 파일의 특정 줄을 622번 지목했는데 그 파일이 멀쩡했던 일을 겪었습니다. 이 글은 로그를 켜고 읽는 절차와, 로그를 믿지 말아야 하는 경우를 같이 정리한 것입니다.

먼저 로그를 남기게 한다

워드프레스 루트에 있는 wp-config.php를 열고 상수 세 개를 넣습니다. WP_DEBUG를 켜서 디버그 모드로 돌리고, WP_DEBUG_LOG로 파일에 적게 하고, WP_DEBUG_DISPLAY를 꺼서 화면에는 안 나오게 합니다.

상수	값	하는 일
WP_DEBUG	true	디버그 모드를 켠다
WP_DEBUG_LOG	true	wp-content/debug.log에 기록한다
WP_DEBUG_DISPLAY	false	화면에는 출력하지 않는다

세 번째가 중요합니다. 이걸 빼먹으면 오류 내용이 방문자 화면에 그대로 나갑니다. 파일 경로와 데이터베이스 관련 문구가 함께 노출되므로 운영 중인 사이트에서는 반드시 꺼 두고 로그로만 봐야 합니다.

저장하고 사이트를 다시 열면 오류가 날 때마다 로그가 쌓입니다. 주의할 점은 이 로그가 오류가 다시 날 때만 생긴다는 것입니다. 이미 지나간 오류는 기록되지 않으니, 문제가 났던 상황을 다시 만들어야 합니다.

로그에서 무엇을 읽나

로그 한 줄은 시각, 등급, 메시지, 파일 경로와 줄 번호로 되어 있습니다. 등급부터 보면 급한 것과 아닌 것이 갈립니다.

등급	뜻	대응
Fatal error	실행이 중단됨	지금 고쳐야 함
Warning	경고, 실행은 계속됨	원인은 봐 둬야 함
Deprecated	곧 없어질 방식을 씀	업데이트 전에 정리
Notice	단순 알림	대개 무시 가능

흰 화면을 만들었다면 그건 Fatal error입니다. 로그에서 Fatal만 먼저 추려 보면 목록이 확 줄어듭니다. 그리고 그중에서도 가장 이른 시각의 것을 봅니다. 뒤에 따라오는 오류는 앞의 오류 때문에 생긴 것일 때가 많습니다.

로그가 가리킨 파일이 범인이 아니었던 날

운영 중인 워드프레스 한 곳이 7분 동안 500 오류를 냈습니다. 로그에는 같은 줄이 622번 찍혀 있었습니다. 메모리 한도를 넘었다는 내용이었고, 지목된 자리는 워드프레스 코어의 테마 관련 파일 189행이었습니다.

그 189행을 열어 봤습니다. 현재 테마 이름을 돌려주는 함수의 반환문 한 줄이었습니다. 메모리를 크게 쓸 만한 코드가 아니었습니다. 게다가 그날 코드도 데이터베이스도 바뀐 것이 없었습니다.

로그가 말한 것	실제
테마 파일 189행에서 터짐	그 줄은 문자열 반환 한 줄
메모리 한도 초과	한도 설정은 그대로였음
622회 반복	7분 뒤 저절로 멈춤
—	명령줄에서 실행하면 정상

결정적인 단서는 요청하려던 메모리 크기였습니다. 4기가바이트가 조금 넘는 값이었는데, 저 한 줄이 만들어 낼 수 있는 숫자가 아닙니다. 정상적인 코드가 잘못 동작한 것이 아니라 숫자 자체가 깨져 있었던 것입니다.

원인은 PHP의 공유 캐시였습니다. 그날 새벽에 PHP를 올린 뒤 컴파일된 코드를 담아 두는 공유 메모리가 망가진 상태였고, 웹 요청을 처리하는 쪽은 그 메모리를 계속 쓰는 반면 명령줄은 매번 새로 만들기 때문에 명령줄에서는 멀쩡했던 것입니다. 캐시를 비우자 바로 복구됐습니다.

숫자가 이상하면 코드를 의심하지 않는다

여기서 얻은 기준이 하나 있습니다. 오류 메시지의 숫자가 상식 밖이면 지목된 코드를 보지 말아야 합니다. 4기가를 할당하려 했다거나, 배열 길이가 음수라거나, 있을 수 없는 문자열 길이가 찍혔다면 그건 그 줄의 문제가 아니라 그 줄을 실행하는 환경의 문제입니다.

반대로 숫자가 그럴듯하면 코드가 맞습니다. 메모리를 128메가 요청하다 막혔다면 실제로 큰 데이터를 다루다 넘친 것이니 그 줄을 봐야 합니다. 같은 “메모리 초과” 메시지라도 숫자에 따라 봐야 할 곳이 정반대입니다.

판별에 도움이 되는 확인이 하나 더 있습니다. 같은 코드를 명령줄에서 돌려 보는 것입니다. 웹에서만 터지고 명령줄에서는 멀쩡하다면 코드가 아니라 웹 서버 쪽 환경을 의심해야 합니다. 둘 다 터지면 코드입니다.

같은 일이 다른 서버에서도 있었다

같은 원인으로 다른 서버에서도 문제가 있었습니다. 그쪽은 화면에 오류가 뜨는 대신 PHP를 처리하는 프로세스가 조용히 죽는 형태였습니다. 열네 시간 동안 이천오백 번쯤 죽었는데, 죽을 때마다 서버가 메모리 덤프 파일을 남겼습니다. 하나에 60메가씩이었습니다.

이쪽이 더 고약했던 이유는 증상이 엉뚱한 곳에서 나타났기 때문입니다. 사이트는 그런대로 돌아가는 것처럼 보였고, 처음 이상을 알아챈 것은 서버 백업이 실패한다는 알림이었습니다. 덤프 파일이 디스크를 채우고 있었던 것입니다. 백업 문제인 줄 알고 백업 설정을 보다가, 디스크를 뒤져 보고서야 원인을 찾았습니다.

두 건 다 같은 조치로 끝났습니다. PHP가 코드를 더 빠르게 돌리려고 쓰는 기능을 꺼 두는 것이었습니다. 속도를 조금 포기하고 안정을 택한 셈인데, 두 서버 모두 그 뒤로는 같은 증상이 없었습니다. 업데이트 직후에 이상이 생겼다면 새로 켜진 기능이 없는지 확인해 볼 만합니다.

원인을 좁히는 순서

로그를 읽은 뒤에는 범위를 줄여 갑니다. 플러그인이나 테마의 충돌인지, PHP 버전이 안 맞는지, 메모리 한도에 걸린 것인지, 직접 넣은 코드가 무한 반복에 빠진 것인지를 차례로 봅니다.

순서를 정할 때는 최근에 바뀐 것부터 봅니다. 어제까지 멀쩡하던 사이트가 오늘 멈췄다면 그 사이에 바뀐 것이 범인일 확률이 가장 높습니다. 플러그인 업데이트, 테마 수정, PHP 버전 변경, 서버 패키지 업데이트 순으로 훑으면 대개 걸립니다. 앞에서 말한 사고도 그날 새벽의 PHP 업데이트가 배경이었습니다.

후보가 여럿이라 못 고르겠으면 반씩 줄이는 방법이 빠릅니다. 플러그인을 하나씩 끄면서 확인하면 스무 개일 때 스무 번을 봐야 하지만, 절반을 한꺼번에 끄고 증상이 사라지는지 보면 다섯 번이면 하나로 좁혀집니다. 사라지면 끈 쪽에, 그대로면 켜 둔 쪽에 있습니다. 이 방식은 플러그인뿐 아니라 직접 넣은 코드를 볼 때도 그대로 쓸 수 있습니다.

다만 운영 중인 사이트에서 플러그인을 껐다 켰다 하는 것은 방문자에게 그대로 보입니다. 가능하면 같은 구성의 사본에서 하시길 권합니다. 사본을 만들 여유가 없다면 방문이 가장 적은 시간을 고르고, 끄기 전에 무엇을 껐는지 순서대로 적어 두어야 합니다. 몇 번 하다 보면 원래 어떤 상태였는지 기억이 흐려집니다.

로그에 아무것도 안 남는 경우도 있습니다. PHP가 시작되기도 전에 죽거나 서버 쪽에서 막혔을 때입니다. 그때는 워드프레스 로그가 아니라 웹 서버 에러 로그를 봐야 합니다. 두 로그는 담는 내용이 다르고, 찾는 것이 어디에 있는지 모를 때는 양쪽을 다 열어 두고 시각을 맞춰 보는 편이 빠릅니다.

특정 시간대에만 반복된다면 자원 문제일 가능성이 큽니다. 사이트가 특정 시간에만 느려지는 경우와 원인이 겹칩니다. 오류가 난 시각을 모아 보면 규칙이 보일 때가 있습니다.

다 끝나면 로그를 끈다

해결한 뒤에는 WP_DEBUG를 다시 꺼야 합니다. 켜 둔 채로 두면 사소한 알림까지 계속 쌓여서 로그 파일이 커지고, 정작 다음에 문제가 생겼을 때 중요한 줄을 찾기 어려워집니다. 디스크를 채우는 경우도 있습니다.

끄기 전에 debug.log 파일을 지우거나 옮겨 두시기를 권합니다. 이 파일은 웹에서 직접 열 수 있는 위치에 있어서, 남겨 두면 누구나 내려받아 파일 경로와 내부 구조를 볼 수 있습니다. 문제를 고쳤다고 끝내지 말고 흔적까지 정리해야 합니다.