티스토리 워프로 이사 후 img 때문에 발생하는 서버 다운 원인 분석 및 해결책 기록
나와 같은 상황이 발생할지 모르는 티스토리 블로거들에게 도움이 되길 바라며 기록으로 남긴다.
티스토리 버린지 4개월
티스토리를 워프로 이전한지 4개월쯤 되어 가는 것 같다.
☞티스토리 라이트세일 워드프레스로 이전하는 과정에 발생한 이슈들!!
☞티스토리에서 워드프레스로 리다이렉트 하면 티스토리 계정 정지 당할 수 있으니 조심하세요.
☞[티스토리 워프로 이전 준비] 문제 많은 카카오 티스토리 이제는 버려야할 시간!
많은 문제들이 있었지만 이번엔 심각했다. 간밤에 자고 일어나면 서버가 죽어 있는 날들이 발생하기 시작했다. 그리고 22일 금요일 오전 아마존 aws 라이트세일 서버가 다운되었다는 알림을 제트팩 앱으로 부터 받았다.
그래서 아마존 라이트세일 콘솔에 로그인하여 해당 인스턴스 지표를 확인하였다. 지표를 보니 아래처럼 버스팅된 후 서버가 다운되니 다시 내려오는 모습의 그래프를 확인하였다.
서버를 다시 켰지만 몇 분 뒤 또 서버가 다운 되었다는 알림을 받았다.
뭐지? 이런적은 없었는데……
라이트세일 콘솔창을 다시 켜서 확인해보니 또 다시 CPU가 버스트 가능 영역에 진입해있었다. 이게 무슨일인가?누군가가 나의 블로그를 공격하는 건가?, 크롤링하는건가? 알 수 없는 의문점들만 생겼다.
계속해서 버스트 영역으로 진입되길래, 안되겠다싶어서 이번엔 내가 서버를 중지 시켰다.
아파치 로그파일 내용 분석
퇴근 후 아파치 로그 파일에 접근하여 접근 정보를 확인하였다. 원인을 반드시 찾아서 해결해야했으니까!!
비트나미 워드프레스 아파치 로그파일의 위치는 아래와 같다.
/opt/bitnami/apache/logs/리눅스 콘솔창에서는 컨트롤하기 불편해서 파일질라 프로그램으로 접근 후 셧다운 당일의 로그파일들을 다운 받았다.
에러로그(error_log) 파일을 먼저 확인하여 서버가 셧다운된 시간들을 확보했다.
[Wed Dec 20 18:44:23.640564 2023] [mpm_event:notice] [pid 757:tid 139730040421632] AH00491: caught SIGTERM, shutting down
[Fri Dec 22 02:32:37.481276 2023] [mpm_event:notice] [pid 758:tid 140513093496064] AH00491: caught SIGTERM, shutting down
[Fri Dec 22 03:32:08.962650 2023] [mpm_event:notice] [pid 752:tid 139855546293504] AH00491: caught SIGTERM, shutting down
[Fri Dec 22 06:57:33.574923 2023] [mpm_event:notice] [pid 763:tid 139804585352448] AH00491: caught SIGTERM, shutting down그리고 access_log 파일을 열어서 해당 시간대의 위치 접근기록을 확인하였다.
서버 셧다운 시간으로 부터 1분전의 로그파일 내용을 살펴보았다.
여러 IP 로부터 서로 다른 이미지 경로를 접근하는 것으로 확인되었고, HTTP/1.1 뒤에 숫자가 상태값을 알려주는 건데 모두 500 혹은 503 에러가 떨어진 상황이었다. 200 혹은 301, 302가 떨어져야 정상이다. 그래서 서버를 다시 재부팅하고, 블로그URL/415/img로 접근해보았더니, 무한 로딩에 빠지는 것이 아닌가?
왜갑자기 사람들이 이미지로 접근해오는것인가? 정말 누군가 ip를 속여가며 공격하는 것인가?
서버다운된 원인 분석
원인은 마리아DB에 저장된 이미지 파일들에 대한 데이터가 문제였다. 워드프레스 글들은 wp_post 테이블에 등록되는데, 이미지 파일 이름으로 DB에 저장된 내용을 확인해보니 주소 경로는 모두 다르지만 post_name과 post_title로 등록된 이름이 모두 동일한 이름들로 등록되었다. 이런 파일들을 모두 조회하여보니 5,000개가 넘었다. 5,000개가 넘는 파일들의 모두 찾다보니 문제가 생기는 것이다. 그럼 왜 이런 사단이 발생했을까?
#이미지 파일 조회
SELECT * FROM `wp_posts` WHERE post_title like 'img%';2023년 7월에 백업다았던 티스토리 백업 파일을 다시 열어서 다시 살펴보니 티스토리에서 해당 게시글 별 이미지를 각각의 폴더에 넣어주는데 문제는 이 폴더안에 이미지 파일 이름이 모두 img, img_1, img_2…이런식으로 모두 동일했던 것이다. 티스토리에서 가져온 이미지들 갯수가 상당히 많은데……ㄷㄷㄷ
WP phpMyAdmin에 접근하여 wp_posts 테이블에서 조회해보았다.
해당 파일을 검색해보니 총 5537개였다.
이런 동일한 이름들로 DB에 등록된 것이었다.
이름이 동일하다보니 데이터를 조회하면서 디스크를 읽게 되니 cpu 부하가 걸렸던 것이다.
삭제를 해버리릴까 하다가, 유니크하게 이미지 이름을 변경하고 검색엔진이 다시 색인되도록 처리하기 위해 다음과 같은 update 작업을 진행하였다.
START TRANSACTION
UPDATE wp_posts a JOIN wp_posts b
ON a.ID = b.ID
SET
b.post_title = concat(concat(a.post_title, '_'), a.id)
, b.post_name = concat(concat(a.post_name, '_'), a.id)
WHERE a.post_title like 'img%';
#ROLLBACK;
#COMMIT;
SELECT * FROM `wp_posts` WHERE post_title like 'img%';그 다음 작업으로 검색엔진 봇들이 다시 긁어가도록 하기 위해 변경된 img 자료의 날짜를 모두 오늘 날짜로 업데이트 처리하였다.
update wp_posts
SET
post_date = now()
,post_date_gmt = now()
,post_modified = now()
,post_modified_gmt = now()
WHERE post_title like 'img%';
SELECT * FROM `wp_posts` WHERE post_title like 'img%';데이터 수정 후 조회한 결과를 스크린샷하여 기록해둔다.
당분간은 또 모니터링을 할 것이다. 또 다른 부하를 주는 원인이 있을 수 있으니까!!
2024.05.04 5개월마에 서버 셧다운 발생
[Sat May 04 14:22:17.566888 2024] [mpm_event:notice] [pid 756:tid 139907904576768] AH00491: caught SIGTERM, shutting down
access_log파일에 해당 시간 위치를 찾아 서버가 다운된 원인을 찾아보았다.
서버다운시간이 14시22분 17초에 다운되었는데, 아래 로그를 보면 feed 관련 url을 봇이 긁어갔는데, 봇이 크롤링해간 시작시간이 14시21분 47초이다. 시간으로 순서대로 로그가 찍히는데 저렇게 중간에 낑겨서 남겨지는 로그는 종료시간이 시작시간 이후라는 것을 의미하고 저 봇 때문에 서버가 다운된 것이다.
feed 관련해서 크롤링 하지 못하도록 막아야할지 고민중이다. 서버 다운되면 다시 재부팅하면 되니까!!!
해당 카테고리 feed시 무거운 사진들이 있으면 서버 cpu사용률이 올라가서 어느 순간 다운된다.
봇 크롤링에 의한 서버 다운 해결 방법
워드 프레스 설정(Settings) > 읽기(Reading) > 피드 글의 보기 옵션(For each post in a feed, include)을 전체 텍스트(Full text)로 되어 있다면, 요약(Excerpt)으로 변경 후 “변경사항 저장” 버튼을 클릭하면 크롤링에 소요되는 시간이 단축되어 서버 다운되는 현상을 방지할 수 있다.
나의 경우에는 피드 글의 보기 옵션이 전체 텍스트로 설정되어 있었다.
그리고 신디케이션 피드에는 최신 정보(Syndication feeds show the most recent)가 표시되는데 300개의 아이템(items)으로 설정되어 있었기에 30개로 줄였다.
[연관 글 더보기]
