ブログを書こうかとこの ブログサイト (https://bigriver.jp) にアクセスします。 コンテンツが表示されず wordpress から障害を示すメッセージが表示されています。
“Your PHP installtion appeares be missing the MySQL extension which is required by WordPress”
とのことでWordpress が正常に動作できず、結果、このブログサイトも正常にコンテンツを提供出来ていません。 この記事を書いている今現在はすでに復旧済ですが、そのトラブルシューティングの過程を記録に残します。
原因として思い当たることは前日にシステムを最新化したことです。 apt-get で更新できるパッケージはすべて最新化していました。 その更新後にも何本かこのWordpress 上で記事を書いていたので特に問題はないと考えていました。 ただ、タイミングはおいておいて昨日の更新が何らかの影響を与えた可能性は高く、まずはその前提でトラブルシューティングを進めます。
まずはログを確認します。 apache のログと システムログです。
/var/log/apache2/errolog
本日の06:25 あたりにログローテーションされたタイミングで、ログ先頭にmbstring の共有ライブラリが読み込めていない旨の警告が出ています。
| PHP Warning: PHP Startup: Unable to load dynamic library ‘mbstring’ (tried: /usr/lib/php/20170718/mbstring (/usr/lib/php/20170718/mbstring: cannot open shared object file: No such file or directory), /usr/lib/php/20170718/mbstring.so (/usr/lib/php/20170718/mbstring.so: cannot open shared object file: No such file or directory)) in Unknown on line 0 [Sun Jun 28 06:25:04.610660 2020] [mpm_prefork:notice] [pid 29991] AH00163: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 configured — resuming normal operations |
ローテーションされる一つ前のログを確認します。
/var/log/apache2/errolog.1
最終行を確認すると “Graceful restart “ということでApacheを再起動しています。 ということでApache を再起動後にPHP関連で必要な共有ライブラリにアクセスできなくなり、結果、Wordpressも動作しなくなったことがわかります。
| [Sun Jun 28 06:25:04.527082 2020] [mpm_prefork:notice] [pid 29991] AH00171: Graceful restart requested, doing restart |
次にPHP の状態を確認します。 apache のエラーログでは”/usr/lib/php/20170718/mbstring: cannot open shared object file: No such file or directory” とのことで、 /usr/lib/php/20170718 ディレクトリに mbstringの共有ライブラリが無いと言っています。
/usr/lib/php/20170718 の中を確認すると確かに”mbstring.so”がありません。また、mysql との接続で必要となる”pdo_mysql.so” なども見つかりません。
| root@bigriver3:/usr/lib/php# ls -l 20170718/ total 7420 drwxr-xr-x 2 root root 4096 Jun 27 06:57 build -rw-r–r– 1 root root 31952 May 14 16:27 calendar.so -rw-r–r– 1 root root 14440 May 14 16:27 ctype.so -rw-r–r– 1 root root 170168 May 14 16:27 dom.so -rw-r–r– 1 root root 84072 May 14 16:27 exif.so -rw-r–r– 1 root root 5044744 May 14 16:27 fileinfo.so -rw-r–r– 1 root root 59496 May 14 16:27 ftp.so -rw-r–r– 1 root root 14440 May 14 16:27 gettext.so -rw-r–r– 1 root root 43176 May 14 16:27 iconv.so -rw-r–r– 1 root root 145632 Feb 25 21:55 igbinary.so -rw-r–r– 1 root root 43112 May 14 16:27 json.so -rw-r–r– 1 root root 445152 May 14 16:27 opcache.so -rw-r–r– 1 root root 113048 May 14 16:27 pdo.so -rw-r–r– 1 root root 272912 May 14 16:27 phar.so -rw-r–r– 1 root root 35112 May 14 16:27 posix.so -rw-r–r– 1 root root 30824 May 14 16:27 readline.so -rw-r–r– 1 root root 586528 Mar 21 18:27 redis.so -rw-r–r– 1 root root 14440 May 14 16:27 shmop.so -rw-r–r– 1 root root 55712 May 14 16:27 simplexml.so -rw-r–r– 1 root root 88168 May 14 16:27 sockets.so -rw-r–r– 1 root root 18536 May 14 16:27 sysvmsg.so -rw-r–r– 1 root root 10344 May 14 16:27 sysvsem.so -rw-r–r– 1 root root 14440 May 14 16:27 sysvshm.so -rw-r–r– 1 root root 18536 May 14 16:27 tokenizer.so -rw-r–r– 1 root root 30824 May 14 16:27 wddx.so -rw-r–r– 1 root root 30824 May 14 16:27 xmlreader.so -rw-r–r– 1 root root 47584 May 14 16:27 xml.so -rw-r–r– 1 root root 47208 May 14 16:27 xmlwriter.so -rw-r–r– 1 root root 30824 May 14 16:27 xsl.so |
結果からいうと、昨日の更新のタイミングでPHP7.4がインストールされ、その過程で/usr/lib/php/20170718 の中身も更新された模様。 もともとこのブログサイトのApache2ではPHP7.2 を利用していました。 とりあえず、ブログサイトが止まっているのはよろしくないので復旧させます。
途中の出力は省きますが、php7.2用のmbstring、php7.2用のmysqlの2つのライブラリをインストールし、apache を再起動します。
| # apt-get install php7.2-mbstring # apt-get install php7.2-mysql # systemctl stop apache2 # systemctl start apache2 |
https://bigriver.jp/ にアクセスし、復旧したことを確認します。
サービス復旧の暫定措置は上記で一段落です。 ただ、何時から発生したのかと今後の再発防止策も進めます。
何時から発生したのか、これはApache2 のアクセスログでステータスコードが4xxや5xxとなっているものを探せば大体の時間はわかります。 また上記のトラブルシューティングから今朝の6:25のApache の再起動後から問題が起きていた可能性が高いこともわかっているのでその前提で確認します。
まずはApacheが再起動する前のログを確認します。
/var/log/apache2/access.log.1
ログの最終行から5行ほど抽出します。 ちょうど最終行に記事コンテンツへのアクセスがあり応答コードも200 と正常動作していたことがわかります。その上の4行はxmlprcの脆弱性を攻撃しようとしたり、不正ログインの試行のログです。
| 157.245.233.164 – – [28/Jun/2020:06:20:27 +0800] “GET /wp-login.php HTTP/1.1” 200 5817 “-” “Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0” 157.245.233.164 – – [28/Jun/2020:06:20:27 +0800] “POST /wp-login.php HTTP/1.1” 200 5944 “-” “Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0” 157.245.233.164 – – [28/Jun/2020:06:20:28 +0800] “POST /xmlrpc.php HTTP/1.1” 403 3726 “-” “Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0” 207.46.13.136 – – [28/Jun/2020:06:24:01 +0800] “GET /robots.txt HTTP/1.1” 404 458 “-” “Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)” 66.249.73.201 – – [28/Jun/2020:06:24:15 +0800] “GET /?p=5956 HTTP/1.1” 200 16243 “-” “Mozilla/5.0 (Linux; Android 6.0.1; Nexus 5X Build/MMB29P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.92 Mobile Safari/537.36 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)” |
次に06:25にApacheが再起動した後からのアクセスログを確認します。 bot さんからのアクセスっぽいですが、応答コードは500です。やはり朝のApache 再起動のタイミングでPHP7.2 で必要な共有ライブラリを読み込めず、Wordpressが機能しない状況となったことがわかりました。
| 77.88.5.76 – – [28/Jun/2020:06:27:32 +0800] “GET /?cat=24 HTTP/1.1” 500 6937 “-” “Mozilla/5.0 (compatible; YandexBot/3.0; +http://yandex.com/bots)” 54.36.148.97 – – [28/Jun/2020:06:29:17 +0800] “GET /?p=6877 HTTP/1.1” 500 6984 “-” “Mozilla/5.0 (compatible; AhrefsBot/6.1; +http://ahrefs.com/robot/)” |
あとは再発防止策です。 Apache で利用しているphpは現在version 7.2です。今回は7.4がインストールされたことで問題が起きたわけですが、取りうる防止策は2つです。 1つは Apache で利用するphpを7.4にすること。もう1つはphp の7.2 を使い続けつつ7.4や7.5の更新が入っても問題が起きないようにすることです。 とは言いつつ、時間が無いので次回のシステム更新時までどちらの方式で進めるか検討し、準備をしておこうと思います。
