にせねこメモ

はてなダイアリーがUTF-8じゃないので移ってきました。

Pleromaのホームタイムラインが500エラー返すようになってた

PostgreSQLの実行でタイムアウトしていたので、VACUUM ANALYZEを実行したら解決した。

問題

以前Pleromaのサーバを移行したが、

その後、多少問題はあったが普通に動いていた。

環境はPleroma 2.3.0で、ソースからインストールしたものである。


しかし、今日急に、SubwayTooterでホームタイムラインを取得しようとした(GET /api/v1/timelines/home)場合に、500 Internal Server Errorが返ってくるようになった。(ブラウザからは普通に見れていたのでよくわからない…)

さてどうしたものか。

調査

サーバーにログインし、

sudo journalctl -fu pleroma.service

実行する。するとpleromaのログが流れてくる。

ここでSubwayTooterでホームタイムラインを取得しようとすると、次のようなログがでてくる。時刻やrequest_idなど先頭部分は省いている。

[info] GET /api/v1/timelines/home
[error] Postgrex.Protocol (#PID<■■■>) disconnected: ** (DBConnection.ConnectionError) client #PID<■■■> timed out because it queued and checked out the connection for longer than 15000ms
#PID<■■■> was at location:
    :prim_inet.recv0/3
    (postgrex) lib/postgrex/protocol.ex:2838: Postgrex.Protocol.msg_recv/4
    (postgrex) lib/postgrex/protocol.ex:1880: Postgrex.Protocol.recv_bind/3
    (postgrex) lib/postgrex/protocol.ex:1735: Postgrex.Protocol.bind_execute_close/4
    (db_connection) lib/db_connection/holder.ex:316: DBConnection.Holder.holder_apply/4
    (db_connection) lib/db_connection.ex:1272: DBConnection.run_execute/5
    (db_connection) lib/db_connection.ex:1359: DBConnection.run/6
    (db_connection) lib/db_connection.ex:613: DBConnection.execute/4
[error] Internal server error: %DBConnection.ConnectionError{message: "tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)", reason: :error, severity: :error}
[info] Sent 500 in 15293ms
[error] #PID<■■■> running Pleroma.Web.Endpoint (connection #PID<■■■>, stream id 1) terminated
Server: nixeneko.info:80 (http)
Request: GET /api/v1/timelines/home?limit=80
** (exit) an exception was raised:
    ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)
        (ecto_sql) lib/ecto/adapters/sql.ex:593: Ecto.Adapters.SQL.raise_sql_call_error/1
        (ecto_sql) lib/ecto/adapters/sql.ex:526: Ecto.Adapters.SQL.execute/5
        (ecto) lib/ecto/repo/queryable.ex:192: Ecto.Repo.Queryable.execute/4
        (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3
        (pleroma) lib/pleroma/pagination.ex:40: Pleroma.Pagination.fetch_paginated/4
        (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:1172: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3
        (pleroma) lib/pleroma/web/mastodon_api/controllers/timeline_controller.ex:59: Pleroma.Web.MastodonAPI.TimelineController.home/2
        (pleroma) lib/pleroma/web/mastodon_api/controllers/timeline_controller.ex:5: Pleroma.Web.MastodonAPI.TimelineController.action/2

ここから、PostgreSQLで時間がかかっていることがわかる。

対策

検索してたら次の投稿を見つけた。
pleroma.gidikroon.eu

I think I remember that once after a migration I needed to do an ANALYZE to stop the timeouts from happening.

そのため、データベースのVACUUM ANALYZEを実行してみた。

VACUUM ANALYZEの実行

cd /opt/pleroma
sudo service pleroma stop
sudo -Hu pleroma MIX_ENV=prod mix pleroma.database vacuum analyze
sudo service pleroma start

参考: Database maintenance tasks - Pleroma Documentation

vacuum analyzeの直前にpg_dumpでバックアップをしている。pleromaはデータベース名、pleroma_database_backup.pgdumpは出力ファイル

sudo -Hu postgres pg_dump -d pleroma --format=custom -f pleroma_database_backup.pgdump

結果

すると、ホームタイムラインが復活した。
副作用として、うまく動かなくなっていたパブリックタイムラインとハッシュタグタイムラインが動くようになった。

データベースを移行した時とか、定期的にVACUUM ANALYZEを実行するといいようだ。