WordPress 서버에서 높은 CPU 사용량의 원인 찾기

게시 됨: 2020-05-07

며칠 전 우리는 호스팅 제공업체(SiteGround)로부터 우리 사이트가 이미 "허용된 월간 CPU 사용량의 90%"에 도달했으며 100%를 초과하면 "웹 서비스가 제한될 것"이라는 이메일을 받았습니다. "액세스하는 데 문제"가 있을 수 있습니다. 꽤 무섭죠? 우리가 가능한 한 빨리 수정해야 하는 완전히 바람직하지 않은 상황이었습니다. 하지만... 어디서부터 시작해야 할까요?

CPU 사용량이 많은 에피소드 동안의 당사 웹사이트 통계
CPU 사용량이 높은 에피소드 동안의 당사 웹사이트 통계입니다.

오늘 우리는 웹사이트에서 흔히 볼 수 있는 문제 에 직면한 경험을 공유하고, 우리가 범인 을 식별하기 위해 한 일과 문제를 해결 한 방법을 설명하고자 합니다. 이렇게 하면 비슷한 문제에 직면했을 때 시작하는 방법에 대한 아이디어를 얻을 수 있습니다.

CPU 사용량이 많은 이유

워드프레스는 PHP로 작성된 콘텐츠 관리 시스템입니다. 이는 제공하는 콘텐츠가 PHP 스크립트 세트에 의해 동적으로 생성된다는 것을 의미합니다. 방문자가 웹사이트에 도착할 때마다 WordPress는 요청(예: "홈페이지를 보내주세요")을 처리하고 응답(in 이 경우 홈 페이지를 전송합니다). 분명히 요청에 응답하는 것은 서버 리소스의 특정 사용을 의미합니다. 요청 자체를 보고, 방문자가 액세스하려는 항목을 결정하고, 데이터베이스에서 가져오고, HTML 응답을 생성하는 등의 작업을 수행해야 합니다.

캐시 시스템이 웹사이트의 로딩 시간을 가속화하는 이유 중 하나는 이제 매우 명백해야 합니다. 기본적으로 이 처리 시간을 절약해 줍니다. 특정 요청이 처음 도착하면("홈 페이지를 보내주세요") WordPress가 시작되고 응답을 생성합니다. 캐시가 있는 경우 방문자에게 실제로 전송되기 전에 해당 응답을 저장합니다. 이렇게 하면 동일한 리소스(이 예에서는 홈 페이지)에 대한 향후 요청에서 WordPress가 더 이상 아무 것도 처리하지 않아도 됩니다. 캐시는 이전에 저장한 복사본을 다시 보낼 수 있으므로 시간과 리소스를 절약할 수 있습니다.

이 성능을 염두에 두고 서버에서 높은 CPU 사용량을 볼 수 있는 이유가 무엇인지 상상하는 것은 어렵지 않습니다.

  • 너무 많은 요청을 받습니다. 많은 사용자가 동시에 귀하의 웹사이트를 방문하거나 불법적인 요청을 많이 받으면(누군가 귀하의 서버를 공격할 가능성이 있음) WordPress는 이러한 모든 요청을 처리해야 하므로 서버 리소스 사용이 증가합니다.
  • 요청을 해결하는 데 느립니다. 많은 플러그인이 설치되어 있거나 어떤 이유로든 일부 플러그인이 비효율적이라면 WordPress가 많은 비효율적인 코드를 실행하기 때문에 받는 모든 요청이 필요 이상으로 오래 걸릴 것입니다.

따라서 캐시는 이러한 문제에 대한 좋은 보호책인 것 같습니다. 맞습니까? 그리고 실제로 그렇습니다. 그러나 캐시가 문제를 "수정"하지 않는다는 점에 유의하십시오. 단순히 "숨깁니다". 그리고 이것은 캐시할 수 없는 WordPress 기능이 있으므로 항상 WordPress를 실행해야 하므로 기억하는 것이 중요합니다.

  • WP-Cron을 사용하여 예약된 작업. WP-Cron은 앞으로 실행될 작업을 예약하기 위한 WordPress 메커니즘입니다. 예를 들어 WordPress는 이를 사용하여 예약된 게시물을 게시합니다.
  • 워드프레스의 REST API. REST API는 JSON 개체를 보내고 받아 WordPress 사이트와 상호 작용하기 위해 타사 응용 프로그램에서 사용할 수 있는 인터페이스입니다. 일부 REST API 요청은 캐시될 수 있지만(즉, GET 요청) 다른 요청은 캐시되지 않을 수 있습니다(POST 및 PUT). 따라서 일반적으로 캐시 할 수없는 것입니다 ...
  • WordPress의 AJAX 요청. WordPress에 REST API가 있기 전에 AJAX API를 사용하여 동적 웹사이트를 만들어야 했습니다. 이 API는 REST API와 매우 유사합니다. 서버와 정보를 주고받는 데 사용할 수도 있기 때문입니다. 다른 시스템이지만 REST API와 동일한 제한 사항이 적용됩니다.

문제 분석

