WordPressサーバーでCPU使用率が高い原因を見つける

公開: 2020-05-07

数日前、ホスティングプロバイダー（SiteGround）から、サイトのCPU使用量が毎月許可されている「90％」であり、100％を超えると「Webサービスが制限される」というメールが届きました。 「アクセスに問題がある」と思われます。 かなり恐ろしいですよね？ できるだけ早く修正しなければならなかったのは、まったく望ましくない状況でした。 しかし…どこから始めればいいのでしょうか？

CPU使用率が高いエピソード中の当社のWebサイトの統計
CPU使用率が高いエピソード中の当社のWebサイトの統計。

今日は、Webサイトでかなり一般的な問題に直面した経験を共有し、原因を特定するために何をしたか、および問題をどのように解決したかを説明したいと思います。 このように、同様の問題に直面した場合、開始方法についていくつかのアイデアがあります…

CPU使用率が高くなる理由

WordPressはPHPで書かれたコンテンツ管理システムです。 これは、提供するコンテンツが一連のPHPスクリプトによって動的に生成されることを意味します。訪問者がWebサイトにアクセスするたびに、WordPressはリクエストを処理し（「ホームページを送ってください」など）、応答を生成します（この場合、ホームページを送信します）。 明らかに、リクエストへの応答はサーバーリソースの特定の使用を意味します。リクエスト自体を調べ、訪問者がアクセスしたいものを決定し、データベースからフェッチし、HTML応答を生成する必要があります。

キャッシュシステムがウェブサイトの読み込み時間を短縮する理由の1つは、今では非常に明白なはずです。基本的に、この処理時間を節約できます。 特定のリクエストが初めて届くと（「ホームページを送って」）、WordPressが起動して応答を生成します。 キャッシュが設定されている場合、実際に訪問者に送信される前に、その応答が保存されます。 このようにして、同じリソース（この例ではホームページ）への今後のリクエストでは、WordPressが何かを処理する必要がなくなります。 キャッシュは以前に保存したコピーを送り返すことができるため、時間とリソースを節約できます。

このパフォーマンスを念頭に置いて、サーバーで高いCPU使用率が見られる理由を想像するのは難しくありません。

  • リクエストが多すぎます。 多くのユーザーが同じ時間にあなたのウェブサイトにアクセスした場合、またはあなたが多くの不正なリクエストを受け取った場合（誰かがあなたのサーバーを攻撃している可能性があります）、WordPressはそれらすべてのリクエストを処理する必要があるため、サーバーリソースの使用が増加します。
  • リクエストの解決には時間がかかります。 多くのプラグインがインストールされている場合、またはプラグインの一部が何らかの理由で非効率的である場合、WordPressは多くの非効率的なコードを実行するため、取得するすべてのリクエストは必要以上に時間がかかります。

つまり、キャッシュはこれらの問題に対する優れた防御策のようですよね？ そして確かにそうです。 ただし、キャッシュは問題を「修正」しないことに注意してください。 それは単にそれを「隠す」だけです。 キャッシュできないWordPress機能があり、したがって常にWordPressを実行する必要があるため、これを覚えておくことが重要です。

  • WP-Cronを使用してスケジュールされたタスク。 WP-Cronは、将来実行されるタスクをスケジュールするためのWordPressメカニズムです。 たとえば、WordPressはそれを使用してスケジュールされた投稿を公開します。
  • WordPressのRESTAPI。 REST APIは、サードパーティのアプリケーションから使用して、JSONオブジェクトを送受信することでWordPressサイトと対話できるインターフェイスです。 一部のRESTAPIリクエストはキャッシュされる可能性がありますが（つまり、GETリクエスト）、他のリクエストはキャッシュされません（POSTおよびPUT）。 したがって、通常はキャッシュできないものです…
  • WordPressでのAJAXリクエスト。 WordPressでRESTAPIを使用する前は、そのAJAXAPIを使用して動的なWebサイトを作成する必要がありました。 このAPIは、サーバーとの間で情報を送受信するためにも使用できるため、RESTAPIと非常によく似ています。 これは別のシステムですが、RESTAPIと同じ制限が適用されます。

問題の分析

まず、Webサイトで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 ）から複数のリクエストを受信したことに注目してください。 これは攻撃のように見えるかもしれませんが、実際にはそうではありません。通常、Webページには複数のアセット（画像、スクリプト、スタイル）が含まれており、サイト内の特定のWebページにアクセスする訪問者が複数のリクエストを実行してすべてを取得するのは完全に正常です。 。

さて、私たちの場合、実際に、非常に多くのリクエストがあったことを確認できました。 実際、非常に高いです。 そして、ログファイルが通常よりもはるかに大きいため、私たちはそれを知っていました。

考えられる理由は、何らかの理由で訪問のピークがあったということです…しかし、Google Analyticsによると、そうではありませんでした。 それで、何か違うことが起こっていました。

アクセスログをより詳細に分析することで、次の事実を特定することができました。受信したすべてのリクエストの15％以上が同じIPからのものでした。 そして（ドラムロール）そのIPは私たち自身のWebサーバーでした！

素晴らしいアイデアを持っている男性を示す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" ...

そして、1つ見つかりました。これらすべての異常なリクエストの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使用率の問題を修正した後の当社のWebサイトからの統計
助けを求めた後の私たちのウェブサイトからの統計。

ご覧のとおり、自由ソフトウェアの優れた点の1つは、使用するアプリケーションのソースコードを調べて、ニーズに適合させることができることです。 この場合、WordPress自体を変更して、必要な情報を明らかにすることができました。

debug_backtraceを使用して、特定の関数を実行しているユーザーを見つけるトリックが気に入っていただけたでしょうか。 確かに、これはオーソドックスな方法ではありませんが、実装は迅速であり、これまでのところ、非常に役立つことが常に証明されています。

UnsplashのMichalMancewiczによる注目の画像。