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

Cannot join #html.css:matrix.org from any homeserver #14933

Closed
progval opened this issue Jan 29, 2023 · 7 comments · Fixed by #14942
Closed

Cannot join #html.css:matrix.org from any homeserver #14933

progval opened this issue Jan 29, 2023 · 7 comments · Fixed by #14942
Assignees
@DMRobertson
Labels
A-Federated-Join joins over federation generally suck O-Uncommon Most users are unlikely to come across this or unexpected workflow S-Minor Blocks non-critical functionality, workarounds exist. T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues.

Comments

@progval
Copy link
Contributor

progval commented Jan 29, 2023

Description

#html.css:matrix.org seemingly cannot be joined from any homeserver (tried from e2e.zone, grin.hu, and synapse.test.progval.net)

Steps to reproduce

On either Matrix.org or another homeserver, type /join #html.css:matrix.org

When joined from Matrix.org, the client gets this response: {"errcode":"M_UNKNOWN","error":"Internal server error"}

When joined from another HS (Synapse), here are the logs:

2023-01-29 21:16:06,187 - synapse.access.http.8008 - 450 - INFO - GET-96 - 2a01:cb08:b92:9000:1760:57af:a3d2:76f1 - 8008 - {@valtest:synapse.test.progval.net} Processed request: 30.023sec/0.004sec (0.008sec, 0.000sec) (0.002sec/0.001sec/1) 234B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s291_33919_0_130_69_2_1_1101_0 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0" [0 dbevts]
2023-01-29 21:16:07,377 - synapse.access.http.8008 - 450 - INFO - GET-101 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.001sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:07,436 - synapse.http.matrixfederationclient - 299 - INFO - POST-100 - {GET-O-13} [matrix.org] Completed request: 200 OK in 0.11 secs, got 69 bytes - GET matrix://matrix.org/_matrix/federation/v1/query/directory?room_alias=%23html.css%3Amatrix.org
2023-01-29 21:16:07,451 - synapse.replication.tcp.handler - 720 - WARNING - store_retry_timings-1 - Dropping command as not connected: 'REMOTE_SERVER_UP'
2023-01-29 21:16:07,538 - synapse.access.http.8008 - 450 - INFO - GET-102 - 2a00:1098:84:1c8::157 - 8008 - {None} Processed request: 0.001sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
2023-01-29 21:16:07,597 - synapse.http.matrixfederationclient - 299 - INFO - POST-100 - {GET-O-14} [matrix.org] Completed request: 200 OK in 0.12 secs, got 11 bytes - GET matrix://matrix.org/_matrix/federation/unstable/rooms/%21HLVrjATAChhKivUcLx%3Amatrix.org/complexity
2023-01-29 21:16:07,640 - synapse.access.http.8008 - 450 - INFO - GET-103 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:07,813 - synapse.http.matrixfederationclient - 299 - INFO - POST-100 - {GET-O-15} [matrix.org] Completed request: 200 OK in 0.21 secs, got 508 bytes - GET matrix://matrix.org/_matrix/federation/v1/make_join/%21HLVrjATAChhKivUcLx%3Amatrix.org/%40valtest%3Asynapse.test.progval.net?ver=1&ver=2&ver=3&ver=4&ver=5&ver=6&ver=org.matrix.msc2176&ver=7&ver=8&ver=9&ver=org.matrix.msc3787&ver=10&ver=org.matrix.msc2716v4
2023-01-29 21:16:07,864 - synapse.access.http.8008 - 450 - INFO - GET-104 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:08,017 - synapse.access.http.8008 - 450 - INFO - GET-105 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:08,174 - synapse.http.matrixfederationclient - 629 - INFO - POST-100 - {PUT-O-16} [matrix.org] Got response headers: 500 Internal Server Error
2023-01-29 21:16:08,177 - synapse.http.matrixfederationclient - 672 - INFO - POST-100 - {PUT-O-16} [matrix.org] Request failed: PUT matrix://matrix.org/_matrix/federation/v2/send_join/%21HLVrjATAChhKivUcLx%3Amatrix.org/%24F15MQq3zZibh9VROeuzWNadoFPR4LlyFR5nm8j8sSOE: HttpResponseException('500: Internal Server Error')
2023-01-29 21:16:08,625 - synapse.access.http.8008 - 450 - INFO - GET-106 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:08,767 - synapse.access.http.8008 - 450 - INFO - GET-107 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.000sec, 0.004sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:08,853 - synapse.http.matrixfederationclient - 629 - INFO - POST-100 - {PUT-O-16} [matrix.org] Got response headers: 500 Internal Server Error
2023-01-29 21:16:08,856 - synapse.http.matrixfederationclient - 672 - INFO - POST-100 - {PUT-O-16} [matrix.org] Request failed: PUT matrix://matrix.org/_matrix/federation/v2/send_join/%21HLVrjATAChhKivUcLx%3Amatrix.org/%24F15MQq3zZibh9VROeuzWNadoFPR4LlyFR5nm8j8sSOE: HttpResponseException('500: Internal Server Error')
2023-01-29 21:16:09,843 - synapse.access.http.8008 - 450 - INFO - GET-108 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:09,962 - synapse.access.http.8008 - 450 - INFO - GET-109 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:10,061 - synapse.http.matrixfederationclient - 629 - INFO - POST-100 - {PUT-O-16} [matrix.org] Got response headers: 500 Internal Server Error
2023-01-29 21:16:10,065 - synapse.http.matrixfederationclient - 672 - INFO - POST-100 - {PUT-O-16} [matrix.org] Request failed: PUT matrix://matrix.org/_matrix/federation/v2/send_join/%21HLVrjATAChhKivUcLx%3Amatrix.org/%24F15MQq3zZibh9VROeuzWNadoFPR4LlyFR5nm8j8sSOE: HttpResponseException('500: Internal Server Error')
2023-01-29 21:16:12,733 - synapse.access.http.8008 - 450 - INFO - GET-110 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:12,861 - synapse.access.http.8008 - 450 - INFO - GET-111 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.002sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 331B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
2023-01-29 21:16:12,943 - synapse.http.matrixfederationclient - 629 - INFO - POST-100 - {PUT-O-16} [matrix.org] Got response headers: 500 Internal Server Error
2023-01-29 21:16:12,946 - synapse.http.matrixfederationclient - 672 - INFO - POST-100 - {PUT-O-16} [matrix.org] Request failed: PUT matrix://matrix.org/_matrix/federation/v2/send_join/%21HLVrjATAChhKivUcLx%3Amatrix.org/%24F15MQq3zZibh9VROeuzWNadoFPR4LlyFR5nm8j8sSOE: HttpResponseException('500: Internal Server Error')
2023-01-29 21:16:12,946 - synapse.util.retryutils - 231 - INFO - POST-100 - Connection to matrix.org was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: HttpResponseException: 500: Internal Server Error)); backoff now 600000
2023-01-29 21:16:12,948 - synapse.federation.federation_client - 789 - WARNING - POST-100 - Failed to send_join via matrix.org: Failed to send request: HttpResponseException: 500: Internal Server Error
2023-01-29 21:16:12,968 - synapse.http.server - 107 - INFO - POST-100 - <XForwardedForRequest at 0x7f7841d430 method='POST' uri='/_matrix/client/r0/join/%23html.css%3Amatrix.org' clientproto='HTTP/1.1' site='8008'> SynapseError: 502 - Failed to send_join via any server

