お名前ドットコムVPSへ移行への道12-エラーログを見て対策

※ 当サイトではアフィリエイト広告を利用しています。リンクは広告リンクも含みます。

この記事は約14分で読めます。
広告

お名前.com VPS を使用中に出たエラーログを見て対策します。
都度、追加していきます。
環境
パソコン Windows11
VPS OS Ubuntu 20.04.3 LTS、 
Docker image: owasp/modsecurity-crs:nginx
image: wordpress:fpm-alpine
こちら↓が環境を構築してきた記録なので参考にしてください。

お名前ドットコムVPSへ移行への道

2024/4お名前.comのレンタルサーバーからVPSへ移行したときの記録になります。

広告

an upstream response is buffered to a temporary file

よく調べるとブログにアクセスすると毎回出てました。

[warn] 127#127: *45 an upstream response is buffered to a temporary file /var/cache/nginx/proxy_temp/7/00/0000000007 while reading upstream, client: ***.***.***.***, server: kikuichige.com, request: "GET /7852/ HTTP/1.1", upstream: "http://***.***.***.***:80/7852/", host: "kikuichige.com"

参考:Nginxの設定 – ソフトウェアエンジニアリング – Torutk
Nginxの「proxy_buffer_size」のエラーログ対策・設定方法まとめ(upstream response is buffered to a temporary file) (doudonn.com)
nginxが上流(upstream)サーバーからのレスポンスを一時ファイルにバッファリングしていることを示しているようです。
今回はWordPressのコンテナから送られてくるもの。
大きなレスポンスデータがnginxのメモリバッファを超えてしまう場合に発生するようです。

なので一時的に
多分/var/cache/nginx/proxy_temp/7/00/0000000007に入れたっていうことだろう。
ただ/var/cache/nginxというディレクトリが存在してなかった。
なので実際は書いたつもりだけで使われてないかも。
とりあえず動いているのでスピードが遅くなるだけで問題となるものではなさそうな気はする。
また、対策でバッファサイズを大きくすると結局メモリの消費を増やすかもしれない。
そうなると更に状況が悪くなるかもしれない。
freeでメモリの使用量を気にしつつ試しに、対策してみる。

まず参考サイト「デフォルトのメモリバッファの大きさは実行している計算機/OSのページサイズと同じ値(4KBか8KB)となっており、」と書いてあるので現状4か8か調べてみる。
Ubuntu 20.04.3 LTSのページサイズを次のコマンドで確認
getconf PAGE_SIZE
4096つまり4k
参考サイトの軽い方の設定だとwarnが消えなかったので重いほうにしてみます。
proxy_buffer_size 8k;
proxy_buffers 100 16k;
proxy_busy_buffers_size 16k;

