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

Ignoring PDU for unknown room_id #8989

Closed
cremesk opened this issue Dec 23, 2020 · 2 comments
Closed

Ignoring PDU for unknown room_id #8989

cremesk opened this issue Dec 23, 2020 · 2 comments

Comments

@cremesk
Copy link
Contributor

cremesk commented Dec 23, 2020 •
edited
Loading

Description

hi, i watched my logs the days and found the following.
I noticed that my cpu occasionally runs to 100% for a while. as soon as the cpu load drops again I get that ..

2020-12-21 15:11:25,451 - synapse.federation.transport.server - 407 - INFO - PUT-191786 - Received txn 1608061380471 from matrix.org. (PDUs: 45, EDUs: 11)
2020-12-21 15:11:25,455 - synapse.handlers.typing - 337 - INFO - PUT-191786 - Got typing update from @Jaypatelani:matrix.org: {'room_id': '!mZjBIxelTDFKLQVWXf:matrix.org', 'typing': False, 'user_id': '@Jaypatelani:matrix.org'}
2020-12-21 15:11:25,456 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28861 - Streaming: typing -> 4523
2020-12-21 15:11:25,457 - synapse.handlers.typing - 337 - INFO - PUT-191786 - Got typing update from @airwolf85:matrix.org: {'room_id': '!mZjBIxelTDFKLQVWXf:matrix.org', 'typing': False, 'user_id': '@airwolf85:matrix.org'}
2020-12-21 15:11:25,457 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28862 - Streaming: typing -> 4524
2020-12-21 15:11:25,460 - synapse.handlers.device - 694 - WARNING - PUT-191786 - Got device list update edu for '@floppypower:matrix.org'/'REMDQCJYTM', but don't share a room
2020-12-21 15:11:25,461 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,461 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,462 - synapse.handlers.e2e_keys - 1320 - INFO - PUT-191786 - pending updates: [({'keys': {'ed25519:Pt6a2a6oLcyztjk8/mtqt5VPvtPgkTla4QlqAQ9f+p8': 'Pt6a2a6oLcyztjk8/mtqt5VPvtPgkTla4QlqAQ9f+p8'}, 'signatures': {'@yellow_reactor:matrix.org': {'ed25519:SXPZBLKVAZ': 'L0YUQq/B4DO9GSVTCrkeEhzJnL1a85Z2eJKGPxRtxahupwVvx66/WOgVXc5/CDl29bzOTBQvptCAjpncnib8Cw'}}, 'usage': [
'master'], 'user_id': '@yellow_reactor:matrix.org'}, None)]
2020-12-21 15:11:25,463 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,464 - synapse.handlers.device - 734 - INFO - PUT-191786 - Received device list update for @yellow_reactor:matrix.org, requiring resync: True. Devices: VKCCGBWNBM
2020-12-21 15:11:25,468 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,468 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28863 - Streaming: receipts -> 7435322
2020-12-21 15:11:25,470 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !UGYpXmlyESJlkXkarj:matrix.org
2020-12-21 15:11:25,472 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,473 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28863 - Streaming: caches -> 1699742
2020-12-21 15:11:25,473 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !PQpRtCUNPqDCLCLGiL:matrix.org
2020-12-21 15:11:25,474 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,476 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28863 - Streaming: device_lists -> 9986700
2020-12-21 15:11:25,477 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,477 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,477 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,478 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28863 - Streaming: to_device -> 105409
2020-12-21 15:11:25,479 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,480 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,481 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,481 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,482 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,483 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,484 - synapse.replication.tcp.resource - 189 - INFO - replication_notifier-28863 - Streaming: receipts -> 7435324
2020-12-21 15:11:25,485 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !UGYpXmlyESJlkXkarj:matrix.org
2020-12-21 15:11:25,488 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !UGYpXmlyESJlkXkarj:matrix.org
2020-12-21 15:11:25,489 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,490 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !UGYpXmlyESJlkXkarj:matrix.org
2020-12-21 15:11:25,491 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,491 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,492 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !GibBpYxFGNraRsZOyl:matrix.org
2020-12-21 15:11:25,493 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !PQpRtCUNPqDCLCLGiL:matrix.org
2020-12-21 15:11:25,494 - synapse.federation.federation_server - 314 - INFO - PUT-191786 - Ignoring PDU for unknown room_id: !KQXjMEEPguxNeKfbHe:matrix.org
2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085632372195416HPRzV:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 1]
2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>26hTnP4FTztA8/cK9miRD4e9nOICmNB2UAoguUzmyto - Waiting for existing lookups for ['matrix.org'] to complete [loop 1]
2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085632542195508OfhXV:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 1]
2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60 - Waiting for existing lookups for ['matrix.org'] to complete [loop 1]
2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 1]
2020-12-21 15:11:25,496 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for ['matrix.org'] to complete [loop 1]
2020-12-21 15:11:25,496 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085634492196446LMGsW:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 1]
2020-12-21 15:11:25,497 - synapse.handlers.federation - 189 - INFO - PUT-191786-"></span>16085632343222694FQsSy:matrix.org - handling received PDU: <FrozenEvent event_id='<span data-mx-maths="16085632343222694FQsSy:matrix.org&apos;, type=&apos;m.room.message&apos;, state_key=None&gt;
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>26hTnP4FTztA8/cK9miRD4e9nOICmNB2UAoguUzmyto - Waiting for existing lookups for ['matrix.org'] to complete [loop 2]
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085632542195508OfhXV:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 2]
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60 - Waiting for existing lookups for ['matrix.org'] to complete [loop 2]
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 2]
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for ['matrix.org'] to complete [loop 2]
2020-12-21 15:11:25,497 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085634492196446LMGsW:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 2]
2020-12-21 15:11:25,499 - synapse.handlers.federation - 189 - INFO - PUT-191786-"></span>16085632372195416HPRzV:matrix.org - handling received PDU: <FrozenEvent event_id='<span data-mx-maths="16085632372195416HPRzV:matrix.org&apos;, type=&apos;m.room.message&apos;, state_key=None&gt;
2020-12-21 15:11:25,499 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>16085632542195508OfhXV:matrix.org - Waiting for existing lookups for ['matrix.org'] to complete [loop 3]
2020-12-21 15:11:25,499 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60 - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 3]
2020-12-21 15:11:25,500 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - Waiting for existing lookups for ['matrix.org'] to complete [loop 3]
2020-12-21 15:11:25,500 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 3]
2020-12-21 15:11:25,500 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>16085634492196446LMGsW:matrix.org - Waiting for existing lookups for ['matrix.org'] to complete [loop 3]
2020-12-21 15:11:25,500 - synapse.metrics - 576 - INFO -  - Collecting gc 1
2020-12-21 15:11:25,507 - synapse.handlers.federation - 189 - INFO - PUT-191786-<span data-mx-maths="26hTnP4FTztA8/cK9miRD4e9nOICmNB2UAoguUzmyto - handling received PDU: &lt;FrozenEventV2 event_id=&apos;"></span>26hTnP4FTztA8/cK9miRD4e9nOICmNB2UAoguUzmyto', type='m.reaction', state_key=None>
2020-12-21 15:11:25,508 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60 - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 4]
2020-12-21 15:11:25,508 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - Waiting for existing lookups for ['matrix.org'] to complete [loop 4]
2020-12-21 15:11:25,508 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 4]
2020-12-21 15:11:25,508 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>16085634492196446LMGsW:matrix.org - Waiting for existing lookups for ['matrix.org'] to complete [loop 4]
2020-12-21 15:11:25,509 - synapse.http.matrixfederationclient - 205 - INFO - PUT-191786 - {GET-O-69833} [matrix.org] Completed request: 200 OK in 0.05 secs - GET matrix://matrix.org/_matrix/federation/v1/user/devices/%40yellow_reactor%3Amatrix.org
2020-12-21 15:11:25,512 - synapse.handlers.federation - 189 - INFO - PUT-191786-<span data-mx-maths="16085632542195508OfhXV:matrix.org - handling received PDU: &lt;FrozenEvent event_id=&apos;"></span>16085632542195508OfhXV:matrix.org', type='m.room.message', state_key=None>
2020-12-21 15:11:25,512 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 5]
2020-12-21 15:11:25,512 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for ['matrix.org'] to complete [loop 5]
2020-12-21 15:11:25,512 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085634492196446LMGsW:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 5]
2020-12-21 15:11:25,514 - synapse.handlers.federation - 189 - INFO - PUT-191786-"></span>NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60 - handling received PDU: <FrozenEventV3 event_id='<span data-mx-maths="NQNIuZpkOxmbPOaZ1b_UZYaoV1ZPQi57g7-h1KOEK60&apos;, type=&apos;m.room.encrypted&apos;, state_key=None&gt;
2020-12-21 15:11:25,514 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - Waiting for existing lookups for ['matrix.org'] to complete [loop 6]
2020-12-21 15:11:25,514 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085634492196446LMGsW:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 6]
2020-12-21 15:11:25,515 - synapse.handlers.federation - 189 - INFO - PUT-191786-"></span>NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk - handling received PDU: <FrozenEventV3 event_id='<span data-mx-maths="NxMIKU7b0bjpHCtJj2mKeKGuv3hOB3ek5srCf731cAk&apos;, type=&apos;m.room.member&apos;, state_key=&apos;@freenode_drlef:matrix.org&apos;&gt;
2020-12-21 15:11:25,515 - synapse.crypto.keyring - 300 - INFO - PUT-191786-"></span>16085634492196446LMGsW:matrix.org - Waiting for existing lookups for ['matrix.org'] to complete [loop 7]
2020-12-21 15:11:25,516 - synapse.handlers.federation - 189 - INFO - PUT-191786-<span data-mx-maths="yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA - handling received PDU: &lt;FrozenEventV3 event_id=&apos;"></span>yd1zzsuCh1AkyiNs1KsmXJzpAgpuWdfOAlvfvar1-ZA', type='m.reaction', state_key=None>
2020-12-21 15:11:25,520 - synapse.handlers.federation - 189 - INFO - PUT-191786-<span data-mx-maths="16085634492196446LMGsW:matrix.org - handling received PDU: &lt;FrozenEvent event_id=&apos;"></span>16085634492196446LMGsW:matrix.org', type='m.room.member', state_key='@_oftc_evon:matrix.org'>