Homeserver

matrix.org

Synapse Version

1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)

Installation Method

I don't know

Database

postgresql

Workers

Multiple workers

Platform

n/a

Configuration

No response

Relevant log output

n/a

Anything else that would be useful to know?

No response
@DMRobertson DMRobertson added T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. A-Federated-Join joins over federation generally suck S-Major Major functionality / product severely impaired, no satisfactory workaround. O-Occasional Affects or can be seen by some users regularly or most users rarely labels Jan 30, 2023
@DMRobertson
Copy link
Contributor

DMRobertson commented Jan 30, 2023 •
edited
Loading

Internal sentry link: https://sentry.tools.element.io/organizations/element/issues/51828/activity/?project=2&query=is%3Aunresolved+send_join&statsPeriod=7d

  File "/home/synapse/src/synapse/handlers/federation_event.py", line 2192, in _run_push_actions_and_persist_event
    await self._bulk_push_rule_evaluator.action_for_events_by_user(
  File "/home/synapse/src/synapse/push/bulk_push_rule_evaluator.py", line 280, in action_for_events_by_user
    await self._action_for_event_by_user(event, context, event_id_to_event)
  File "/home/synapse/src/synapse/util/metrics.py", line 113, in measured_func
    r = await func(self, *args, **kwargs)
  File "/home/synapse/src/synapse/push/bulk_push_rule_evaluator.py", line 343, in _action_for_event_by_user
    notification_levels[user_id] = int(level)
TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType'

The power levels for that room are currently:

   {"ban": 50, "events": {"im.vector.modular.widgets": 50, "m.room.avatar": 50, "m.room.canonical_alias": 50, "m.room.history_visibility": 100, "m.room.name": 50, "m.room.power_levels": 100,   "m.room.tombstone": 0, "m.room.topic": 50}, "events_default": 0, "invite": 0, "kick": 50, "notifications": {"room": null}, "redact": 50, "state_default": 50, "users": {"@<redacted>": 100, "@<redacted>": 10}, "users_default": 0}

via select json::json->'content' from current_state_events NATURAL JOIN event_json where room_id = '!HLVrjATAChhKivUcLx:matrix.org' AND type = 'm.room.power_levels';.

In particular, "room": null looks bogus.

Indeed,

synapse/synapse/push/bulk_push_rule_evaluator.py

Lines 338 to 343 in 62ed877

# It's possible that old room versions have non-integer power levels (floats or
# strings). Workaround this by explicitly converting to int.
notification_levels = power_levels.get("notifications", {})
if not event.room_version.msc3667_int_only_power_levels:
for user_id, level in notification_levels.items():
notification_levels[user_id] = int(level)
is mistaken: the keys are not user_ids. We should probably interpret a null value as 50 per the spec.

We also don't seem to be inspecting and fixing up the users or users_default fields, which is distressing.

@DMRobertson
Copy link
Contributor

Since this only shows up in room v10, I am guessing the room was recently created or upgraded. Can you confirm this?

@clokep
Copy link
Member

clokep commented Jan 30, 2023

Since this only shows up in room v10, I am guessing the room was recently created or upgraded. Can you confirm this?

I thought room version 10 explicitly verifies the format of power-level events? I'm wondering how this got created in the first place...

@progval
Copy link
Contributor Author

progval commented Jan 30, 2023 •
edited
Loading

Since this only shows up in room v10, I am guessing the room was recently created or upgraded. Can you confirm this?

I can't, I've never been in that room. @bkil any idea?

@bkil
Copy link

bkil commented Jan 30, 2023

I have only bumped into it accidentally, so I have no information either.

@DMRobertson DMRobertson self-assigned this Jan 30, 2023
@DMRobertson DMRobertson added the X-Release-Blocker Must be resolved before making a release label Jan 30, 2023
@DMRobertson
Copy link
Contributor

Oh, I misread. The condition is if not event.room_version.msc3667_int_only_power_levels: (emphasis not), so this isn't in a v10 room. So I don't think this is related to #14111 and therefore I don't think this is a regression in 1.76.

@DMRobertson DMRobertson removed the X-Release-Blocker Must be resolved before making a release label Jan 30, 2023
@DMRobertson
Copy link
Contributor

DMRobertson commented Jan 30, 2023 •
edited
Loading

Xref #14073 and #14060

@DMRobertson DMRobertson mentioned this issue Jan 30, 2023
Merged
@DMRobertson DMRobertson added S-Minor Blocks non-critical functionality, workarounds exist. O-Uncommon Most users are unlikely to come across this or unexpected workflow and removed S-Major Major functionality / product severely impaired, no satisfactory workaround. O-Occasional Affects or can be seen by some users regularly or most users rarely labels Jan 30, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@DMRobertson DMRobertson

Labels
A-Federated-Join joins over federation generally suck O-Uncommon Most users are unlikely to come across this or unexpected workflow S-Minor Blocks non-critical functionality, workarounds exist. T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Handle malformed values of notification.room in power level events matrix-org/synapse
4 participants
@progval @clokep @bkil @DMRobertson