プログラミングなんてわからないんですけど〜

元プログラマによるプライベートでのプログラミング日記。1/3のつもりだけどソフト関連はここがメイン

日本時間2020/10/17 12時頃に起こったpopon.pptdn.jpのスローダウンの原因と対処について

お昼すぎ、私は昼食を摂っていました。その間は自分で運用しているmastodonサーバであるpopon.pptdn.jpのWebUIは特に見ていませんでした。昼食を終えたあと、ゲームをするかと思いゲーム機を取り出しながらふとタブレットのブラウザ画面を見るとタイムラインの表示がまったく変わっていないことに気づきました。「接続がうまく行っていないのかな?」と思いリロードしてみたところ、サーバからデータが送られてきません。「自宅回線がおかしいのかな?」と考えて、念の為スマホLTE回線でつなぎWebUIを見に行ったところ「反応がありません」みたいな表示が。「サーバ側で問題が発生したかな?この前いろいろ対策したからそうそう変なことは起こらないと思っていたんだが」と思いながら、VPSのコンソールを見に行きました。まずはVPS自体が障害を起こしていないか確認しましたが問題なさそうです。VPSの画面からCPUの使用状況など確認したところ、12時10分ぐらいに30MBぐらいのデータを受信したあとCPUの使用率が上がっていることに気づきました。ただし、CPUは100%になっていないので別の原因がありそうです。そこで、sshでサーバに接続してみました。

sshクライアントからサーバに接続しようと試みましたがなかなか接続が完了しません。切断もされないので接続されるのをまっているとやっと接続されました。「こんなに反応が悪いということは何か重いプロセスが走っていそうだ」と考え、どんなプロセスが走っているか確認するためhtopコマンドを実行してみました。そこで見たものはメモリの枯渇と複数のffmpegプロセスが動いているというものでした。何が起きているのか最初理解できませんでしたが、よく見るとmovファイルをaacに変換するffmpegプロセスが複数立ち上がっており、1プロセスあたり1GBのメモリを消費しているためメモリの枯渇が起きてスローダウンが起きていることがわかりました。

メモリが足りていないのでswapファイルを追加すればなんとかなるのではないかと思いましたのでswapファイルの追加を行おうとしましたが、htopコマンドの終了がなかなかできません。一度sshのセッションを切って再度つなげ直してなんとか4GBのswapファイルを追加しました。ちなみに、swapファイルの追加と有効化については以下のサイトを参考にしました。

https://blog.masato.xyz/ubuntu-server-1804-lts-swapfile-setup

swapファイルを有効にしたあとhtopコマンドを再度実行して状況を確認したところ、原因となっていたffmpegコマンド群が順調に終了してメモリの空き容量が回復したことを確認しました。念の為sidekiqも見てみましたが、溜まっていたキューも処理しきったようで少なくとも14時には正常な状態に戻りました。

念のため何が起きていたのか調べてみようと思いログを見てみました。最終的にsyslogにて日本時間の12:12頃に6つのMOVファイルのffmpegによる変換が走っていることを確認しました。sidekiqも確認しましたが同様でした。ここから先、どのtootで起きていたのか調査の方法がわからなかったのでひとまずここで終了です。たぶんDBの中を見れば該当するtootを特定できると思いますが、DBの構造を理解していないのでやめます。

うちの環境が悪かったのは物理メモリが8GBあったためswapをまったく用意していなかったことでした。いまのところ、4GBのswapファイルを追加していますがディスクの空き容量を再検討して増やすかもしれません。キューが急増したときでも処理できるようにしていたつもりでしたが、まったく考えていなかった処理で起こったのは痛かったです。

ひとまず自分ができることはしましたが、今後はDBのデータを読めるようになってみたいと思います。