焦りました。
朝からサーバーがトラブりました。
(当サイトも30分くらいダウンしていたと思います。)
朝からトラブル発生~
ちょっとゴツ目のプログラムを作ろうと、基礎的な設計プログラムを作っていました。
DBテーブルをジョインして、Where句でこういうレコードを抽出して…
↑頭ではこんなイメージですw
ここはWhileで繰り返してデータがつきるまで処理をして…
ここは、●回繰り返したいから、for文で繰り返し処理をして…
と、次々に行いたい処理を書いていきます。
基本的にプログラムというのは、条件分岐と繰り返し処理の組み合わせが基本です。
ある程度プログラムを組んだことがある方はご理解いただけるかと思います。
良いプログラムというのはいかに短いコードで複雑な処理を行うことができるのかです。
いつもの作業です。
そして、まずはしっかりとデータが出力させるかをチェックします。まだ、何も複雑な処理をしていない、DBのデータをとりあえずガーーーーっと出力するものです。
こんなところで普段はミスなどおきようがないのですが。。。
処理を開始しても、全然終わらない。。。
何かがおかしい。。
あれ?無限ループしてる?
答えは、私が変数名を間違ったために、for分の処理が無限ループしていました。
終了条件が、設定していない変数になっていますから、終了条件を満たすことが無い状態で永遠に繰り返していました。
これに気づくまでに2分、そのままプログラムを実行していました。
2分後これに気づき慌てて終了。
しかし、DBへの負荷なのかWEBサーバーへの負荷なのか、処理を注視してもサーバーが戻ってきません。
もしかしたらプロセスが終了していないのかもしれない
と、思いましたので、こういう時は再起動処理に限ると。(あまり褒められた方法ではありませんwマネしないようにw)
まず、DBの再起動処理をしてみたところ何らかのエラーで起動できないというエラー。
LinuxのDB(特にMariaDB)の場合、何かの拍子にサーバーがダウンしてしまうことがありますが、その際に、起動しているという信号をOSに流すためにLockファイルというものを起動時に作っているのですが、このLockファイルが消えていないために、起動はしていないのだがシステム上Lockファイルがあるから起動しているということになることがあります。
もしかして、これではないのか?とおもいLockファイルがあるべき場所に言ってもDBのロックファイルは見当たりませんでした。だから、逆に考えれば起動していてもOS的には起動していないことになります。
結局、よくわからないから一回マシンごと再起動しようと思い再起動しました。
戻ってくるはずが…戻ってこない
現在当サイトで利用しているサーバー機はAWSのLightSailというサービスで作ってある仮想サーバーです。
マシンの再起動処理はかなり早く、通常であれば1~2分もすれば戻ってきます。
まず最初にSSHで接続を試みましたが、つながりません。
つぎに、Pleskにつないでみましたがつながりません。
というか、つながらないというより、設定してあるドメイン名が引けていない(DNS名前解決ができていない)感じでした。
IPアドレスで直接接続を試みるとSSHは接続できました。
Pleskは、通信はできたのですが、DBが起動していないというエラーで正常な状態ではありませんでした。
Lockファイル云々ではなく、現実的にDBが起動していないようでした。
SSHログインはできたので、いろいろ見てみると、WEBサーバも起動していませんし、DNSサーバーもメールサーバーも起動していませんでした。
事象としてはLockファイル自身を何らかの理由で作成できないため、ダウン処理をして停止した感じでした。
この時点でサーバーがおかしくなってから30分経過しています。WEBサイト、メールサーバー等すべてが30分ダウン中です。
再起動したのに、DBが起動していない。おまけにどうやらDNSサーバーもダウンしていて起動していないことがわかりました。
DNSサーバーの起動コマンドをたたいたときに出力されていたエラーをよく読みますと、答えが書いてありました。【ディスクがいっぱいです】
とのこと。
スグにdfコマンドで確認すると、ディスク領域の使用量は、100%となっていました。
なんだこんなことかよっ!と思うなかれ。起動に失敗した時点ですぐにディスク容量に想いを馳せることができるほど私は神ではありませんw
私の思考は、先ほどのプログラムミスでDBデータに欠損を生じさせ、DBが起動しないことが起因してその他もろもろのサービスにも影響しているのではないかと考えましたからね。
普通はそんな思考じゃないかと思います。
昨日まで使用量は、ディスク全体の約50%の使用率だったので、この半日程度で残りの50%を使い切って各種サーバーを起動すらできないくらいに容量を圧迫しているとは、何かおかしいです。
この50%のディスク仕様に至るまでに10年かかっています。(メールはIMAPで受信しているためどんどんたまっていて、ディスク容量の大半を食っているのがメールです。)
考えられることは、DBファイルを壊してしまって、ファイルが無駄に肥大化しているか、かログファイルです。
はっきりいって、どちらにせよ昨日の厳密なログファイルやDBのファイルのファイルサイズを知らないので、DBのファイルが大きくても小さくてもこれが妥当なのかどうなのかはわかりません。
とりあえず、duコマンドで、容量を大量に食っているディレクトリを順に追求することにしました。
そこで発見できたのは、Pleskのマイグレーションマネージャーでマイグレーションした場合、その時点でのデータをバックアップファイルとして永久に保存しています。
確認すると、10年前にマイグレーションした際のデータが残っていました。このバックアップファイルで約20%ものデータを食っていました。
今回の件とは全く関係はないのですが、無駄なファイルサイズが20%減りますから、削除することで起動できるだけの余裕ができますね。
なので、とりあえず削除してマシンを再起動。その結果問題なく起動し、サイトも接続できるようになりました。
ここにたどり着くまでダウンしてから45分くらいかかりました。結構いたいですね。45分のダウン。
さて、でも、根本的な問題は解決に至っていません。マシンが正常に動いたことを確認してからじっくりと犯人探し。
なぜ、ディスク容量がいっぱいになったのか。半日で約50%の残り容量を食ったのか。これを追求し解明しておかないとまた起きるかもしれません。
無限ループ後おかしくなったことからも、ログファイルじゃないかと推測。
まずは、該当ドメインのWEBサーバーログファイルを確認。
該当ドメインのログファイルは多くてもせいぜい100KB でした。ローテーション設定もしてあり、1日1個、30個までログファイルをためるように設定してあり、合計でも100MBもありません。
また、該当ドメイン向けのPHP.iniではPHPのエラーはログに出力しない設定となっていて、実際に確認しても今回の無限ループ時にエラーログは吐いていません。
おかしいな。。。ログファイルじゃないのかな???と思った次第です。
しかし!やっぱり犯人はログファイルだった!
いや、ログファイルが犯人じゃないです。犯人は自分ですねw
今一度容量の大きいところを順に追いかけるために、duコマンドで追いかけたところ、/var/logディレクトリに、各ドメインごとではなく、全体としてのPHPのエラーログを吐き出しているところがあり、その中を見ると、ディスク全体の40%近くの容量を使っているログファイルがありました。
これで確定です。こちらの過去ログを見ても、1ヵ月で100MBも出力していないのに現在のログファイルだけで40GB近くありました。
中を確認すると、頭から最後まで、その2分間の無限ループのエラーログでした。
ログ内容はPHPのNoticeで、とるに足らない記載なのですが、1回の処理で1行。無限ループした2分間で数百万~数千万ループしていたようで同じログが上から下までビッチリ。
結局このログがディスク上限まで溜まり、DBサーバーを再起動処理した時点で、ダウンはしたけど起動するためのロックファイルを作るだけのディスク空き容量も無いため起動できず。
という状態だったようです。
原因がわかれば簡単なんですが、もうちょっとで迷宮入りするところでした。
Pleskのこのログ書き出しの仕様を調べると。。。
しかし、こんなところに、PHPのエラーログを出力されても、ホスティングユーザは確認できない(Pleskを入れたサーバーでは、/var/logは、rootユーザのみが閲覧できる場所になっています。)し、よほどのことが無い限りroot権限者も、このファイルを確認することはないと思いますし、そもそも、各ホスティングドメインごとに自分で確認できるエリアにPHPエラーログを出力させることができるので、はっきり言って不必要なログです。
ということは、Plesk上でどこかで書きださない設定があるのではないかと思いいろいろ文献を漁ってみたら、結論で言えば、どうもPleskのバグか何かで、現状では書きだしを止める設定はPlesk上にはないそうです。
ただ、Plesk上でベースのphp.iniを編集できるのでログの書き出しやログの出力レベルは編集できたので、ログの書き出し停止と、ログレベルをWarningからと設定しました。
書きだしを停止すれば、それほど問題ではないのですが、display_errorをONにした際もNoticeが出るとちょっと邪魔なときも多いので、全体設定はWarningからとして、ドメインレベルで必要な際はログの書き出しとエラーレベルを調整すればいいかと思い、設定しました。
そうしたところ、ログの書き出しが止まりましたので、ほっと一安心です。