Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bridge is unable to accept DM invites #1270

Open
jkhsjdhjs opened this issue Mar 17, 2021 · 9 comments
Open

Bridge is unable to accept DM invites #1270

jkhsjdhjs opened this issue Mar 17, 2021 · 9 comments
Labels
needs-investigation S-Major Severely degrades major functionality or product features, with no satisfactory workaround T-Defect Bugs, crashes, hangs, vulnerabilities, or other reported problems.

Comments

@jkhsjdhjs
Copy link

Describe the bug
When inviting the IRC bridge to a DM it attempts to accept the invitation, but is unable to because of a 404 - Profile was not found error.
I'm not sure whether this is actually a bug of this bridge of a bug/misconfiguration of my synapse instance, so I asked on #synapse:matrix.org first. However, no one was able to help me there and since the configuration of my synapse instance is mostly vanilla, I decided to create an issue here.

To Reproduce
Steps to reproduce the behavior:

  1. Invite the IRC Bridge to a DM room

Expected behavior
The bridge joins the room.

Log

Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge 192.168.0.6 - - [17/Mar/2021:06:14:16 +0000] "PUT /transactions/1532?access_token=<REDACTED> HTTP/1.1" 200 2 "-" "Synapse/1.28.0"
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:req [2kwddvzbq2i00] [[M->I]] onInvite: from=@jkhsjdhjs:matrix.org to=@irc:example.com rm=!zPtGChNuntQMiqhJoG:matrix.org id=$KC9gvEiIX5t3cLRyCE8j7O9CnQQ-2kNOzALd_07Adeo
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:req [2kwddvzbq2i00] [[M->I]] Handling invite from @jkhsjdhjs:matrix.org directed to bot.
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.040 DEBUG MembershipQueue [2kwddvzbq2i00] @irc:example.com@!zPtGChNuntQMiqhJoG:matrix.org -> join (reason: none, kicker: undefined)
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.040 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.040 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.050 WARN MembershipQueue [2kwddvzbq2i00] Failed to join !zPtGChNuntQMiqhJoG:matrix.org, delaying for 61.90264450694605ms
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.050 DEBUG MembershipQueue [2kwddvzbq2i00] Failed with: undefined Failed to join room
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.125 DEBUG MembershipQueue [2kwddvzbq2i00] @irc:example.com@!zPtGChNuntQMiqhJoG:matrix.org -> join (reason: none, kicker: undefined)
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.125 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.126 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.127 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.127 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.134 WARN MembershipQueue [2kwddvzbq2i00] Failed to join !zPtGChNuntQMiqhJoG:matrix.org, delaying for 500ms
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.134 DEBUG MembershipQueue [2kwddvzbq2i00] Failed with: undefined Failed to join room
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge [2kwddvzbq2i00] [M->I] FAILED  (106ms)
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:main TypeError: Cannot read property 'error' of undefined
Mar 17 06:14:16 synapse node[16387]:     at MatrixHandler.handleAdminRoomInvite (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:69:93)
Mar 17 06:14:16 synapse node[16387]:     at processTicksAndRejections (node:internal/process/task_queues:94:5)
Mar 17 06:14:16 synapse node[16387]:     at async MatrixHandler._onInvite (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:296:17)
Mar 17 06:14:16 synapse node[16387]:     at async reqHandler (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:14:21)
Mar 17 06:14:16 synapse node[16387]:     at async IrcBridge._onEvent (/opt/matrix-appservice-irc/lib/bridge/IrcBridge.js:757:17)
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:main TypeError: Cannot read property 'error' of undefined
Mar 17 06:14:16 synapse node[16387]:     at MatrixHandler.handleAdminRoomInvite (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:69:93)
Mar 17 06:14:16 synapse node[16387]:     at processTicksAndRejections (node:internal/process/task_queues:94:5)
Mar 17 06:14:16 synapse node[16387]:     at async MatrixHandler._onInvite (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:296:17)
Mar 17 06:14:16 synapse node[16387]:     at async reqHandler (/opt/matrix-appservice-irc/lib/bridge/MatrixHandler.js:14:21)
Mar 17 06:14:16 synapse node[16387]:     at async IrcBridge._onEvent (/opt/matrix-appservice-irc/lib/bridge/IrcBridge.js:757:17)
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.637 DEBUG MembershipQueue [2kwddvzbq2i00] @irc:example.com@!zPtGChNuntQMiqhJoG:matrix.org -> join (reason: none, kicker: undefined)
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.637 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.637 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:16 synapse node[16387]: 2021-03-17 06:14:16 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.645 WARN MembershipQueue [2kwddvzbq2i00] Failed to join !zPtGChNuntQMiqhJoG:matrix.org, delaying for 500ms
Mar 17 06:14:16 synapse node[16387]: Mar-17 06:14:16.645 DEBUG MembershipQueue [2kwddvzbq2i00] Failed with: undefined Failed to join room
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.145 DEBUG MembershipQueue [2kwddvzbq2i00] @irc:example.com@!zPtGChNuntQMiqhJoG:matrix.org -> join (reason: none, kicker: undefined)
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.146 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.146 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:17 synapse node[16387]: 2021-03-17 06:14:17 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:17 synapse node[16387]: 2021-03-17 06:14:17 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.153 WARN MembershipQueue [2kwddvzbq2i00] Failed to join !zPtGChNuntQMiqhJoG:matrix.org, delaying for 500ms
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.154 DEBUG MembershipQueue [2kwddvzbq2i00] Failed with: undefined Failed to join room
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.657 DEBUG MembershipQueue [2kwddvzbq2i00] @irc:example.com@!zPtGChNuntQMiqhJoG:matrix.org -> join (reason: none, kicker: undefined)
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.657 DEBUG Intent Checking if user @irc:example.com is registered
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.657 DEBUG Intent ensureRegistered: Registered, and not encrypted
Mar 17 06:14:17 synapse node[16387]: 2021-03-17 06:14:17 INFO:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) Body: "{}"
Mar 17 06:14:17 synapse node[16387]: 2021-03-17 06:14:17 ERROR:IrcBridge [-] POST http://192.168.0.6:8008/_matrix/client/r0/join/!zPtGChNuntQMiqhJoG%3Amatrix.org (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.664 WARN MembershipQueue [2kwddvzbq2i00] Failed to join !zPtGChNuntQMiqhJoG:matrix.org, delaying for 500ms
Mar 17 06:14:17 synapse node[16387]: Mar-17 06:14:17.664 DEBUG MembershipQueue [2kwddvzbq2i00] Failed with: undefined Failed to join room

