Synapse has accepted a power levels event with a malformed notifications field into current state

[grinapo]

Description

Got this:

2022-11-02 09:11:36,627 - synapse.http.server - 123 - ERROR - PUT-135075- Failed handle request via 'RoomSendEventRestServlet': <XForwardedForRequest at 0x7f3599a141c0 method='PUT' uri='/_matrix/client/r0/rooms/!YcwkOsrOwEmdsTNhLw%3Agrin.hu/send/m.roo
m.message/m1667376581869.55' clientproto='HTTP/1.1' site='8184'>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1660, in _inlineCallbacks
    result = current_context.run(gen.send, result)
StopIteration: [{'event_id': '$TrLPKO9P_8gk83KOmnp0U3JrDgHucIcbMz7JMSuyX5A', 'depth': 1499}]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
[...]
  File "/usr/lib/python3/dist-packages/synapse/push/bulk_push_rule_evaluator.py", line 296, in action_for_event_by_user
    for user_id, level in notification_levels.items():
AttributeError: 'int' object has no attribute 'items'

Steps to reproduce

This was a response to a m.room.message, which may have been misformatted?

Homeserver

grin.hu

Synapse Version

1.69.0

Installation Method

Other (please mention below)

Platform

Debian package from debian.
OS: Debian/bookworm (and some sid due to deps), amd64.

Relevant log output

2022-11-02 09:11:36,627 - synapse.http.server - 123 - ERROR - PUT-135075- Failed handle request via 'RoomSendEventRestServlet': <XForwardedForRequest at 0x7f3599a141c0 method='PUT' uri='/_matrix/client/r0/rooms/!YcwkOsrOwEmdsTNhLw%3Agrin.hu/send/m.roo
m.message/m1667376581869.55' clientproto='HTTP/1.1' site='8184'>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1660, in _inlineCallbacks
    result = current_context.run(gen.send, result)
StopIteration: [{'event_id': '$TrLPKO9P_8gk83KOmnp0U3JrDgHucIcbMz7JMSuyX5A', 'depth': 1499}]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/synapse/http/server.py", line 306, in _async_render_wrapper
    callback_return = await self._async_render(request)
  File "/usr/lib/python3/dist-packages/synapse/http/server.py", line 512, in _async_render
    callback_return = await raw_callback_return
  File "/usr/lib/python3/dist-packages/synapse/rest/client/room.py", line 353, in on_POST
    ) = await self.event_creation_handler.create_and_send_nonmember_event(
  File "/usr/lib/python3/dist-packages/synapse/handlers/message.py", line 1020, in create_and_send_nonmember_event
    ev = await self.handle_new_client_event(
  File "/usr/lib/python3/dist-packages/synapse/util/metrics.py", line 113, in measured_func
    r = await func(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/synapse/handlers/message.py", line 1382, in handle_new_client_event
    result, _ = await make_deferred_yieldable(
  File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1660, in _inlineCallbacks
    result = current_context.run(gen.send, result)
  File "/usr/lib/python3/dist-packages/synapse/handlers/message.py", line 1436, in _persist_events
    await self._bulk_push_rule_evaluator.action_for_event_by_user(
  File "/usr/lib/python3/dist-packages/synapse/util/metrics.py", line 113, in measured_func
    r = await func(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/synapse/push/bulk_push_rule_evaluator.py", line 296, in action_for_event_by_user
    for user_id, level in notification_levels.items():
AttributeError: 'int' object has no attribute 'items'

Anything else that would be useful to know?

No response

[grinapo]

Or maybe it's related to room state, since upgrade gives also a funny result:
https://matrix.grin.hu:8448/_matrix/client/r0/rooms/!YcwkOsrOwEmdsTNhLw%3Agrin.hu/upgrade

{"new_version":"10"}

and the server response was

{"errcode":"M_BAD_JSON","error":"\"notifications\": 150 is not of type 'object'"}

[DMRobertson]

What is the content of the current power levels event in that room (as seen by your server)?

[DMRobertson]

Reminds me a bit of #14060.

[DMRobertson]

What is the content of the current power levels event in that room (as seen by your server)?

The following DB query will answer this:

SELECT json
FROM  current_state_events cse 
    JOIN event_json USING(event_id)
WHERE cse.room_id = '!YcwkOsrOwEmdsTNhLw:grin.hu' AND cse.type = 'm.room.power_levels' AND cse.state_key = ''
;

Alternatively you could make a /state/... request to get the content via the API.

[grinapo]

{ "ban":800,
"events": 
{"im.vector.modular.widgets":400, "m.room.avatar":400, "m.room.canonical_alias":400, 
"m.room.history_visibility":400, "m.room.name":500, "m.room.power_levels":900, 
"m.room.topic":400}, 
"events_default":10, "invite":50, "kick":700, "notifications":150, "redact":25, "state_default":400, 
"users": {"xxx": 1000000} ,
"users_default":100}

Oh. I see that's a non-synapse created room.
Seems that the reason is that synapse still lives in 0-100 land. 🤷

[DMRobertson]

No, the reason is that notifications is malformed. Quoting from https://spec.matrix.org/v1.4/client-server-api/#mroompower_levels:

notifications: The power level requirements for specific notification types. This is a mapping from key to power level for that notifications key.

To fix this: change the state of the room so that the power levels has "notifications": {"room": 150}.

Oh. I see that's a non-synapse created room.

Might be worth filing a bug against whichever server created the room (edit: and/or whichever client set those power levels): that's an invalid power levels event.

Equally: Synapse should have rejected that power levels event when it joined the room, so we have a bug of our own.

[DMRobertson]

Before room v10 we allowed a sloppier notifications field. See https://spec.matrix.org/v1.4/rooms/v10/.

I'm not 100% convinced this was legit under old rooms, but if it was we shouldn't internally error like this.