Page MenuHomePhorge

Finally update my damn Pleroma server and unfuck what the updates fucked up
Closed, ResolvedPublic

Assigned To
Authored By
keithzg
Nov 20 2022, 7:35 PM
Tags
  • Restricted Project
  • Restricted Project
Referenced Files
F43198: image.png
Dec 29 2022, 11:15 AM
Subscribers

Description

Event Timeline

https://docs.pleroma.social/backend/administration/updating/ seems to be the official update instructions, I'm pretty sure I'm an "OTP installation" rather than Git, so I go:

# Download the new release
su pleroma -s $SHELL -lc "./bin/pleroma_ctl update"

# Migrate the database, you are advised to stop the instance before doing that
su pleroma -s $SHELL -lc "./bin/pleroma_ctl migrate"

Before I do that I should take backups, maybe both rsync and Digital Ocean's snapshot capability? Yeah lets go hog wild on #Backups (huh why isn't that a project on my personal Phabricator, oof that feels telling).


Okay sometime tonight or tomorrow I'm going to update my instance. If you never hear from @keithzg again, I clearly REALLY fucked up the upgrade somehow and maybe I just ragequit and I'll be at, say, @keithzg@misskey.keithzg.ca now or maybe the hex that makes any Node.js software blow up will have held strong and that attempt will fail too, maybe I'll remember I have a blog up at https://keithzg.ca and I'll say something there, oh I did open myself a bugtracker ticket at https://phabricator.keithzg.ca/T138 although I don't have that set public but if I do really fuck up the upgrade I probably will, okay later!
https://fediverse.keithzg.ca/notice/APoZbrGMfzbmK3X7BI

Kermode Reply to keithzg
@keithzg OK, just one suggestion, so I don't have to follow all that:
Don't fuck up!! :-)
https://fediverse.keithzg.ca/notice/APoZhimV7k0DkqMPAW


Okay, everything's backed up now, coarsely. I'm gonna update the Ubuntu install from 18.04 to 20.04 first, so things aren't too out of date and there's one less thing to potentially blame if the Pleroma update itself leads to a non-functional state.

Hmm I never have luck with PostgreSQL but maybe today's the day that changes...

Configuring postgresql-common
Obsolete major version 10                                                                                                                                                                                                                                             

The PostgreSQL version 10 is obsolete, but the server or client packages are still installed. Please install the latest packages (postgresql-12 and postgresql-client-12) and upgrade the existing  clusters with pg_upgradecluster (see manpage).                                                                 


Please be aware that the installation of postgresql-12 will automatically create a default cluster 12/main. If you want to upgrade the 10/main cluster, you need to remove the already existing 12 cluster (pg_dropcluster --stop 12 main, see manpage for details). 

The old server and client packages are no longer supported. After the existing clusters are upgraded, the postgresql-10 and postgresql-client-10 packages should be removed.   

Please see /usr/share/doc/postgresql-common/README.Debian.gz for details.

A surprise challenger has appeared, upgrade stalled out at

Setting up libblockdev-fs2:amd64 (2.23-2ubuntu3) ...                                                                                                                                                                                                                                                                                                                                                                                   
Setting up python3-josepy (1.2.0-2) ...
Setting up libxslt1.1:amd64 (1.1.34-4ubuntu0.20.04.1) ...
Setting up cloud-initramfs-dyn-netconf (0.45ubuntu2) ...
Setting up python3-keyring (18.0.1-2ubuntu1) ...
Setting up language-selector-common (0.204.2) ...
Installing new version of config file /etc/fonts/conf.avail/64-language-selector-prefer.conf ...
Setting up libfontconfig1:amd64 (2.13.1-2ubuntu3) ...
Setting up libxmlsec1:amd64 (1.2.28-2) ...
Setting up python3-lazr.restfulclient (0.14.2-2build1) ...
Setting up bind9-host (1:9.16.1-0ubuntu2.11) ...
Setting up thermald (1.9.1-1ubuntu0.6) ...
Created symlink /etc/systemd/system/dbus-org.freedesktop.thermald.service → /lib/systemd/system/thermald.service.
Created symlink /etc/systemd/system/multi-user.target.wants/thermald.service → /lib/systemd/system/thermald.service.
Setting up overlayroot (0.45ubuntu2) ...
Setting up cryptsetup-initramfs (2:2.2.2-3ubuntu2.4) ...
update-initramfs: deferring update (trigger activated)
update-initramfs: deferring update (trigger activated)
Setting up libkrb5-26-heimdal:amd64 (7.7.0+dfsg-1ubuntu1.1) ...
Setting up networkd-dispatcher (2.1-2~ubuntu20.04.3) ...
Setting up gsettings-desktop-schemas (3.36.0-1ubuntu1) ...
Setting up udisks2 (2.8.4-1ubuntu2) ...
Created symlink /etc/systemd/system/graphical.target.wants/udisks2.service → /lib/systemd/system/udisks2.service.
Setting up linux-image-generic (5.4.0.132.132) ...
Setting up cloud-init (22.3.4-0ubuntu1~20.04.1) ...
Installing new version of config file /etc/cloud/cloud.cfg ...

A quick Google search turns up https://www.digitalocean.com/community/questions/ubuntu-upgrade-from-18-04-to-20-04-hangs which concludes basically that a dpkg reconfigure, mounting in the recovery ISO boot, and manually installing GRUB solves it. Or disabling cloud-init and running the upgrade might work?

Just in case it's crunching away at something maybe I'll let it disconnect on its own before I go further.

Oddly enough it restarted just fine afterwards?

Now running the Pleroma upgrade itself...

22:37:16.696 [info] create index if not exists deliveries_user_id_object_id_index

22:37:16.699 [info] == Migrated 20190912065617 in 0.0s

22:37:16.702 [info] == Running 20190917100019 Pleroma.Repo.Migrations.UpdateOban.up/0 forward

22:37:16.733 [info] alter table public.oban_jobs

22:37:16.736 [info] create table if not exists public.oban_beats

22:37:16.741 [info] create index if not exists public.oban_beats_inserted_at_index

22:37:16.744 [info] execute "COMMENT ON TABLE public.oban_jobs IS '3'"

22:37:16.745 [info] execute "DROP FUNCTION IF EXISTS public.oban_wrap_id(value bigint)"

22:37:16.747 [info] execute "COMMENT ON TABLE public.oban_jobs IS '4'"

22:37:16.748 [info] == Migrated 20190917100019 in 0.0s

22:37:16.752 [info] == Running 20190929201536 Pleroma.Repo.Migrations.DropSubscriptionIfExists.up/0 forward

22:37:16.753 [info] drop index if exists subscription_notifications_user_id_index

22:37:16.754 [info] index "subscription_notifications_user_id_index" does not exist, skipping

22:37:16.754 [info] drop index if exists subscription_notifications_id_desc_nulls_last_index

22:37:16.758 [info] index "subscription_notifications_id_desc_nulls_last_index" does not exist, skipping

22:37:16.758 [info] drop table if exists subscription_notifications

22:37:16.759 [info] table "subscription_notifications" does not exist, skipping

22:37:16.759 [info] == Migrated 20190929201536 in 0.0s

22:37:16.762 [info] == Running 20191005165212 Pleroma.Repo.Migrations.AddUnreadConversationCountToUserInfo.up/0 forward

22:37:16.763 [info] execute "update users set info = jsonb_set(info, '{unread_conversation_count}', 0::varchar::jsonb, true) where local=true\n"

