Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Migration 79/04_mitigate_stream_ordering_update_race fails because there is no unique constraint matching given keys for referenced table "events" #16192

Open
gpetters94 opened this issue Aug 27, 2023 · 20 comments
Labels
A-Background-Updates Filling in database columns, making the database eventually up-to-date A-Database DB stuff like queries, migrations, new/remove columns, indexes, unexpected entries in the db O-Uncommon Most users are unlikely to come across this or unexpected workflow S-Major Major functionality / product severely impaired, no satisfactory workaround. X-Needs-Info This issue is blocked awaiting information from the reporter

Comments

@gpetters94
Copy link

gpetters94 commented Aug 27, 2023

Description

Similar to #10691, I'm having issues after a system update. After an upgrade (from Debian 11 to 12) and a reboot, I get the following error on startup: psycopg2.errors.InvalidForeignKey: there is no unique constraint matching given keys for referenced table "events"

What's strange is I don't think synapse actually updated. It looks like it's still using a bullseye version, and I have daily unattended upgrades so it shouldn't have changed much. I've compared the schema to the one referenced in the source code, but I don't see any missing keys.

synapse=> \d events
                      Table "public.events"
        Column        |  Type   | Collation | Nullable | Default 
----------------------+---------+-----------+----------+---------
 stream_ordering      | integer |           | not null | 
 topological_ordering | bigint  |           | not null | 
 event_id             | text    |           | not null | 
 type                 | text    |           | not null | 
 room_id              | text    |           | not null | 
 content              | text    |           |          | 
 unrecognized_keys    | text    |           |          | 
 processed            | boolean |           | not null | 
 outlier              | boolean |           | not null | 
 depth                | bigint  |           | not null | 0
 origin_server_ts     | bigint  |           |          | 
 received_ts          | bigint  |           |          | 
 sender               | text    |           |          | 
 contains_url         | boolean |           |          | 
 instance_name        | text    |           |          | 
 stream_ordering2     | bigint  |           |          | 
 state_key            | text    |           |          | 
 rejection_reason     | text    |           |          | 
Indexes:
    "events_pkey" PRIMARY KEY, btree (stream_ordering)
    "event_contains_url_index" btree (room_id, topological_ordering, stream_ordering) WHERE contains_url = true AND outlier = false
    "events_event_id_key" UNIQUE CONSTRAINT, btree (event_id)
    "events_order_room" btree (room_id, topological_ordering, stream_ordering)
    "events_room_stream" btree (room_id, stream_ordering)
    "events_ts" btree (origin_server_ts, stream_ordering)
Referenced by:
    TABLE "event_edges" CONSTRAINT "event_edges_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) NOT VALID
    TABLE "event_forward_extremities" CONSTRAINT "event_forward_extremities_event_id" FOREIGN KEY (event_id) REFERENCES events(event_id) DEFERRABLE INITIALLY DEFERRED NOT VALID
    TABLE "current_state_events" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "local_current_membership" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "room_memberships" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "event_txn_id_device_id" CONSTRAINT "event_txn_id_device_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "event_txn_id" CONSTRAINT "event_txn_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "partial_state_events" CONSTRAINT "partial_state_events_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id)
    TABLE "partial_state_rooms" CONSTRAINT "partial_state_rooms_join_event_id_fkey" FOREIGN KEY (join_event_id) REFERENCES events(event_id)
    TABLE "un_partial_stated_event_stream" CONSTRAINT "un_partial_stated_event_stream_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
Rules:
    populate_stream_ordering2 AS
    ON INSERT TO events DO  UPDATE events SET stream_ordering2 = new.stream_ordering
  WHERE events.stream_ordering = new.stream_ordering

Steps to reproduce

  • Upgrade from Debian 11 to 12
  • Start the server

Homeserver

My self-hosted server

Synapse Version

1.90.0+bullseye1

Installation Method

Debian packages from packages.matrix.org

Database

PostgreSQL, single server, never ported.

Workers

I don't know

Platform

Debian 12 (previously 11) on a VPS

Configuration

No response

Relevant log output

