matrix-org / synapse

Synapse: Matrix homeserver written in Python/Twisted.
https://matrix-org.github.io/synapse
Apache License 2.0
11.82k stars 2.13k forks source link

Unable to upgrade from 1.85.2 to 1.86.0 due to unique constraint "user_filters_unique" violation in db migration #16254

Closed starcraft66 closed 1 year ago

starcraft66 commented 1 year ago

Description

I can no longer upgrade my home server past 1.85.2 due to the schema upgrade from v77 to v78 not being able to apply on my database.

Steps to reproduce

Homeserver

nerdsin.space

Synapse Version

1.86.0

Installation Method

Docker (matrixdotorg/synapse)

Database

PostgreSQL 15.3

Workers

Single process

Platform

Docker on debian linux bare metal

Configuration

No response

Relevant log output

2023-09-05 10:51:54,138 - root - 348 - WARNING - main - ***** STARTING SERVER *****
2023-09-05 10:51:54,138 - root - 349 - WARNING - main - Server /usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py version 1.86.0
2023-09-05 10:51:54,138 - root - 354 - INFO - main - Server hostname: nerdsin.space
2023-09-05 10:51:54,138 - root - 355 - INFO - main - Instance name: master
2023-09-05 10:51:54,138 - root - 356 - INFO - main - Twisted reactor: EPollReactor
2023-09-05 10:51:54,138 - synapse.app.homeserver - 349 - INFO - main - Setting up server
2023-09-05 10:51:54,138 - synapse.server - 337 - INFO - main - Setting up.
2023-09-05 10:51:54,141 - synapse.storage.databases - 66 - INFO - main - [database config 'master']: Checking database server
2023-09-05 10:51:54,142 - synapse.storage.engines.postgres - 98 - WARNING - main - Database has incorrect collation of 'en_US.utf8'. Should be 'C'
2023-09-05 10:51:54,143 - synapse.storage.databases - 69 - INFO - main - [database config 'master']: Preparing for databases ['main', 'state']
2023-09-05 10:51:54,143 - synapse.storage.prepare_database - 120 - INFO - main - ['main', 'state']: Checking existing schema version
2023-09-05 10:51:54,144 - synapse.storage.prepare_database - 124 - INFO - main - ['main', 'state']: Existing schema is 77 (+9 deltas)
2023-09-05 10:51:54,144 - synapse.storage.databases.main - 288 - INFO - main - Checking database for consistency with configuration...
2023-09-05 10:51:54,145 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v77
2023-09-05 10:51:54,146 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v78
2023-09-05 10:51:54,146 - synapse.storage.prepare_database - 513 - INFO - main - Running 78/01_validate_and_update_profiles.py:run_upgrade
2023-09-05 10:51:54,147 - synapse.storage.prepare_database - 513 - INFO - main - Running 78/02_validate_and_update_user_filters.py:run_upgrade
2023-09-05 10:51:54,176 - synapse.app._base - 215 - ERROR - main - Exception during startup
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 352, in setup
    hs.setup()
  File "/usr/local/lib/python3.11/site-packages/synapse/server.py", line 339, in setup
    self.datastores = Databases(self.DATASTORE_CLASS, self)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/__init__.py", line 74, in __init__
    prepare_database(
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/prepare_database.py", line 141, in prepare_database
    _upgrade_existing_database(
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/prepare_database.py", line 514, in _upgrade_existing_database
    module.run_upgrade(cur, database_engine, config=config)
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/schema/main/delta/78/02_validate_and_update_user_filters.py", line 49, in run_upgrade
    cur.execute(process_rows_sql, (f":{hostname}",))
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 417, in execute
    self._do_execute(self.txn.execute, sql, parameters)
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 469, in _do_execute
    return func(sql, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
DETAIL:  Key (user_id, filter_id)=(loui_v, 0) already exists.


### Anything else that would be useful to know?

_No response_
clokep commented 1 year ago

Any idea what version of Synapse you initially deployed?

Can you SELECT * FROM applied_schema_deltas; and paste the response here?

Additionally can you run \d user_filters and paste the response here?

starcraft66 commented 1 year ago

Any idea what version of Synapse you initially deployed?

Not exactly sure what you mean by this. I am running 1.85.2, tried to upgrade to latest and I got an error about the database version being unknown, so I decided to upgrade to the next version and ran into this.

Can you SELECT * FROM applied_schema_deltas; and paste the response here?

synapse=# select * from applied_schema_deltas;
 version |                                    file
---------+----------------------------------------------------------------------------
      17 | 17/drop_indexes.sql
      17 | 17/server_keys.sql
      17 | 17/user_threepids.sql
      18 | 18/server_keys_bigger_ints.sql
      19 | 19/event_index.sql
      20 | 20/dummy.sql
      20 | 20/pushers.py
      20 | 20/pushers.pyc
      21 | 21/end_to_end_keys.sql
      21 | 21/receipts.sql
      22 | 22/receipts_index.sql
      22 | 22/user_threepids_unique.sql
      23 | 23/drop_state_index.sql
      24 | 24/stats_reporting.sql
      25 | 25/00background_updates.sql
      25 | 25/fts.py
      25 | 25/fts.pyc
      25 | 25/guest_access.sql
      25 | 25/history_visibility.sql
      25 | 25/tags.sql
      26 | 26/account_data.sql
      27 | 27/account_data.sql
      27 | 27/forgotten_memberships.sql
      27 | 27/ts.py
      27 | 27/ts.pyc
      28 | 28/event_push_actions.sql
      28 | 28/events_room_stream.sql
      28 | 28/public_roms_index.sql
      28 | 28/receipts_user_id_index.sql
      28 | 28/upgrade_times.sql
      28 | 28/users_is_guest.sql
      29 | 29/push_actions.sql
      30 | 30/alias_creator.sql
      30 | 30/as_users.py
      30 | 30/as_users.pyc
      30 | 30/deleted_pushers.sql
      30 | 30/presence_stream.sql
      30 | 30/public_rooms.sql
      30 | 30/push_rule_stream.sql
      30 | 30/state_stream.sql
      30 | 30/threepid_guest_access_tokens.sql
      31 | 31/invites.sql
      31 | 31/local_media_repository_url_cache.sql
      31 | 31/pushers.py
      31 | 31/pushers.pyc
      31 | 31/pushers_index.sql
      31 | 31/search_update.py
      31 | 31/search_update.pyc
      32 | 32/events.sql
      32 | 32/openid.sql
      32 | 32/pusher_throttle.sql
      32 | 32/remove_indices.sql
      32 | 32/reports.sql
      33 | 33/access_tokens_device_index.sql
      33 | 33/devices.sql
      33 | 33/devices_for_e2e_keys.sql
      33 | 33/devices_for_e2e_keys_clear_unknown_device.sql
      33 | 33/event_fields.py
      33 | 33/event_fields.pyc
      33 | 33/remote_media_ts.py
      33 | 33/remote_media_ts.pyc
      33 | 33/user_ips_index.sql
      34 | 34/appservice_stream.sql
      34 | 34/cache_stream.py
      34 | 34/cache_stream.pyc
      34 | 34/device_inbox.sql
      34 | 34/push_display_name_rename.sql
      34 | 34/received_txn_purge.py
      34 | 34/received_txn_purge.pyc
      34 | 34/sent_txn_purge.py
      34 | 34/sent_txn_purge.pyc
      35 | 35/add_state_index.sql
      35 | 35/contains_url.sql
      35 | 35/device_outbox.sql
      35 | 35/device_stream_id.sql
      35 | 35/event_push_actions_index.sql
      35 | 35/public_room_list_change_stream.sql
      35 | 35/state.sql
      35 | 35/state_dedupe.sql
      35 | 35/stream_order_to_extrem.sql
      36 | 36/readd_public_rooms.sql
      37 | 37/remove_auth_idx.py
      37 | 37/remove_auth_idx.pyc
      37 | 37/user_threepids.sql
      38 | 38/postgres_fts_gist.sql
      39 | 39/appservice_room_list.sql
      39 | 39/device_federation_stream_idx.sql
      39 | 39/event_push_index.sql
      39 | 39/federation_out_position.sql
      39 | 39/membership_profile.sql
      40 | 40/current_state_idx.sql
      40 | 40/device_inbox.sql
      40 | 40/device_list_streams.sql
      40 | 40/event_push_summary.sql
      40 | 40/pushers.sql
      41 | 41/device_list_stream_idx.sql
      41 | 41/device_outbound_index.sql
      41 | 41/event_search_event_id_idx.sql
      41 | 41/ratelimit.sql
      42 | 42/current_state_delta.sql
      42 | 42/device_list_last_id.sql
      42 | 42/event_auth_state_only.sql
      42 | 42/user_dir.py
      42 | 42/user_dir.pyc
      43 | 43/blocked_rooms.sql
      43 | 43/quarantine_media.sql
      43 | 43/url_cache.sql
      43 | 43/user_share.sql
      44 | 44/expire_url_cache.sql
      45 | 45/group_server.sql
      45 | 45/profile_cache.sql
      46 | 46/drop_refresh_tokens.sql
      46 | 46/drop_unique_deleted_pushers.sql
      46 | 46/group_server.sql
      46 | 46/local_media_repository_url_idx.sql
      46 | 46/user_dir_null_room_ids.sql
      46 | 46/user_dir_typos.sql
      47 | 47/last_access_media.sql
      47 | 47/postgres_fts_gin.sql
      47 | 47/push_actions_staging.sql
      47 | 47/state_group_seq.py
      47 | 47/state_group_seq.pyc
      48 | 48/add_user_ips_last_seen_index.sql
      48 | 48/groups_joinable.sql
      48 | 48/deactivated_users.sql
      48 | 48/group_unique_indexes.py
      48 | 48/group_unique_indexes.pyc
      48 | 48/add_user_consent.sql
      49 | 49/add_user_consent_server_notice_sent.sql
      49 | 49/add_user_daily_visits.sql
      49 | 49/add_user_ips_last_seen_only_index.sql
      50 | 50/add_creation_ts_users_index.sql
      50 | 50/erasure_store.sql
      50 | 50/make_event_content_nullable.py
      50 | 50/make_event_content_nullable.pyc
      51 | 51/monthly_active_users.sql
      51 | 51/e2e_room_keys.sql
      56 | 56/event_expiry.sql
      52 | 52/add_event_to_state_group_index.sql
      52 | 52/device_list_streams_unique_idx.sql
      52 | 52/e2e_room_keys.sql
      53 | 53/drop_sent_transactions.sql
      53 | 53/add_user_type_to_users.sql
      53 | 53/event_format_version.sql
      53 | 53/user_ips_index.sql
      53 | 53/user_dir_populate.sql
      53 | 53/user_share.sql
      53 | 53/users_in_public_rooms.sql
      53 | 53/user_threepid_id.sql
      54 | 54/account_validity.sql
      54 | 54/drop_legacy_tables.sql
      54 | 54/drop_presence_list.sql
      54 | 54/delete_forward_extremities.sql
      54 | 54/relations.sql
      54 | 54/account_validity_with_renewal.sql
      54 | 54/add_validity_to_server_keys.sql
      54 | 54/stats.sql
      54 | 54/stats2.sql
      55 | 55/track_threepid_validations.sql
      55 | 55/users_alter_deactivated.sql
      55 | 55/access_token_expiry.sql
      56 | 56/current_state_events_membership.sql
      56 | 56/current_state_events_membership_mk2.sql
      56 | 56/room_membership_idx.sql
      56 | 56/add_spans_to_device_lists.sql
      56 | 56/destinations_failure_ts.sql
      56 | 56/destinations_retry_interval_type.sql.postgres
      56 | 56/devices_last_seen.sql
      56 | 56/fix_room_keys_index.sql
      56 | 56/redaction_censor.sql
      56 | 56/redaction_censor2.sql
      56 | 56/stats_separated.sql
      56 | 56/user_external_ids.sql
      56 | 56/users_in_public_rooms_idx.sql
      56 | 56/redaction_censor3_fix_update.sql.postgres
      56 | 56/drop_unused_event_tables.sql
      56 | 56/hidden_devices.sql
      56 | 56/public_room_list_idx.sql
      56 | 56/signing_keys.sql
      56 | 56/unique_user_filter_index.py
      56 | 56/delete_keys_from_deleted_backups.sql
      56 | 56/event_labels.sql
      56 | 56/event_labels_background_update.sql
      56 | 56/redaction_censor4.sql
      56 | 56/room_key_etag.sql
      56 | 56/room_retention.sql
      56 | 56/signing_keys_nonunique_signatures.sql
      56 | 56/device_stream_id_insert.sql
      56 | 56/nuke_empty_communities_from_db.sql
      56 | 56/remove_tombstoned_rooms_from_directory.sql
      56 | 56/state_group_room_idx.sql
      57 | 57/local_current_membership.py
      57 | 57/delete_old_current_state_events.sql
      57 | 57/device_list_remote_cache_stale.sql
      57 | 57/rooms_version_column.sql
      57 | 57/rooms_version_column_2.sql.postgres
      57 | 57/rooms_version_column_3.sql.postgres
      57 | 57/remove_sent_outbound_pokes.sql
      58 | 58/00background_update_ordering.sql
      58 | 58/02remove_dup_outbound_pokes.sql
      58 | 58/03persist_ui_auth.sql
      58 | 58/05cache_instance.sql.postgres
      58 | 58/06dlols_unique_idx.py
      58 | 58/08_media_safe_from_quarantine.sql.postgres
      58 | 58/10drop_local_rejections_stream.sql
      58 | 58/10federation_pos_instance_name.sql
      58 | 58/11user_id_seq.py
      58 | 58/12room_stats.sql
      58 | 58/07persist_ui_auth_ips.sql
      58 | 58/09shadow_ban.sql
      58 | 58/13remove_presence_allow_inbound.sql
      58 | 58/15unread_count.sql
      58 | 58/07add_method_to_thumbnail_constraint.sql.postgres
      58 | 58/10_pushrules_enabled_delete_obsolete.sql
      58 | 58/14events_instance_name.sql
      58 | 58/14events_instance_name.sql.postgres
      58 | 58/15_catchup_destination_rooms.sql
      58 | 58/16populate_stats_process_rooms_fix.sql
      58 | 58/17_catchup_last_successful.sql
      58 | 58/18stream_positions.sql
      58 | 58/11dehydration.sql
      58 | 58/11fallback.sql
      58 | 58/19instance_map.sql.postgres
      58 | 58/19txn_id.sql
      58 | 58/20instance_name_event_tables.sql
      58 | 58/20user_daily_visits.sql
      58 | 58/21as_device_stream.sql
      58 | 58/21drop_device_max_stream_id.sql
      58 | 58/22puppet_token.sql
      58 | 58/22users_have_local_media.sql
      58 | 58/23e2e_cross_signing_keys_idx.sql
      58 | 58/24drop_event_json_index.sql
      58 | 58/25user_external_ids_user_id_idx.sql
      58 | 58/26access_token_last_validated.sql
      58 | 58/27local_invites.sql
      58 | 58/28drop_last_used_column.sql.postgres
      58 | 58/28rejected_events_metadata.sql
      59 | 59/01ignored_user.py
      59 | 59/02shard_send_to_device.sql
      59 | 59/03shard_send_to_device_sequence.sql.postgres
      59 | 59/04_event_auth_chains.sql
      59 | 59/04_event_auth_chains.sql.postgres
      59 | 59/04drop_account_data.sql
      59 | 59/05cache_invalidation.sql
      59 | 59/06chain_cover_index.sql
      59 | 59/06shard_account_data.sql
      59 | 59/06shard_account_data.sql.postgres
      59 | 59/07shard_account_data_fix.sql
      59 | 59/08delete_pushers_for_deactivated_accounts.sql
      59 | 59/08delete_stale_pushers.sql
      59 | 59/09rejected_events_metadata.sql
      59 | 59/10delete_purged_chain_cover.sql
      59 | 59/11drop_thumbnail_constraint.sql.postgres
      59 | 59/12account_validity_token_used_ts_ms.sql
      59 | 59/12presence_stream_instance.sql
      59 | 59/12presence_stream_instance_seq.sql.postgres
      59 | 59/13users_to_send_full_presence_to.sql
      59 | 59/11add_knock_members_to_stats.sql
      59 | 59/15locks.sql
      59 | 59/16federation_inbound_staging.sql
      59 | 59/14refresh_tokens.sql
      60 | 60/01recreate_stream_ordering.sql.postgres
      60 | 60/02change_stream_ordering_columns.sql.postgres
      61 | 61/01change_appservices_txns.sql.postgres
      61 | 61/01insertion_event_lookups.sql
      61 | 61/02drop_redundant_room_depth_index.sql
      61 | 61/02state_groups_state_n_distinct.sql.postgres
      61 | 61/03recreate_min_depth.py
      62 | 62/01insertion_event_extremities.sql
      63 | 63/01create_registration_tokens.sql
      63 | 63/02delete_unlinked_email_pushers.sql
      63 | 63/03session_store.sql
      63 | 63/02populate-rooms-creator.sql
      63 | 63/04add_presence_stream_not_offline_index.sql
      64 | 64/01msc2716_chunk_to_batch_rename.sql.postgres
      65 | 65/01msc2716_insertion_event_edges.sql
      65 | 65/02_thread_relations.sql
      65 | 65/03remove_hidden_devices_from_device_inbox.sql
      65 | 65/04_local_group_updates.sql
      65 | 65/06remove_deleted_devices_from_device_inbox.sql
      65 | 65/05_remove_room_stats_historical_and_user_stats_historical.sql
      65 | 65/07_arbitrary_relations.sql
      65 | 65/08_device_inbox_background_updates.sql
      65 | 65/10_expirable_refresh_tokens.sql
      65 | 65/11_devices_auth_provider_session.sql
      67 | 67/01drop_public_room_list_stream.sql
      68 | 68/01event_columns.sql
      68 | 68/02_msc2409_add_device_id_appservice_stream_type.sql
      68 | 68/03_delete_account_data_for_deactivated_accounts.sql
      68 | 68/04_refresh_tokens_index_next_token_id.sql
      68 | 68/04partial_state_rooms.sql
      68 | 68/05partial_state_rooms_triggers.py
      68 | 68/06_msc3202_add_device_list_appservice_stream_type.sql
      69 | 69/01as_txn_seq.py
      69 | 69/01device_list_oubound_by_room.sql
      69 | 69/02cache_invalidation_index.sql
      70 | 70/01clean_table_purged_rooms.sql
      70 | 70/08_state_group_edges_unique.sql
      71 | 71/01rebuild_event_edges.sql.postgres
      71 | 71/01remove_noop_background_updates.sql
      71 | 71/02event_push_summary_unique.sql
      72 | 72/01event_push_summary_receipt.sql
      72 | 72/02event_push_actions_index.sql
      72 | 72/01add_room_type_to_state_stats.sql
      72 | 72/03bg_populate_events_columns.py
      72 | 72/03drop_event_reference_hashes.sql
      72 | 72/03remove_groups.sql
      72 | 72/04drop_column_application_services_state_last_txn.sql.postgres
      72 | 72/05receipts_event_stream_ordering.sql
      72 | 72/05remove_unstable_private_read_receipts.sql
      72 | 72/06add_consent_ts_to_users.sql
      72 | 72/06thread_notifications.sql
      72 | 72/07force_update_current_state_events_membership.py
      72 | 72/07thread_receipts.sql.postgres
      72 | 72/08begin_cache_invalidation_seq_at_2.sql.postgres
      72 | 72/08thread_receipts.sql
      73 | 73/01event_failed_pull_attempts.sql
      73 | 73/02add_pusher_enabled.sql
      73 | 73/02room_id_indexes_for_purging.sql
      73 | 73/03pusher_device_id.sql
      73 | 73/03users_approved_column.sql
      73 | 73/04partial_join_details.sql
      73 | 73/04pending_device_list_updates.sql
      73 | 73/05old_push_actions.sql.postgres
      73 | 73/06thread_notifications_thread_id_idx.sql
      73 | 73/08thread_receipts_non_null.sql.postgres
      73 | 73/09partial_joined_via_destination.sql
      73 | 73/09threads_table.sql
      73 | 73/10_update_sqlite_fts4_tokenizer.py
      73 | 73/10login_tokens.sql
      73 | 73/11event_search_room_id_n_distinct.sql.postgres
      73 | 73/12refactor_device_list_outbound_pokes.sql
      73 | 73/13add_device_lists_index.sql
      73 | 73/20_un_partial_stated_room_stream.sql
      73 | 73/21_un_partial_stated_room_stream_seq.sql.postgres
      73 | 73/22_rebuild_user_dir_stats.sql
      73 | 73/22_un_partial_stated_event_stream.sql
      73 | 73/23_fix_thread_index.sql
      73 | 73/23_un_partial_stated_room_stream_seq.sql.postgres
      73 | 73/24_events_jump_to_date_index.sql
      73 | 73/25drop_presence.sql
      74 | 74/01_user_directory_stale_remote_users.sql
      74 | 74/02_set_device_id_for_pushers_bg_update.sql
      74 | 74/03_room_membership_index.sql
      74 | 74/04_delete_e2e_backup_keys_for_deactivated_users.sql
      74 | 74/90COMMENTS_destinations.sql.postgres
      74 | 74/03_membership_tables_event_stream_ordering.sql.postgres
      74 | 74/04_membership_tables_event_stream_ordering_triggers.py
      74 | 74/05_events_txn_id_device_id.sql
      76 | 76/01_add_profiles_full_user_id_column.sql
      76 | 76/02_add_user_filters_full_user_id_column.sql
      76 | 76/03_per_user_experimental_features.sql
      76 | 76/04_add_room_forgetter.sql
      77 | 77/01_add_profiles_not_valid_check.sql.postgres
      77 | 77/02_add_user_filters_not_valid_check.sql.postgres
      77 | 77/03bg_populate_full_user_id_profiles.sql
      77 | 77/04bg_populate_full_user_id_user_filters.sql
      77 | 77/05thread_notifications_backfill.sql
      77 | 77/06thread_notifications_not_null_event_push_actions.sql.postgres
      77 | 77/06thread_notifications_not_null_event_push_actions_staging.sql.postgres
      77 | 77/06thread_notifications_not_null_event_push_summary.sql.postgres
      77 | 77/14bg_indices_event_stream_ordering.sql
(362 rows)

Additionally can you run \d user_filters and paste the response here?

synapse=# \d user_filters
              Table "public.user_filters"
    Column    |  Type  | Collation | Nullable | Default
--------------+--------+-----------+----------+---------
 user_id      | text   |           | not null |
 filter_id    | bigint |           | not null |
 filter_json  | bytea  |           | not null |
 full_user_id | text   |           |          |
Indexes:
    "full_users_unique_idx" UNIQUE, btree (full_user_id, filter_id)
    "user_filters_unique" UNIQUE, btree (user_id, filter_id)
Check constraints:
    "full_user_id_not_null" CHECK (full_user_id IS NOT NULL) NOT VALID
clokep commented 1 year ago

I think we're tripping up over something related to #15396. A timeline of some PRs:


  1. You're currently on 1.85.2, which shows you do have the column and it is not valid. (This seems correct.)
  2. Synapse 1.86.0 is now attempting to run 78/02_validate_and_update_user_filters.py which is failing when attempting to insert data.

Can you run SELECT * FROM background_updates; and paste the results here? I wonder if you have some very old background update that's stuck (although I can't really see how that would be the issue here.)

starcraft66 commented 1 year ago

Can you run SELECT * FROM background_updates; and paste the results here? I wonder if you have some very old background update that's stuck (although I can't really see how that would be the issue here.)

synapse=# SELECT * FROM background_updates;
                 update_name                  |         progress_json         |              depends_on              | ordering 
----------------------------------------------+-------------------------------+--------------------------------------+----------
 event_push_actions_thread_id                 | {}                            | event_push_actions_staging_thread_id |     7706
 event_push_actions_staging_thread_id         | {}                            |                                      |     7706
 event_push_summary_thread_id                 | {}                            | event_push_actions_thread_id         |     7706
 event_push_drop_null_thread_id_indexes       | {}                            | event_push_summary_thread_id         |     7706
 current_state_events_stream_ordering_idx     | {}                            |                                      |     7714
 local_current_membership_stream_ordering_idx | {}                            |                                      |     7714
 room_memberships_stream_ordering_idx         | {}                            |                                      |     7714
 populate_full_user_id_user_filters           | {"lower_bound_id":"imnotgay"} |                                      |     7704
(8 rows)

I tried grepping the logs for background_update to see if there were any exceptions but did not get any results back.

clokep commented 1 year ago

Ideally populate_full_user_id_user_filters would be finished before you attempt to upgrade to 1.86.0, although 78/02_validate_and_update_user_filters.py does seem to attempt to handle this:

https://github.com/matrix-org/synapse/blob/78cfa55dad911e667b5a9b613e232eb72410382f/synapse/storage/schema/main/delta/78/02_validate_and_update_user_filters.py#L40-L49

This is the query that's failing, I was unable to reproduce this locally though.

I tried grepping the logs for background_update to see if there were any exceptions but did not get any results back.

One option is to stay on 1.85.2 and let the populate_full_user_id_user_filters update finish. (If you re-run the SELECT * FROM background_updates; hopefully the progress_json changes over time.) You should be able to see in the logs if this is running or not, although it is concerning if you didn't get any results. There should be INFO level logs for this.

starcraft66 commented 1 year ago

Here's what I get related to user_filters:


$ rg user_filters homeserver*
homeserver.log.4
33220:2023-09-06 02:01:54,740 - synapse.storage.background_updates - 431 - INFO - background_updates-0 - Starting update batch on background update 'populate_full_user_id_user_filters'
33235:  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
33280:psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
33472:2023-09-06 02:01:55,771 - synapse.storage.background_updates - 431 - INFO - background_updates-0 - Starting update batch on background update 'populate_full_user_id_user_filters'
33484:  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
33529:psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
33704:2023-09-06 02:01:56,789 - synapse.storage.background_updates - 431 - INFO - background_updates-0 - Starting update batch on background update 'populate_full_user_id_user_filters'
33729:  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
33774:psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
33877:2023-09-06 02:01:57,816 - synapse.storage.background_updates - 431 - INFO - background_updates-0 - Starting update batch on background update 'populate_full_user_id_user_filters'
33888:  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
33933:psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
33989:2023-09-06 02:01:58,835 - synapse.storage.background_updates - 431 - INFO - background_updates-0 - Starting update batch on background update 'populate_full_user_id_user_filters'
34012:  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
34057:psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
starcraft66 commented 1 year ago

Full stack:

2023-09-06 02:01:54,765 - synapse.storage.background_updates - 302 - ERROR - background_updates-0 - Error doing update
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 294, in run_background_updates
    result = await self.do_next_background_update(sleep)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 424, in do_next_background_update
    await self._do_background_update(desired_duration_ms)
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 467, in _do_background_update
    items_updated = await update_handler(progress, batch_size)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 128, in populate_full_user_id_user_filters
    await self.db_pool.runInteraction(
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 924, in runInteraction
    return await delay_cancellation(_runInteraction())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py", line 1693, in _inlineCallbacks
    result = context.run(
             ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/python/failure.py", line 518, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 890, in _runInteraction
    result = await self.runWithConnection(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 1019, in runWithConnection
    return await make_deferred_yieldable(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/python/threadpool.py", line 244, in inContext
    result = inContext.theWork()  # type: ignore[attr-defined]
             ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/python/threadpool.py", line 260, in <lambda>
    inContext.theWork = lambda: context.call(  # type: ignore[attr-defined]
                                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/python/context.py", line 117, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/python/context.py", line 82, in callWithContext
    return func(*args, **kw)
           ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/twisted/enterprise/adbapi.py", line 282, in _runWithConnection
    result = func(conn, *args, **kw)
             ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 1012, in inner_func
    return func(db_conn, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 752, in new_transaction 
    r = func(cursor, *args, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/databases/main/filtering.py", line 92, in _process_batch
    txn.execute(sql, (f":{self.server_name}", lower_bound_id, upper_bound_id))
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 417, in execute
    self._do_execute(self.txn.execute, sql, parameters)
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/database.py", line 469, in _do_execute
    return func(sql, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "user_filters_unique"
DETAIL:  Key (user_id, filter_id)=(loui_v, 0) already exists.

This doesn't really make sense to me because:

synapse=# select * from user_filters where user_id = 'loui_v';
 user_id | filter_id |                                                                 filter_json                                                                  | full_user_id 
---------+-----------+----------------------------------------------------------------------------------------------------------------------------------------------+--------------
 loui_v  |         0 | redacted | 
(1 row)
clokep commented 1 year ago

Chatting a bit with other folks, it is possible the index is broken. Can you try running REINDEX INDEX user_filters_unique; and see if that fixes the issue? (Note that this will take a lock on the user_filters table -- if that table isn't large it should complete fairly quickly though.)

starcraft66 commented 1 year ago

My user_filters table is under a meg in size so I went ahead with your suggestion, only to run right back into the same issue:

synapse=# REINDEX INDEX user_filters_unique;
ERROR:  could not create unique index "user_filters_unique"
DETAIL:  Key (user_id, filter_id)=(loui_v, 0) is duplicated.
clokep commented 1 year ago
2023-09-05 10:51:54,142 - synapse.storage.engines.postgres - 98 - WARNING - main - Database has incorrect collation of 'en_US.utf8'. Should be 'C'

What might have happened is that your operating system updated which can cause the index to break if the locale changes underneath Postgres.

In this case a SELECT will only show the single row the index knows about, although there might be more. Can you try:

SET enable_indexscan TO off; SET enable_bitmapscan TO off;
SELECT * FROM user_filters WHERE user_id = 'loui_v';

Note that the docs for how to fix your collation are at https://matrix-org.github.io/synapse/latest/postgres.html#fixing-incorrect-collate-or-ctype.

starcraft66 commented 1 year ago

What might have happened is that your operating system updated which can cause the index to break if the locale changes underneath Postgres.

Looks like this appears to be the issue.

synapse=# SET enable_indexscan TO off; SET enable_bitmapscan TO off;
SET
SET
synapse=# SELECT * FROM user_filters WHERE user_id = 'loui_v';
 user_id | filter_id |                                                                 filter_json                                                                  | full_user_id
---------+-----------+----------------------------------------------------------------------------------------------------------------------------------------------+--------------
 loui_v  |         0 | redacted |
 loui_v  |         0 | redacted |
(2 rows)

Your official docs recommend dumping the database and reloading it. This isn't really an option for me because my database is multiple terabytes in size and I don't have enough disk space to do this. Is there a way to just change my collation and rebuild my indexes instead?

clokep commented 1 year ago

Your official docs recommend dumping the database and reloading it. This isn't really an option for me because my database is multiple terabytes in size and I don't have enough disk space to do this. Is there a way to just change my collation and rebuild my indexes instead?

From doing some reading it seems like this is the only safe way. As this shows your current database indexes are going to be very broken potentially causing missing data, etc.

You might be able to do this table-by-table or find a way to update it in-place, but that's beyond the ability of our help.

clokep commented 1 year ago

Unfortunately there's nothing we can do about this if the database is running in the wrong collation. Alternately you could somehow try to rebuild all indexes in the database and manually delete any duplicated data, but that seems fraught with issues.