【Mastodon】【お知らせ】【備忘録】昨日の自サーバ2カ所で発生したトラブルの顛末につきまして
昨日、私が運営するMastodonサーバ2カ所におきまして、重大なトラブルが発生しておりました。
特に、リベラル（自由主義者）向けコミュニティとして一般の方のご登録も（一応）受け付けております「LIBERA TOKYO」では、1時間ほどコミュニティの運営そのものが停止する事態にまで至りました。こちらについては昨日日中に仮復旧しております。
なお、当初発生していた問題であるメディアファイルアップロード時の不具合につきましては、昨日の22時頃に復旧しております。これにより、昨日発生していたトラブルについてはすべて解決いたしました。
もし昨日中に問題が解決しなかった場合、サーバのデータやメディアファイルのバックアップを取得した上で、Mastodon本体をクリーンインストールしてそちらにデータやメディアファイルを復元することも検討しておりましたが、その必要もなくなりました。
Mastodonを含むFediverse（分散型SNS）をご利用の皆様、特に「LIBERA TOKYO」のユーザ様および「LIBERA TOKYO」と連合していただいているサーバの管理者各位に対し、多大なるご心配とご迷惑をおかけしてしまい、誠に申し訳ありませんでした。
なお、今回の問題はめったに起こるものでもないと思いますが、後学のために顛末について記録しておくことにします。
そもそも何が起きていたのか
大きく、次の2点の問題が発生していました。
- 自サーバ2カ所共に発生していた問題
- ある程度の容量以上のメディアファイル（画像等）をアップロードできなくなる問題
- なお、アイコンのような小さな画像のアップロードは可能だったが、これが問題の原因切り分けに時間を掛ける要因となってしまった…。
- ある程度の容量以上のメディアファイル（画像等）をアップロードできなくなる問題
- 「LIBERA TOKYO」でのみ発生していた問題
- Webブラウザ、クライアントアプリのいずれからも、「LIBERA TOKYO」のコンテンツにアクセスできなくなり、タイムラインの確認等一切出来ない現象
- 本件は、メディアをアップロードできない問題について、せめて「LIBERA TOKYO」だけでも解決しようと思ったものの、それに失敗したことによって引き起こされてしまった。
- Webブラウザ、クライアントアプリのいずれからも、「LIBERA TOKYO」のコンテンツにアクセスできなくなり、タイムラインの確認等一切出来ない現象
結論
サーバアプリケーション「Nginx」の作業ディレクトリの権限が設定ファイルの内容と一致していなかったことによる不具合でした。
10月1日（金）の未明に、たまたま自分はMastodonのサーバ2カ所において、パッケージを更新するコマンド「yum update」を実行しました。しかし、どうもそのときに、上述のNginxの設定と作業ディレクトリの権限の不一致が起きてしまったようです。
以下、私が使用しているCentOS7のVPS環境を前提に話を進めることにします。
Nginxの設定ファイルは、/etc/nginx/にあるnginx.confです。
このファイルの先頭付近に、「user」で始まる行があります。「user」に続いて書かれている情報が、作業ディレクトリの所有者のユーザ名になっている、という前提のようです。
ところが、問題が発生していた時点で、nginx.confに記録されているユーザ名と、作業用ディレクトリ「/var/lib/nginx」の所有者名が一致しておらず、さらに、作業用ディレクトリの配下のディレクトリにもまた別の所有者名が割り当てられていました。
しかも、nginx.confに記録されているユーザ名もどうも想定通りのものでなさそうでした。
そこで、nginx.confのユーザ名を想定されるものに書き換え、さらに次のコマンドで作業ディレクトリおよびその配下の所有者を書き換えました。
chown -P <nginx.conf で設定した所有者名> /var/lib/nginx
これで、晴れて問題解決し、Mastodonへのメディアアップロードが可能になりました。
しかしここに来るまでが長かった…
結論がわかればどうってことない問題のように思えますが、ここに至るまでまるまる半日かかってしまい、挙げ句の果てに、「LIBERA TOKYO」を一時的に停止させてしまうというミスまでやらかしてしまいました。
疑ったことその1：サーバの容量逼迫
外出中に、スマートフォンアプリ（iOS版「Tootle」）から、画像付きの投稿をしようとしたところ、「Internal Server Error 500」が発生してしまいました。
画像なしの文字のみのトゥートは普通に出来るので、いよいよストレージ容量が限界に達したのかと思いました。
しかし、よくよく見たら、連合しているほかのサーバのトゥートに含まれる画像は普通に取得できます。真に容量が逼迫しているのであればこの現象を説明できません。
さらに、帰宅したあとに試しにアイコンのような小さな画像をアップロードしたときには普通に受け付けられたので、なおさら状況がわからなくなりました。
疑ったことその2：アップロードされるメディアが格納されるディレクトリの所有者やパーミッションの不備
これは実際に過去に経験したことですが、今回のようにファイルアップロードを出来なくなったときに、なぜか知らないうちに、Mastodonでトゥートに添付したメディアファイルなどが格納されるっディレクトリのパーミッションが変わっているという現象が発生していました。
具体的には、/home/mastodon/live/publis/system/以下のディレクトリ群ですが、これらについては、いずれも今回は問題ありませんでした。
疑ったことその3：前日未明におこなったyum update
実は私は、自分が運営するMastodonのサーバ2カ所とも、10月1日（金）未明にyum updateを実施するまでは、数ヶ月間大きな設定変更をしていませんでした。
ですので、不具合を埋め込んだタイミングはほぼ間違いなくここです。
半ばダメ元で「yum update」の前の状態に戻せないかとネット上を検索したところ、いくつか記事がヒットしました。
その中から、私は下記の記事を参考に、先に復旧させたかった「LIBERA TOKYO」のほうから、yum updateの前の状態に戻そうとしました。
yum history
yum history undo <更新を取り消したいヒストリーのID>
しかし、この更新取り消し作業は失敗し、これにより「LIBERA TOKYO」のサーバはうんともすんとも言わなくなってしまいました。
疑ったことその4：原因はNginxにあり？
ブラウザからアクセスしても反応が返ってこなくなってしまった「LIBERA TOKYO」のサーバですが、SSHクライアント経由での接続は可能で、コマンドも普通に受け付けてくれました。
なすすべもなく途方に暮れて、「Nginxを再起動するか」と思い、systemctl restart nginx.serviceとコマンドを打とうとしたら…
ない！ Nginxがない！
どうやら、先ほどのアップデート取り消し失敗の時に、Nginxそのものが消失してしまったようです。
とりあえずNginxを再インストールして、なんとか「LIBERA TOKYO」をブラウザからアクセスできる状態にまでは戻しましたが、何かおかしいです。
タイムラインは表示されるのですが、画像が一切表示されなくなってしまいました。なお、試しにその状態で先程アップロードに失敗していた画像をアップロードしてみたところ、成功したような挙動は見せたのですが、結局画像が表示されないので、うまくいったのかどうかはわからずじまいです。
アップデート取り消しをしていないお一人様サーバ「Telmina One」では、もちろん画像が一切表示されない現象には陥っていません。そこで両者のnginx.confの内容を見比べて、「LIBERA TOKYO」側では先述のユーザ名の情報が初期状態の「user nginx」に戻っていたため、これを「Telmina One」側の設定に合わせました。
サーバ再起動後、「LIBERA TOKYO」側の画面表示も元通りとなり、とりあえず仮復旧は出来ました。しかし、この状態で先ほどアップロードに失敗した画像を挙げ直してみると、やっぱり500エラーが出て受け付けられません。nginx.confの設定がおかしかったときはアップロード自体には成功する挙動を見せたので、原因がNginx側にあるとみてほぼ間違いありません。
…しかし、そこから先の手がかりをまるでつかめません。
疑ったことその5：アップロード容量上限
闇雲に検索していたら、Nginxには「client_max_body_size」という設定があることがわかりました。
これはフォームからファイルをアップロードするときのサイズの上限を決める設定で、Nginxの初期状態ではどうやらこれが1MBytesに制限されているようです。
Mastodon側の設定である「/etc/nginx/conf.d/」配下の「mastodon.conf」を見ると、確かにこの設定項目があるにはあるのですが、ここに書かれていた内容は0。どうやらこれは初期値を踏襲するという意味らしいです。
なお、この値を10M（10MBytes）とかに変えてみても、状況は改善しませんでした。
疑ったことその6：作業フォルダのパーミッションと所有者
ここでようやく、自分はエラーログを確認することを始めます。
そもそも、Mastodonは今回のようなトラブルが起きてもどこのログを見てどの情報を分析してどう対処すれば良いのかが極めてわかりにくく、原因を追及するくらいなら再インストールしたほうが早いという決断を下すことがしょっちゅうあります（IT技術者の端くれとしてはあるまじき行為であることはわかっているが、原因を究明したところでRubyのRの字も知らない自分には対処不可能）。
またしても途方に暮れて闇雲に検索していてたまたま引っかかった記事に、Mastodonのログの見方に関する言及もありました。
一応この中で、今回の問題解決で自分がすべきことがドンピシャリで掲載されています。
一時ディレクトリアクセス権の問題 … 画像のアップロードができなくなり、画面上に500エラーが出る。 nginxのエラーログに「access denied」といったエラーが出る。エラーが出ているディレクトリの所有者を nginx.confで指定したユーザーにする
とはいえ、「一時ディレクトリ？それおいしい？」状態だった自分には、どこをどうすれば良いのかその時点ではわかりませんでした。
そこで、とりあえずはNginxのエラーログ（/var/log/nginx/error.log）を見てみたところ、確かにそれっぽいエラーが大量に記録されていました。
2021/10/02 14:44:27 [crit] 2679#2679: *3 open() "/var/lib/nginx/tmp/client_body/0000000001" failed (13: Permission denied), client: ***.***.***.***, server: libera.tokyo, request: "POST /api/v2/media HTTP/2.0", host: "libera.tokyo", referrer: "https://libera.tokyo/"
2021/10/02 14:50:53 [crit] 2679#2679: *3 open() "/var/lib/nginx/tmp/client_body/0000000002" failed (13: Permission denied), client: ***.***.***.***, server: libera.tokyo, request: "POST /api/v2/media HTTP/2.0", host: "libera.tokyo", referrer: "https://libera.tokyo/"
2021/10/02 14:52:56 [crit] 2679#2679: *3 open() "/var/lib/nginx/tmp/client_body/0000000003" failed (13: Permission denied), client: ***.***.***.***, server: libera.tokyo, request: "POST /api/v2/media HTTP/2.0", host: "libera.tokyo", referrer: "https://libera.tokyo/"
ここに出てくる「/var/lib/nginx/tmp/client_body/」というディレクトリの所有者は、紛れもなくnginx.confに設定されているユーザ名と同じでした。
ではパーミッションが悪いのかと思い、元の状態であった700から755や777等に変えても、ファイルアップロードに失敗する状況は改善されず。
しかし、ログに記録されている「/var/lib/nginx/tmp/client_body/」の親ディレクトリの所有者が異なっていました。
どうやら、/var/lib/nginxとその配下の所有者をすべてnginx.confに設定されているユーザに統一しなければならなかったようです。
そこで、冒頭でも述べた下記のコマンドを打ち込み、ようやく問題解決に至りました。
chown -P <nginx.conf で設定した所有者名> /var/lib/nginx
長かった～！
- 参考記事
それにしても、思いのほか問題解決に時間がかかったものの、最悪の事態だけは免れることが出来ましたし、いい勉強にもなりました。
が、出来ることならもう二度とこんな経験したくないです。
#2021年 #2021年10月 #2021年10月3日 #Mastodon #マストドン #Fediverse #分散型SNS #LiberaTokyo #業務連絡 #お知らせ #Nginx #Linux