具体的な設定手順
sudo docker exec -it コンテナ名 sh
でコンテナの中に入って現状の設定を見る。
cat /etc/nginx/nginx.conf
略
http {
略
    include /etc/nginx/conf.d/*.conf;
}
で中身を見ると上記設定は書いてないのでデフォルト値で使われているみたいです。
デフォルトがいくつの設定かは分からない。
include /etc/nginx/conf.d/*.conf;になっていて
ymlで以下のようにバインドしてコンテナを作っているのでjikken1.confに上記設定を追加した。
    volumes:
      - ./modsecurity/jikken1.conf:/etc/nginx/conf.d/jikken1.conf
設定反映(コンテナを使っている環境の私の場合)
sudo docker restart コンテナ名
動作確認(エラーログとアクセスログは両方同時にみたほうがいい。)
sudo docker logs コンテナ名 -f --tail=5 | awk '{print $1,$2,$3,$4,$5,$6,$7,$8,$9,$10}'
でログを見て様子見ます。

軽い方の設定では閲覧(get)したときwarnが出るページがあったけど
重い方の設定にしたら出なくなりました。
ただ投稿(post)するときはwarnになります。設定値の微調整が必要かもしれません。
freeで見たメモリ使用量もそれほど変化はありませんでした。

しかしalertが出るようになった。
→(加筆)前から出ていたのが気づかなかっただけ、warnの表示がなくなったので目立つようになった。modesecurityでアクセス拒否したアクセスに対して出ていることが分かったので問題なさそう。
2024/05/25 04:04:45 [error] 127#127: *16743 [client *.*.*.*] ModSecurity: Access denied with code 403 (phase 4). 略
2024/05/25 04:04:45 [alert] 127#127: *16743 header already sent while sending response to client, 
というこで、このまま運用してみます。
目次へ
proxy_bufferingをoffにしてみた。
server {
略
    server_name  kikuichige.com;
    proxy_buffering off
参考:https://mogile.web.fc2.com/nginx/admin-guide/reverse-proxy.html
バッファーしなくなるのかと思ったが、そうでもなかった。
warnになる頻度は減った気がする。
しかしpage insisightでアクセスするとaleartになった。
alertの前にmodesecurityで引っかかっていた。
設定を戻してもalertになったのでpage insight
の場合はmodesecurityが原因かも。
もしかしたら設定の切り替えでバッファーの中身がクリアされてないとかかも。
今回の対策した設定は全部戻しwarnよりalertがでないかしばらく様子見する。
→(加筆)aleartは出る。今まで気づかなかっただけ。

[error] 126#126: *210 access forbidden by rule, client: GatewayのIP, server: kikuichigevps.com, request: “POST /wp-cron.php?doing_wp_cron=1712025848.6137320995330810546875 HTTP/1.1”, host: “kikuichigevps.com”

調査材料

そもそも、これは何のログかというとコンテナのログに出ている。
client: 172.*.*.*が何かといえば以下で調べるとネットワークのGATEWAYになっている。
sudo docker inspect shared
[
{
“Name”: “shared”,

“IPAM”: {
“Driver”: “default”,
“Options”: {},
“Config”: [
{
“Subnet”: “172.*.*.*/16”,
“Gateway”: “172.*.*.*”
}

  1. WP-Cron の動作方法
    • クライアントがサイトにアクセスすると、WP-Cron は現在時刻と予約されたタスクの実行時刻を比較します。
    • 指定された時間を過ぎていれば、タスクを実行します。
  2. 注意点
    • WP-Cron は、OS の cron とは異なります。Web アクセスに依存しているため、アクセス数の少ないサイトでは実行にタイムラグが生じることがあります。
    • サーバー側で用意された cron が利用できない場合や、特定のタスクを定期的に実行したい場合に WP-Cron を活用します。

/wp-cron.php?doing_wp_cron=1712025848.6137320995330810546875? 以降は、WordPress の cron 機能に関する情報です。具体的には、以下の情報を表します。

  • doing_wp_cron: cron ジョブの実行中であることを示します。
  • 1712025848.6137320995330810546875: cron ジョブの開始時刻を表すタイムスタンプです。

この情報は、WordPress が cron ジョブを管理するために使用されます。

詳細

WordPress は、定期的に実行する必要があるタスクをスケジュールするために cron 機能を使用します。これらのタスクには、例えば、データベースのバックアップや投稿の公開などがあります。

cron ジョブは、wp-cron.php というファイルによって実行されます。このファイルは、WordPress のインストールフォルダにあります。

? 以降のパラメータは、wp-cron.php に渡される情報です。これらの情報は、WordPress が実行する cron ジョブを特定するために使用されます。

タイムスタンプ

タイムスタンプは、10進数の Unix 時間を表します。これは、1970 年 1 月 1 日 00:00:00 UTC から経過した秒数を表します。

例えば、以下の URL は、2023 年 3 月 8 日 12:34:56 JST に開始された cron ジョブを表します。

/wp-cron.php?doing_wp_cron=1646722496.6137320995330810546875

参考資料

  • WordPress の cron 機能に関する公式ドキュメント: URL WordPress cron 機能 公式ドキュメント
  • wp-cron.php ファイルに関する解説記事: URL wp-cron.php ファイル 解説記事

止める方法WordPressのwp-cron.phpを停止するときの注意 | お役立ち記事 | 大阪のWeb制作会社 ナンクマ (nankuma.jp)

分かったこと

WordPressが自分でPOST /wp-cron.php?doing_wp_cron=~(~はタイムスタンプ)を実行している。
実効タイミング:
クライアントがサイトにアクセスすると、WP-Cron は現在時刻と予約されたタスクの実行時刻(~タイムスタンプ)を過ぎていれば実行する。
何のためかというとサーバーのCronのように指定された時刻に処理を実行するCron機能がないから、
苦肉の策としてクライアントのアクセスのタイミングを利用している。
ただ、(~タイムスタンプ)の設定の仕組みは未調査。次は何分後だとか設定してるのかも。
私の環境だとWordPressのコンテナがPOST /wp-cron.php?doing_wp_cron=~をhttps://kikuichigevpsにPOSTしているので、
この場合クライアントになりえるのは、VPSのIPとか考えられるが
実際はNginxのGATEWAYのIPになっているっぽい。
目次へ

