사이트를 한 차례 대규모 업그레이드하고 나서 서버가 하루이틀에 한 번씩 다운되는 일이 벌어졌습니다. 부하가 커질 것을 예상하고 아마존 서버를 한 단계 업그레이드했는데도 이런 일이 벌어져 당황스러웠는데요.
처음에는 설정값을 조금 조정하면 해결될 거라고 생각했습니다. 그런데 되지 않아서 각잡고 테스트를 시작했죠. 쌍둥이 서버를 파 변인을 주고 트래픽을 난사한 뒤 결과를 봤습니다.
아래는 끈질긴 최적화의 기록입니다. 서버 최적화하는 분들께 도움이 됐으면 합니다. (이하 반말입니다.)
목차
방법
효과를 확실히 하기 위해서는 방법을 세우고, 근거를 남겨야 한다. 아래와 같이 절차를 정했다.
- 실제 서버와 똑같은 쌍둥이 서버를 하나 만든다. (이하 테스트 서버)
- 실제 서버가 다운되기 직전 있었던 요청 URL들을 이용해 테스트 서버에 부하 테스트를 진행하고 실패율을 기록한다. 실패는 2초를 초과하는 응답으로 정의했다.
- 서버 부하를 실시간으로 확인하고, 로그를 조사하고, 가설을 세운다.
- 가설에 맞춰 해결 방법을 설계해 테스트 서버에 적용하고 다시 부하 테스트를 한다. 단, 이 때 해결책은 한 가지만 적용해야 한다(변인 통제).
- 실패율이 줄어들었는지 확인한다.
- 유의미한 개선이 이뤄졌다면 실서버에 적용한다.
사용한 도구
- Gatling: 서버 부하 테스트 툴.
Scala로 스크립트를 짜서 테스트를 수행한다. 스크립트로 테스트 내용을 제어할 수 있기 때문에 자유도가 높고 가설에 맞춰서 실험을 진행하기 편리하다. Scala는 몰라서 ChatGPT를 이용해 스크립트 기본틀을 얻고 변수를 조정해 가며 테스트했다. - Percona Toolkit: MySQL의
slow_query_log를 분석해 주는 툴.
터미널에서 실행. 기본적으로 쿼리 로그를 분석해서 일목요연하게 요약해 보여준다. 쿼리 횟수, 걸리는 시간 등을 기준으로 개선할 쿼리가 무엇인지 순위로 정리해 주는데 간단하면서도 효과적이다. - 다양한 로그: 기본적인 Apache, Laravel, syslog, kern.log, php-fpm, MySQL에러 로그에, 추가로 MySQL의 slow_query_log 기능과 PHP-FPM slowlog 기능도 사용했다.
결과 요약
첫째, 이미지 요청을 처리하는 로직을 PHP에서 Apache의 정적 처리로 변경했다. 인덱스 페이지의 이미지 요청에 PHP가 응대하도록 한 것이 서버 부하의 최대 원인이었다.
인덱스 페이지에는 이미지가 많았고, 당연히 과도하게 많은 PHP-FPM 프로세스들이 실행됐다. 이미지를 원래 역할에 맞게 Apache에 맞기면서 필요 PHP-FPM 프로세스 수가 줄었고 이것이 서버 안정화에 크게 기여했다.
둘째, 데이터베이스(MySQL) 서버를 분리했다. 서버 CPU 사용량의 20%가량을 항상 차지하고 있던 MySQL을 별도의 서버로 분리하면서 Apache, PHP의 안정성도 확보하고, MySQL 자체의 안정성도 확보했다. 사실상 서버를 추가한 것인데 값싼 증설로 최대한의 효과를 누린 것이라고 생각하면 된다.
셋째, 목록 페이지들을 캐시했다. 새 사이트는 목록 링크가 이전보다 전진 배치된 구조였다. 다양한 봇들이 목록을 요청하는 경우가 2.6배로 증가했다. 목록 페이지는 MySQL 부하가 컸고, 이를 캐시한 것도 안정화에 기여했다.
1차 시도 – 서버 설정값 테스트
가설
PHP-FPM, Apache, MySQL의 설정값들이 최적화 되어 있지 않아서 서버 성능이 불안정하다
실험 설계
아래의 값들을 하나씩 조정하면서 테스트를 진행한다.
- PHP:
pm.max_children조정 - MySQL:
mysqltuner가 추천해 주는 값들skip-name-resolve=ONjoin_buffer_size(> 256.0K, or always use indexes with JOINs)innodb_redo_log_capacityshould be (=1G) if possible, so InnoDB Redo log Capacity equals 25% of buffer pool size.innodb_buffer_pool_instances(=4)innodb_log_buffer_size(> 16M)
- Apache:
mods-available/mpm_prefork.conf의 MaxRequestWorkers를 조정. KeepAlive 설정도 고려.
서버 다운 45분 전부터 들어온 요청을 모두 수집해 Gatling으로 트래픽을 보냈다.
결과
실패율의 유의미한 변화는 없었다. 그간 설정값을 이렇게 저렇게 바꾼 것이 거의 의미가 없었다는 것을 확인한 것이다.
2차 시도 – MySQL 쿼리 최적화
가설
MySQL의 특정 쿼리가 서버에 부하를 일으킨다.
서버 다운시 MySQL 프로세스 때문에 CPU 사용량이 100%가 되는 것을 목격해 세운 가설.
실험 설계
slow_query_log를 기록. 로그를 Percona Toolkit으로 분석.
아래는 MySQL 설정. 우분투라면 설정 파일 경로는 /etc/mysql/mysql.conf.d/mysqld.conf.
[mysqld]
slow_query_log = 1
slow_query_log_file = /path/to/your/log/file.log
long_query_time = 0
log_queries_not_using_indexes = 1long_query_time을 0으로 지정하면 모든 쿼리를 로그에 기록한다.
분석 결과 시간이 가장 오래 걸리는 쿼리는 검색 쿼리였다. 하지만 횟수가 너무 적고 다운 시점 직전/직후로 검색요청이 있지는 않았다. 때문에 직접적 원인으로 보긴 어려웠다.
그 다음은 본문 페이지들이었다. 쿼리 시간이 길진 않았지만, 횟수가 가장 많았아 영향이 클거라 보고 기사 본문 페이지를 캐시하고 성능을 테스트 했다.
결과
성능에 큰 변화는 없었다. CPU 사용량이 약간 줄어들기는 했지만 드라마틱한 변화는 없었다.
이득에 비해 캐시했을 때 증가하는 코드의 복잡성이 너무 커 기사 본문 캐시는 하지 않기로 했다.
3차 시도 – 목록 페이지 쿼리 캐시
가설
목록 페이지의 MySQL 쿼리 부하가 다운의 주된 원인이다.
서버 다운 사례 5회 모두 직전에 목록 페이지 요청이 많았다. 전체 요청중 차지하는 비율은 적었지만 공통점이고 목록 요청은 쿼리 부하가 크다는 점에 착안했다.
실험 설계
목록 페이지들의 페이지네이션 쿼리를 캐시하고 차이를 검증한다.
쿼리 캐시와 무효화는 라라벨의 모델 updated 이벤트로 비교적 손쉽게 처리함.
결과
테스트 결과 실패율이 95%에서 4%로 극적으로 줄어들었다.
서버에 적용했는데 서버 다운 빈도는 줄었지만 완전히 막지는 못했다.
4차 시도 – PHP 스크립트 개선
여기부터는 3차 시도 결과를 적용한 서버에서 테스트를 진행했다.
가설
특정 PHP 코드가 서버 부하를 일으킨다.
3차 시도에서 개선 결과로 MySQL이 부하를 크게 일으키지 않게 됐다. 그런데 이제 PHP-FPM 프로세스가 부하를 100%로 일으키는 경우가 발견됐다.
PHP-FPM 관련 설정들은 이미 이전에 모두 테스트를 해 봤기 때문에 특정 PHP 코드가 문제일 것이라고 가설을 세웠다.
설계
서버가 다운 20분 전부터의 URL들에 순서대로 접속하게 한다. PHP-FPM의 slowlog 설정을 켜고 여기에 잡힌 스크립트를 수정한 뒤 비교한다.
결과
테스트에서 다운이 발생하지 않음. slowlog에도 특징적인 것이 나타나지 않음.
특정 PHP 스크립트가 비효율적이라 서버에 과부하를 준다는 가설은 일단 잘못된 가설로 결론냈다.
그러나 뒤에서 볼 수 있듯, PHP 스크립트로 이미지를 서비스하고 있던 것이 핵심 문제였고, 이 단계에서는 발견하지 못했던 것이다.
서버 환경에서 거의 모든 최적화를 끝내고 나서도 다운이 벌어지자 그제서야 이 문제를 떠올릴 수 있었다. 변인을 통제한 실험과 개선으로 변수를 줄인 것이 도움이 됐다. 그런 조건에서 개발자 자신의 경험이 종합되니 해결책이 떠오른 것이다.
5차 시도 – CPU 최적화 서버로 변경
가설
그냥 서버가 느린 것이 문제이므로 빠른 서버로 바꾸면 개선될 것이다.
4개의 시도 중 3개가 실패하자 그냥 새 사이트의 부하 자체가 원래 큰 것이 아닌가 생각하게 됐다.
설계
아마존이 CPU 성능이 더 좋다고 설명하는 c6g 라인에서 동급(large) 서버를 테스트했다. 원래 서버는 범용이라는 t4g 라인이었다.
결과
오히려 t4g에서 성공률이 6%p 더 높았다. 아마존의 설명과 다르게 c6g가 성능이 더 안 좋게 나온 것이다.
(아마존 서버를 large에서 xlarge 등급으로 업그레이드하면 비용이 2배가 됐기 때문에 이건 하지 않았다.)
6차 시도 – DB 서버 분리
가설
여하간 서버가 느리다.
설계
서버 자체를 업그레이드하는 것은 너무 비싸고, 대신 좀 싼 서버(t4g.small)를 신설해 DB를 분리한다. 이러면 비용 효율적으로 서버를 증설할 수 있다.
결과
DB를 분리하니 실패율이 55%에서 39%로 16%p 줄었다. 실서버 적용.
7차 시도 – pm.max_children 설정 조정
가설
CPU 리소스가 적을 때는 pm.max_children 설정을 변경해도 소용이 없었지만 이제 CPU 리소스에 여유가 생겼으니 이 값을 조정해 유의미한 차이를 낼 수 있을 것이다.
설계
수치를 조정하며 실패율 기록
결과
의외로 프로세스 개수를 줄이니 오히려 실패율이 줄었다. 프로세스 하나당 차지하는 CPU 리소스가 높아지면 CPU 리소스가 꽉 차면서 오히려 다운이 되는구나 하는 생각이 들었다. 그래서 값을 기존 16에서 4로 줄이는 것으로 실서버에 적용했다.
적용후 원상복귀
실서버에 적용하자 서버가 더 불안정해져 16개로 값을 원상복구했다.
중간 결론
테스트 결과로 두 가지 안정화 조처를 시행했다.
- 목록 페이지 쿼리 캐시
- DB 서버 분리
이후 서버가 많이 안정화돼 일단 테스트는 마무리했다.
추가 조처들
이후는 앞선 방법론에 따라 테스트를 진행한 것은 아니다. 하지만 테스트 이후에 중요한 해결을 많이 했다.
앞선 실험은 무의미하지 않았다. 주요한 의심 사항들을 체계적으로 테스트하고 나서 머리가 정리됐고, 서버 환경도 정리가 돼 문제를 파악하기 쉬워졌기 때문이다.
추가 조처 1 – 이미지 처리 방법 변화
두 가지 개선 조처 이후에도 일주일 동안 서버가 2차례 다운됐다. 그런데 신기하게도 다운시 CPU와 메모리 사용량이 모두 높지 않았다. 그냥 PHP-FPM 프로세스가 최대 개수로 차서 서버가 뻗은 것이었다.
부하는 작지만 PHP에 갑자기 많이 들어오는 종류의 요청이 무엇일까? 그러자 퍼뜩 생각이 나는 게 있었다. 이미지 리사이즈를 편하게 처리하기 위해서 PHP를 거쳐 정적 이미지 파일을 요청하게 만든 URL을 맘놓고 사용했던 것이다. 이 요청 경로는 아래와 같다.
/image/resize/44885/30044885번 이미지를 가로 300px, 세로 auto로 리사이즈해서 응답하라는 요청이다.
즉, 이미지 하나를 호출할 때마다 PHP-FPM 프로세스가 생성되는 것이었는데, 인덱스 페이지에 여러 클라이언트가 들어와 이미지 수백 개가 요청되면 서버가 뻗었던 것이다.
조처
이미지는 미리 리사이즈해 둔 걸 아파치가 PHP를 거치지 않고 서비스하게 했다(사실 별도 조처를 하지 않으면 이렇게 한다).
결과
다운이 줄어들고 서버가 빨라짐.
이 부분이 결정적인 해결이었다. 이후는 예외적인 트래픽을 처리하면 됐다.
추가 조처 2 – 진짜 대량 트래픽과 싸우기
구 URL에 대한 과도한 요청
이번에는 구 URL에 대한 요청이 PHP 프로세스를 과도하게 띄우게 만들어 서버가 다운됐다. 예컨대 이런 URL들로 1초에 100회정도 요청이 들어왔다.
/wp-content/themes/ws/favicon.ico
/wp-content/themes/ws/img/logo-large.png문제는 구 사이트의 URL들을 새 사이트 URL로 리디렉트하게 해 둔 PHP 코드였다. 일단 위 URL로 요청이 들어오면 어디로 리디렉트시킬지 판단하기 위해 PHP-FPM 프로세스가 뜨게 돼 있었던 것이다. 그래서 PHP-FPM 프로세스 수가 모자라 서버가 다운된 것이다.
그런데 구 사이트의 정적 이미지에 대한 요청은 리디렉팅 할 가치가 없다. PHP로 보내지 않고 아파치가 바로 404를 띄우게 해 해결했다.
RewriteRule ^/wp-content/.*\.(ico|jpg|png|pdf)$ - [R=404,L]그냥 과도한 요청
이제 서버가 다운되는 일은 거의 없었고, 성능 자체가 쾌적해졌다.
그런데 한 달에 한 번 서버를 다운시키는 범인이 있었는데 바로 facebookexternalhits/1.1이라는 유저 에이전트 문자열을 가진 페이스북 봇이다.
이 봇은 1초에 수십회 요청을 보냈다.
그런데 함부로 차단할 수 없어 난감했다. 무의미한 URL에 대한 요청도 아닌 데다, 무려 페이스북이 내 페이지를 캐시하시겠다는데 그걸 차단할 수도 없지 않나.
일단 robots.txt에 빈도 조절을 공지했는데 이 봇은 그걸 무시했다.
결국 라라벨이 제공하는 스로틀링 기능을 이용하기로 했다. 특정 IP에서 1초에 몇 회 이상 요청이 있으면 제한을 걸어 주는 기능이다.
그런데 라라벨11에서만 1초 기준 기능을 제공하고 10까지는 1분 기준 기능을 제공하고 있어서 당장 적용은 힘들었다. 1분 기준이면 이미 서버가 다운된 후일 것이기 때문이다. 그래서 우선 라라벨을 업그레이드하고 있다.
지금은 한 달에 한 번씩 폭풍이 몰아치면 Fail2ban으로 페이스북 봇의 IP들을 차단했다가 1-2시간 후에 차단을 푸는 식으로 대응중이다.
스로틀링 기능을 적용하고 나면 결과를 이 글에 보고하겠다.
추가 조처 3 – 빈 값 검색이 되는 버그 수정
이후 쾌적한 서버가 유지되다가 한 번 다운되는 일이 있었다. 이번엔 아마존 봇이라고 밝힌 봇이 빈 쿼리로 계속 검색을 시도하고 있었다.
원래는 빈 쿼리로 검색 시도시 검색을 해 주면 안 되는 건데 그 부분을 처리하지 않은 게 문제였다(즉, 버그였다!). 빈 값 검색이 안 되게 해 이 이슈는 해결했다.
나가며 – 배운 점
위 조치 이후 서버는 안정적으로 돌아가고 있다. 아래는 이 과정에서 배운 점을 짧게 정리한 것이다.
종합적인 판단
다양한 로그를 봐야 한다. 내가 원하는 정보(특정 시점, 특정 상황에서 서버가 불안정해진 원인)만 콕 찝어 기록하는 로그는 없다. 예를 들면, 인덱스 페이지의 이미지 처리방법 변화에 관한 로그는 둘 뿐이다.
pm.max_children이 부족하다는 PHP-FPM 로그- 요청
url이 기록된 아파치 로그
이 정보에 더해 사이트 코드와 서버의 다른 설정에 대한 이해까지 종합해야 결론을 도출할 수 있었다.
종합적 판단은 원인 조사뿐 아니라 해결 과정에서도 필요하다. 코드나 서버 설정 수정은 다른 프로그램에 영향을 미칠 수 있고, 다른 문제의 원인이 될 수 있기 때문이다.
시간과 집요함
시간을 많이 들이며 집요해야 한다. 서버 문제는 복합적이고 꼬여있는 경우가 있다.
그래서 해결책을 찾는 과정이 꽤 지난하다. 변수도 많고 피드백도 즉각적이지 않아 시간이 든다.때문에 세부적인 부분까지 변수를 바꿔가며 집요하게 물고 늘어져야 한다.
도구
도구를 잘 사용하면 시간을 단축할 수 있다.
예컨대 Gatling은 시간을 많이 단축해 줬다. 프로그래밍 언어로 테스트를 작성하는 게 어려워 보여도 오히려 효율적이었다. 딱 필요한 방식으로 테스트를 할 수 있기 때문이다. 게다가 테스트 보고서도 매우 깔끔하고 일목요연했다.
이런 툴을 잘 사용하면 테스트 시간을 잘 줄일 수 있다.
댓글 남기기