22:37:16.776 [info] == Migrated 20191005165212 in 0.0s

22:37:16.783 [info] == Running 20191007073319 Pleroma.Repo.Migrations.CreateFollowingRelationships.change/0 forward

22:37:16.783 [info] create table if not exists following_relationships

22:37:16.790 [info] create index if not exists following_relationships_follower_id_index

22:37:16.793 [info] create index if not exists following_relationships_follower_id_following_id_index

22:37:16.796 [info] execute "CREATE OR REPLACE FUNCTION thread_visibility(actor varchar, activity_id varchar) RETURNS boolean AS $$\nDECLARE\n  public varchar := 'https://www.w3.org/ns/activitystreams#Public';\n  child objects%ROWTYPE;\n  activity activities%ROWTYPE;\n  author_fa varchar;\n  valid_recipients varchar[];\n  actor_user_following varchar[];\nBEGIN\n  --- Fetch actor following\n  SELECT array_agg(following.follower_address) INTO actor_user_following FROM following_relationships\n  JOIN users ON users.id = following_relationships.follower_id\n  JOIN users AS following ON following.id = following_relationships.following_id\n  WHERE users.ap_id = actor;\n\n  --- Fetch our initial activity.\n  SELECT * INTO activity FROM activities WHERE activities.data->>'id' = activity_id;\n\n  LOOP\n    --- Ensure that we have an activity before continuing.\n    --- If we don't, the thread is not satisfiable.\n    IF activity IS NULL THEN\n      RETURN false;\n    END IF;\n\n    --- We only care about Create activities.\n    IF activity.data->>'type' != 'Create' THEN\n      RETURN true;\n    END IF;\n\n    --- Normalize the child object into child.\n    SELECT * INTO child FROM objects\n    INNER JOIN activities ON COALESCE(activities.data->'object'->>'id', activities.data->>'object') = objects.data->>'id'\n    WHERE COALESCE(activity.data->'object'->>'id', activity.data->>'object') = objects.data->>'id';\n\n    --- Fetch the author's AS2 following collection.\n    SELECT COALESCE(users.follower_address, '') INTO author_fa FROM users WHERE users.ap_id = activity.actor;\n\n    --- Prepare valid recipients array.\n    valid_recipients := ARRAY[actor, public];\n    IF ARRAY[author_fa] && actor_user_following THEN\n      valid_recipients := valid_recipients || author_fa;\n    END IF;\n\n    --- Check visibility.\n    IF NOT valid_recipients && activity.recipients THEN\n      --- activity not visible, break out of the loop\n      RETURN false;\n    END IF;\n\n    --- If there's a parent, load it and do this all over again.\n    IF (child.data->'inReplyTo' IS NOT NULL) AND (child.data->'inReplyTo' != 'null'::jsonb) THEN\n      SELECT * INTO activity FROM activities\n      INNER JOIN objects ON COALESCE(activities.data->'object'->>'id', activities.data->>'object') = objects.data->>'id'\n      WHERE child.data->>'inReplyTo' = objects.data->>'id';\n    ELSE\n      RETURN true;\n    END IF;\n  END LOOP;\nEND;\n$$ LANGUAGE plpgsql IMMUTABLE;\n"

22:37:16.799 [info] == Migrated 20191007073319 in 0.0s

22:37:16.802 [info] == Running 20191008132217 Pleroma.Repo.Migrations.MigrateFollowingRelationships.change/0 forward

22:37:16.803 [info] execute "INSERT INTO following_relationships (follower_id, following_id, state, inserted_at, updated_at)\nSELECT\n    relations.follower_id,\n    following.id,\n    'accept',\n    now(),\n    now()\nFROM (\n    SELECT\n        users.id AS follower_id,\n        unnest(users.following) AS following_ap_id\n    FROM\n        users\n    WHERE\n        users.following != '{}'\n        AND users.local = false OR users.local = true AND users.email IS NOT NULL -- Exclude `internal/fetch` and `relay`\n) AS relations\n    JOIN users AS \"following\" ON \"following\".follower_address = relations.following_ap_id\n\n    WHERE relations.follower_id != following.id\nON CONFLICT DO NOTHING\n"

22:37:16.948 [info] execute "INSERT INTO\n    following_relationships (\n        follower_id,\n        following_id,\n        state,\n        inserted_at,\n        updated_at\n    )\nSELECT\n    followers.id,\n    following.id,\n    activities.data ->> 'state',\n    (activities.data ->> 'published') :: timestamp,\n    now()\nFROM\n    activities\n    JOIN users AS followers ON (activities.actor = followers.ap_id)\n    JOIN users AS following ON (activities.data ->> 'object' = following.ap_id)\nWHERE\n    activities.data ->> 'type' = 'Follow'\n    AND activities.data ->> 'state' IN ('accept', 'pending', 'reject')\nORDER BY activities.updated_at DESC\nON CONFLICT DO NOTHING\n"

22:37:17.156 [info] == Migrated 20191008132217 in 0.3s

22:37:17.162 [info] == Running 20191008132427 Pleroma.Repo.Migrations.DropUsersFollowing.change/0 forward

22:37:17.163 [info] drop index users_following_index

22:37:17.169 [info] alter table users

22:37:17.175 [info] == Migrated 20191008132427 in 0.0s

22:37:17.179 [info] == Running 20191009154606 Pleroma.Repo.Migrations.AddUsersInfoColumns.change/0 forward