Desktop (please complete the following information):

  • OS: Arch Linux
  • Browser Firefox
  • Version 24 and 25
@Rodrigo-Barros
Copy link

I don't know if helps but you can try run npm test inside bridge folder just to you gather more info about the problem you are facing, maybe this way some developers can help you better.

@mweinelt
Copy link
Contributor

mweinelt commented May 27, 2021

Trying to invite the appservice, this is whats happening for us.

May 27 02:37:11 matrix synapse[3908]: synapse.access.http.8008: [GET-0] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.022sec/-0.000sec (0.006sec, 0.001sec) (0.002sec/0.012sec/4) 111B 200 "GET /_matrix/federation/v1/user/devices/%40appservice-irc%3Ahackint.org HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 02:37:12 matrix synapse[3908]: synapse.http.server: [GET-1] <XForwardedForRequest at 0x7f47741b3b50 method='GET' uri='/_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=displayname' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:12 matrix synapse[3908]: synapse.access.http.8008: [GET-1] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.011sec/-0.000sec (0.002sec, 0.002sec) (0.000sec/0.005sec/1) 57B 404 "GET /_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=displayname HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 02:37:12 matrix synapse[3908]: synapse.access.http.8008: [PUT-2] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.090sec/-0.000sec (0.009sec, 0.001sec) (0.002sec/0.017sec/5) 1237B 200 "PUT /_matrix/federation/v2/invite/%21PZwRnxCHGkegUXtiUP%3Alossy.network/%24p8xCQtktawjLI24AKSlrq0VEuMjWwI9WF4Uu07o9jaM HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 02:37:12 matrix synapse[3908]: synapse.appservice.scheduler: [as_scheduler-0] Starting appservice scheduler
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:IrcBridge 127.0.0.1 - - [27/May/2021:00:37:12 +0000] "PUT /transactions/219?access_token=<REDACTED> HTTP/1.1" 200 2 "-" "Synapse/1.34.0"
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:req [3xw9sgrrguu00] [[M->I]] onInvite: from=@hexa:lossy.network to=@appservice-irc:hackint.org rm=!PZwRnxCHGkegUXtiUP:lossy.network id=$p8xCQtktawjLI24AKSlrq0VEuMjWwI9WF4Uu07o9jaM
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:req [3xw9sgrrguu00] [[M->I]] Handling invite from @hexa:lossy.network directed to bot.
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.598 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.598 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.599 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:12 matrix synapse[3908]: synapse.http.client: [as-sender-df621695152f1092fb1a7309a14676fe86c49a3ebc0cd50ee2b526accf53f09a-0] Received response to PUT http://127.0.0.1:8009/transactions/219?access_token=<redacted>: 200
May 27 02:37:12 matrix synapse[3908]: synapse.http.server: [POST-3] <XForwardedForRequest at 0x7f4774211a90 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:12 matrix synapse[3908]: synapse.access.http.8008: [POST-3] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.019sec/-0.000sec (0.003sec, 0.002sec) (0.003sec/0.009sec/4) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.636 WARN MembershipQueue [3xw9sgrrguu00] Failed to join !PZwRnxCHGkegUXtiUP:lossy.network, delaying for 49.979099480444766ms
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.636 DEBUG MembershipQueue [3xw9sgrrguu00] Failed with: undefined Failed to join room
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.685 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.688 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.688 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.689 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.689 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:12 matrix synapse[3908]: synapse.http.server: [POST-4] <XForwardedForRequest at 0x7f477122fbe0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:12 matrix synapse[3908]: synapse.access.http.8008: [POST-4] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.007sec/-0.000sec (0.003sec, 0.000sec) (0.001sec/0.003sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.725 WARN MembershipQueue [3xw9sgrrguu00] Failed to join !PZwRnxCHGkegUXtiUP:lossy.network, delaying for 500ms
May 27 02:37:12 matrix matrix-appservice-irc[3817]: May-27 02:37:12.725 DEBUG MembershipQueue [3xw9sgrrguu00] Failed with: undefined Failed to join room
May 27 02:37:12 matrix synapse[3908]: synapse.http.server: [POST-5] <XForwardedForRequest at 0x7f4771258dc0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:12 matrix synapse[3908]: synapse.access.http.8008: [POST-5] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.009sec/-0.000sec (0.002sec, 0.001sec) (0.001sec/0.004sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 DEBUG:req [3xw9sgrrguu00] [[M->I]] Not a plumbed room: Error retrieving m.room.plumbing
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:NeDBDataStore storeAdminRoom (id=!PZwRnxCHGkegUXtiUP:lossy.network, user_id=@hexa:lossy.network)
May 27 02:37:12 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:12 INFO:IrcBridge [3xw9sgrrguu00] [M->I] SUCCESS  (144ms)
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.225 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.226 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.227 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:13 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:13 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:13 matrix synapse[3908]: synapse.http.server: [POST-6] <XForwardedForRequest at 0x7f4771258ee0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:13 matrix synapse[3908]: synapse.access.http.8008: [POST-6] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.014sec/-0.000sec (0.003sec, 0.000sec) (0.001sec/0.008sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:13 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:13 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.252 WARN MembershipQueue [3xw9sgrrguu00] Failed to join !PZwRnxCHGkegUXtiUP:lossy.network, delaying for 500ms
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.252 DEBUG MembershipQueue [3xw9sgrrguu00] Failed with: undefined Failed to join room
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.753 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.753 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.753 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:13 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:13 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:13 matrix synapse[3908]: synapse.http.server: [POST-7] <XForwardedForRequest at 0x7f477124dca0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:13 matrix synapse[3908]: synapse.access.http.8008: [POST-7] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.008sec/-0.000sec (0.003sec, 0.001sec) (0.001sec/0.003sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:13 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:13 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.772 WARN MembershipQueue [3xw9sgrrguu00] Failed to join !PZwRnxCHGkegUXtiUP:lossy.network, delaying for 500ms
May 27 02:37:13 matrix matrix-appservice-irc[3817]: May-27 02:37:13.772 DEBUG MembershipQueue [3xw9sgrrguu00] Failed with: undefined Failed to join room
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.273 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.274 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.274 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:14 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:14 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:14 matrix synapse[3908]: synapse.http.server: [POST-8] <XForwardedForRequest at 0x7f47741f6af0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:14 matrix synapse[3908]: synapse.access.http.8008: [POST-8] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.009sec/-0.000sec (0.002sec, 0.001sec) (0.001sec/0.004sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:14 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:14 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.294 WARN MembershipQueue [3xw9sgrrguu00] Failed to join !PZwRnxCHGkegUXtiUP:lossy.network, delaying for 500ms
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.294 DEBUG MembershipQueue [3xw9sgrrguu00] Failed with: undefined Failed to join room
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.795 DEBUG MembershipQueue [3xw9sgrrguu00] @appservice-irc:hackint.org@!PZwRnxCHGkegUXtiUP:lossy.network -> join (reason: none, kicker: undefined)
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.796 DEBUG Intent Checking if user @appservice-irc:hackint.org is registered
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.796 DEBUG Intent ensureRegistered: Registered, and not encrypted
May 27 02:37:14 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:14 INFO:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) Body: "{}"
May 27 02:37:14 matrix synapse[3908]: synapse.http.server: [POST-9] <XForwardedForRequest at 0x7f47742185e0 method='POST' uri='/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted>' clientproto='HTTP/1.0' site='8008'> SynapseError: 404 - Profile was not found
May 27 02:37:14 matrix synapse[3908]: synapse.access.http.8008: [POST-9] 127.0.0.1 - 8008 - {@appservice-irc:hackint.org} Processed request: 0.006sec/-0.000sec (0.003sec, 0.000sec) (0.001sec/0.002sec/2) 57B 404 "POST /_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network?access_token=<redacted> HTTP/1.0" "-" [0 dbevts]
May 27 02:37:14 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:14 ERROR:IrcBridge [-] POST https://matrix.hackint.org/_matrix/client/r0/join/!PZwRnxCHGkegUXtiUP%3Alossy.network (AS) HTTP 404 Error: "{\"errcode\":\"M_NOT_FOUND\",\"error\":\"Profile was not found\"}"
May 27 02:37:14 matrix matrix-appservice-irc[3817]: May-27 02:37:14.819 ERROR MembershipQueue Failed to handle membership change: Error: Failed to join room
May 27 02:37:14 matrix matrix-appservice-irc[3817]:     at Intent._ensureJoined (/nix/store/w35azw6ryb21g8swwxpn57mxndyc7dqn-node_matrix-appservice-irc-0.26.0/lib/node_modules/matrix-appservice-irc/node_modules/matrix-appservice-bridge/lib/components/intent.js:786:60)
May 27 02:37:14 matrix matrix-appservice-irc[3817]:     at processTicksAndRejections (internal/process/task_queues.js:97:5)
May 27 02:37:15 matrix matrix-appservice-irc[3817]: 2021-05-27 02:37:15 INFO:IrcBridge 127.0.0.1 - - [27/May/2021:00:37:15 +0000] "PUT /transactions/220?access_token=<REDACTED> HTTP/1.1" 200 2 "-" "Synapse/1.34.0"
May 27 02:37:15 matrix synapse[3908]: synapse.http.client: [as-sender-df621695152f1092fb1a7309a14676fe86c49a3ebc0cd50ee2b526accf53f09a-1] Received response to PUT http://127.0.0.1:8009/transactions/220?access_token=<redacted>: 200

Joining rooms, querying users on IRC both works. This is our registration.yml

id: foo
hs_token: bar
as_token: baz
url: 'http://127.0.0.1:8009'
sender_localpart: appservice-irc
de.sorunome.msc2409.push_ephemeral: true
protocols:
  - irc
namespaces:
  aliases:
    - exclusive: true
      regex: '#.*:hackint\.org'
  users:
    - exclusive: true
      regex: '@irc_.*:hackint\.org'
rate_limited: false
{
  "database": {
    "connectionString": "nedb://var/lib/matrix-appservice-irc/data",
    "engine": "nedb"
  },
  "homeserver": {
    "domain": "hackint.org",
    "enablePresence": true,
    "url": "https://matrix.hackint.org"
  },
  "ircService": {
    "ircHandler": {
      "leaveConcurrency": 10,
      "mapIrcMentionsToMatrix": "on"
    },
    "logging": {
      "level": "debug",
      "toConsole": true
    },
    "passwordEncryptionKeyPath": "/var/lib/matrix-appservice-irc/passkey.pem",
    "permissions": {
      "@hexa:example.com": "admin"
    },
    "servers": {
      "irc.hackint.org": {
        "allowExpiredCerts": true,
        "botConfig": {
          "enabled": false
        },
        "dynamicChannels": {
          "aliasTemplate": "$CHANNEL",
          "createAlias": true,
          "enabled": true,
          "federate": true,
          "joinRule": "public",
          "published": true
        },
        "excludedUsers": [],
        "icon": "https://hackint.org/images/avatar.png",
        "ircClients": {
          "allowNickChanges": true,
          "concurrentReconnectLimit": 512,
          "idleTimeout": 604800,
          "lineLimit": 5,
          "maxClients": 4096,
          "nickTemplate": "$DISPLAY|m"
        },
        "matrixClients": {
          "displayName": "$NICK",
          "userTemplate": "@irc_$NICK"
        },
        "membershipLists": {
          "enabled": true,
          "global": {
            "ircToMatrix": {
              "incremental": true,
              "initial": true,
              "requireMatrixJoined": true
            },
            "matrixToIrc": {
              "incremental": true,
              "initial": true,
              "requireMatrixJoined": true
            }
          }
        },
        "modePowerMap": {
          "o": 50,
          "v": 1
        },
        "name": "hackint",
        "port": 6697,
        "privateMessages": {
          "enabled": true,
          "federate": true
        },
        "quitDebounce": {
          "enabled": false
        },
        "sasl": false,
        "ssl": true,
        "sslselfsign": false
      }
    }
  }
}

We are running 02591d4 and I've cherrypicked both #1337 and #1339.

Our synapse 1.34.0 configuration looks like this:

no_tls: true
server_name: hackint.org
pid_file: /run/matrix-synapse.pid
public_baseurl: 'https://matrix.hackint.org'
listeners:
  - port: 8008
    bind_address: 127.0.0.1
    type: http
    tls: false
    x_forwarded: true
    resources:
      - names:
          - client
          - metrics
        compress: true
      - names:
          - federation
        compress: false
database:
  name: psycopg2
  args:
    database: matrix-synapse
    user: matrix-synapse
event_cache_size: 10K
verbose: 0
log_config: /nix/store/zc10h40shgrr55qhm14jqywrgih3wwda-log_config.yaml
rc_messages_per_second: 0.2
rc_message_burst_count: 10
federation_rc_window_size: 1000
federation_rc_sleep_limit: 10
federation_rc_sleep_delay: 500
federation_rc_reject_limit: 50
federation_rc_concurrent: 3
media_store_path: /var/lib/matrix-synapse/media
uploads_path: /var/lib/matrix-synapse/uploads
max_upload_size: 10M
max_image_pixels: 32M
dynamic_thumbnails: false
url_preview_enabled: false
recaptcha_private_key: ''
recaptcha_public_key: ''
enable_registration_captcha: false
turn_uris: []
turn_shared_secret: ''
enable_registration: false
recaptcha_siteverify_api: 'https://www.google.com/recaptcha/api/siteverify'
turn_user_lifetime: 1h
user_creation_max_duration: 1209600000
bcrypt_rounds: 12
allow_guest_access: false
account_threepid_delegates: null
room_invite_state_types:
  - m.room.join_rules
  - m.room.canonical_alias
  - m.room.avatar
  - m.room.name
macaroon_secret_key: ...
expire_access_token: false
enable_metrics: true
report_stats: false
signing_key_path: /var/lib/matrix-synapse/homeserver.signing.key
key_refresh_interval: 1d
perspectives:
  servers:
    matrix.org:
      verify_keys:
        'ed25519:auto':
          key: Noi6WqcDj0QmPxCNQqgezwTlBKrfqehY1u2FyWP9uYw
redaction_retention_period: 7
app_service_config_files:
  - /var/lib/matrix-appservice-irc/registration.yml
retention:
  enabled: true
  default_policy:
    min_lifetime: 1m
    max_lifetime: 1m
  allowed_lifetime_min: 1m
  allowed_lifetime_max: 1m
  purge_jobs:
    - interval: 5m

@mweinelt
Copy link
Contributor

mweinelt commented May 27, 2021

To clarify: It works if I stop the appservice, remove all mentions of my account from nedb, start the appservice again and have the appservice bot invite me.

It still doesn't work if I invite the appservice to a DM or a room. My account is also the bridge admin.

@Half-Shot
Copy link
Contributor

This is matrix-org/synapse#2807.

Workaround is to curl --data '{"type": "m.login.application_service", "username": "your_sender_localpart"}' 'http://yourhomeserver/_matrix/client/r0/register?access_token=your_as_token' which will give the bot a profile and allow invites to work.

@mweinelt
Copy link
Contributor

That made the errors go away, but the appservice still won't join the rooms it is invited to.

May 27 19:09:10 matrix synapse[5904]: synapse.access.http.8008: [GET-2033] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.005sec/-0.000sec (0.003sec, 0.000sec) (0.001sec/0.001sec/1) 32B 200 "GET /_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=displayname HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 19:09:10 matrix synapse[5904]: synapse.access.http.8008: [GET-2034] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.004sec/-0.000sec (0.003sec, 0.000sec) (0.000sec/0.001sec/1) 19B 200 "GET /_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=avatar_url HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 19:09:10 matrix synapse[5904]: synapse.access.http.8008: [GET-2035] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.004sec/-0.000sec (0.003sec, 0.000sec) (0.001sec/0.001sec/1) 32B 200 "GET /_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=displayname HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 19:09:10 matrix synapse[5904]: synapse.access.http.8008: [GET-2036] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.004sec/-0.000sec (0.002sec, 0.000sec) (0.000sec/0.001sec/1) 19B 200 "GET /_matrix/federation/v1/query/profile?user_id=%40appservice-irc%3Ahackint.org&field=avatar_url HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 19:09:10 matrix synapse[5904]: synapse.crypto.keyring: [PUT-2037] Waiting for existing lookups for ['lossy.network'] to complete [loop 1]
May 27 19:09:10 matrix synapse[5904]: synapse.access.http.8008: [PUT-2037] 2001:67c:2ed8::666:1 - 8008 - {lossy.network} Processed request: 0.055sec/-0.000sec (0.004sec, 0.000sec) (0.001sec/0.001sec/2) 1467B 200 "PUT /_matrix/federation/v2/invite/%21tvjcYPFyuCmfAbBTwW%3Alossy.network/%24-uU0jyeXyRU12zxfFsjPvviTgvLQI9f4FgBxTbbXYQI HTTP/1.0" "Synapse/1.34.0" [0 dbevts]
May 27 19:09:10 matrix matrix-appservice-irc[5943]: 2021-05-27 19:09:10 INFO:IrcBridge 127.0.0.1 - - [27/May/2021:17:09:10 +0000] "PUT /transactions/1602?access_token=<REDACTED> HTTP/1.1" 200 2 "-" "Synapse/1.34.0"
May 27 19:09:10 matrix synapse[5904]: synapse.http.client: [as-sender-df621695152f1092fb1a7309a14676fe86c49a3ebc0cd50ee2b526accf53f09a-1261] Received response to PUT http://127.0.0.1:8009/transactions/1602?access_token=<redacted>: 200
May 27 19:09:10 matrix matrix-appservice-irc[5943]: 2021-05-27 19:09:10 INFO:req [49ui9wk176q00] [[M->I]] onInvite: from=@hexa:lossy.network to=@appservice-irc:hackint.org rm=!tvjcYPFyuCmfAbBTwW:lossy.network id=$-uU0jyeXyRU12zxfFsjPvviTgvLQI9f4FgBxTbbXYQI
May 27 19:09:10 matrix matrix-appservice-irc[5943]: 2021-05-27 19:09:10 INFO:IrcBridge [49ui9wk176q00] [M->I] SUCCESS  (1ms)

@Half-Shot
Copy link
Contributor

I'm not sure why that's happening, but that sounds more like a synapse issue than ours.

@chayleaf
Copy link

chayleaf commented Sep 24, 2021

happened to me as well

edit: ok, i simply didn't set the firewall up properly...

@andir
Copy link

andir commented Nov 23, 2021

Many months later. We (@mweinelt and I) picked this topic back up. We reset everything and started from scratch (empty synapse, empty appservice irc, ...). On first startup, everything seemingly works except for the Admin room with the appservice.

We are getting invites but are unable to accept the invites. I managed to start a new DM with the appservice after creating the profile (as posted above). New users are still unable to accept an invite from the appservice into the admin room.

After explicitly allowing anyone (in particular matrix.org) to fetch our HS's public key via federation we were able to accept the invites. It is a bit confusing to see that a closed-network of servers doesn't work without federating with matrix.org.

@jaller94 jaller94 added needs-investigation T-Defect Bugs, crashes, hangs, vulnerabilities, or other reported problems. S-Major Severely degrades major functionality or product features, with no satisfactory workaround labels May 16, 2022
@mckaygerhard
Copy link

hi today it seem that prevously bridged rooms have similar problem, i guess, in matrix network:

after solvin the problem of not appears the bridge, i try to rejoin my ones.. checking that irc channels does not show the responses.. but at the side of matrix noted that "there are already bridged channel at irc".. intersting..

i just removed the bridge and try to remade, got this error:

Could not request link. Error IRC_DOUBLE_BRIDGE: Room failed validation. You may be attempting to "double bridge" this room. Error: Error: M_FORBIDDEN: Appservice not in room

becouse appservice it not in the room and must be invited and cannot get invites in matrix public networks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs-investigation S-Major Severely degrades major functionality or product features, with no satisfactory workaround T-Defect Bugs, crashes, hangs, vulnerabilities, or other reported problems.
Projects
None yet
Development

No branches or pull requests

8 participants