対策

対策として、この機能自体を止めてホストのCronで定期的にPOST /wp-cron.phpを実行するみたい。
?doing_wp_cron=~は別にいらなそう。
POSTなのでbodyに何か必要かもしれないがエラー回避には、なくてもよかった。
これでwp-cron.phpを実行する本来の目的が達成されているかは、分からない。

wp-cronを停止する
参考:WordPress の wp-cron.php を無効にする | Web Design Leaves
私の環境の場合
htmlディレクトリはバインドマウントしてあるのでSSH接続しているVsコードで直接見れます。
しかし、wp-config.phpはrootユーザで編集しても変更できません。
そこでwp-config.phpを
ターミナルで今、コマンドを実行しているディレクトリにコピーして以下追加。
define( 'DB_COLLATE', getenv_docker('WORDPRESS_DB_COLLATE', '') );
/** wp-cron停止 **/
define('DISABLE_WP_CRON', 'true');←追加

WordPressのコンテナにコピー
sudo docker cp wp-config.php コンテナ名:/var/www/html/wp-config.php
設定を反映
sudo docker restart コンテナ名
ホスト(お名前.comのVPS)のCronで30分毎にwp-cron.phpを実行

設定方法はターミナルで
crontab -e
1. /bin/nano        <---- easiest
*/5 * * * * curl -X POST https://kikuichigevps.com/wp-cron.php
をコピーして右クリックするだけで貼りついた。
CTRL+O
Enter
CTRL+X
nanoの使い方は、参考:https://minoru.okinawa/archives/2247

wafで引っかからないようにwafの入ってるNginxのconfig修正
    location /wp-cron.php {
        allow ホストのIP;
        deny all;

実効ログ
VPSのホストのIP - - [02/Apr/2024:14:30:02 +0900] "POST /wp-cron.php HTTP/2.0" 200 0 "-" "curl/7.68.0" "-"
取り合えず動いている。
wp-cron.phpが何をやっているかは、よくわかりませんがエラーはなくなった。
目次へ

functions.phpを「ファイル更新」したら致命的なエラーをチェックするためにサイトと通信できないため、PHP の変更は取り消されました。SFTP を使うなど、他の手段で PHP ファイルの変更をアップロードする必要があります。

原因はWordPressから自分自身に対してGetする通信がWAFではじかれてる。
ログ
GatewayのIP - - [03/Apr/2024:08:46:35 +0900] "GET /wp-admin/theme-editor.php?theme=cocoon-child-master&file=functions.php&wp_scrape_key=32略95&wp_scrape_nonce=36略4 HTTP/1.1" 403 21
{"transaction":{"client_ip":"GatewayのIP","time_stamp":"Wed Apr 3 08:46:35 2024","server_id":"40略80e","client_port":*****,"host_ip":"WordPressのコンテナのIP","host_port":443,"unique_id":"171210159564.530244","request":{"method":"GET","http_version":1.1,"uri":"/wp-admin/theme-editor.php?theme=cocoon-child-master&file=functions.php&wp_scrape_key=~
自分のパソコンのIP - - [03/Apr/2024:08:46:35 +0900] "POST /wp-admin/admin-ajax.php HTTP/2.0" 200 554
対策はWordPressのphp編集のときだけ手動でGatewayのIPを許可するように
Nginxのconfを修正
location /wp-admin {
        allow GatewayのIP;
結果、phpのファイル更新できた。
ログ
GatewayのIP - - [03/Apr/2024:08:52:14 +0900] "GET /wp-admin/theme-editor.php?theme=cocoon-child-master&file=functions.php&wp_scrape_key=369略b4d&wp_scrape_nonce=1略0 HTTP/1.1" 200 146246
GatewayのIP - - [03/Apr/2024:08:52:15 +0900] "GET /?wp_scrape_key=36947ce5cb97e57dc0ec2008543b7b4d&wp_scrape_nonce=1362168440 HTTP/1.1" 200 289464
自分のパソコンのIP - - [03/Apr/2024:08:52:15 +0900] "POST /wp-admin/admin-ajax.php HTTP/2.0" 200 128
目次へ

所感

WordPressが自分自身にGETやPOSTするときにWAFでひっかる件は他にもありそう。
イチゲをOFUSEで応援する(御質問でもOKです)Vプリカでのお支払いがおすすめです。
MENTAやってます(ichige)
目次へ

コメント

タイトルとURLをコピーしました