먼저 웹 사이트에서 CPU 사용량이 증가한 이유 를 확인해야 합니다. 당사 웹사이트에 대한 요청 수가 증가했습니까? 이제 개별 요청을 처리하는 속도가 느려집니까? 이러한 질문에 답하기 위해 서버에 매우 유용한 도구인 액세스 로그 가 있습니다.

액세스 로그는 서버가 수신한 모든 요청과 이에 대한 유용한 정보를 기록하는 텍스트 파일입니다. 특히 액세스 로그는 요청을 받은 시간(날짜 및 시간), 요청한 사람(IP), 요청한 리소스(URL), 요청 성공 여부 등을 알려줍니다. 다음은 서버의 예입니다. :

 66.249.83.82 - - [22/Apr/2020:14:04:59 +0200] "GET /es/blog/imagenes-gratuitas-para-tu-blog/ HTTP/1.0" 200 22325 "-" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" 66.249.83.84 - - [22/Apr/2020:14:05:02 +0200] "GET /es/wp-content/uploads/sites/3/2018/07/aziz-acharki-549137-unsplash-540x350.jpg HTTP/1.0" 200 10566 "https://neliosoftware.com/es/blog/imagenes-gratuitas-para-tu-blog/" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" 66.249.83.82 - - [22/Apr/2020:14:05:02 +0200] "GET /es/wp-content/uploads/sites/3/2018/07/Screenshot-of-Unsplah-website-768x520.png HTTP/1.0" 200 399577 "https://neliosoftware.com/es/blog/imagenes-gratuitas-para-tu-blog/" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" ... 188.79.17.218 - - [22/Apr/2020:14:06:14 +0200] "GET /es/blog/problemas-mas-comunes-de-wordpress/ HTTP/1.0" 200 110741 "https://www.google.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" 188.79.17.218 - - [22/Apr/2020:14:06:16 +0200] "GET /es/wp-content/plugins/nelio-ab-testing/assets/dist/js/alternative-loader.js?version=52b0ff65c68ab39896d47d6ff673fd59 HTTP/1.0" 200 2763 "https://neliosoftware.com/es/blog/problemas-mas-comunes-de-wordpress/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" 188.79.17.218 - - [22/Apr/2020:14:06:16 +0200] "GET /es/wp-includes/css/dist/block-library/style.min.css?ver=5.4 HTTP/1.0" 200 7627 "https://neliosoftware.com/es/blog/problemas-mas-comunes-de-wordpress/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" ...

