はんドンクラブ 運営ブログ

Mastodonインスタンス「handon.club」の運営ブログです。コラムなど,Mastodonに関する一般的な記事も投稿予定です。

容量の大きな動画がアップロードできなかった問題が解決しました

ご報告いただいていたにも関わらず長らく解決できていなかった、容量の大きな動画がアップロードできなかった問題が解決しました。分からないことも多いのですが、原因と対策について説明します。

事象の概要

  • 発生日時: 2021年5月9日(推定)-2022年7月28日23:00頃
  • 事象の内容: 容量の大きな動画のアップロードに失敗する場合がある
    • 手元での再現試験とログの解析結果から、2つの失敗事例がありました。
      • 422エラーが表示される場合
      • 500エラーが表示される場合
    • 発生条件:
      • Webまたは/api/v2/mediaを使って非同期アップロードを行う3rdパーティークライアントからのアップロードであること
        • /api/v1/mediaではおそらく問題は発生していないと思いますが、自信はありません。
      • おおむね15MB以上の動画であること
  • 原因: オブジェクトストレージへのアップロード処理に失敗していたため。
    • 2つの事象毎に原因が異なるようでした。
      1. マルチパートアップロードに失敗している
      2. アップロード自体は成功しているが、何らかのタイムアウトにより失敗したと勘違いしている
    • 当初、1. だけが原因かと思ったのですが、どうも2. もたまに発生している場合があるようです。
  • 対処: マストドン側の設定変更。
    • 2つの事象毎に以下の対処を行いました。
      1. マルチパートアップロードを行う閾値を大幅に上げ、事実上マルチパートアップロードが行われないようにしました。
      2. S3関係のリードタイムアウトを延長しました。

原因

Web側の問題のときは Api::V2::MediaController がエラーを吐き、バックエンド処理(sidekiq)側の問題のときは PostProcessMediaWorker がエラーを吐いていました。当初、バックエンドの問題に引っ張られてApi::V2::MediaControllerがエラーを吐いているのだと思っていましたが、稀に違う場合があり、バックエンド側は正常終了しているのにもかかわらずWeb側が前述の問題と同じエラーを吐いているログも見つけました。

ただ、バックエンド側が明らかにアップロードに失敗しているログが一番多くありましたので、先にここを調査しました。

2022-07-28T13:05:08.717Z pid=18954 tid=h71ve class=PostProcessMediaWorker jid=○○○○○○○○○○○○○○○ ERROR: Processing media attachment ○○○○○○○○○○○○ failed with undefined method `split' for nil:NilClass
from /home/highemerly/mastodon/vendor/bundle/ruby/3.0.0/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/file_downloader.rb:127:in `block (3 levels) in thread_batches'
/home/highemerly/mastodon/vendor/bundle/ruby/3.0.0/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/file_downloader.rb:135:in `write': undefined method `split' for nil:NilClass (NoMethodError)
#<Thread:0x00007f3f816ef290 /home/highemerly/mastodon/vendor/bundle/ruby/3.0.0/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/file_downloader.rb:123 run> terminated with exception (report_on_exception is true):

調査の結果、このバックエンド側の根本的な問題は、オブジェクトストレージをWasabiに変えた際にマルチパートアップロード(大容量のファイルを複数のチャンクに分割してアップロードする方法)が上手くいっていないことが分かりました。本当は対応しているそうなのですが、少なくともpaperclip(mastodonがS3へのアップロード処理等で使っているgem)からは使えませんでした。

wasabi-support.zendesk.com

ぐぐったところ、オブジェクトストレージをGCPにしている場合にも同じ問題が発生しているそうで、こちらの投稿を参考にさせていただいて対処しました。具体的には、マルチパートアップロードを行う閾値を大きくする(=マルチパートアップロードが起こらないような閾値にする)という設定変更を行いました。

mstdn.anqou.net

一方、422でサムネイルが作られないというエラーは、実際にアップロードが成功しているのにも関わらずAPIの内部処理がタイムアウトしていることが分かりました。以下の問題が関係ありそうだと考え、リードタイムアウトも長めにとりました。

github.com

どちらもなんと .env ファイルへの記載だけで変更できるということで、以下のような設定をいれてみました。

S3_READ_TIMEOUT=20
S3_MULTIPART_THRESHOLD=52428801

現時点では両方を設定しています。しかし、リードタイムアウトの変更は本当に必要だったのか怪しいと考えており、余裕のあるときにA/Bテストを行ってもう少し原因を追跡する予定です。

その他

実はここ最近、バックエンド(sidekiq)サーバで、特定プロセスがファイルディスクリプタを食い潰してしまい、システムが不安定になるケースが散見されていました。特に、/etc/resolve.confが開けなくなり、外部サーバ宛の配信が失敗することが多かったです。この問題はsidekiqプロセス再起動によりファイルディスクリプタは返してもらえるので、当面は定期的なプロセス再起動でやり過ごしています。しかし、今回のアップロード処理失敗によりファイルディスクリプタを食い潰していたのかもしれないですね。

以前より5分おきにlsofコマンドで開いているファイル数を監視するスクリプトを回しているので、本当にこれが原因だったのか、少し様子を見てみようと思います。