2023-08-27 22:28:54,839 - root - 348 - WARNING - main - ***** STARTING SERVER *****
2023-08-27 22:28:54,839 - root - 349 - WARNING - main - Server /opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py version 1.90.0
2023-08-27 22:28:54,839 - root - 354 - INFO - main - Server hostname: REDACTED
2023-08-27 22:28:54,839 - root - 355 - INFO - main - Instance name: master
2023-08-27 22:28:54,839 - root - 356 - INFO - main - Twisted reactor: EPollReactor
2023-08-27 22:28:54,839 - synapse.app.homeserver - 350 - INFO - main - Setting up server
2023-08-27 22:28:54,839 - synapse.server - 337 - INFO - main - Setting up.
2023-08-27 22:28:54,853 - synapse.storage.databases - 66 - INFO - main - [database config 'master']: Checking database server
2023-08-27 22:28:54,854 - synapse.storage.databases - 69 - INFO - main - [database config 'master']: Preparing for databases ['main', 'state']
2023-08-27 22:28:54,855 - synapse.storage.prepare_database - 120 - INFO - main - ['main', 'state']: Checking existing schema version
2023-08-27 22:28:54,857 - synapse.storage.prepare_database - 124 - INFO - main - ['main', 'state']: Existing schema is 79 (+0 deltas)
2023-08-27 22:28:54,857 - synapse.storage.databases.main - 323 - INFO - main - Checking database for consistency with configuration...
2023-08-27 22:28:54,858 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v79
2023-08-27 22:28:54,859 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 79/03_read_write_locks_triggers.sql.postgres
2023-08-27 22:28:54,886 - synapse.storage.prepare_database - 509 - INFO - main - Running 79/04_mitigate_stream_ordering_update_race.py:run_create
2023-08-27 22:28:54,895 - synapse.app._base - 215 - ERROR - main - Exception during startup
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py", line 353, in setup
    hs.setup()
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/server.py", line 339, in setup
    self.datastores = Databases(self.DATASTORE_CLASS, self)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/databases/__init__.py", line 74, in __init__
    prepare_database(
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/prepare_database.py", line 141, in prepare_database
    _upgrade_existing_database(
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/prepare_database.py", line 510, in _upgrade_existing_database
    module.run_create(cur, database_engine)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/schema/main/delta/79/04_mitigate_stream_ordering_update_race.py", line 58, in run_create
    cur.execute(add_cse_sql)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/database.py", line 417, in execute
    self._do_execute(self.txn.execute, sql, parameters)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/database.py", line 471, in _do_execute
    return func(sql, *args, **kwargs)
psycopg2.errors.InvalidForeignKey: there is no unique constraint matching given keys for referenced table "events"


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

_No response_
@DMRobertson DMRobertson changed the title there is no unique constraint matching given keys for referenced table "events" Migration 79/04_mitigate_stream_ordering_update_race fails because there is no unique constraint matching given keys for referenced table "events" Aug 29, 2023
@DMRobertson
Copy link
Contributor

The SQL in question is

add_cse_sql = """
ALTER TABLE current_state_events ADD CONSTRAINT event_stream_ordering_fkey
FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering2) NOT VALID;
"""
cur.execute(add_cse_sql)

which suggests that there isn't a unique index on events(stream_ordering2). This is surprising.

@DMRobertson
Copy link
Contributor

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

@DMRobertson DMRobertson added X-Needs-Info This issue is blocked awaiting information from the reporter A-Database DB stuff like queries, migrations, new/remove columns, indexes, unexpected entries in the db labels Aug 29, 2023
@gpetters94
Copy link
Author

gpetters94 commented Aug 29, 2023

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

Yep, here's the output.
out.txt

                           update_name                            |                                   progress_json                                    |                  depends_on                   | ordering 
------------------------------------------------------------------+------------------------------------------------------------------------------------+-----------------------------------------------+----------
 media_repository_drop_index_wo_method_2                          | {}                                                                                 | remote_media_repository_thumbnails_method_idx |     5911
 populate_stream_ordering2                                        | {}                                                                                 |                                               |     6001
 index_stream_ordering2                                           | {}                                                                                 | populate_stream_ordering2                     |     6001
 index_stream_ordering2_room_order                                | {}                                                                                 | index_stream_ordering2                        |     6001
 index_stream_ordering2_contains_url                              | {}                                                                                 | index_stream_ordering2_room_order             |     6001
 index_stream_ordering2_room_stream                               | {}                                                                                 | index_stream_ordering2_contains_url           |     6001
 index_stream_ordering2_ts                                        | {}                                                                                 | index_stream_ordering2_room_stream            |     6001
 replace_stream_ordering_column                                   | {}                                                                                 | index_stream_ordering2_ts                     |     6001
 populate_room_depth_min_depth2                                   | {}                                                                                 |                                               |     6103
 replace_room_depth_min_depth                                     | {}                                                                                 | populate_room_depth2                          |     6103
 remove_deleted_email_pushers                                     | {}                                                                                 |                                               |     6302
 populate_rooms_creator_column                                    | {}                                                                                 |                                               |     6302
 presence_stream_not_offline_index                                | {}                                                                                 |                                               |     6304
 event_arbitrary_relations                                        | {}                                                                                 |                                               |     6507
 remove_dead_devices_from_device_inbox                            | {}                                                                                 |                                               |     6508
 delete_account_data_for_deactivated_users                        | {}                                                                                 |                                               |     6803
 cache_invalidation_index_by_instance                             | {}                                                                                 |                                               |     6902
 state_group_edges_unique_idx                                     | {}                                                                                 |                                               |     7008
 event_edges_drop_invalid_rows                                    | {}                                                                                 |                                               |     7101
 event_edges_replace_index                                        | {}                                                                                 | event_edges_drop_invalid_rows                 |     7101
 add_room_type_column                                             | {}                                                                                 |                                               |        0
 event_push_actions_stream_highlight_index                        | {}                                                                                 |                                               |     7202
 events_populate_state_key_rejections                             | {"min_stream_ordering_exclusive": -4047, "max_stream_ordering_inclusive": 1011910} |                                               |     7203
 populate_event_stream_ordering                                   | {}                                                                                 |                                               |        0
 event_push_summary_unique_index2                                 | {}                                                                                 |                                               |     7006
 receipts_linearized_unique_index                                 | {}                                                                                 |                                               |     7007
 receipts_graph_unique_index                                      | {}                                                                                 |                                               |     7007
 threads_backfill                                                 | {}                                                                                 |                                               |     7309
 device_lists_changes_in_room_by_room_index                       | {}                                                                                 |                                               |     7313
 populate_user_directory_createtables                             | {}                                                                                 |                                               |     7322
 populate_user_directory_process_rooms                            | {}                                                                                 | populate_user_directory_createtables          |     7322
 populate_user_directory_process_users                            | {}                                                                                 | populate_user_directory_process_rooms         |     7322
 populate_user_directory_cleanup                                  | {}                                                                                 | populate_user_directory_process_users         |     7322
 populate_stats_process_rooms                                     | {}                                                                                 |                                               |     7322
 populate_stats_process_users                                     | {}                                                                                 |                                               |     7322
 events_jump_to_date_index                                        | {}                                                                                 |                                               |     7324
 set_device_id_for_pushers                                        | {}                                                                                 |                                               |     7402
 room_membership_user_room_index                                  | {}                                                                                 |                                               |     7403
 delete_e2e_backup_keys_for_deactivated_users                     | {}                                                                                 |                                               |     7404
 profiles_full_user_id_key_idx                                    | {}                                                                                 |                                               |     7501
 full_users_filters_unique_idx                                    | {}                                                                                 |                                               |     7502
 populate_full_user_id_profiles                                   | {}                                                                                 |                                               |     7703
 populate_full_user_id_user_filters                               | {}                                                                                 |                                               |     7704
 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
 event_forward_extremities_event_id_foreign_key_constraint_update | {}                                                                                 |                                               |     7803
(51 rows)

@DMRobertson DMRobertson added A-Background-Updates Filling in database columns, making the database eventually up-to-date S-Major Major functionality / product severely impaired, no satisfactory workaround. O-Uncommon Most users are unlikely to come across this or unexpected workflow labels Aug 29, 2023
@DMRobertson
Copy link
Contributor

DMRobertson commented Aug 29, 2023

It looks like you have a long backlog of background updates that have failed to apply, and that the migration in question is failing because it requires one of them to have completed. This is very strange and needs more investigation.

Can you downgrade to older versions of Synapse until you find one that starts up without the error message you quoted? Once Synapse is started, can you leave it running for an hour, then grep the logs for background update or background_update and upload them here?

@clokep
Copy link
Member

clokep commented Aug 29, 2023

Can you downgrade to older versions of Synapse until you find one that starts up without the error message you quoted? Once Synapse is started, can you leave it running for an hour, then grep the logs for background update or background_update and upload them here?

I think v1.87.0 should work since you want earlier than #15998 / #15887?

@gpetters94
Copy link
Author

gpetters94 commented Aug 29, 2023

It looks like you have a long backlog of background updates that have failed to apply, and that the migration in question is failing because it requires one of them to have completed. This is very strange and needs more investigation.

Can you downgrade to older versions of Synapse until you find one that starts up without the error message you quoted? Once Synapse is started, can you leave it running for an hour, then grep the logs for background update or background_update and upload them here?

Here you go.

@clokep
Copy link
Member

clokep commented Aug 29, 2023

The relevant bit seems to be:

2023-08-29 17:22:03,215 - synapse.storage.background_updates - 461 - INFO - background_updates-0 - Starting update batch on background update 'replace_stream_ordering_column'
2023-08-29 17:22:03,923 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: UPDATE events SET stream_ordering2 = stream_ordering WHERE stream_ordering2 IS NULL
2023-08-29 17:22:03,927 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: DROP RULE populate_stream_ordering2 ON events
2023-08-29 17:22:03,936 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: ALTER TABLE events DROP COLUMN stream_ordering
2023-08-29 17:22:03,962 - synapse.storage.background_updates - 332 - ERROR - background_updates-0 - Error doing update
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 323, in run_background_updates
    result = await self.do_next_background_update(sleep)
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 454, in do_next_background_update
    await self._do_background_update(desired_duration_ms)
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 497, in _do_background_update
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/databases/main/events_bg_updates.py", line 1313, in _background_replace_stream_ordering_column

@damienvancouver
Copy link

I'm also having this problem, but I am upgrading from an older database (v59).

For me, the problem seems to be that background_updates queued in v60 are not able to run before the v79 update throws an exception, which then prevents synapse from starting.

I can see why this is failing though, the index doesn't exist because the v60 background_updates haven't run.

Delta 60 sets these up when it creates the stream_ordering2 field:

-- ... and some more to build indexes on it. These aren't really interdependent
-- but the backround_updates manager can only handle a single dependency per update.
INSERT INTO background_updates (ordering, update_name, progress_json, depends_on) VALUES
  (6001, 'index_stream_ordering2', '{}', 'populate_stream_ordering2'),
  (6001, 'index_stream_ordering2_room_order', '{}', 'index_stream_ordering2'),
  (6001, 'index_stream_ordering2_contains_url', '{}', 'index_stream_ordering2_room_order'),
  (6001, 'index_stream_ordering2_room_stream', '{}', 'index_stream_ordering2_contains_url'),
  (6001, 'index_stream_ordering2_ts', '{}', 'index_stream_ordering2_room_stream');

Because my homeserver refuses to start now, I can't get these background updates to run. This will probably happen to anyone who upgrades from <= 60 to 79.

I suspect if I can just prevent 79 from running temporarily, then the v60 background updates will run, and then I can let v79 do its thing. But I'm not sure how to disable it. Or how the problem needs to be solved longterm!

My logs / etc:

empty background_updates table starting out in v59:

synapse=# select * from background_updates;
 update_name | progress_json | depends_on | ordering 
-------------+---------------+------------+----------
(0 rows)

On my new server, it runs through the upgrade patches on the old database, but then fails at delta 79

My homeserver.log output of the upgrade:

2023-08-29 17:07:24,564 - synapse.storage.databases.main - 323 - INFO - main - Checking database for consistency with configuration...
2023-08-29 17:07:24,566 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v59
2023-08-29 17:07:24,569 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/08delete_pushers_for_deactivated_accounts.sql
2023-08-29 17:07:24,571 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/08delete_stale_pushers.sql
2023-08-29 17:07:24,573 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/09rejected_events_metadata.sql
2023-08-29 17:07:24,574 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/10delete_purged_chain_cover.sql
2023-08-29 17:07:24,575 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/11add_knock_members_to_stats.sql
2023-08-29 17:07:24,576 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 59/11drop_thumbnail_constraint.sql.postgres
2023-08-29 17:07:24,578 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/12account_validity_token_used_ts_ms.sql
2023-08-29 17:07:24,579 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/12presence_stream_instance.sql
2023-08-29 17:07:24,580 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 59/12presence_stream_instance_seq.sql.postgres
2023-08-29 17:07:24,585 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/13users_to_send_full_presence_to.sql
2023-08-29 17:07:24,592 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/14refresh_tokens.sql
2023-08-29 17:07:24,599 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/15locks.sql
2023-08-29 17:07:24,605 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 59/16federation_inbound_staging.sql
2023-08-29 17:07:24,613 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v60
2023-08-29 17:07:24,614 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 60/01recreate_stream_ordering.sql.postgres
2023-08-29 17:07:24,618 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 60/02change_stream_ordering_columns.sql.postgres
2023-08-29 17:07:24,654 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v61
2023-08-29 17:07:24,655 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 61/01change_appservices_txns.sql.postgres
2023-08-29 17:07:24,665 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 61/01insertion_event_lookups.sql
2023-08-29 17:07:24,686 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 61/02drop_redundant_room_depth_index.sql
2023-08-29 17:07:24,688 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 61/02state_groups_state_n_distinct.sql.postgres
2023-08-29 17:07:24,691 - synapse.storage.prepare_database - 509 - INFO - main - Running 61/03recreate_min_depth.py:run_create
2023-08-29 17:07:24,703 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v62
2023-08-29 17:07:24,704 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 62/01insertion_event_extremities.sql
2023-08-29 17:07:24,711 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v63
2023-08-29 17:07:24,712 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 63/01create_registration_tokens.sql
2023-08-29 17:07:24,718 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 63/02delete_unlinked_email_pushers.sql
2023-08-29 17:07:24,720 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 63/02populate-rooms-creator.sql
2023-08-29 17:07:24,721 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 63/03session_store.sql
2023-08-29 17:07:24,727 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 63/04add_presence_stream_not_offline_index.sql
2023-08-29 17:07:24,729 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v64
2023-08-29 17:07:24,730 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 64/01msc2716_chunk_to_batch_rename.sql.postgres
2023-08-29 17:07:24,735 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v65
2023-08-29 17:07:24,736 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/01msc2716_insertion_event_edges.sql
2023-08-29 17:07:24,739 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/03remove_hidden_devices_from_device_inbox.sql
2023-08-29 17:07:24,741 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/04_local_group_updates.sql
2023-08-29 17:07:24,742 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/05_remove_room_stats_historical_and_user_stats_historical.sql
2023-08-29 17:07:24,746 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/06remove_deleted_devices_from_device_inbox.sql
2023-08-29 17:07:24,750 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/07_arbitrary_relations.sql
2023-08-29 17:07:24,751 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/08_device_inbox_background_updates.sql
2023-08-29 17:07:24,752 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/10_expirable_refresh_tokens.sql
2023-08-29 17:07:24,754 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 65/11_devices_auth_provider_session.sql
2023-08-29 17:07:24,763 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v66
2023-08-29 17:07:24,763 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v67
2023-08-29 17:07:24,764 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 67/01drop_public_room_list_stream.sql
2023-08-29 17:07:24,767 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v68
2023-08-29 17:07:24,768 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/01event_columns.sql
2023-08-29 17:07:24,771 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/02_msc2409_add_device_id_appservice_stream_type.sql
2023-08-29 17:07:24,772 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/03_delete_account_data_for_deactivated_accounts.sql
2023-08-29 17:07:24,774 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/04_refresh_tokens_index_next_token_id.sql
2023-08-29 17:07:24,778 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/04partial_state_rooms.sql
2023-08-29 17:07:24,796 - synapse.storage.prepare_database - 509 - INFO - main - Running 68/05partial_state_rooms_triggers.py:run_create
2023-08-29 17:07:24,798 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 68/06_msc3202_add_device_list_appservice_stream_type.sql
2023-08-29 17:07:24,799 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v69
2023-08-29 17:07:24,801 - synapse.storage.prepare_database - 509 - INFO - main - Running 69/01as_txn_seq.py:run_create
2023-08-29 17:07:24,802 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 69/01device_list_oubound_by_room.sql
2023-08-29 17:07:24,810 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 69/02cache_invalidation_index.sql
2023-08-29 17:07:24,812 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v70
2023-08-29 17:07:24,813 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 70/01clean_table_purged_rooms.sql
2023-08-29 17:07:24,814 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 70/08_state_group_edges_unique.sql
2023-08-29 17:07:24,816 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v71
2023-08-29 17:07:24,817 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 71/01rebuild_event_edges.sql.postgres
2023-08-29 17:07:24,820 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 71/01remove_noop_background_updates.sql
2023-08-29 17:07:24,825 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 71/02event_push_summary_unique.sqlI'm upgrading from the old Debian 10 buster-backports version to the matrix.org repository version on Debian 11.
2023-08-29 17:07:24,826 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v72
2023-08-29 17:07:24,827 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/01add_room_type_to_state_stats.sql
2023-08-29 17:07:24,829 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/01event_push_summary_receipt.sql
2023-08-29 17:07:24,834 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/02event_push_actions_index.sql
2023-08-29 17:07:24,836 - synapse.storage.prepare_database - 509 - INFO - main - Running 72/03bg_populate_events_columns.py:run_create
2023-08-29 17:07:24,839 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/03drop_event_reference_hashes.sql
2023-08-29 17:07:24,842 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/03remove_groups.sql
2023-08-29 17:07:24,872 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 72/04drop_column_application_services_state_last_txn.sql.postgres
2023-08-29 17:07:24,877 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/05receipts_event_stream_ordering.sql
2023-08-29 17:07:24,879 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/05remove_unstable_private_read_receipts.sql
2023-08-29 17:07:24,882 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/06add_consent_ts_to_users.sql
2023-08-29 17:07:24,883 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/06thread_notifications.sql
2023-08-29 17:07:24,886 - synapse.storage.prepare_database - 513 - INFO - main - Running 72/07force_update_current_state_events_membership.py:run_upgrade
2023-08-29 17:07:24,886 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 72/07thread_receipts.sql.postgres
2023-08-29 17:07:24,923 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 72/08begin_cache_invalidation_seq_at_2.sql.postgres
2023-08-29 17:07:24,933 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 72/08thread_receipts.sql
2023-08-29 17:07:24,934 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v73
2023-08-29 17:07:24,936 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/01event_failed_pull_attempts.sql
2023-08-29 17:07:24,943 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/02add_pusher_enabled.sql
2023-08-29 17:07:24,944 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/02room_id_indexes_for_purging.sql
2023-08-29 17:07:24,951 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/03pusher_device_id.sql
2023-08-29 17:07:24,952 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/03users_approved_column.sql
2023-08-29 17:07:24,954 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/04partial_join_details.sql
2023-08-29 17:07:24,956 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/04pending_device_list_updates.sql
2023-08-29 17:07:24,964 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 73/05old_push_actions.sql.postgres
2023-08-29 17:07:24,970 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/06thread_notifications_thread_id_idx.sql
2023-08-29 17:07:24,972 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 73/08thread_receipts_non_null.sql.postgres
2023-08-29 17:07:24,973 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/09partial_joined_via_destination.sql
2023-08-29 17:07:24,975 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/09threads_table.sql
2023-08-29 17:07:24,984 - synapse.storage.prepare_database - 509 - INFO - main - Running 73/10_update_sqlite_fts4_tokenizer.py:run_create
2023-08-29 17:07:24,984 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/10login_tokens.sql
2023-08-29 17:07:24,993 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 73/11event_search_room_id_n_distinct.sql.postgres
2023-08-29 17:07:24,995 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/12refactor_device_list_outbound_pokes.sql
2023-08-29 17:07:25,003 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/13add_device_lists_index.sql
2023-08-29 17:07:25,005 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/20_un_partial_stated_room_stream.sql
2023-08-29 17:07:25,012 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 73/21_un_partial_stated_room_stream_seq.sql.postgres
2023-08-29 17:07:25,014 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/22_rebuild_user_dir_stats.sql
2023-08-29 17:07:25,015 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/22_un_partial_stated_event_stream.sql
2023-08-29 17:07:25,024 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/23_fix_thread_index.sql
2023-08-29 17:07:25,026 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 73/23_un_partial_stated_room_stream_seq.sql.postgres
2023-08-29 17:07:25,028 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/24_events_jump_to_date_index.sql
2023-08-29 17:07:25,030 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 73/25drop_presence.sql
2023-08-29 17:07:25,033 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v74
2023-08-29 17:07:25,034 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 74/01_user_directory_stale_remote_users.sql
2023-08-29 17:07:25,045 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 74/02_set_device_id_for_pushers_bg_update.sql
2023-08-29 17:07:25,046 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 74/03_membership_tables_event_stream_ordering.sql.postgres
2023-08-29 17:07:25,051 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 74/03_room_membership_index.sql
2023-08-29 17:07:25,052 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 74/04_delete_e2e_backup_keys_for_deactivated_users.sql
2023-08-29 17:07:25,054 - synapse.storage.prepare_database - 509 - INFO - main - Running 74/04_membership_tables_event_stream_ordering_triggers.py:run_create
2023-08-29 17:07:25,057 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 74/05_events_txn_id_device_id.sql
2023-08-29 17:07:25,068 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 74/90COMMENTS_destinations.sql.postgres
2023-08-29 17:07:25,071 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v75
2023-08-29 17:07:25,072 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v76
2023-08-29 17:07:25,073 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 76/01_add_profiles_full_user_id_column.sql
2023-08-29 17:07:25,075 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 76/02_add_user_filters_full_user_id_column.sql
2023-08-29 17:07:25,076 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 76/03_per_user_experimental_features.sql
2023-08-29 17:07:25,082 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 76/04_add_room_forgetter.sql
2023-08-29 17:07:25,086 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v77
2023-08-29 17:07:25,087 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/01_add_profiles_not_valid_check.sql.postgres
2023-08-29 17:07:25,088 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/02_add_user_filters_not_valid_check.sql.postgres
2023-08-29 17:07:25,090 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 77/03bg_populate_full_user_id_profiles.sql
2023-08-29 17:07:25,091 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 77/04bg_populate_full_user_id_user_filters.sql
2023-08-29 17:07:25,092 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 77/05thread_notifications_backfill.sql
2023-08-29 17:07:25,100 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/06thread_notifications_not_null_event_push_actions.sql.postgres
2023-08-29 17:07:25,103 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/06thread_notifications_not_null_event_push_actions_staging.sql.postgres
2023-08-29 17:07:25,103 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/06thread_notifications_not_null_event_push_actions_staging.sql.postgres
2023-08-29 17:07:25,107 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 77/06thread_notifications_not_null_event_push_summary.sql.postgres
2023-08-29 17:07:25,110 - synapse.storage.prepare_database - 526 - INFO - main - Applying schema 77/14bg_indices_event_stream_ordering.sql
2023-08-29 17:07:25,113 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v78
2023-08-29 17:07:25,116 - synapse.storage.prepare_database - 513 - INFO - main - Running 78/01_validate_and_update_profiles.py:run_upgrade
2023-08-29 17:07:25,122 - synapse.storage.prepare_database - 513 - INFO - main - Running 78/02_validate_and_update_user_filters.py:run_upgrade
2023-08-29 17:07:25,130 - synapse.storage.prepare_database - 509 - INFO - main - Running 78/03event_extremities_constraints.py:run_create
2023-08-29 17:07:25,135 - synapse.storage.prepare_database - 509 - INFO - main - Running 78/04_add_full_user_id_index_user_filters.py:run_create
2023-08-29 17:07:25,136 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v79
2023-08-29 17:07:25,138 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 79/03_read_write_locks_triggers.sql.postgres
2023-08-29 17:07:25,170 - synapse.storage.prepare_database - 509 - INFO - main - Running 79/04_mitigate_stream_ordering_update_race.py:run_create
2023-08-29 17:07:25,196 - synapse.app._base - 215 - ERROR - main - Exception during startup
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py", line 353, in setup
    hs.setup()
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/server.py", line 339, in setup
    self.datastores = Databases(self.DATASTORE_CLASS, self)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/databases/__init__.py", line 74, in __init__
    prepare_database(
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/prepare_database.py", line 141, in prepare_database
    _upgrade_existing_database(
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/prepare_database.py", line 510, in _upgrade_existing_database
    module.run_create(cur, database_engine)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/schema/main/delta/79/04_mitigate_stream_ordering_update_race.py", line 58, in run_create
    cur.execute(add_cse_sql)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/database.py", line 417, in execute
    self._do_execute(self.txn.execute, sql, parameters)
  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/database.py", line 469, in _do_execute
    return func(sql, *args, **kwargs)
psycopg2.errors.InvalidForeignKey: there is no unique constraint matching given keys for referenced table "events"

my background_tasks table has 55 new rows in it after the upgrade:

synapse=#  SELECT * FROM background_updates; 
                           update_name                            |                                   progress_json                                   |                  depends_on                   | ordering 
------------------------------------------------------------------+-----------------------------------------------------------------------------------+-----------------------------------------------+----------
 remove_deactivated_pushers                                       | {}                                                                                |                                               |     5908
 remove_stale_pushers                                             | {}                                                                                |                                               |     5908
 rejected_events_metadata                                         | {}                                                                                |                                               |     5828
 purged_chain_cover                                               | {}                                                                                |                                               |     5910
 media_repository_drop_index_wo_method_2                          | {}                                                                                | remote_media_repository_thumbnails_method_idx |     5911
 populate_stream_ordering2                                        | {}                                                                                |                                               |     6001
 index_stream_ordering2                                           | {}                                                                                | populate_stream_ordering2                     |     6001
 index_stream_ordering2_room_order                                | {}                                                                                | index_stream_ordering2                        |     6001
 index_stream_ordering2_contains_url                              | {}                                                                                | index_stream_ordering2_room_order             |     6001
 index_stream_ordering2_room_stream                               | {}                                                                                | index_stream_ordering2_contains_url           |     6001
 index_stream_ordering2_ts                                        | {}                                                                                | index_stream_ordering2_room_stream            |     6001
 replace_stream_ordering_column                                   | {}                                                                                | index_stream_ordering2_ts                     |     6001
 populate_room_depth_min_depth2                                   | {}                                                                                |                                               |     6103
 replace_room_depth_min_depth                                     | {}                                                                                | populate_room_depth2                          |     6103
 remove_deleted_email_pushers                                     | {}                                                                                |                                               |     6302
 populate_rooms_creator_column                                    | {}                                                                                |                                               |     6302
 presence_stream_not_offline_index                                | {}                                                                                |                                               |     6304
 event_arbitrary_relations                                        | {}                                                                                |                                               |     6507
 remove_dead_devices_from_device_inbox                            | {}                                                                                |                                               |     6508
 delete_account_data_for_deactivated_users                        | {}                                                                                |                                               |     6803
 cache_invalidation_index_by_instance                             | {}                                                                                |                                               |     6902
 state_group_edges_unique_idx                                     | {}                                                                                |                                               |     7008
 event_edges_drop_invalid_rows                                    | {}                                                                                |                                               |     7101
 event_edges_replace_index                                        | {}                                                                                | event_edges_drop_invalid_rows                 |     7101
 add_room_type_column                                             | {}                                                                                |                                               |        0
 event_push_actions_stream_highlight_index                        | {}                                                                                |                                               |     7202
 events_populate_state_key_rejections                             | {"min_stream_ordering_exclusive": -4265, "max_stream_ordering_inclusive": 635228} |                                               |     7203
 populate_event_stream_ordering                                   | {}                                                                                |                                               |        0
 event_push_summary_unique_index2                                 | {}                                                                                |                                               |     7006
 receipts_linearized_unique_index                                 | {}                                                                                |                                               |     7007
 receipts_graph_unique_index                                      | {}                                                                                |                                               |     7007
 threads_backfill                                                 | {}                                                                                |                                               |     7309
 device_lists_changes_in_room_by_room_index                       | {}                                                                                |                                               |     7313
 populate_user_directory_createtables                             | {}                                                                                |                                               |     7322
 populate_user_directory_process_rooms                            | {}                                                                                | populate_user_directory_createtables          |     7322
 populate_user_directory_process_users                            | {}                                                                                | populate_user_directory_process_rooms         |     7322
 populate_user_directory_cleanup                                  | {}                                                                                | populate_user_directory_process_users         |     7322
 populate_stats_process_rooms                                     | {}                                                                                |                                               |     7322
 populate_stats_process_users                                     | {}                                                                                |                                               |     7322
 events_jump_to_date_index                                        | {}                                                                                |                                               |     7324
 set_device_id_for_pushers                                        | {}                                                                                |                                               |     7402
 room_membership_user_room_index                                  | {}                                                                                |                                               |     7403
 delete_e2e_backup_keys_for_deactivated_users                     | {}                                                                                |                                               |     7404
 profiles_full_user_id_key_idx                                    | {}                                                                                |                                               |     7501
 full_users_filters_unique_idx                                    | {}                                                                                |                                               |     7502
 populate_full_user_id_profiles                                   | {}                                                                                |                                               |     7703
 populate_full_user_id_user_filters                               | {}                                                                                |                                               |     7704
 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
 event_forward_extremities_event_id_foreign_key_constraint_update | {}                                                                                |                                               |     7803
(55 rows)

and my events table is missing that unique index alright:

synapse=# \d events
                      Table "public.events"
        Column        |  Type   | Collation | Nullable | Default 
----------------------+---------+-----------+----------+---------
 stream_ordering      | integer |           | not null | 
 topological_ordering | bigint  |           | not null | 
 event_id             | text    |           | not null | 
 type                 | text    |           | not null | 
 room_id              | text    |           | not null | 
 content              | text    |           |          | 
 unrecognized_keys    | text    |           |          | 
 processed            | boolean |           | not null | 
 outlier              | boolean |           | not null | 
 depth                | bigint  |           | not null | 0
 origin_server_ts     | bigint  |           |          | 
 received_ts          | bigint  |           |          | 
 sender               | text    |           |          | 
 contains_url         | boolean |           |          | 
 instance_name        | text    |           |          | 
 stream_ordering2     | bigint  |           |          | 
 state_key            | text    |           |          | 
 rejection_reason     | text    |           |          | 
Indexes:
    "events_pkey" PRIMARY KEY, btree (stream_ordering)
    "events_event_id_key" UNIQUE CONSTRAINT, btree (event_id)
    "events_order_room" btree (room_id, topological_ordering, stream_ordering)
    "events_room_stream" btree (room_id, stream_ordering)
    "events_ts" btree (origin_server_ts, stream_ordering)
Referenced by:
    TABLE "event_edges" CONSTRAINT "event_edges_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) NOT VALID
    TABLE "event_forward_extremities" CONSTRAINT "event_forward_extremities_event_id" FOREIGN KEY (event_id) REFERENCES events(event_id) DEFERRABLE INITIALLY DEFERRED NOT VALID
    TABLE "current_state_events" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "local_current_membership" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "room_memberships" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "event_txn_id_device_id" CONSTRAINT "event_txn_id_device_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "event_txn_id" CONSTRAINT "event_txn_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "partial_state_events" CONSTRAINT "partial_state_events_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id)
    TABLE "partial_state_rooms" CONSTRAINT "partial_state_rooms_join_event_id_fkey" FOREIGN KEY (join_event_id) REFERENCES events(event_id)
    TABLE "un_partial_stated_event_stream" CONSTRAINT "un_partial_stated_event_stream_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
Rules:
    populate_stream_ordering2 AS
    ON INSERT TO events DO  UPDATE events SET stream_ordering2 = new.stream_ordering
  WHERE events.stream_ordering = new.stream_ordering

@DMRobertson
Copy link
Contributor

It looks like @gpetters94's installation couldn't run

-- ALTER TABLE events DROP COLUMN stream_ordering;

from

_REPLACE_STREAM_ORDERING_SQL_COMMANDS = (
# there should be no leftover rows without a stream_ordering2, but just in case...
"UPDATE events SET stream_ordering2 = stream_ordering WHERE stream_ordering2 IS NULL",
# now we can drop the rule and switch the columns
"DROP RULE populate_stream_ordering2 ON events",
"ALTER TABLE events DROP COLUMN stream_ordering",
"ALTER TABLE events RENAME COLUMN stream_ordering2 TO stream_ordering",
# ... and finally, rename the indexes into place for consistency with sqlite
"ALTER INDEX event_contains_url_index2 RENAME TO event_contains_url_index",
"ALTER INDEX events_order_room2 RENAME TO events_order_room",
"ALTER INDEX events_room_stream2 RENAME TO events_room_stream",
"ALTER INDEX events_ts2 RENAME TO events_ts",
)

Can you share the output of \d events please?

@damienvancouver: thanks for the report, but can you hold off for the time being? I would like to use this issue to fix one installation first and then see if that fix also works for you.

@DMRobertson
Copy link
Contributor

The relevant bit seems to be:

2023-08-29 17:22:03,215 - synapse.storage.background_updates - 461 - INFO - background_updates-0 - Starting update batch on background update 'replace_stream_ordering_column'
2023-08-29 17:22:03,923 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: UPDATE events SET stream_ordering2 = stream_ordering WHERE stream_ordering2 IS NULL
2023-08-29 17:22:03,927 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: DROP RULE populate_stream_ordering2 ON events
2023-08-29 17:22:03,936 - synapse.storage.databases.main.events_bg_updates - 1300 - INFO - background_updates-0 - completing stream_ordering migration: ALTER TABLE events DROP COLUMN stream_ordering
2023-08-29 17:22:03,962 - synapse.storage.background_updates - 332 - ERROR - background_updates-0 - Error doing update
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 323, in run_background_updates
    result = await self.do_next_background_update(sleep)
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 454, in do_next_background_update
    await self._do_background_update(desired_duration_ms)
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/background_updates.py", line 497, in _do_background_update
  File "/opt/venvs/matrix-synapse/lib/python3.11/site-packages/synapse/storage/databases/main/events_bg_updates.py", line 1313, in _background_replace_stream_ordering_column

It is frustrating that this obscures the exception from the background update. Maybe I can improve this...

@gpetters94
Copy link
Author

\d events

The output of \d events is:

                      Table "public.events"
        Column        |  Type   | Collation | Nullable | Default 
----------------------+---------+-----------+----------+---------
 stream_ordering      | integer |           | not null | 
 topological_ordering | bigint  |           | not null | 
 event_id             | text    |           | not null | 
 type                 | text    |           | not null | 
 room_id              | text    |           | not null | 
 content              | text    |           |          | 
 unrecognized_keys    | text    |           |          | 
 processed            | boolean |           | not null | 
 outlier              | boolean |           | not null | 
 depth                | bigint  |           | not null | 0
 origin_server_ts     | bigint  |           |          | 
 received_ts          | bigint  |           |          | 
 sender               | text    |           |          | 
 contains_url         | boolean |           |          | 
 instance_name        | text    |           |          | 
 stream_ordering2     | bigint  |           |          | 
 state_key            | text    |           |          | 
 rejection_reason     | text    |           |          | 
Indexes:
    "events_pkey" PRIMARY KEY, btree (stream_ordering)
    "event_contains_url_index" btree (room_id, topological_ordering, stream_ordering) WHERE contains_url = true AND outlier = false
    "event_contains_url_index2" btree (room_id, topological_ordering, stream_ordering2) WHERE contains_url = true AND outlier = false
    "events_event_id_key" UNIQUE CONSTRAINT, btree (event_id)
    "events_order_room" btree (room_id, topological_ordering, stream_ordering)
    "events_order_room2" btree (room_id, topological_ordering, stream_ordering2)
    "events_room_stream" btree (room_id, stream_ordering)
    "events_room_stream2" btree (room_id, stream_ordering2)
    "events_stream_ordering" UNIQUE, btree (stream_ordering2)
    "events_ts" btree (origin_server_ts, stream_ordering)
    "events_ts2" btree (origin_server_ts, stream_ordering2)
Referenced by:
    TABLE "event_edges" CONSTRAINT "event_edges_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) NOT VALID
    TABLE "event_forward_extremities" CONSTRAINT "event_forward_extremities_event_id" FOREIGN KEY (event_id) REFERENCES events(event_id) DEFERRABLE INITIALLY DEFERRED NOT VALID
    TABLE "current_state_events" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "local_current_membership" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "room_memberships" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "event_txn_id_device_id" CONSTRAINT "event_txn_id_device_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "event_txn_id" CONSTRAINT "event_txn_id_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
    TABLE "partial_state_events" CONSTRAINT "partial_state_events_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id)
    TABLE "partial_state_rooms" CONSTRAINT "partial_state_rooms_join_event_id_fkey" FOREIGN KEY (join_event_id) REFERENCES events(event_id)
    TABLE "un_partial_stated_event_stream" CONSTRAINT "un_partial_stated_event_stream_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
Rules:
    populate_stream_ordering2 AS
    ON INSERT TO events DO  UPDATE events SET stream_ordering2 = new.stream_ordering
  WHERE events.stream_ordering = new.stream_ordering

@DMRobertson
Copy link
Contributor

It looks like @gpetters94's installation couldn't run

-- ALTER TABLE events DROP COLUMN stream_ordering;

... bugger. Is this because of the foreign keys on this column?

    TABLE "current_state_events" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "local_current_membership" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID
    TABLE "room_memberships" CONSTRAINT "event_stream_ordering_fkey" FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering) NOT VALID

@clokep
Copy link
Member

clokep commented Sep 8, 2023

@DMRobertson Shared with my privately:

Hypothesis (unchecked): if you run this migration (74/03_membership_tables_event_stream_ordering.sql.postgres) before you run this background update (replace_stream_ordering_column) you’re going to end up in a world of pain.

@clokep
Copy link
Member

clokep commented Sep 8, 2023

So there's a couple of things here:

  1. How do we fix @gpetters94's broken database?
  2. How do we keep others from ending up in the same position?
  3. How do we keep this from happening in the future?

Let's start with the first one. Note that we highly don't recommend manually modifying your database without input from us.

Our goal is to get the background updates to "catch-up" and finish before some of the foreground updates have run.

Looking at #15677 I think the manual fixes in there are "correct", but the automated fixed added in #15887 might not be working properly? Or might not have worked yet, it seems to require that index_stream_ordering2 has run, but replace_stream_ordering_column has not.

Looking at the background updates given above, but then the logs given above it looks like some additional background updates have run now and in-fact you should have the needed index:

2023-08-29 17:21:36,010 - synapse.storage.background_updates - 461 - INFO - background_updates-0 - Starting update batch on background update 'index_stream_ordering2'
2023-08-29 17:21:36,014 - synapse.storage.background_updates - 740 - INFO - background_updates-0 - Adding index events_stream_ordering to events

Just to double check, is this still failing with the same error? Can you redump the applied background updates and confirm which version of Synapse you're now running?

@damienvancouver
Copy link

damienvancouver commented Sep 8, 2023

I was able to fix my broken database with the following workaround. All commands below ran as root (or you can add "sudo" first if you aren't the root user)

  • Stop matrix-synapse service: systemctl stop matrix-synapse
  • Using your favourite text editor, edit the file /opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/schema/__init__.py. e.g. nano /opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/storage/schema/__init__.py (if it's a file not found see the instructions at the bottom for finding the right path).
  • Adjust the line: SCHEMA_VERSION = 80 # remember to update the list below when updating and change the 80 to 78, so the line now reads: SCHEMA_VERSION = 78 # CHANGED FROM 80 remember to update the list below when updating . Note that the SCHEMA_VERSION might not be 80 any more by the time you are reading this. Change it to 78 still (we are trying to prevent update 79 running) but make note of what it was so you can change it back!
  • Save the init.py file
  • Now restart synapse with: systemctl start matrix-synapse. Matrix will start up but it will not try and apply schema update 79. Update 78 is going to take a while depending on how big your events table is. It took me several hours with 600k event rows. Tail the log file (tail -f /var/log/matrix-synapse/homeserver.log and ctrl-C to exit), so you can see when it's finally finished applying the update 79 updates, it's fairly obvious once that starts happening, there will be no more log file entries of the job running and it will just be "normal" matrix logs because your clients will be reconnected (yay!).
  • When the updates are finished, we need to allow updates 79+ to run. Shut down matrix again (briefly): systemctl stop matrix-synapse
  • Now return or re-launch your text edit of __init__.py
  • Change the line back to how it was (SCHEMA_VERSION = 80 or whatever you changed from)
  • Now save and exit the editor
  • restart matrix with systemctl start matrix-synapse
  • Updates 79 and 80 will apply cleanly, you are done!

Things that might go wrong:

If you didn't install via the matrix.org repo packages, your __init__.py might be in a different spot. Try to find your top level matrix dir with which matrix-homeserver .. then go one folder up from that (it will be in the matrix-dir/bin ) and run the command grep -r SCHEMA_VERSION and it should return a bunch of results from the __init__.py you are looking for.

If you restart too early before those background updates are done, it will crash the same way again. Just repeat the process but wait longer!

I hope this helps out, it totally worked for me. In hindsight I should have gone from the Debian 10 backports package to the Debian 11 backports package (which is v78), before going to the matrix.org package which is v80. For those who read the warnings in time, that upgrade path should avoid this problem and the need for a workaround.

@jalin2
Copy link

jalin2 commented Sep 24, 2023

Subscribed. I believe I have the same problem. Stuck on v1.88.0. When I try to upgrade to v1.89.0 or later it errors out.

docker logs from postgres container:
2023-09-24 04:31:08.285 UTC [116] STATEMENT:

                  ALTER TABLE current_state_events ADD CONSTRAINT event_stream_ordering_fkey
  
                  FOREIGN KEY (event_stream_ordering) REFERENCES events(stream_ordering2) NOT VALID;

docker logs from synapse container:

    2023-09-24 00:34:09,393 - synapse.app.homeserver - 350 - INFO - main - Setting up server
    
    2023-09-24 00:34:09,393 - synapse.server - 336 - INFO - main - Setting up.
    
    2023-09-24 00:34:09,410 - synapse.storage.databases - 66 - INFO - main - [database config 'master']: Checking database server
    
    2023-09-24 00:34:09,415 - synapse.storage.databases - 69 - INFO - main - [database config 'master']: Preparing for databases ['main', 'state']
    
    2023-09-24 00:34:09,415 - synapse.storage.prepare_database - 120 - INFO - main - ['main', 'state']: Checking existing schema version
    
    2023-09-24 00:34:09,427 - synapse.storage.prepare_database - 124 - INFO - main - ['main', 'state']: Existing schema is 79 (+0 deltas)
    
    2023-09-24 00:34:09,427 - synapse.storage.databases.main - 323 - INFO - main - Checking database for consistency with configuration...
    
    2023-09-24 00:34:09,431 - synapse.storage.prepare_database - 418 - INFO - main - Applying schema deltas for v79
    
    2023-09-24 00:34:09,436 - synapse.storage.prepare_database - 534 - INFO - main - Applying engine-specific schema 79/03_read_write_locks_triggers.sql.postgres
    
    2023-09-24 00:34:09,624 - synapse.storage.prepare_database - 509 - INFO - main - Running 79/04_mitigate_stream_ordering_update_race.py:run_create
    
    2023-09-24 00:34:09,677 - 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 353, in setup
    
        hs.setup()
    
      File "/usr/local/lib/python3.11/site-packages/synapse/server.py", line 338, 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(

@fidoman
Copy link

fidoman commented Nov 7, 2023

I have the same issue upgrading from 1.53 to 1.95.1.
So I restored database from backup and currently installing 1.71.0.
I think it would be resonable to deny start-up in newer version if schema is too old and to give user message to install older version first.

@clokep
Copy link
Member

clokep commented Nov 8, 2023

I think it would be resonable to deny start-up in newer version if schema is too old and to give user message to install older version first.

This is essentially the idea behind #16397.

@DMRobertson
Copy link
Contributor

@gpetters94, are you able to answer Patrick's questions from #16192 (comment)?

Just to double check, is this still failing with the same error? Can you redump the applied background updates and confirm which version of Synapse you're now running?

@jalin2
Copy link

jalin2 commented Nov 25, 2023

I was able to fix my issue which looked like it had 2 problems within (#16192 (comment))

  1. The background updates were stuck and it seemed to be related to duplicate entries in the db. The following issue helped me to identify and delete those duplicate entries in the db (Background update fails with: UniqueViolation e2e_cross_signing_keys_stream_idx #8781 (comment)). After the duplicates were deleted the background updates were chugging along again but then got stuck again.

  2. The second error gave the following in the log:

psycopg2.errors.DependentObjectsStillExist: cannot drop column stream_ordering of table events because other objects depend on it

DETAIL: constraint event_stream_ordering_fkey on table current_state_events depends on column stream_ordering of table events

constraint event_stream_ordering_fkey on table local_current_membership depends on column stream_ordering of table events

constraint event_stream_ordering_fkey on table room_memberships depends on column stream_ordering of table events

To get around this problem I used the work around from this issue (#15677).

After apply the second workaround the background_updates table eventually emptied and then updating to v1.96.1 went smoothly.

I hope this may help others that may be in my situation

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
A-Background-Updates Filling in database columns, making the database eventually up-to-date A-Database DB stuff like queries, migrations, new/remove columns, indexes, unexpected entries in the db O-Uncommon Most users are unlikely to come across this or unexpected workflow S-Major Major functionality / product severely impaired, no satisfactory workaround. X-Needs-Info This issue is blocked awaiting information from the reporter
Projects
None yet
Development

No branches or pull requests

6 participants