psycopg2.errors.UniqueViolation: could not create unique index "receipts_graph_unique_index"

[MTRNord]

Description

It seems like it has some unique index issue for me.

Steps to reproduce

I have no idea :/

Homeserver

matrix.midnightthoughts.space

Synapse Version

{"server_version":"1.68.0","python_version":"3.9.14"}

Installation Method

Docker (matrixdotorg/synapse)

Platform

Running in docker/kubernetes/cri-o on a gentoo system.

Relevant log output

2022-10-10 16:50:14,874 - synapse.storage.background_updates - 428 - INFO - background_updates-0- Starting update batch on background update 'receipts_graph_unique_index'
2022-10-10 16:50:14,877 - synapse.storage.background_updates - 620 - INFO - background_updates-0- Adding index receipts_graph_unique_index to receipts_graph
2022-10-10 16:50:14,949 - synapse.storage.background_updates - 299 - ERROR - background_updates-0- Error doing update
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/background_updates.py", line 291, in run_background_updates
    result = await self.do_next_background_update(sleep)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/background_updates.py", line 421, in do_next_background_update
    await self._do_background_update(desired_duration_ms)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/background_updates.py", line 464, in _do_background_update
    items_updated = await update_handler(progress, batch_size)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/background_updates.py", line 621, in updater
    await self.db_pool.runWithConnection(runner)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/database.py", line 976, in runWithConnection
    return await make_deferred_yieldable(
  File "/usr/local/lib/python3.9/site-packages/twisted/python/threadpool.py", line 244, in inContext
    result = inContext.theWork()  # type: ignore[attr-defined]
  File "/usr/local/lib/python3.9/site-packages/twisted/python/threadpool.py", line 260, in <lambda>
    inContext.theWork = lambda: context.call(  # type: ignore[attr-defined]
  File "/usr/local/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
    return func(*args, **kw)
  File "/usr/local/lib/python3.9/site-packages/twisted/enterprise/adbapi.py", line 282, in _runWithConnection
    result = func(conn, *args, **kw)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/database.py", line 969, in inner_func
    return func(db_conn, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/background_updates.py", line 572, in create_index_psql
    c.execute(sql)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/database.py", line 389, in execute
    self._do_execute(self.txn.execute, sql, *args)
  File "/usr/local/lib/python3.9/site-packages/synapse/storage/database.py", line 432, in _do_execute
    return func(sql, *args, **kwargs)
psycopg2.errors.UniqueViolation: could not create unique index "receipts_graph_unique_index"
DETAIL:  Key (room_id, receipt_type, user_id)=(!watercooler-v9:maunium.net, m.read, @cat:feline.support) is duplicated.

Anything else that would be useful to know?

It seems to try a few times and then aborts trying. This happens on several restarts.

[reivilibre]

Introduced in #13753

[clokep]

Duplicates #14120.

[clokep]

Err, that's not true. Likely related though!

[clokep]

@MTRNord Can you run the following and let me know what it returns:

SELECT thread_id FROM receipts_graph WHERE room_id = '!watercooler-v9:maunium.net' AND receipt_type = 'm.read' AND user_id = '@cat:feline.support'

(The expectation is that it returns a single row, which is null.)

Did you ever enable experimental support for MSC3771 or MSC3773?

---

Let's also take a look at the indexes on that table currently?

SELECT indexname, indexdef FROM pg_indexes WHERE tablename = 'receipts_graph' ORDER BY indexname;

[clokep]

It would also be good to see if the backfill has completed yet:

select * from background_updates;

[MTRNord]

@MTRNord Can you run the following and let me know what it returns:

SELECT thread_id FROM receipts_graph WHERE room_id = '!watercooler-v9:maunium.net' AND receipt_type = 'm.read' AND user_id = '@cat:feline.support'

(The expectation is that it returns a single row, which is null.)

Did you ever enable experimental support for MSC3771 or MSC3773?

I had neither of the 2 MSCs activated.

The output of the query is:

synapse=> SELECT thread_id FROM receipts_graph WHERE room_id = '!watercooler-v9:maunium.net' AND receipt_type = 'm.read' AND user_id = '@cat:feline.support';
 thread_id
-----------


(2 rows)

Let's also take a look at the indexes on that table currently?

SELECT indexname, indexdef FROM pg_indexes WHERE tablename = 'receipts_graph' ORDER BY indexname;

synapse=> SELECT indexname, indexdef FROM pg_indexes WHERE tablename = 'receipts_graph' ORDER BY indexname;
            indexname             |                                                                    indexdef
----------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------
 receipts_graph_unique_index      | CREATE UNIQUE INDEX receipts_graph_unique_index ON public.receipts_graph USING btree (room_id, receipt_type, user_id) WHERE (thread_id IS NULL)
 receipts_graph_uniqueness        | CREATE UNIQUE INDEX receipts_graph_uniqueness ON public.receipts_graph USING btree (room_id, receipt_type, user_id)
 receipts_graph_uniqueness_thread | CREATE UNIQUE INDEX receipts_graph_uniqueness_thread ON public.receipts_graph USING btree (room_id, receipt_type, user_id, thread_id)
(3 rows)

It would also be good to see if the backfill has completed yet:

select * from background_updates;

synapse=> select * from background_updates;
           update_name            | progress_json | depends_on | ordering
----------------------------------+---------------+------------+----------
 receipts_linearized_unique_index | {}            |            |     7007
 receipts_graph_unique_index      | {}            |            |     7007
(2 rows)

[MTRNord]

I hope those help. The error seems to happen anytime I restart synapse.

[clokep]

@MTRNord Sorry for the delay, I missed the notification here.

I'm not really sure how you got multiple of the same receipt in there, maybe the indexes weren't added in quite the proper order by the code. Receipts are mostly transient so I think the easiest thing might be to nuke receipts from that user in that room (once they send a new receipt it should process fine). The user-facing impact of this is that your client wouldn't show their avatar in the timeline until they send a new receipt.

DELETE FROM receipts_graph WHERE room_id = '!watercooler-v9:maunium.net' AND receipt_type = 'm.read' AND user_id = '@cat:feline.support'; 

(Alternately you could try to inspect the two returned rows and try to figure out which is "older" and only delete that one. There's a data column which has a JSON object with a ts field in it you could probably use to do this.)

[MTRNord]

Thanks, I will just nuke that receipt entirely. In the end, there anyway will be a new one eventually :)

[clokep]

Hopefully it is just the one duplicate entry! 👍 Do shout if it works for you (and sorry for the inconvenience...)

[MTRNord]

Hopefully it is just the one duplicate entry! 👍 Do shout if it works for you (and sorry for the inconvenience...)

Yes, there were just 2 entries deleted by that command (it's missing the word WHERE by the way). And nothing exploded yet :D

[clokep]

I'm going to consider this OK. Let me know if you're still seeing an issue.

[MTRNord]

It seems like this is coming back for me again :/ same error but this time my own local user instead.

[squahtx]

We're planning to fix the background update automatically in 1.72.0. Tracked in #14406.