Synapse: Leaving room throws 500 internal error

[nomelif]

Description

Synapse throws a 500 internal error when I try to leave a room.

Steps to reproduce

• Attempt to leave a room.

This is only broken for me with the postmarketOS offtopic channel for some reason. I have moved synapse twice via postgres dump. I don't know whether that has had an effect on the integrity of my data base. I was trying to leave the room in the first place because new messages stopped being received (into that specific room, other rooms work). They were being received for some time (months) after the second migration though.

What I expected: room is left successfully
What happened: a 500 error is thrown, the room is not left.

I got a clear error from journalctl:

Jul 20 13:00:33 puppisnix synapse[5556]: synapse.access.http.8008: [OPTIONS-1160] - - 8008 - {None} Processed request: 0.003sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 2B 200 "OPTIONS /_matrix/client/r0/rooms/!VYsYJQNEpQSJlMMxiC%3Afam-ribbers.com/leave HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Riot/1.6.7 Chrome/78.0.3904.130 Electron/7.3.0 Safari/537.36" [0 dbevts]
Jul 20 13:00:33 puppisnix synapse[5556]: synapse.http.server: [POST-1161] Failed handle request via 'RoomMembershipRestServlet': <XForwardedForRequest at 0x7f5484f090 method='POST' uri='/_matrix/client/r0/rooms/!VYsYJQNEpQSJlMMxiC%3Afam-ribbers.com/leave' clientproto='HTTP/1.0' site=8008>
Traceback (most recent call last):
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/http/server.py", line 228, in _async_render_wrapper
callback_return = await self._async_render(request)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/http/server.py", line 399, in _async_render
callback_return = await raw_callback_return
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/rest/client/v1/room.py", line 746, in on_POST
content=event_content,
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 285, in update_membership
require_consent=require_consent,
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 501, in _update_membership
require_consent=require_consent,
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 198, in _local_membership_update
requester, event, context, extra_users=[target], ratelimit=ratelimit
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/util/metrics.py", line 73, in measured_func
r = await func(self, *args, **kwargs)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/handlers/message.py", line 864, in handle_new_client_event
requester, event, context, ratelimit=ratelimit, extra_users=extra_users
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/handlers/message.py", line 1079, in persist_and_notify_client_event
event, context=context
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 149, in handle_queue_loop
ret = await per_item_callback(item)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 259, in persisting_queue
item.events_and_contexts, backfilled=item.backfilled
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 324, in _persist_events
room_id, ev_ctx_rm, latest_event_ids
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 485, in _calculate_new_extremities
e_id for event in new_events for e_id in event.prev_event_ids()
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
result = result.throwExceptionIntoGenerator(g)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
return g.throw(self.type, self.value, self.tb)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/data_stores/main/events.py", line 333, in _get_prevs_before_rejected
"_get_prevs_before_rejected", _get_prevs_before_rejected_txn, chunk
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
result = result.throwExceptionIntoGenerator(g)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
return g.throw(self.type, self.value, self.tb)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/database.py", line 525, in runInteraction
**kwargs
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
result = result.throwExceptionIntoGenerator(g)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
return g.throw(self.type, self.value, self.tb)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/database.py", line 573, in runWithConnection
self._db_pool.runWithConnection(inner_func, *args, **kwargs)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
result = inContext.theWork()
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/context.py", line 122, in callWithContext
return self.currentContext().callWithContext(ctx, func, *args, **kw)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/context.py", line 85, in callWithContext
return func(*args,**kw)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 306, in _runWithConnection
compat.reraise(excValue, excTraceback)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/compat.py", line 464, in reraise
raise exception.with_traceback(traceback)
File "/nix/store/6fpiyl8g17n47fk1b37ivq12874zrix3-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 297, in _runWithConnection
result = func(conn, *args, **kw)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/database.py", line 570, in inner_func
return func(conn, *args, **kwargs)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/database.py", line 416, in new_transaction
r = func(cursor, *args, **kwargs)
File "/nix/store/8vh43w13g29bkgjapwb0a6yg5rpc49iq-matrix-synapse-1.17.0/lib/python3.7/site-packages/synapse/storage/data_stores/main/events.py", line 326, in _get_prevs_before_rejected_txn
soft_failed = json.loads(metadata).get("soft_failed")
File "/nix/store/b7q8gw17aqxqqcvw3nqmw9pv4fx231iy-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/init.py", line 525, in loads
return _default_decoder.decode(s)
File "/nix/store/b7q8gw17aqxqqcvw3nqmw9pv4fx231iy-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/decoder.py", line 370, in decode
obj, end = self.raw_decode(s)
File "/nix/store/b7q8gw17aqxqqcvw3nqmw9pv4fx231iy-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/decoder.py", line 392, in raw_decode
raise TypeError("Input string must be text, not bytes")
TypeError: Input string must be text, not bytes

