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

Error joining a state compressed room #4372

Closed
mytbk opened this issue Jan 10, 2019 · 14 comments
Closed

Error joining a state compressed room #4372

mytbk opened this issue Jan 10, 2019 · 14 comments

Comments

@mytbk
Copy link

mytbk commented Jan 10, 2019

I don't know whether it has something to do with the state_groups_state compression. I now have problem joining a room, whose state is compressed a few days ago.

I'm using synapse 0.34.0-3 from Debian buster.

2019-01-10 02:48:49,763 - synapse.http.server - 112 - ERROR - POST-135913- Failed handle request via <function JsonResource._async_render at 0x7fbab39a32f0>: <XForwardedForRequest at 0x7fba3a7e7898 method='POST' uri='/_matrix/client/r0/join/%23freenode_%23archlinux-cn-offtopic%3Amatrix.org' clientproto='HTTP/1.1' site=8008>: Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
--- <exception caught here> ---
  File "/usr/lib/python3/dist-packages/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/http/server.py", line 316, in _async_render
    callback_return = yield callback(request, **kwargs)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/rest/client/v1/room.py", line 282, in on_POST
    third_party_signed=content.get("third_party_signed", None),
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/handlers/room_member.py", line 254, in update_membership
    content=content,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/handlers/room_member.py", line 451, in _update_membership
    content=content,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/handlers/room_member.py", line 201, in _local_membership_update
    ratelimit=ratelimit,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/util/metrics.py", line 63, in measured_func
    r = yield func(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/handlers/message.py", line 647, in handle_new_client_event
    extra_users=extra_users,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/handlers/message.py", line 778, in persist_and_notify_client_event
    event, context=context
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 305, in persist_event
    yield make_deferred_yieldable(deferred)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 157, in handle_queue_loop
    ret = yield per_item_callback(item)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 316, in persisting_queue
    backfilled=item.backfilled,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 198, in f
    res = yield func(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 493, in _persist_events
    new_forward_extremeties=new_forward_extremeties,
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 326, in runInteraction
    *args, **kwargs
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 375, in runWithConnection
    inner_func, *args, **kwargs
  File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python3/dist-packages/twisted/enterprise/adbapi.py", line 306, in _runWithConnection
    compat.reraise(excValue, excTraceback)
  File "/usr/lib/python3/dist-packages/twisted/python/compat.py", line 464, in reraise
    raise exception.with_traceback(traceback)
  File "/usr/lib/python3/dist-packages/twisted/enterprise/adbapi.py", line 297, in _runWithConnection
    result = func(conn, *args, **kw)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 371, in inner_func
    return func(conn, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 247, in _new_transaction
    r = func(txn, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/synapse/util/logutils.py", line 88, in wrapped
    return f(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 809, in _persist_events_txn
    self._update_current_state_txn(txn, state_delta_for_room, max_stream_order)
  File "/usr/lib/python3/dist-packages/synapse/storage/events.py", line 925, in _update_current_state_txn
    for (etype, state_key), ev_id in iteritems(to_insert)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 91, in executemany
    self._do_execute(self.txn.executemany, sql, *args)
  File "/usr/lib/python3/dist-packages/synapse/storage/_base.py", line 118, in _do_execute
    sql, *args
psycopg2.ProgrammingError: more than one row returned by a subquery used as an expression
2019-01-10 02:48:49,767 - synapse.access.http.8008 - 302 - INFO - POST-135913- 115.27.203.126 - 8008 - {@vimacs:matrixim.cc} Processed request: 1.548sec/0.003sec (0.171sec, 0.043sec) (0.018sec/1.094sec/16) 67B 500 "POST /_matrix/client/r0/join/%23freenode_%23archlinux-cn-offtopic%3Amatrix.org HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64; rv:64.0) Gecko/20100101 Firefox/64.0" [3 dbevts]
@erikjohnston
Copy link
Member

So this looks to be due to the query: https://github.com/matrix-org/synapse/blob/master/synapse/storage/events.py#L903-L909, which is weird because the error suggests the table has current_state_events duplicate for a set of room_id, type and state_key. However, there should be a unique index on that table preventing that. Could you log into the DB and run \d current_state_events please? That should tell us what state the schema is in.

Either way, this looks to be a problem with current_state_events table, which isn't touched by the state compressor.

@erikjohnston erikjohnston transferred this issue from matrix-org/rust-synapse-compress-state Jan 10, 2019
@erikjohnston
Copy link
Member

(I've transferred the issue to the synapse repo)

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019 

        Table "public.current_state_events"
  Column   | Type | Collation | Nullable | Default 
-----------+------+-----------+----------+---------
 event_id  | text |           | not null | 
 room_id   | text |           | not null | 
 type      | text |           | not null | 
 state_key | text |           | not null | 
Indexes:
    "current_state_events_event_id_key" UNIQUE CONSTRAINT, btree (event_id)
    "current_state_events_member_index" btree (state_key) WHERE type = 'm.room.member'::text

@erikjohnston
Copy link
Member

How bizarre. Is there any chance you've fiddled with the database? Did you port from an sqlite database?

The unique index has been defined on that table since a very very early version of synapse.

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019 •
edited
Loading

The database had some error on WAL some time ago. At that time I ran a pg_dump, drop the database, and imported the dump. Maybe I screwed up the database since then.

So how can I recover from this?

@erikjohnston
Copy link
Member

That should've worked as far as I know.

You can add the unique constraint back in by:

ALTER TABLE current_state_events 
    ADD CONSTRAINT current_state_events_room_id_type_state_key_key
    UNIQUE (room_id, type, state_key);

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019

So now I try to add a unique constraint, and get:

ERROR:  could not create unique index "current_state_events_room_id_type_state_key_key"
DETAIL:  Key (room_id, type, state_key)=(!SudviOJlimDvrGdFCY:matrix.org, m.room.member, @freenode_thrrgilag__:matrix.org) is duplicated.
CONTEXT:  parallel worker

@erikjohnston
Copy link
Member

Annoying. If you query for that row are the event_ids the same? If so you can just delete the duplicates (ensuring there is one row left).

Let me dig out a query that will fix conflicts where the event IDs are different

@erikjohnston
Copy link
Member

In fact, I'd be interested to see the output of:

SELECT room_id, type, state_key, array_to_string(array_agg(DISTINCT event_id), E'\n')
FROM current_state_events
GROUP BY room_id, type, state_key
HAVING count(*) > 1;

which will output all duplicate rows. Feel free to DM me if you don't want to post it on public GH :)

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019

I got 113 duplicate rows: https://matrixim.cc/dup.txt

@erikjohnston
Copy link
Member

They all look like large public rooms (mostly IRC bridged rooms). I'd be very tempted to have your server leave those rooms (by having all your uses leave the rooms), doing a DELETE FROM current_state_events WHERE room_id = ? and then rejoining those rooms.

However, I've looked up what the correct rows for the current state should be and are:
answers.txt. You should be able to delete the duplicates, insert the correct answers and then add the constraint

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019

What if just removing a room from current_state_events without having all the users on the server leaving the room?

@erikjohnston
Copy link
Member

Err, bad things would probably end up happening, but I'm not 100% sure what they would be off the top of my head

@mytbk
Copy link
Author

mytbk commented Jan 10, 2019

Now I removed the duplications and can join the room now, thanks.

@mytbk mytbk closed this as completed Jan 10, 2019
@gergelypolonkai gergelypolonkai mentioned this issue Oct 14, 2019
Closed
@MurzNN MurzNN mentioned this issue Jan 11, 2021
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mytbk @erikjohnston