for example !UGYpXmlyESJlkXkarj:matrix.org is #freenode_python:matrix.org
i tried to join this room weeks ago. without success!
However, when I go into the room with my matrix.org account it works. There I see strange white but that my envs.net account is inside.

when I try to delete the room via the api I get the following:

curl -X POST -H "Authorization: Bearer $token" "https://matrix.envs.net/_synapse/admin/v1/rooms/\!UGYpXmlyESJlkXkarj:matrix.org/delete" --data '{ "new_room_user_id": "@notices:envs.net", "room_name": "Content Violation Notification", "message": "Bad Room has been shutdown due to content violations on this server. Please review our Terms of Service.", "block": false, "purge": true, "force-purge": true }'""

{"errcode":"M_NOT_FOUND","error":"Unknown room id !UGYpXmlyESJlkXkarj:matrix.org"}

Is there any idea what I can do to fix this problem please?

full homeserver.log
unknown room_id summary

Version information

  • Homeserver: envs.net

  • Version: Synapse 1.24.0

  • Install method: package manager (apt) matrix-synapse-py3

  • Platform: Debian 10 (buster) on AMD Ryzen 7 3700X with 64GB RAM and 2x1TB SSD m.2
@richvdh
Copy link
Member

richvdh commented Jan 14, 2021

the events causing "unknown room id" warnings will simply be ignored: if you see 100% cpu usage, it is almost certainly due to other rooms.

they are typically caused by the join request timing out (https://github.com/matrix-org/matrix-doc/issues/2963), so that the remote server thinks you are joined but the local server doesn't. See also #1211,

As I said, the warnings aren't really a problem, but potential workarounds include trying again to join the room (and then possibly leaving it), or asking a mod in the relevant rooms to kick you.

I'm going to go ahead and close this, because the warnings you mention are somewhat expected and we have issues open to track the root cause.

@richvdh richvdh closed this as completed Jan 14, 2021
@richvdh
Copy link
Member

richvdh commented Jan 14, 2021 

2020-12-21 15:11:25,495 - synapse.crypto.keyring - 300 - INFO - PUT-191786-<span data-mx-maths="16085632372195416HPRzV:matrix.org - Waiting for existing lookups for [&apos;matrix.org&apos;] to complete [loop 1]

I'm assuming these log lines are being corrupted by being cut-and-pasted from an HTML pastebin, rather than the you actually getting events with IDs which look like <span data-mx-maths="16085632372195416HPRzV:matrix.org.

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
@richvdh @cremesk