Version information

• Homeserver: puppisrausku.dy.fi

If not matrix.org:

• Version: 1.17.0

$ curl http://localhost:8008/_synapse/admin/v1/server_version
{"server": {"name": "Synapse", "version": "1.17.0"}}

This was broken for the two previous matrix versions from nixpkgs as well. I hoped that the updates would fix it.

• Install method: installed through nixpkgs, package nixpkgs.matrix-synapse
  

• Platform: NixOS 20.03 running on a raspi 4 (non-virtual)

[chell@puppisnix:~]$ uname -a
Linux puppisnix 4.19.75 #1-NixOS SMP Thu Jan 1 00:00:01 UTC 1970 aarch64 GNU/Linux

[clokep]

This was broken for the two previous matrix versions from nixpkgs as well. I hoped that the updates would fix it.

Do you happen to know what those versions were?

We have messed a bit with JSON stuff recently (see #7674).

[anoadragon453]

Looks like the relevant code lines have been changed (after v1.17.0): https://github.com/matrix-org/synapse/commit/f460da6031d01b2b271ded097ed6be65fd1b24f9#diff-5a0797e349006661a23d6b420d7735d1

[clokep]

@anoadragon453 Ah, yeah I wonder if something came in as the wrong data type ("I have moved synapse twice via postgres dump. I don't know whether that has had an effect on the integrity of my data base.") If so, that PR should fix it.

[anoadragon453]

@nomelif Please let us know if this issue is resolved in the next Synapse release. You may also try running on the latest develop branch (but it is not recommended for a production instance).

[nomelif]

This was broken for the two previous matrix versions from nixpkgs as well. I hoped that the updates would fix it.

Do you happen to know what those versions were?

We have messed a bit with JSON stuff recently (see #7674).

Looking at the git blame for nixpkgs, the previous version they distributed was 1.16.1 and the one before was 1.15.2.

[nomelif]

@nomelif Please let us know if this issue is resolved in the next Synapse release. You may also try running on the latest develop branch (but it is not recommended for a production instance).

I'll let you know. I don't want to mess around with multiple versions of synapse if the case happens to be that my db is flaky, tho.

[nomelif]

@anoadragon453 Ah, yeah I wonder if something came in as the wrong data type ("I have moved synapse twice via postgres dump. I don't know whether that has had an effect on the integrity of my data base.") If so, that PR should fix it.

I wonder if I could see what postgres returns somehow.

[nomelif]

Have updated my synapse to 1.18.0 (as it landed in nixpkgs-stable) but this is still broken.

[nomelif]

From journalctl:

Aug 01 11:36:17 puppisnix synapse[21688]: synapse.access.http.8008: [OPTIONS-196] - - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 0B 204 "OPTIONS /_matrix/client/r0/rooms/!VYsYJQNEpQSJlMMxiC%3Afam-ribbers.com/leave HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.7.2 Chrome/83.0.4103.94 Electron/9.0.2 Safari/537.36" [0 dbevts]
Aug 01 11:36:18 puppisnix synapse[21688]: root: [persist_events-3] Tried to decode 'None' as JSON and failed
Aug 01 11:36:18 puppisnix synapse[21688]: synapse.http.server: [POST-197] Failed handle request via 'RoomMembershipRestServlet': <XForwardedForRequest at 0x7f5abc3890 method='POST' uri='/_matrix/client/r0/rooms/!VYsYJQNEpQSJlMMxiC%3Afam-ribbers.com/leave' clientproto='HTTP/1.0' site=8008>
                                          Traceback (most recent call last):
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/http/server.py", line 228, in _async_render_wrapper
                                              callback_return = await self._async_render(request)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/http/server.py", line 399, in _async_render
                                              callback_return = await raw_callback_return
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/rest/client/v1/room.py", line 747, in on_POST
                                              content=event_content,
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 285, in update_membership
                                              require_consent=require_consent,
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 501, in _update_membership
                                              require_consent=require_consent,
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/handlers/room_member.py", line 198, in _local_membership_update
                                              requester, event, context, extra_users=[target], ratelimit=ratelimit
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/util/metrics.py", line 73, in measured_func
                                              r = await func(self, *args, **kwargs)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/handlers/message.py", line 878, in handle_new_client_event
                                              requester, event, context, ratelimit=ratelimit, extra_users=extra_users
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/handlers/message.py", line 1094, in persist_and_notify_client_event
                                              event, context=context
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 148, in handle_queue_loop
                                              ret = await per_item_callback(item)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 258, in persisting_queue
                                              item.events_and_contexts, backfilled=item.backfilled
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 323, in _persist_events
                                              room_id, ev_ctx_rm, latest_event_ids
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/persist_events.py", line 484, in _calculate_new_extremities
                                              e_id for event in new_events for e_id in event.prev_event_ids()
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
                                              result = result.throwExceptionIntoGenerator(g)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
                                              return g.throw(self.type, self.value, self.tb)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/data_stores/main/events.py", line 306, in _get_prevs_before_rejected
                                              "_get_prevs_before_rejected", _get_prevs_before_rejected_txn, chunk
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
                                              result = result.throwExceptionIntoGenerator(g)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
                                              return g.throw(self.type, self.value, self.tb)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/database.py", line 525, in runInteraction
                                              **kwargs
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
                                              result = result.throwExceptionIntoGenerator(g)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
                                              return g.throw(self.type, self.value, self.tb)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/database.py", line 573, in runWithConnection
                                              self._db_pool.runWithConnection(inner_func, *args, **kwargs)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
                                              result = inContext.theWork()
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
                                              inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/context.py", line 122, in callWithContext
                                              return self.currentContext().callWithContext(ctx, func, *args, **kw)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/context.py", line 85, in callWithContext
                                              return func(*args,**kw)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 306, in _runWithConnection
                                              compat.reraise(excValue, excTraceback)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/python/compat.py", line 464, in reraise
                                              raise exception.with_traceback(traceback)
                                            File "/nix/store/vkjhkf40njamh7h257dcw1vy9963g95g-python3.7-Twisted-20.3.0/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 297, in _runWithConnection
                                              result = func(conn, *args, **kw)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/database.py", line 570, in inner_func
                                              return func(conn, *args, **kwargs)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/database.py", line 416, in new_transaction
                                              r = func(cursor, *args, **kwargs)
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/data_stores/main/events.py", line 299, in _get_prevs_before_rejected_txn
                                              soft_failed = db_to_json(metadata).get("soft_failed")
                                            File "/nix/store/nkj4rasgvnf0ix9nzvw3zpmy5n7zwbvr-matrix-synapse-1.18.0/lib/python3.7/site-packages/synapse/storage/_base.py", line 109, in db_to_json
                                              return json.loads(db_content)
                                            File "/nix/store/87yihjqc6hyjc0vm41y554grgdrg9l92-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/__init__.py", line 525, in loads
                                              return _default_decoder.decode(s)
                                            File "/nix/store/87yihjqc6hyjc0vm41y554grgdrg9l92-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/decoder.py", line 370, in decode
                                              obj, end = self.raw_decode(s)
                                            File "/nix/store/87yihjqc6hyjc0vm41y554grgdrg9l92-python3.7-simplejson-3.17.0/lib/python3.7/site-packages/simplejson/decoder.py", line 392, in raw_decode
                                              raise TypeError("Input string must be text, not bytes")
                                          TypeError: Input string must be text, not bytes
Aug 01 11:36:18 puppisnix synapse[21688]: synapse.access.http.8008: [POST-197] - - 8008 - {@fsmnarmosta:puppisrausku.dy.fi} Processed request: 0.164sec/0.001sec (0.037sec, 0.000sec) (0.011sec/0.014sec/5) 55B 500 "POST /_matrix/client/r0/rooms/!VYsYJQNEpQSJlMMxiC%3Afam-ribbers.com/leave HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.7.2 Chrome/83.0.4103.94 Electron/9.0.2 Safari/537.36" [0 dbevts]
Aug 01 11:36:18 puppisnix synapse[21688]: synapse.logging.context: [POST-197] Re-starting finished log context POST-197

[nomelif]

If my db is the problem, would there be a way to see that by messing with psql directly?

[auscompgeek]

This log message in particular seems interesting:

root: [persist_events-3] Tried to decode 'None' as JSON and failed

As it turns out, the TypeError message from simplejson is extremely misleading and actually means whatever was passed in here was not a str or bytes (not necessarily that a bytes was passed).

So my hypothesis is that at least one row in the event_json table has NULL in the internal_metadata column.

[erikjohnston]

@nomelif can you check to see if there are any NULLs in your DB? SELECT * FROM event_json WHERE internal_metadata IS NULL LIMIT 5?

[nomelif]

No nulls:

synapse=> SELECT COUNT(*) FROM event_json WHERE internal_metadata IS NULL;
 count 
-------
     0
(1 row)

[nomelif]

Stronger statement: there is no column with nulls in that table

synapse=> SELECT * FROM event_json  WHERE event_id IS NULL;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

synapse=> SELECT * FROM event_json  WHERE room_id IS NULL;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

synapse=> SELECT * FROM event_json  WHERE internal_metadata IS NULL;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

synapse=> SELECT * FROM event_json  WHERE json IS NULL;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

synapse=> SELECT * FROM event_json  WHERE format_version IS NULL;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

[erikjohnston]

Interesting. Can you try: SELECT DISTINCT pg_typeof(internal_metadata) FROM event_json ;?

[nomelif]

Only text

synapse=> SELECT DISTINCT pg_typeof(internal_metadata) FROM event_json ;
 pg_typeof 
-----------
 text
(1 row)

[nomelif]

For some reason trying to join a room also fails. I haven't managed to get a good error yet tho.

[erikjohnston]

Hmm, the last thing I can think of trying is SELECT * FROM event_json WHERE internal_metadata NOT LIKE '{%' LIMIT 5;

[nomelif]

synapse=> SELECT * FROM event_json WHERE internal_metadata NOT LIKE '{%' LIMIT 5;
 event_id | room_id | internal_metadata | json | format_version 
----------+---------+-------------------+------+----------------
(0 rows)

[nomelif]

Would there be a way to figure out the exact request synapse is making?

[erikjohnston]

You could turn up logging for SQL temporarily, though its very very verbose:

    synapse.storage.txn:
        level: DEBUG

    synapse.storage.SQL:
        level: DEBUG

[nomelif]

I have installed the thing through nix and configured it statelessly. I don't really have writable config files

[nomelif]

I'll try to figure out if I can catch the queries on the postgres side

[auscompgeek]

I have installed the thing through nix and configured it statelessly. I don't really have writable config files

Can't you change the log config in your nix config?

[ptman]

should be possible: https://nixos.org/nixos/options.html#services.matrix-synapse.logconfig

[PC-Admin]

Quite frustrating when you're trying to clear your client out a bit and you just encounter this over and over:

I assume it's the same error mentioned here.

[richvdh]

I assume it's the same error mentioned here.

this is likely to be a bad assumption. Please open a new issue and share the server logs.

[richvdh]

@nomelif are you still seeing this problem? there's likely little we can do to help unless you are able to adjust your logging settings.