22:37:17.180 [info] alter table users
^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OA^[OB^[OB^[OB^[OB^[OB^[OB^[OB^[OB^[OB^[OB^[OB^[OB
22:37:33.287 [info] == Migrated 20191009154606 in 16.1s

22:37:33.448 [info] == Running 20191009154608 Pleroma.Repo.Migrations.CopyUsersInfoFieldsToUsers.change/0 forward

22:37:33.453 [info] execute "update users set banner = case when info->>'banner' IS NULL then null else info->'banner' end, background = case when info->>'background' IS NULL then null else info->'background' end, source_data = case when info->>'source_data' IS NULL then null else info->'source_data' end, note_count = (info->>'note_count')::int, follower_count = (info->>'follower_count')::int, following_count = (info->>'following_count')::int, locked = coalesce((info->>'locked')::boolean, false), confirmation_pending = coalesce((info->>'confirmation_pending')::boolean, false), password_reset_pending = coalesce((info->>'password_reset_pending')::boolean, false), confirmation_token = info->>'confirmation_token', default_scope = info->>'default_scope', blocks = ARRAY(SELECT jsonb_array_elements_text(case when info->>'blocks' IS NULL then null else info->'blocks' end)), domain_blocks = ARRAY(SELECT jsonb_array_elements_text(case when info->>'domain_blocks' IS NULL then null else info->'domain_blocks' end)), mutes = ARRAY(SELECT jsonb_array_elements_text(case when info->>'mutes' IS NULL then null else info->'mutes' end)), muted_reblogs = ARRAY(SELECT jsonb_array_elements_text(case when info->>'muted_reblogs' IS NULL then null else info->'muted_reblogs' end)), muted_notifications = ARRAY(SELECT jsonb_array_elements_text(case when info->>'muted_notifications' IS NULL then null else info->'muted_notifications' end)), subscribers = ARRAY(SELECT jsonb_array_elements_text(case when info->>'subscribers' IS NULL then null else info->'subscribers' end)), deactivated = coalesce((info->>'deactivated')::boolean, false), no_rich_text = coalesce((info->>'no_rich_text')::boolean, false), ap_enabled = coalesce((info->>'ap_enabled')::boolean, false), is_moderator = coalesce((info->>'is_moderator')::boolean, false), is_admin = coalesce((info->>'is_admin')::boolean, false), show_role = coalesce((info->>'show_role')::boolean, false), settings = case when info->>'settings' IS NULL then null else info->'settings' end, magic_key = info->>'magic_key', uri = info->>'uri', hide_followers_count = coalesce((info->>'hide_followers_count')::boolean, false), hide_follows_count = coalesce((info->>'hide_follows_count')::boolean, false), hide_followers = coalesce((info->>'hide_followers')::boolean, false), hide_follows = coalesce((info->>'hide_follows')::boolean, false), hide_favorites = coalesce((info->>'hide_favorites')::boolean, false), unread_conversation_count = (info->>'unread_conversation_count')::int, pinned_activities = ARRAY(SELECT jsonb_array_elements_text(case when info->>'pinned_activities' IS NULL then null else info->'pinned_activities' end)), email_notifications = case when info->>'email_notifications' IS NULL then null else info->'email_notifications' end, mascot = case when info->>'mascot' IS NULL then null else info->'mascot' end, emoji = coalesce(case when info->>'emoji' IS NULL then null else info->'emoji' end, '[]'::jsonb), pleroma_settings_store = case when info->>'pleroma_settings_store' IS NULL then null else info->'pleroma_settings_store' end, fields = coalesce(case when info->>'fields' IS NULL then null else info->'fields' end, '[]'::jsonb), raw_fields = coalesce(case when info->>'raw_fields' IS NULL then null else info->'raw_fields' end, '[]'::jsonb), discoverable = coalesce((info->>'discoverable')::boolean, false), invisible = coalesce((info->>'invisible')::boolean, false), skip_thread_containment = coalesce((info->>'skip_thread_containment')::boolean, false), notification_settings = case when info->>'notification_settings' IS NULL then null else info->'notification_settings' end"
keithzg changed the task status from Open to Waiting.Nov 21 2022, 3:52 PM

We've reached February of last year:

22:48:40.229 [info] execute "\nupdate users set featured_address = concat(ap_id, '/collections/featured') where local = true and featured_address is null;\n\n"

22:48:40.278 [info] == Migrated 20210203141144 in 3.4s

22:48:40.286 [info] == Running 20210205145000 Pleroma.Repo.Migrations.MovePinnedActivitiesIntoPinnedObjects.up/0 forward

22:51:57.826 [info] == Migrated 20210205145000 in 197.5s

22:51:57.846 [info] == Running 20210206045221 Pleroma.Repo.Migrations.RemovePinnedActivitiesFromUsers.up/0 forward

22:51:57.847 [info] alter table users

22:51:58.894 [info] == Migrated 20210206045221 in 1.0s

22:51:58.901 [info] == Running 20210218223811 Pleroma.Repo.Migrations.AddDiscloseClientToUsers.change/0 forward
keithzg changed the visibility from "All Users" to "Public (No Login Required)".Nov 21 2022, 3:52 PM

Or, wait, that was it?

22:48:32.248 [info] == Migrated 20210113225652 in 0.0s

22:48:32.252 [info] == Running 20210115205649 Pleroma.Repo.Migrations.UpgradeObanJobsToV9.up/0 forward

22:48:32.306 [info] alter table public.oban_jobs

22:48:32.335 [info] execute "DO $$\nDECLARE\n  version int;\n  already bool;\nBEGIN\n  SELECT current_setting('server_version_num')::int INTO version;\n  SELECT '{cancelled}' <@ enum_range(NULL::public.oban_job_state)::text[] INTO already;\n\n  IF already THEN\n    RETURN;\n  ELSIF version >= 120000 THEN\n    ALTER TYPE public.oban_job_state ADD VALUE IF NOT EXISTS 'cancelled';\n  ELSE\n    ALTER TYPE public.oban_job_state RENAME TO _oban_job_state;\n\n    CREATE TYPE public.oban_job_state AS ENUM (\n      'available',\n      'scheduled',\n      'executing',\n      'retryable',\n      'completed',\n      'discarded',\n      'cancelled'\n    );\n\n    ALTER TABLE public.oban_jobs RENAME column state TO _state;\n    ALTER TABLE public.oban_jobs ADD state public.oban_job_state NOT NULL default 'available';\n\n    UPDATE public.oban_jobs SET state = _state::text::public.oban_job_state;\n\n    ALTER TABLE public.oban_jobs DROP column _state;\n    DROP TYPE public._oban_job_state;\n  END IF;\nEND$$;\n"

22:48:32.367 [info] create index if not exists public.oban_jobs_queue_state_priority_scheduled_at_id_index

22:48:32.371 [info] execute "COMMENT ON TABLE public.oban_jobs IS '9'"

22:48:32.371 [info] == Migrated 20210115205649 in 0.1s

22:48:32.379 [info] == Running 20210121080964 Pleroma.Repo.Migrations.AddDefaultTextSearchConfig.change/0 forward

22:48:32.379 [info] execute "DO $$\n    BEGIN\n    execute 'ALTER DATABASE \"'||current_database()||'\" SET default_text_search_config = ''english'' ';\n    END\n    $$;"

22:48:32.389 [info] == Migrated 20210121080964 in 0.0s

22:48:32.393 [info] == Running 20210122151424 Pleroma.Repo.Migrations.AddLastActiveAtToUsers.change/0 forward

22:48:32.394 [info] alter table users

22:48:33.398 [info] create index if not exists users_last_active_at_index

22:48:36.772 [info] == Migrated 20210122151424 in 4.3s

22:48:36.793 [info] == Running 20210128092834 Pleroma.Repo.Migrations.RemoveDuplicatesFromActivityExpirationQueue.up/0 forward

22:48:36.813 [info] == Migrated 20210128092834 in 0.0s

22:48:36.820 [info] == Running 20210202110641 Pleroma.Repo.Migrations.AddPinnedObjectsToUsers.change/0 forward

22:48:36.821 [info] alter table users

22:48:36.824 [info] == Migrated 20210202110641 in 0.0s

22:48:36.829 [info] == Running 20210203141144 Pleroma.Repo.Migrations.AddFeaturedAddressToUsers.up/0 forward

22:48:36.832 [info] alter table users

22:48:36.835 [info] create index users_featured_address_index

22:48:40.229 [info] execute "\nupdate users set featured_address = concat(ap_id, '/collections/featured') where local = true and featured_address is null;\n\n"

22:48:40.278 [info] == Migrated 20210203141144 in 3.4s

22:48:40.286 [info] == Running 20210205145000 Pleroma.Repo.Migrations.MovePinnedActivitiesIntoPinnedObjects.up/0 forward

22:51:57.826 [info] == Migrated 20210205145000 in 197.5s

22:51:57.846 [info] == Running 20210206045221 Pleroma.Repo.Migrations.RemovePinnedActivitiesFromUsers.up/0 forward

22:51:57.847 [info] alter table users

22:51:58.894 [info] == Migrated 20210206045221 in 1.0s

22:51:58.901 [info] == Running 20210218223811 Pleroma.Repo.Migrations.AddDiscloseClientToUsers.change/0 forward

22:51:58.902 [info] alter table users

22:52:14.833 [info] == Migrated 20210218223811 in 15.9s

22:52:14.943 [info] == Running 20210222183840 Pleroma.Repo.Migrations.RemoveHashtagsObjectsDuplicateIndex.up/0 forward

22:52:14.948 [info] drop index if exists hashtags_objects_hashtag_id_object_id_index

22:52:14.951 [info] index "hashtags_objects_hashtag_id_object_id_index" does not exist, skipping

22:52:14.951 [info] == Migrated 20210222183840 in 0.0s

22:52:14.956 [info] == Running 20210222184616 Pleroma.Repo.Migrations.ChangeHashtagsNameToText.up/0 forward

22:52:14.957 [info] alter table hashtags

22:52:14.971 [info] == Migrated 20210222184616 in 0.0s

22:52:14.977 [info] == Running 20210401143153 Pleroma.Repo.Migrations.UserNotificationSettingsFix.up/0 forward

22:52:14.978 [info] execute "UPDATE users\n    SET \n      notification_settings = '{\"followers\": true, \"follows\": true, \"non_follows\": true, \"non_followers\": true}'::jsonb WHERE notification_settings IS NULL\n"

22:52:15.523 [info] execute "ALTER TABLE users\n    ALTER COLUMN notification_settings SET NOT NULL"

22:52:15.613 [info] == Migrated 20210401143153 in 0.6s

22:52:15.620 [info] == Running 20210420204354 Pleroma.Repo.Migrations.DeleteHashtagsObjectsCascade.up/0 forward

22:52:15.621 [info] execute "ALTER TABLE hashtags_objects DROP CONSTRAINT hashtags_objects_object_id_fkey"

22:52:15.629 [info] alter table hashtags_objects

22:52:15.643 [info] == Migrated 20210420204354 in 0.0s

Okay, maybe it'll all just work now, but be newer?

{"errors":{"detail":"Internal server error"}}

lol okay, well

Service thinks things are fine?

● pleroma.service - Pleroma social network
     Loaded: loaded (/etc/systemd/system/pleroma.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2022-11-21 22:54:51 UTC; 36s ago
   Main PID: 898 (beam.smp)
      Tasks: 25 (limit: 1066)
     Memory: 199.1M
     CGroup: /system.slice/pleroma.service
             ├─ 898 /opt/pleroma/erts-10.7.2.18/bin/beam.smp -- -root /opt/pleroma -progname erl -- -home /opt/pleroma -- -noshell -s elixir start_cli -mode embedded -setcookie DEFIM7M3ZQNSRB5AGUT5Y437SRKORNIG7O7DNAPINZXHVZCNDKIA==== -name pleroma@127.0.0.1 -config /opt/pleroma/tmp/pleroma-2.4.4-20221121225451-f0db.runtime -boot /opt/pleroma/releases/2.4.4/start -boot_var RELEASE_LIB /opt/pleroma/lib -- -extra --no-halt
             ├─ 933 /opt/pleroma/erts-10.7.2.18/bin/epmd -daemon
             ├─ 937 erl_child_setup 1024
             ├─1084 /opt/pleroma/lib/fast_html-2.0.4/priv/fasthtml_worker
             ├─1085 inet_gethost 4
             ├─1086 inet_gethost 4
             ├─1101 /opt/pleroma/lib/majic-1.0.0/priv/libmagic_port
             └─1102 /opt/pleroma/lib/majic-1.0.0/priv/libmagic_port

Nov 21 22:55:25 fediverse pleroma[898]: 22:55:25.142 [info] Running Pleroma.Web.Endpoint with cowboy 2.9.0 at 127.0.0.1:4000 (http)
Nov 21 22:55:25 fediverse pleroma[898]: 22:55:25.147 [info] Access Pleroma.Web.Endpoint at https://fediverse.keithzg.ca
Nov 21 22:55:25 fediverse pleroma[898]: 22:55:25.155 [info] Gopher server disabled
Nov 21 22:55:25 fediverse pleroma[898]: 22:55:25.199 [info] Transferring embedded hashtags to `hashtags` (from oid: 0)...
Nov 21 22:55:26 fediverse pleroma[898]: 22:55:26.440 [info] tzdata release in place is from a file last modified Wed, 21 Oct 2020 18:40:20 GMT. Release file on server was last modified Sat, 29 Oct 2022 01:50:44 GMT.
Nov 21 22:55:28 fediverse pleroma[898]: 22:55:28.101 [info] POST /inbox
Nov 21 22:55:28 fediverse pleroma[898]: 22:55:28.331 [info] POST /inbox
Nov 21 22:55:28 fediverse pleroma[898]: 22:55:28.439 [info] POST /inbox
Nov 21 22:55:28 fediverse pleroma[898]: 22:55:28.501 request_id=Fym7h7ZKsMPh0usAABCB [info] Sent 200 in 61ms
Nov 21 22:55:28 fediverse pleroma[898]: 22:55:28.832 request_id=Fym7h6HuV6s1sR8AABAx [info] Sent 200 in 731ms

Nginx disagrees:

502 Bad Gateway
nginx/1.18.0 (Ubuntu)

Nginx fucks me again . . .

Had to use the pleroma.nginx config shipped with the latest version and port over my few domain-specific options into it, but now it seems fine! I'm on 2.4.4, which according to https://pleroma.social/announcements/ seems to be the latest stable release, done 2022-05-08. Okay! Maybe I'll upgrade the server to 22.04 sometime but lets just leave well enough alone for now.

Opening this up again because I keep getting timeouts and random loading errors on 2.4.5 so I'm gonna upgrade to 2.5.0 and hope that fixes things.

Wait why is snapd using some godawful amount of CPU, honestly why is snapd even running is that how I have Elixr running or something?! The two hogs seems to be snapd and kswapd0, and I can't help but suspect the former is sprawling with its containerized nonsense and triggering the need of the latter, though that could easily be my anti-container bias showing.

keithzg triaged this task as Unbreak Now! priority.Dec 28 2022, 4:58 AM

Ah, hmm, I'll actually have to upgrade to 22.04 after all, at https://git.pleroma.social/pleroma/pleroma/-/releases or more specificaly https://git.pleroma.social/pleroma/pleroma/-/releases/v2.5.0 it says

Breaking: Elixir >=1.11 is now required (was >= 1.9)

and apt show elixir returns

1.9.1.dfsg-1.3

meanwhile according to https://packages.ubuntu.com/search?keywords=elixir 22.04 has 1.12. Okay, do-release-upgrade time . . .

Majority of downtime so far just taking the snapshot before upgrading Pleroma (I didn't before upgrading the OS lol).

Alrighty, got the pleroma and nginx (just because I like shutting that fucker down) services stopped and I'm running the database upgrade from https://docs.pleroma.social/backend/administration/updating/#for-otp-installations now . . .

wait nevermind it's done already, guess my extreme upgrade last time gave me the wrong impression about how long it'd take haha

Everything seems fine so far? Closing this issue again, but warily . . .

Haven't seen it go as bad as that again, but I'm still getting the

Error fetching timeline: Unexpected token '<', "<html> <h"... is not valid JSON

red popups.

/opt/pleroma/erts-11.2.2.17/bin/beam.smp seems to be just using max CPU a lot but otherwise I'm not seeing the obvious performance issues with kswapd0 chugging away that I was seeing before (which my only semi-expert eyes think of as some kind of memory leak or at least otherwise a lack of sufficient memory). So maybe those two symptoms are unrelated problems.

lol wait spoke too soon, bad gateway again.

Current diff between my nginx service file and the shipping default template is, other than the standard site-specific fields where I'm just saying hostname and cert location stuff:


83,95d82
< 
<     # Uncomment this if you want notice compatibility routes for frontends like Soapbox.
<     # location ~ ^/@[^/]+/([^/]+)$ {
<     #     proxy_pass http://phoenix/notice/$1;
<     # }
<     #
<     # location ~ ^/@[^/]+/posts/([^/]+)$ {
<     #     proxy_pass http://phoenix/notice/$1;
<     # }
<     #
<     # location ~ ^/[^/]+/status/([^/]+)$ {
<     #     proxy_pass http://phoenix/notice/$1;
<     # }

Soapbox is the frontend by the TERF-y guy though, right? So that shouldn't really be necessary in any way.

Tried restarting both the Pleroma and Nginx services and I'm still getting bad gateway, arghh . . .

Rebooting the entire system worked, which . . . oof. I don't like that one bit.

Keeps dying; checking the Pleroma service log via journalctl gives me

Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4995.
Jan 03 02:01:57 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Consumed 7.018s CPU time.
Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:01:57 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:01:57 fediverse systemd[1]: Started Pleroma social network.
Jan 03 02:02:03 fediverse pleroma[307619]: 02:02:03.315 [info]     :alarm_handler: {:set, {:system_memory_high_watermark, []}}
Jan 03 02:02:03 fediverse pleroma[307619]: 02:02:03.476 [info] Function passed as a handler with ID "pleroma-logger" is local function.
Jan 03 02:02:03 fediverse pleroma[307619]: This mean that it is either anonymous function or capture of function without module specified. That may cause performance penalty when calling such handler. For more details see note in `telemetry:attach/4` documentation.
Jan 03 02:02:03 fediverse pleroma[307619]: https://hexdocs.pm/telemetry/telemetry.html#attach-4
Jan 03 02:02:04 fediverse pleroma[307619]: 02:02:04.600 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:04 fediverse pleroma[307619]: 02:02:04.600 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.596 [error] Could not create schema migrations table. This error usually happens due to the following:
Jan 03 02:02:06 fediverse pleroma[307619]:   * The database does not exist
Jan 03 02:02:06 fediverse pleroma[307619]:   * The "schema_migrations" table, which Ecto uses for managing
Jan 03 02:02:06 fediverse pleroma[307619]:     migrations, was defined by another library
Jan 03 02:02:06 fediverse pleroma[307619]:   * There is a deadlock while migrating (such as using concurrent
Jan 03 02:02:06 fediverse pleroma[307619]:     indexes with a migration_lock)
Jan 03 02:02:06 fediverse pleroma[307619]: To fix the first issue, run "mix ecto.create".
Jan 03 02:02:06 fediverse pleroma[307619]: To address the second, you can run "mix ecto.drop" followed by
Jan 03 02:02:06 fediverse pleroma[307619]: "mix ecto.create". Alternatively you may configure Ecto to use
Jan 03 02:02:06 fediverse pleroma[307619]: another table and/or repository for managing migrations:
Jan 03 02:02:06 fediverse pleroma[307619]:     config :pleroma, Pleroma.Repo,
Jan 03 02:02:06 fediverse pleroma[307619]:       migration_source: "some_other_table_for_schema_migrations",
Jan 03 02:02:06 fediverse pleroma[307619]:       migration_repo: AnotherRepoForSchemaMigrations
Jan 03 02:02:06 fediverse pleroma[307619]: The full error report is shown below.
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.602 [info] Application pleroma exited: exited in: Pleroma.Application.start(:normal, [])
Jan 03 02:02:06 fediverse pleroma[307619]:     ** (EXIT) an exception was raised:
Jan 03 02:02:06 fediverse pleroma[307619]:         ** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 2000ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:
Jan 03 02:02:06 fediverse pleroma[307619]:   1. Ensuring your database is available and that you can connect to it
Jan 03 02:02:06 fediverse pleroma[307619]:   2. Tracking down slow queries and making sure they are running fast enough
Jan 03 02:02:06 fediverse pleroma[307619]:   3. Increasing the pool_size (although this increases resource consumption)
Jan 03 02:02:06 fediverse pleroma[307619]:   4. Allowing requests to wait longer by increasing :queue_target and :queue_interval
Jan 03 02:02:06 fediverse pleroma[307619]: See DBConnection.start_link/2 for more information
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:905: Ecto.Adapters.SQL.raise_sql_call_error/1
Jan 03 02:02:06 fediverse pleroma[307619]:             (elixir 1.11.4) lib/enum.ex:1411: Enum."-map/2-lists^map/1-0-"/2
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:997: Ecto.Adapters.SQL.execute_ddl/4
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:672: Ecto.Migrator.verbose_schema_migration/3
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:486: Ecto.Migrator.lock_for_migrations/4
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:444: Ecto.Migrator.migrations/3
Jan 03 02:02:06 fediverse pleroma[307619]:             (pleroma 2.5.0) lib/pleroma/application_requirements.ex:84: anonymous fn/1 in Pleroma.ApplicationRequirements.check_migrations_applied!/1
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:146: Ecto.Migrator.with_repo/3
Jan 03 02:02:06 fediverse pleroma[307672]: [os_mon] memory supervisor port (memsup): Erlang has closed
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.629 [info]     :alarm_handler: {:clear, :system_memory_high_watermark}
Jan 03 02:02:06 fediverse pleroma[307673]: [os_mon] cpu supervisor port (cpu_sup): Erlang has closed
Jan 03 02:02:08 fediverse pleroma[307619]: {"Kernel pid terminated",application_controller,"{application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Elixir.DBConnection.ConnectionError',message => <<\"connection not available and request was dropped from queue after 2000ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (although this increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n\">>,reason => queue_timeout,severity => error},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,\"lib/ecto/adapters/sql.ex\"},{line,905}]},{'Elixir.Enum','-map/2-lists^map/1-0-',2,[{file,\"lib/enum.ex\"},{line,1411}]},{'Elixir.Ecto.Adapters.SQL',execute_ddl,4,[{file,\"lib/ecto/adapters/sql.ex\"},{line,997}]},{'Elixir.Ecto.Migrator',verbose_schema_migration,3,[{file,\"lib/ecto/migrator.ex\"},{line,672}]},{'Elixir.Ecto.Migrator',lock_for_migrations,4,[{file,\"lib/ecto/migrator.ex\"},{line,486}]},{'Elixir.Ecto.Migrator',migrations,3,[{file,\"lib/ecto/migrator.ex\"},{line,444}]},{'Elixir.Pleroma.ApplicationRequirements','-check_migrations_applied!/1-fun-2-',1,[{file,\"lib/pleroma/application_requirements.ex\"},{line,84}]},{'Elixir.Ecto.Migrator',with_repo,3,[{file,\"lib/ecto/migrator.ex\"},{line,146}]}]}}}}}"}
Jan 03 02:02:08 fediverse pleroma[307619]: Kernel pid terminated (application_controller) ({application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Eli
Jan 03 02:02:08 fediverse pleroma[307619]: 
Jan 03 02:02:08 fediverse pleroma[307619]: Crash dump is being written to: erl_crash.dump...done
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Main process exited, code=exited, status=1/FAILURE
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Failed with result 'exit-code'.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Unit process 868 (epmd) remains running after unit stopped.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Consumed 7.269s CPU time.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4996.
Jan 03 02:02:08 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Consumed 7.269s CPU time.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:02:08 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:02:08 fediverse systemd[1]: Started Pleroma social network.
Jan 03 02:02:14 fediverse pleroma[307681]: 02:02:14.368 [info]     :alarm_handler: {:set, {:system_memory_high_watermark, []}}
Jan 03 02:02:14 fediverse pleroma[307681]: 02:02:14.543 [info] Function passed as a handler with ID "pleroma-logger" is local function.
Jan 03 02:02:14 fediverse pleroma[307681]: This mean that it is either anonymous function or capture of function without module specified. That may cause performance penalty when calling such handler. For more details see note in `telemetry:attach/4` documentation.
Jan 03 02:02:14 fediverse pleroma[307681]: https://hexdocs.pm/telemetry/telemetry.html#attach-4
Jan 03 02:02:15 fediverse pleroma[307681]: 02:02:15.561 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:15 fediverse pleroma[307681]: 02:02:15.561 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:17 fediverse pleroma[307681]: 02:02:17.593 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:17 fediverse pleroma[307681]: 02:02:17.979 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.557 [error] Could not create schema migrations table. This error usually happens due to the following:
Jan 03 02:02:18 fediverse pleroma[307681]:   * The database does not exist
Jan 03 02:02:18 fediverse pleroma[307681]:   * The "schema_migrations" table, which Ecto uses for managing
Jan 03 02:02:18 fediverse pleroma[307681]:     migrations, was defined by another library
Jan 03 02:02:18 fediverse pleroma[307681]:   * There is a deadlock while migrating (such as using concurrent
Jan 03 02:02:18 fediverse pleroma[307681]:     indexes with a migration_lock)
Jan 03 02:02:18 fediverse pleroma[307681]: To fix the first issue, run "mix ecto.create".
Jan 03 02:02:18 fediverse pleroma[307681]: To address the second, you can run "mix ecto.drop" followed by
Jan 03 02:02:18 fediverse pleroma[307681]: "mix ecto.create". Alternatively you may configure Ecto to use
Jan 03 02:02:18 fediverse pleroma[307681]: another table and/or repository for managing migrations:
Jan 03 02:02:18 fediverse pleroma[307681]:     config :pleroma, Pleroma.Repo,
Jan 03 02:02:18 fediverse pleroma[307681]:       migration_source: "some_other_table_for_schema_migrations",
Jan 03 02:02:18 fediverse pleroma[307681]:       migration_repo: AnotherRepoForSchemaMigrations
Jan 03 02:02:18 fediverse pleroma[307681]: The full error report is shown below.
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.562 [info] Application pleroma exited: exited in: Pleroma.Application.start(:normal, [])
Jan 03 02:02:18 fediverse pleroma[307681]:     ** (EXIT) an exception was raised:
Jan 03 02:02:18 fediverse pleroma[307681]:         ** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 2999ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:
Jan 03 02:02:18 fediverse pleroma[307681]:   1. Ensuring your database is available and that you can connect to it
Jan 03 02:02:18 fediverse pleroma[307681]:   2. Tracking down slow queries and making sure they are running fast enough
Jan 03 02:02:18 fediverse pleroma[307681]:   3. Increasing the pool_size (although this increases resource consumption)
Jan 03 02:02:18 fediverse pleroma[307681]:   4. Allowing requests to wait longer by increasing :queue_target and :queue_interval
Jan 03 02:02:18 fediverse pleroma[307681]: See DBConnection.start_link/2 for more information
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:905: Ecto.Adapters.SQL.raise_sql_call_error/1
Jan 03 02:02:18 fediverse pleroma[307681]:             (elixir 1.11.4) lib/enum.ex:1411: Enum."-map/2-lists^map/1-0-"/2
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:997: Ecto.Adapters.SQL.execute_ddl/4
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:672: Ecto.Migrator.verbose_schema_migration/3
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:486: Ecto.Migrator.lock_for_migrations/4
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:444: Ecto.Migrator.migrations/3
Jan 03 02:02:18 fediverse pleroma[307681]:             (pleroma 2.5.0) lib/pleroma/application_requirements.ex:84: anonymous fn/1 in Pleroma.ApplicationRequirements.check_migrations_applied!/1
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:146: Ecto.Migrator.with_repo/3
Jan 03 02:02:18 fediverse pleroma[307734]: [os_mon] memory supervisor port (memsup): Erlang has closed
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.586 [info]     :alarm_handler: {:clear, :system_memory_high_watermark}
Jan 03 02:02:18 fediverse pleroma[307735]: [os_mon] cpu supervisor port (cpu_sup): Erlang has closed
Jan 03 02:02:20 fediverse pleroma[307681]: {"Kernel pid terminated",application_controller,"{application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Elixir.DBConnection.ConnectionError',message => <<\"connection not available and request was dropped from queue after 2999ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (although this increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n\">>,reason => queue_timeout,severity => error},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,\"lib/ecto/adapters/sql.ex\"},{line,905}]},{'Elixir.Enum','-map/2-lists^map/1-0-',2,[{file,\"lib/enum.ex\"},{line,1411}]},{'Elixir.Ecto.Adapters.SQL',execute_ddl,4,[{file,\"lib/ecto/adapters/sql.ex\"},{line,997}]},{'Elixir.Ecto.Migrator',verbose_schema_migration,3,[{file,\"lib/ecto/migrator.ex\"},{line,672}]},{'Elixir.Ecto.Migrator',lock_for_migrations,4,[{file,\"lib/ecto/migrator.ex\"},{line,486}]},{'Elixir.Ecto.Migrator',migrations,3,[{file,\"lib/ecto/migrator.ex\"},{line,444}]},{'Elixir.Pleroma.ApplicationRequirements','-check_migrations_applied!/1-fun-2-',1,[{file,\"lib/pleroma/application_requirements.ex\"},{line,84}]},{'Elixir.Ecto.Migrator',with_repo,3,[{file,\"lib/ecto/migrator.ex\"},{line,146}]}]}}}}}"}
Jan 03 02:02:20 fediverse pleroma[307681]: Kernel pid terminated (application_controller) ({application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Eli
Jan 03 02:02:20 fediverse pleroma[307681]: 
Jan 03 02:02:20 fediverse pleroma[307681]: Crash dump is being written to: erl_crash.dump...done
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Main process exited, code=exited, status=1/FAILURE
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Failed with result 'exit-code'.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Unit process 868 (epmd) remains running after unit stopped.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Consumed 7.082s CPU time.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4997.
Jan 03 02:02:20 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Consumed 7.082s CPU time.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:02:20 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:02:20 fediverse systemd[1]: Started Pleroma social network.

ad nauseum. Probably the cited process is still squatting on things:

UID          PID    PPID  C STIME TTY          TIME CMD
pleroma      868       1  0 Jan02 ?        00:00:02 /opt/pleroma/erts-11.2.2.17/bin/epmd -daemon

except, killing that process doesn't seem to have resolved anything? Starting the service back up it still deathloops.

Rebooting the VM "fixed" it again. Sigh . . .

Keeps dying; checking the Pleroma service log via journalctl gives me

Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4995.
Jan 03 02:01:57 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Consumed 7.018s CPU time.
Jan 03 02:01:57 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:01:57 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:01:57 fediverse systemd[1]: Started Pleroma social network.
Jan 03 02:02:03 fediverse pleroma[307619]: 02:02:03.315 [info]     :alarm_handler: {:set, {:system_memory_high_watermark, []}}
Jan 03 02:02:03 fediverse pleroma[307619]: 02:02:03.476 [info] Function passed as a handler with ID "pleroma-logger" is local function.
Jan 03 02:02:03 fediverse pleroma[307619]: This mean that it is either anonymous function or capture of function without module specified. That may cause performance penalty when calling such handler. For more details see note in `telemetry:attach/4` documentation.
Jan 03 02:02:03 fediverse pleroma[307619]: https://hexdocs.pm/telemetry/telemetry.html#attach-4
Jan 03 02:02:04 fediverse pleroma[307619]: 02:02:04.600 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:04 fediverse pleroma[307619]: 02:02:04.600 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.596 [error] Could not create schema migrations table. This error usually happens due to the following:
Jan 03 02:02:06 fediverse pleroma[307619]:   * The database does not exist
Jan 03 02:02:06 fediverse pleroma[307619]:   * The "schema_migrations" table, which Ecto uses for managing
Jan 03 02:02:06 fediverse pleroma[307619]:     migrations, was defined by another library
Jan 03 02:02:06 fediverse pleroma[307619]:   * There is a deadlock while migrating (such as using concurrent
Jan 03 02:02:06 fediverse pleroma[307619]:     indexes with a migration_lock)
Jan 03 02:02:06 fediverse pleroma[307619]: To fix the first issue, run "mix ecto.create".
Jan 03 02:02:06 fediverse pleroma[307619]: To address the second, you can run "mix ecto.drop" followed by
Jan 03 02:02:06 fediverse pleroma[307619]: "mix ecto.create". Alternatively you may configure Ecto to use
Jan 03 02:02:06 fediverse pleroma[307619]: another table and/or repository for managing migrations:
Jan 03 02:02:06 fediverse pleroma[307619]:     config :pleroma, Pleroma.Repo,
Jan 03 02:02:06 fediverse pleroma[307619]:       migration_source: "some_other_table_for_schema_migrations",
Jan 03 02:02:06 fediverse pleroma[307619]:       migration_repo: AnotherRepoForSchemaMigrations
Jan 03 02:02:06 fediverse pleroma[307619]: The full error report is shown below.
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.602 [info] Application pleroma exited: exited in: Pleroma.Application.start(:normal, [])
Jan 03 02:02:06 fediverse pleroma[307619]:     ** (EXIT) an exception was raised:
Jan 03 02:02:06 fediverse pleroma[307619]:         ** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 2000ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:
Jan 03 02:02:06 fediverse pleroma[307619]:   1. Ensuring your database is available and that you can connect to it
Jan 03 02:02:06 fediverse pleroma[307619]:   2. Tracking down slow queries and making sure they are running fast enough
Jan 03 02:02:06 fediverse pleroma[307619]:   3. Increasing the pool_size (although this increases resource consumption)
Jan 03 02:02:06 fediverse pleroma[307619]:   4. Allowing requests to wait longer by increasing :queue_target and :queue_interval
Jan 03 02:02:06 fediverse pleroma[307619]: See DBConnection.start_link/2 for more information
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:905: Ecto.Adapters.SQL.raise_sql_call_error/1
Jan 03 02:02:06 fediverse pleroma[307619]:             (elixir 1.11.4) lib/enum.ex:1411: Enum."-map/2-lists^map/1-0-"/2
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:997: Ecto.Adapters.SQL.execute_ddl/4
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:672: Ecto.Migrator.verbose_schema_migration/3
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:486: Ecto.Migrator.lock_for_migrations/4
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:444: Ecto.Migrator.migrations/3
Jan 03 02:02:06 fediverse pleroma[307619]:             (pleroma 2.5.0) lib/pleroma/application_requirements.ex:84: anonymous fn/1 in Pleroma.ApplicationRequirements.check_migrations_applied!/1
Jan 03 02:02:06 fediverse pleroma[307619]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:146: Ecto.Migrator.with_repo/3
Jan 03 02:02:06 fediverse pleroma[307672]: [os_mon] memory supervisor port (memsup): Erlang has closed
Jan 03 02:02:06 fediverse pleroma[307619]: 02:02:06.629 [info]     :alarm_handler: {:clear, :system_memory_high_watermark}
Jan 03 02:02:06 fediverse pleroma[307673]: [os_mon] cpu supervisor port (cpu_sup): Erlang has closed
Jan 03 02:02:08 fediverse pleroma[307619]: {"Kernel pid terminated",application_controller,"{application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Elixir.DBConnection.ConnectionError',message => <<\"connection not available and request was dropped from queue after 2000ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (although this increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n\">>,reason => queue_timeout,severity => error},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,\"lib/ecto/adapters/sql.ex\"},{line,905}]},{'Elixir.Enum','-map/2-lists^map/1-0-',2,[{file,\"lib/enum.ex\"},{line,1411}]},{'Elixir.Ecto.Adapters.SQL',execute_ddl,4,[{file,\"lib/ecto/adapters/sql.ex\"},{line,997}]},{'Elixir.Ecto.Migrator',verbose_schema_migration,3,[{file,\"lib/ecto/migrator.ex\"},{line,672}]},{'Elixir.Ecto.Migrator',lock_for_migrations,4,[{file,\"lib/ecto/migrator.ex\"},{line,486}]},{'Elixir.Ecto.Migrator',migrations,3,[{file,\"lib/ecto/migrator.ex\"},{line,444}]},{'Elixir.Pleroma.ApplicationRequirements','-check_migrations_applied!/1-fun-2-',1,[{file,\"lib/pleroma/application_requirements.ex\"},{line,84}]},{'Elixir.Ecto.Migrator',with_repo,3,[{file,\"lib/ecto/migrator.ex\"},{line,146}]}]}}}}}"}
Jan 03 02:02:08 fediverse pleroma[307619]: Kernel pid terminated (application_controller) ({application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Eli
Jan 03 02:02:08 fediverse pleroma[307619]: 
Jan 03 02:02:08 fediverse pleroma[307619]: Crash dump is being written to: erl_crash.dump...done
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Main process exited, code=exited, status=1/FAILURE
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Failed with result 'exit-code'.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Unit process 868 (epmd) remains running after unit stopped.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Consumed 7.269s CPU time.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4996.
Jan 03 02:02:08 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Consumed 7.269s CPU time.
Jan 03 02:02:08 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:02:08 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:02:08 fediverse systemd[1]: Started Pleroma social network.
Jan 03 02:02:14 fediverse pleroma[307681]: 02:02:14.368 [info]     :alarm_handler: {:set, {:system_memory_high_watermark, []}}
Jan 03 02:02:14 fediverse pleroma[307681]: 02:02:14.543 [info] Function passed as a handler with ID "pleroma-logger" is local function.
Jan 03 02:02:14 fediverse pleroma[307681]: This mean that it is either anonymous function or capture of function without module specified. That may cause performance penalty when calling such handler. For more details see note in `telemetry:attach/4` documentation.
Jan 03 02:02:14 fediverse pleroma[307681]: https://hexdocs.pm/telemetry/telemetry.html#attach-4
Jan 03 02:02:15 fediverse pleroma[307681]: 02:02:15.561 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:15 fediverse pleroma[307681]: 02:02:15.561 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:17 fediverse pleroma[307681]: 02:02:17.593 [error] Postgrex.Protocol (#PID<0.3968.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:17 fediverse pleroma[307681]: 02:02:17.979 [error] Postgrex.Protocol (#PID<0.3969.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (localhost:5432): connection refused - :econnrefused
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.557 [error] Could not create schema migrations table. This error usually happens due to the following:
Jan 03 02:02:18 fediverse pleroma[307681]:   * The database does not exist
Jan 03 02:02:18 fediverse pleroma[307681]:   * The "schema_migrations" table, which Ecto uses for managing
Jan 03 02:02:18 fediverse pleroma[307681]:     migrations, was defined by another library
Jan 03 02:02:18 fediverse pleroma[307681]:   * There is a deadlock while migrating (such as using concurrent
Jan 03 02:02:18 fediverse pleroma[307681]:     indexes with a migration_lock)
Jan 03 02:02:18 fediverse pleroma[307681]: To fix the first issue, run "mix ecto.create".
Jan 03 02:02:18 fediverse pleroma[307681]: To address the second, you can run "mix ecto.drop" followed by
Jan 03 02:02:18 fediverse pleroma[307681]: "mix ecto.create". Alternatively you may configure Ecto to use
Jan 03 02:02:18 fediverse pleroma[307681]: another table and/or repository for managing migrations:
Jan 03 02:02:18 fediverse pleroma[307681]:     config :pleroma, Pleroma.Repo,
Jan 03 02:02:18 fediverse pleroma[307681]:       migration_source: "some_other_table_for_schema_migrations",
Jan 03 02:02:18 fediverse pleroma[307681]:       migration_repo: AnotherRepoForSchemaMigrations
Jan 03 02:02:18 fediverse pleroma[307681]: The full error report is shown below.
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.562 [info] Application pleroma exited: exited in: Pleroma.Application.start(:normal, [])
Jan 03 02:02:18 fediverse pleroma[307681]:     ** (EXIT) an exception was raised:
Jan 03 02:02:18 fediverse pleroma[307681]:         ** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 2999ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:
Jan 03 02:02:18 fediverse pleroma[307681]:   1. Ensuring your database is available and that you can connect to it
Jan 03 02:02:18 fediverse pleroma[307681]:   2. Tracking down slow queries and making sure they are running fast enough
Jan 03 02:02:18 fediverse pleroma[307681]:   3. Increasing the pool_size (although this increases resource consumption)
Jan 03 02:02:18 fediverse pleroma[307681]:   4. Allowing requests to wait longer by increasing :queue_target and :queue_interval
Jan 03 02:02:18 fediverse pleroma[307681]: See DBConnection.start_link/2 for more information
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:905: Ecto.Adapters.SQL.raise_sql_call_error/1
Jan 03 02:02:18 fediverse pleroma[307681]:             (elixir 1.11.4) lib/enum.ex:1411: Enum."-map/2-lists^map/1-0-"/2
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/adapters/sql.ex:997: Ecto.Adapters.SQL.execute_ddl/4
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:672: Ecto.Migrator.verbose_schema_migration/3
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:486: Ecto.Migrator.lock_for_migrations/4
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:444: Ecto.Migrator.migrations/3
Jan 03 02:02:18 fediverse pleroma[307681]:             (pleroma 2.5.0) lib/pleroma/application_requirements.ex:84: anonymous fn/1 in Pleroma.ApplicationRequirements.check_migrations_applied!/1
Jan 03 02:02:18 fediverse pleroma[307681]:             (ecto_sql 3.9.0) lib/ecto/migrator.ex:146: Ecto.Migrator.with_repo/3
Jan 03 02:02:18 fediverse pleroma[307734]: [os_mon] memory supervisor port (memsup): Erlang has closed
Jan 03 02:02:18 fediverse pleroma[307681]: 02:02:18.586 [info]     :alarm_handler: {:clear, :system_memory_high_watermark}
Jan 03 02:02:18 fediverse pleroma[307735]: [os_mon] cpu supervisor port (cpu_sup): Erlang has closed
Jan 03 02:02:20 fediverse pleroma[307681]: {"Kernel pid terminated",application_controller,"{application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Elixir.DBConnection.ConnectionError',message => <<\"connection not available and request was dropped from queue after 2999ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (although this increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n\">>,reason => queue_timeout,severity => error},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,\"lib/ecto/adapters/sql.ex\"},{line,905}]},{'Elixir.Enum','-map/2-lists^map/1-0-',2,[{file,\"lib/enum.ex\"},{line,1411}]},{'Elixir.Ecto.Adapters.SQL',execute_ddl,4,[{file,\"lib/ecto/adapters/sql.ex\"},{line,997}]},{'Elixir.Ecto.Migrator',verbose_schema_migration,3,[{file,\"lib/ecto/migrator.ex\"},{line,672}]},{'Elixir.Ecto.Migrator',lock_for_migrations,4,[{file,\"lib/ecto/migrator.ex\"},{line,486}]},{'Elixir.Ecto.Migrator',migrations,3,[{file,\"lib/ecto/migrator.ex\"},{line,444}]},{'Elixir.Pleroma.ApplicationRequirements','-check_migrations_applied!/1-fun-2-',1,[{file,\"lib/pleroma/application_requirements.ex\"},{line,84}]},{'Elixir.Ecto.Migrator',with_repo,3,[{file,\"lib/ecto/migrator.ex\"},{line,146}]}]}}}}}"}
Jan 03 02:02:20 fediverse pleroma[307681]: Kernel pid terminated (application_controller) ({application_start_failure,pleroma,{bad_return,{{'Elixir.Pleroma.Application',start,[normal,[]]},{'EXIT',{#{'__exception__' => true,'__struct__' => 'Eli
Jan 03 02:02:20 fediverse pleroma[307681]: 
Jan 03 02:02:20 fediverse pleroma[307681]: Crash dump is being written to: erl_crash.dump...done
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Main process exited, code=exited, status=1/FAILURE
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Failed with result 'exit-code'.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Unit process 868 (epmd) remains running after unit stopped.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Consumed 7.082s CPU time.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Scheduled restart job, restart counter is at 4997.
Jan 03 02:02:20 fediverse systemd[1]: Stopped Pleroma social network.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Consumed 7.082s CPU time.
Jan 03 02:02:20 fediverse systemd[1]: pleroma.service: Found left-over process 868 (epmd) in control group while starting unit. Ignoring.
Jan 03 02:02:20 fediverse systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Jan 03 02:02:20 fediverse systemd[1]: Started Pleroma social network.

ad nauseum. Probably the cited process is still squatting on things:

UID          PID    PPID  C STIME TTY          TIME CMD
pleroma      868       1  0 Jan02 ?        00:00:02 /opt/pleroma/erts-11.2.2.17/bin/epmd -daemon

except, killing that process doesn't seem to have resolved anything? Starting the service back up it still deathloops.


I wrote all of that above ages ago, and nothing much has changed, other than that I've yet to figure out any way to actually resolve this other than rebooting the server, and so, uhhh,

/etc/cron.hourly/kludge

#!/bin/bash
response=$(curl --write-out '%{http_code}' --silent --output /dev/null https://fediverse.keithzg.ca)
if (($response == 502)); then
        #echo "Looks like nginx/pleroma/whatever is fucked again"
        reboot
fi
keithzg renamed this task from Finally update my damn Pleroma server to Finally update my damn Pleroma server and unfuck what the updates fucked up.Feb 4 2023, 2:16 AM
keithzg updated the task description. (Show Details)

I was about to be like "well this has been working fine for ages now, time to close this task!" and then I noticed my comment above and yeah, /etc/cron.hourly/kludge is still marked executable. So uhh lets disable that and see if things remain stable before I hang up the Mission Accomplished banner...

It's been fine since! I should probably update it again, but that's another task's task.