자세히 살펴보겠습니다.

  • 66.249.83.82 . 요청한 장치의 IP입니다.
  • 22/Apr/2020:14:04:59 +0200 . 이것은 요청의 정확한 날짜와 시간입니다.
  • GET /es/blog/imagenes-gratuitas-para-tu-blog/ HTTP/1.0 . 그런 다음 방문자가 요청한( GET ) 블로그(스페인어) 게시물을 봅니다.
  • Mozilla/5.0 (Linux; Android ... 이것은 브라우저의 사용자 에이전트 이며 요청한 장치 및 운영 체제에 대한 일부 정보를 제공합니다.

우리 서버가 첫 번째 요청 이후에 동일한 IP( 66.249.83.82 )에서 여러 요청을 수신한 방법에 주목하십시오. 이것은 공격처럼 보일 수 있지만 실제로는 그렇지 않습니다. 웹 페이지에는 일반적으로 여러 자산(이미지, 스크립트, 스타일)이 포함되며 사이트의 특정 웹 페이지에 액세스하는 방문자가 모든 자산을 검색하기 위해 여러 요청을 수행하는 것은 완전히 정상입니다. .

글쎄, 우리의 경우에는 실제로 비정상적으로 많은 수의 요청이 있음을 확인할 수 있었습니다. 실제로 매우 높습니다. 그리고 우리는 로그 파일이 평소보다 훨씬 컸기 때문에 알고 있었습니다.

어떤 이유에서인지 방문자가 최고조에 달했다는 설명이 있을 수 있습니다. 하지만 Google Analytics에 따르면 그렇지 않습니다. 그래서 다른 일이 일어나고 있었습니다.

액세스 로그를 보다 자세히 분석한 결과 다음과 같은 사실을 확인할 수 있었습니다. 우리가 받은 모든 요청의 15% 이상이 동일한 IP에서 온 것입니다. 그리고 (드럼 롤) 그 IP는 우리 자신의 웹 서버였습니다!

멋진 아이디어를 가진 남자를 보여주는 GIF

범인 식별

이 시점에서 우리는 CPU 사용량이 최고조에 달할 정도로 많은 요청을 하는 것이 우리 자신의 서버라는 것을 마침내 알게 되었습니다. 하지만 왜? 왜 이런 일이 일어났습니까? 누가 그러한 요청을 생성했습니까? 대답하기 어려운 질문입니다.

먼저 우리는 로그를 다시 살펴보고 IP로 필터링하고 당면한 문제를 밝힐 수 있는 패턴을 식별하려고 했습니다.

 35.214.244.124 - - [22/Apr/2020:14:06:08 +0200] "GET /es HTTP/1.0" 301 - "https://neliosoftware.com/es" "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:06:08 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:06:18 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:07:21 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:07:24 +0200] "GET /es?..." "php-requests/1.7-3470169" ...

그리고 우리는 하나를 찾았습니다. 이러한 모든 비정상적인 요청의 User-Agent 는 php-requests/1.7-3470169 입니다. 흥미로운!

WordPress에는 요청을 트리거하는 몇 가지 기능이 있습니다: wp_remote_request . 이러한 함수의 소스 코드를 살펴보면 기본적으로 WP_Http 라는 클래스의 몇 가지 메서드를 래핑하는 것을 볼 수 있습니다. 이 클래스는 기본적으로 모든 요청이 User-Agent 를 "WordPress/version"으로 설정하기 때문에 흥미롭습니다. 따라서 이것이 우리 문제와 관련이 있을 수 있습니다. 그러나 그것은… 아직.

WordPress의 소스 코드를 계속 검사하면 WP_Http 가 내부적으로 다른 WordPress 클래스를 사용하여 실제로 요청을 수행하는 것을 알 수 있습니다. Requests . 그리고 이 클래스는 흥미롭습니다. 정의의 맨 처음에 값이 1.7-3470169 인 VERSION 이라는 상수를 정의하는 것을 볼 수 있습니다. 그리고 조금 후에 이 상수를 사용하여 로그에서 찾은 User-Agent 를 빌드합니다: php-requests/1.7-3470169 .

멋진! 우리는 이제 이러한 모든 이상한 요청이 WordPress 사이트에서 온 것임을 확인했습니다. 이것은 아마도 범인이 플러그인이라는 것을 의미할 것입니다… 하지만 어느 것이요?

이것을 알아내야 하는 아이디어는 매우 간단했습니다. Requests 클래스를 사용하는 플러그인의 이름을 포함하도록 User-Agent 를 수정하면 서버의 액세스 로그에 플러그인 이름이 표시됩니다. 그리고 이것은 실제로 달성하기가 매우 쉽습니다. 다음 스니펫으로 Requests ' get_default_options 함수를 편집하기만 하면 됩니다.

 $trace = debug_backtrace(); $files = []; foreach ( $trace as $log ) { if ( false !== strpos( $log['file'], '/wp-content/plugins/' ) ) { $files[] = $log['file']; } } if ( empty( $files ) ) { $debug = 'no-plugin'; } else { $plugins = array_map( function( $x ) { return preg_replace( '/.*\/wp-content\/plugins\/([^\/]+)\/.*/', '$1', $x ); }, $files ); $plugins = array_unique( $plugins ); $debug = implode( ' ', $plugins ); } $defaults['useragent'] .= " (NelioDebug {$debug})";

단계별로 수행하는 작업을 살펴보겠습니다.

  • 먼저 debug_backtrace 로 실행 스택을 얻습니다. 이것은 현재 함수에 도달하기 위해 호출된 모든 함수를 표시하는 역추적을 생성하는 PHP 함수입니다.
  • 실행 스택의 각 요소에 대해 호출된 함수, 정의된 파일 및 행, 호출된 인수 등과 같은 정보가 있습니다. 그러나 우리가 집중하고 싶은 것은 함수가 정의된 파일: wp-content/plugins 에 있다면 플러그인에 정의된 함수임을 확실히 알 수 있습니다.
  • 스택의 모든 요소를 ​​처리했으면 찾은 모든 플러그인의 이름(있는 경우)을 가져와서 useragent 변수에 포함하기만 하면 됩니다.

설명된 대로 WordPress를 확장한 후 우리는 범인 이 누구인지 빠르게 확인하기 시작했습니다.

 35.214.244.124 - - [23/Apr/2020:10:59:08 +0200] "GET /es HTTP/1.0" 301 - "https://neliosoftware.com/es" "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:10:59:20 +0200] "GET /?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:10:59:36 +0200] "GET /?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:11:00:01 +0200] "GET /es?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:11:05:21 +0200] "GET /es?..." "php-requests/1.7-3470169 (NelioDebug culprit)" ...

문제 해결

문제가 되는 플러그인의 이름을 알게 된 후에는 해당 개발자에게 연락하여 도움을 요청했습니다. 그들은 적절한 해결책을 찾는 동안 문제를 극복하는 방법에 대해 답장을 보내고 우리에게 말했습니다. 운 좋게도 상황이 빠르게 개선되었습니다.

CPU 사용량 문제 수정 후 당사 웹사이트의 통계
도움을 요청한 후 웹 사이트의 통계.

보시다시피 자유 소프트웨어의 가장 큰 장점 중 하나는 우리가 사용하는 응용 프로그램의 소스 코드를 탐색하고 필요에 맞게 조정할 수 있다는 것입니다. 이 경우 필요한 정보를 표시할 수 있도록 WordPress 자체를 수정할 수 있었습니다.

누가 특정 기능을 실행하는지 알아내기 위해 debug_backtrace 를 사용하는 트릭이 마음에 드셨기를 바랍니다. 물론, 전통적인 방법은 아니지만 구현이 빠르고 지금까지 항상 매우 유용한 것으로 입증되었습니다.

Unsplash에서 Michal Mancewicz의 추천 이미지.