Can't upload files anymore using S3
Environment
- Installation type (OTP or From Source): container image (https://github.com/innereq/containers/blob/master/pleroma/Dockerfile)
- Pleroma version (could be found in the "Version" tab of settings in Pleroma-FE): 2.3.50-0-g745375bd-develop
- Elixir version (
elixir -v
for from source installations, N/A for OTP): OTP - Operating system: Fedora 32, Podman 2.2.1
- PostgreSQL version (
psql -V
): psql (PostgreSQL) 12.6
Bug description
Users of my server at https://sect.sunbutt.faith reported that uploading stopped working. It's true, uploading causes these cryptic errors:
19:35:58.433 [info] POST /api/v1/media
19:35:58.455 request_id=FnyRVJZtu_bRMUEAABIE [error] Internal server error: %CaseClauseError{term: {:EXIT, {:noproc, {:gen_server, :call, [#PID<0.6741.0>, {:checkout, {'s3.eu-central-1.wasabisys.com', 443, :hackney_ssl}, #PID<0.8030.0>, #Reference<0.1827926764.2013790210.6572>}, 5000]}}}}
19:35:58.455 request_id=FnyRVJZtu_bRMUEAABIE [info] Sent 500 in 22ms
19:35:58.456 [error] #PID<0.8030.0> running Pleroma.Web.Endpoint (connection #PID<0.8029.0>, stream id 1) terminated
Server: sect.sunbutt.faith:80 (http)
Request: POST /api/v1/media
** (exit) an exception was raised:
** (CaseClauseError) no case clause matching: {:EXIT, {:noproc, {:gen_server, :call, [#PID<0.6741.0>, {:checkout, {'s3.eu-central-1.wasabisys.com', 443, :hackney_ssl}, #PID<0.8030.0>, #Reference<0.1827926764.2013790210.6572>}, 5000]}}}
(hackney) /build/deps/hackney/src/hackney_pool.erl:72: :hackney_pool.checkout/4
(hackney) /build/deps/hackney/src/hackney_connect.erl:217: :hackney_connect.socket_from_pool/4
(hackney) /build/deps/hackney/src/hackney_connect.erl:47: :hackney_connect.connect/5
(hackney) /build/deps/hackney/src/hackney.erl:333: :hackney.request/5
(tesla) lib/tesla/adapter/hackney.ex:71: Tesla.Adapter.Hackney.request/5
(tesla) lib/tesla/adapter/hackney.ex:33: Tesla.Adapter.Hackney.call/2
(pleroma) lib/pleroma/http/ex_aws.ex:16: Pleroma.HTTP.ExAws.request/5
(ex_aws) lib/ex_aws/request.ex:42: ExAws.Request.request_and_retry/7
With enabled debug log level:
20:15:21.476 [info] POST /api/v1/media
20:15:21.476 request_id=FnyTesbHGfnkW48AACri [debug] POST /api/v1/media
20:15:21.484 request_id=FnyTesbHGfnkW48AACri [debug] Processing with Pleroma.Web.MastodonAPI.MediaController.create/2
Parameters: %{"file" => %Plug.Upload{content_type: "image/png", filename: "matrix-p2p.png", path: "/tmp/plug-1620/multipart-1620332121-106971859079583-3"}}
Pipelines: [:authenticated_api]
20:15:21.486 request_id=FnyTesbHGfnkW48AACri [debug] QUERY OK source="oauth_tokens" db=1.9ms idle=174.6ms
SELECT o0."id", o0."token", o0."refresh_token", o0."scopes", o0."valid_until", o0."user_id", o0."app_id", o0."inserted_at", o0."updated_at", u1."id", u1."bio", u1."raw_bio", u1."email", u1."name", u1."nickname", u1."password_hash", u1."keys", u1."public_key", u1."ap_id", u1."avatar", u1."local", u1."follower_address", u1."following_address", u1."featured_address", u1."tags", u1."last_refreshed_at", u1."last_digest_emailed_at", u1."banner", u1."background", u1."note_count", u1."follower_count", u1."following_count", u1."is_locked", u1."is_confirmed", u1."password_reset_pending", u1."is_approved", u1."registration_reason", u1."confirmation_token", u1."default_scope", u1."domain_blocks", u1."is_active", u1."no_rich_text", u1."ap_enabled", u1."is_moderator", u1."is_admin", u1."show_role", u1."mastofe_settings", u1."uri", u1."hide_followers_count", u1."hide_follows_count", u1."hide_followers", u1."hide_follows", u1."hide_favorites", u1."email_notifications", u1."mascot", u1."emoji", u1."pleroma_settings_store", u1."fields", u1."raw_fields", u1."is_discoverable", u1."invisible", u1."allow_following_move", u1."skip_thread_containment", u1."actor_type", u1."also_known_as", u1."inbox", u1."shared_inbox", u1."accepts_chat_messages", u1."last_active_at", u1."disclose_client", u1."pinned_objects", u1."notification_settings", u1."blocks", u1."mutes", u1."muted_reblogs", u1."muted_notifications", u1."subscribers", u1."multi_factor_authentication_settings", u1."inserted_at", u1."updated_at" FROM "oauth_tokens" AS o0 INNER JOIN "users" AS u1 ON u1."id" = o0."user_id" WHERE (o0."token" = $1) ["REDACTED JUST IN CASE"]
20:15:21.497 request_id=FnyTesbHGfnkW48AACri [error] Internal server error: %CaseClauseError{term: {:EXIT, {:noproc, {:gen_server, :call, [#PID<0.6741.0>, {:checkout, {'s3.eu-central-1.wasabisys.com', 443, :hackney_ssl}, #PID<0.8275.0>, #Reference<0.357438633.3093299203.8139>}, 5000]}}}}
20:15:21.497 request_id=FnyTesbHGfnkW48AACri [debug] Sent 500 in 21ms
20:15:21.497 request_id=FnyTesbHGfnkW48AACri [info] Sent 500 in 21ms
20:15:21.497 request_id=FnyTesbHGfnkW48AACri [debug] Converted error {:case_clause, {:EXIT, {:noproc, {:gen_server, :call, [#PID<0.6741.0>, {:checkout, {'s3.eu-central-1.wasabisys.com', 443, :hackney_ssl}, #PID<0.8275.0>, #Reference<0.357438633.3093299203.8139>}, 5000]}}}} to 500 response
20:15:21.499 [error] #PID<0.8275.0> running Pleroma.Web.Endpoint (connection #PID<0.8274.0>, stream id 1) terminated
Server: sect.sunbutt.faith:80 (http)
Request: POST /api/v1/media
** (exit) an exception was raised:
** (CaseClauseError) no case clause matching: {:EXIT, {:noproc, {:gen_server, :call, [#PID<0.6741.0>, {:checkout, {'s3.eu-central-1.wasabisys.com', 443, :hackney_ssl}, #PID<0.8275.0>, #Reference<0.357438633.3093299203.8139>}, 5000]}}}
(hackney) /build/deps/hackney/src/hackney_pool.erl:72: :hackney_pool.checkout/4
(hackney) /build/deps/hackney/src/hackney_connect.erl:217: :hackney_connect.socket_from_pool/4
(hackney) /build/deps/hackney/src/hackney_connect.erl:47: :hackney_connect.connect/5
(hackney) /build/deps/hackney/src/hackney.erl:333: :hackney.request/5
(tesla) lib/tesla/adapter/hackney.ex:71: Tesla.Adapter.Hackney.request/5
(tesla) lib/tesla/adapter/hackney.ex:33: Tesla.Adapter.Hackney.call/2
(pleroma) lib/pleroma/http/ex_aws.ex:16: Pleroma.HTTP.ExAws.request/5
(ex_aws) lib/ex_aws/request.ex:42: ExAws.Request.request_and_retry/7
But already uploaded attachments are reachable just fine. I use Wasabi S3 as main storage and BunnyCDN for caching. They are both working.
nginx log just in case:
10.88.0.1 - - [06/May/2021:20:12:38 +0000] "GET /api/v1/timelines/public?since_id=A6z17wykfpYONytcTw&local=true&only_media=false&with_muted=true&limit=20 HTTP/1.1" 200 2 "https://sect.sunbutt.faith/main/public" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0" "195.138.76.37"
2021/05/06 20:12:39 [warn] 31#31: *34 a client request body is buffered to a temporary file /var/cache/nginx/client_temp/0000000001, client: 10.88.0.1, server: sect.sunbutt.faith, request: "POST /api/v1/media HTTP/1.1", host: "sect.sunbutt.faith", referrer: "https://sect.sunbutt.faith/main/public"
10.88.0.1 - - [06/May/2021:20:12:39 +0000] "POST /api/v1/media HTTP/1.1" 500 45 "https://sect.sunbutt.faith/main/public" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0" "195.138.76.37"
Any ideas what can be wrong here?
Edited by Sasha Epona