hi! this morning I suddenly started getting “internal server error” messages when loading my akkoma instance. logs show
Loaded: loaded (/etc/systemd/system/akkoma.service; enabled; vendor preset: enabled)
Active: active (running) since Wed 2024-05-08 08:20:23 NZST; 28s ago
Main PID: 3019 (beam.smp)
Tasks: 74 (limit: 154353)
Memory: 292.3M
CPU: 4.572s
CGroup: /system.slice/akkoma.service
├─3019 /opt/akkoma/erts-13.1.4/bin/beam.smp -- -root /opt/akkoma -bindir /opt/akkoma/erts-13.1.4/bin -progname erl -- -home /opt/akkoma -- -no>
├─3056 erl_child_setup 1024
├─3123 /opt/akkoma/lib/fast_html-2.0.5/priv/fasthtml_worker
├─3124 /opt/akkoma/lib/fast_html-2.0.5/priv/fasthtml_worker
├─3125 sh -s disksup
├─3126 /opt/akkoma/lib/os_mon-2.8/priv/bin/memsup
├─3127 /opt/akkoma/lib/os_mon-2.8/priv/bin/cpu_sup
├─3130 /opt/akkoma/erts-13.1.4/bin/inet_gethost 4
├─3131 /opt/akkoma/erts-13.1.4/bin/inet_gethost 4
├─3146 /opt/akkoma/lib/majic-1.0.0/priv/libmagic_port
└─3147 /opt/akkoma/lib/majic-1.0.0/priv/libmagic_port
May 08 08:20:45 z133 pleroma[3019]: ]},
May 08 08:20:45 z133 pleroma[3019]: {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 1123]},
May 08 08:20:45 z133 pleroma[3019]: {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 1200]}
May 08 08:20:45 z133 pleroma[3019]: ]
May 08 08:20:45 z133 pleroma[3019]: 08:20:45.891 request_id=F81OZ87VsQJeLGkAAEOC [error] Internal server error: {:timeout, {GenServer, :call, [Pleroma.Stat>
May 08 08:20:45 z133 pleroma[3019]: 08:20:45.957 [error] #PID<0.4269.0> running Pleroma.Web.Endpoint (connection #PID<0.4268.0>, stream id 1) terminated
May 08 08:20:45 z133 pleroma[3019]: Server: fedi.lamer-ethos.site:80 (http)
May 08 08:20:45 z133 pleroma[3019]: Request: GET /main/all
May 08 08:20:45 z133 pleroma[3019]: ** (exit) exited in: GenServer.call(Pleroma.Stats, :get_state, 5000)
May 08 08:20:45 z133 pleroma[3019]: ** (EXIT) time out
if I go directly to the frontpage of the site it will load however it will not let me log in.
log output:
May 08 08:22:40 z133 pleroma[3019]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:913: Ecto.Adapters.SQL.raise_sql_call_error/1
May 08 08:22:40 z133 pleroma[3019]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:828: Ecto.Adapters.SQL.execute/6
May 08 08:22:40 z133 pleroma[3019]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:229: Ecto.Repo.Queryable.execute/4
May 08 08:22:40 z133 pleroma[3019]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
May 08 08:22:40 z133 pleroma[3019]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:73: Pleroma.Stats.calculate_stat_data/0
May 08 08:22:40 z133 pleroma[3019]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:121: Pleroma.Stats.handle_continue/2
May 08 08:22:40 z133 pleroma[3019]: (stdlib 4.2) gen_server.erl:1123: :gen_server.try_dispatch/4
May 08 08:22:40 z133 pleroma[3019]: (stdlib 4.2) gen_server.erl:865: :gen_server.loop/7
May 08 08:22:40 z133 pleroma[3019]: 08:22:40.797 [info] Postgrex.Protocol (#PID<0.3901.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.44>
May 08 08:22:44 z133 pleroma[3019]: 08:22:44.936 [info] Postgrex.Protocol (#PID<0.3905.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.45>
May 08 08:22:50 z133 pleroma[3019]: 08:22:50.027 request_id=F81OhbY-E5JpAXUAAFFC [error] Could not decode featured collection at fetch https://masto.ai/
any advice would be greatly appreciated, thanks.
take a look at your full log output; both the systemctls and log section in your post truncate the actual problem showing only lower parts of the stacktrace
Also please mention which version of Akkoma (release/develop git commit, OTP/source/docker) and PostgreSQL you’re using and check the postgresql server is actually running
here is log from “journalctl -u akkoma.service”
May 08 09:28:10 z133 pleroma[4667]: State: nil
May 08 09:28:10 z133 pleroma[4667]: Last message: {:continue, :calculate_stats}
May 08 09:28:10 z133 pleroma[4667]: (stdlib 4.2) gen_server.erl:865: :gen_server.loop/7
May 08 09:28:10 z133 pleroma[4667]: (stdlib 4.2) gen_server.erl:1123: :gen_server.try_dispatch/4
May 08 09:28:10 z133 pleroma[4667]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:121: Pleroma.Stats.handle_continue/2
May 08 09:28:10 z133 pleroma[4667]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:73: Pleroma.Stats.calculate_stat_data/0
May 08 09:28:10 z133 pleroma[4667]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
May 08 09:28:10 z133 pleroma[4667]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:229: Ecto.Repo.Queryable.execute/4
May 08 09:28:10 z133 pleroma[4667]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:828: Ecto.Adapters.SQL.execute/6
May 08 09:28:10 z133 pleroma[4667]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:913: Ecto.Adapters.SQL.raise_sql_call_error/1
May 08 09:28:10 z133 pleroma[4667]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or>
May 08 09:28:10 z133 pleroma[4667]: 09:28:10.292 [error] GenServer Pleroma.Stats terminating
May 08 09:28:10 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:656: DBConnection.parsed_prepare_execute/5
May 08 09:28:10 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:1527: DBConnection.run/6
May 08 09:28:10 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:1432: DBConnection.run_execute/5
May 08 09:28:10 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection/holder.ex:354: DBConnection.Holder.holder_apply/4
May 08 09:28:10 z133 pleroma[4667]: (postgrex 0.16.5) lib/postgrex/protocol.ex:2056: Postgrex.Protocol.bind_execute_close/4
May 08 09:28:10 z133 pleroma[4667]: (postgrex 0.16.5) lib/postgrex/protocol.ex:2201: Postgrex.Protocol.recv_bind/3
May 08 09:28:10 z133 pleroma[4667]: (postgrex 0.16.5) lib/postgrex/protocol.ex:3171: Postgrex.Protocol.msg_recv/4
May 08 09:28:10 z133 pleroma[4667]: :prim_inet.recv0/3
May 08 09:28:10 z133 pleroma[4667]: #PID<0.4624.0> was at location:
May 08 09:28:10 z133 pleroma[4667]: 09:28:10.286 [error] Postgrex.Protocol (#PID<0.3907.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.4>
May 08 09:28:09 z133 caddy[2261]: {"level":"error","ts":1715117289.7301528,"logger":"http.handlers.reverse_proxy","msg":"aborting with incomplete response">
May 08 09:28:06 z133 pleroma[4667]: 09:28:06.817 [info] Postgrex.Protocol (#PID<0.3910.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.46>
May 08 09:27:55 z133 pleroma[4667]: State: nil
May 08 09:27:55 z133 pleroma[4667]: Last message: {:continue, :calculate_stats}
May 08 09:27:55 z133 pleroma[4667]: (stdlib 4.2) gen_server.erl:865: :gen_server.loop/7
May 08 09:27:55 z133 pleroma[4667]: (stdlib 4.2) gen_server.erl:1123: :gen_server.try_dispatch/4
May 08 09:27:55 z133 pleroma[4667]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:121: Pleroma.Stats.handle_continue/2
May 08 09:27:55 z133 pleroma[4667]: (pleroma 3.9.3-0-g9d7c877) lib/pleroma/stats.ex:73: Pleroma.Stats.calculate_stat_data/0
May 08 09:27:55 z133 pleroma[4667]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
May 08 09:27:55 z133 pleroma[4667]: (ecto 3.9.5) lib/ecto/repo/queryable.ex:229: Ecto.Repo.Queryable.execute/4
May 08 09:27:55 z133 pleroma[4667]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:828: Ecto.Adapters.SQL.execute/6
May 08 09:27:55 z133 pleroma[4667]: (ecto_sql 3.9.2) lib/ecto/adapters/sql.ex:913: Ecto.Adapters.SQL.raise_sql_call_error/1
May 08 09:27:55 z133 pleroma[4667]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or>
May 08 09:27:55 z133 pleroma[4667]: 09:27:55.282 [error] GenServer Pleroma.Stats terminating
May 08 09:27:55 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:656: DBConnection.parsed_prepare_execute/5
May 08 09:27:55 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:1527: DBConnection.run/6
May 08 09:27:55 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection.ex:1432: DBConnection.run_execute/5
May 08 09:27:55 z133 pleroma[4667]: (db_connection 2.5.0) lib/db_connection/holder.ex:354: DBConnection.Holder.holder_apply/4
May 08 09:27:55 z133 pleroma[4667]: (postgrex 0.16.5) lib/postgrex/protocol.ex:2056: Postgrex.Protocol.bind_execute_close/4
this version of akkoma is from last year, was release with otp install. how to check exact version I am not sure.
postgresql is running version " postgres (PostgreSQL) 13.14 (Debian 13.14-0+deb11u1)".
the database service is running.
I do not know how to get a full log for akkoma, will post if instructions are provided.
thanks for the quick reply.
i think journalctl -u akkoma should already give you a full log (but you might need to scroll a bit with the keyboard)
This contains an info message but there’s not the typical startup info messages. The error indicates problems connecting to your database. Normally when there’s no connection at all though a different error should be shown before Akkoma even starts accepting any connections. Either there’s more missing log output, or it for some reason thinks the DB is online but the connection is not actually usable. (the local user count query it fails on shouldn’t be that expensive)
I can’t really say what’s wrong, but if you changed some postgres config or firewall settings recently (or not so recently but they only got applied recently with a restart), that might be the problem. You probably should also take a look at postgres logs.
If Postgres logs don’t reveal anything, try restarting postgres and then manually start akkoma in the foreground to make sure you actually get the full output; i.e. if you’re running Akkoma under the akkoma user, run: sudo -Hu akkoma /opt/akkoma/bin/pleroma start
You’re using Akkoma 3.9.3 (2023.05), once this issue is fixed i strongly recommend upgrading to an up-to-date release since you’re missing security fixes. Make sure to read release announcments of every release since, especially 3.12 (2024.03); some manual extra steps are needed this time.
there were no errors in the postgresql logs.
here is full output from that sudo command:
https://pastebin.com/raw/ebcPGdDf
I have not made any changes to either postgresql configuration or firewall settings though I did update my vps software (thru apt)
thanks again for helping me with this.
stats failing to calculate can indicate that a database is starting to hit the limits of what the hardware can reasonably manage - you might want to check your cache statistics on /phoenix/live_dashboard/ecto_stats to make sure they’re not unreasonably low or anything
The very first message indicates even before Akkoma actually properly started anything most of the system’s memory is already occupied (if you didn’t tweak the settings it’s 80%)
The thing is you’re already timing out on the very first stat query which just get’s all remote domains from the user table. Either you missed earlier timeouts on more expensive queries and you’re really hitting hardware CPU/IO limits, or considering memory is tight, PostgreSQL get’s OOM killed while running the query. (or early-oom, systemd-oom or a similar service acting before memory is actually full).
Either way, you’ll need to free up some resources on your machine. To get a better idea of what’s up maybe stop Akkoma, connect directly to the database with sudo -Hu akkoma psql -d akkoma -U akkoma (adjust names to what’s used in your config) and check how long the following takes to complete (or if it completes):
SELECT DISTINCT split_part(nickname, '@', 2) FROM users WHERE local = 'f';
If it’s near or more than 15s, you’re CPU/IO constraint or somethings up with your cache hit ratio and you can check what Floati suggested. If it’s significantly below 15s, OOM is probably more likely; try shutting down some other services to free up RAM.
this vps runs around 80% memory usage for akkoma and an owncast install.
somehow the server is running again, no idea why.
thanks for support I will now look at updating. that will likely result in me being back here attempting to get support!
thanks again.