Bridge between multiple rocketchat servers only receives messages from the first one

[andynd]

Describe the bug
When configuring multiple rocketchat servers, only the first one added to a gateways inout section is able to receive messages. All can send messages but only the frist can receive them.

To Reproduce

1. Use the following config:

[rocketchat]
[rocketchat.a]
Server="https://<domain A>:443"
Nick="<nick>"
Login="<user>"
Password="<password>"
PrefixMessagesWithNick=false
RemoteNickFormat="[{PROTOCOL} {LABEL}] {NICK}"
Label="a"

[rocketchat.b]
Server="https://<domain B>:443"
Nick="<nick>"
Login="<user>"
Password="<password>"
PrefixMessagesWithNick=false
RemoteNickFormat="[{PROTOCOL} {LABEL}] {NICK}"
Label="b"

[[gateway]]
name="test-gateway"
enable=true
[[gateway.inout]]
account="rocketchat.a"
channel="#test1"
[[gateway.inout]]
account="rocketchat.b"
channel="#test1"

2. write something on rocketchat b in the channel #test1

Expected behavior
I see the message on rocketchat a in channel #test1

Screenshots/debug logs
No Logs or anything is produced for writing in rocketchat b after startup, even with -debug.
Startup looks like that:

Dec 03 14:35:24 misc-01 systemd[1]: Started Matterbridge bridge.
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Enabling debug logging." func=setupLogger file="matterbridge.go:104" prefix=main
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Running version 1.23.2 73ec02ab" func=main file="matterbridge.go:44" prefix=main
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="enabling rocketchat" func=New file="bridge/rocketchat/rocketchat.go:49" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="enabling rocketchat" func=New file="bridge/rocketchat/rocketchat.go:49" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Parsing gateway test-gateway" func=Start file="gateway/router.go:66" prefix=router
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Starting bridge: rocketchat.a " func=Start file="gateway/router.go:75" prefix=router
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Connecting using login/password (sending and receiving)" func=Connect file="bridge/rocketchat/rocketchat.go:73" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="handling apiLogin()" func=apiLogin file="bridge/rocketchat/helpers.go:59" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Connection succeeded" func=apiLogin file="bridge/rocketchat/helpers.go:84" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="rocketchat.a: joining #test1 (ID: #test1rocketchat.a)" func=joinChannels file="bridge/bridge.go:77" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="Choosing login/password based receiving" func=handleRocket file="bridge/rocketchat/handlers.go:17" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Starting bridge: rocketchat.b " func=Start file="gateway/router.go:75" prefix=router
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Connecting using login/password (sending and receiving)" func=Connect file="bridge/rocketchat/rocketchat.go:73" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="handling apiLogin()" func=apiLogin file="bridge/rocketchat/helpers.go:59" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Connection succeeded" func=apiLogin file="bridge/rocketchat/helpers.go:84" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="rocketchat.b: joining #test1 (ID: #test1rocketchat.b)" func=joinChannels file="bridge/bridge.go:77" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=debug msg="Choosing login/password based receiving" func=handleRocket file="bridge/rocketchat/handlers.go:17" prefix=rocketchat
Dec 03 14:35:24 misc-01 matterbridge[86704]: time="2021-12-03T14:35:24Z" level=info msg="Gateway(s) started succesfully. Now relaying messages" func=main file="matterbridge.go:68" prefix=main

Environment (please complete the following information):

• OS: Debian Bullseye
• Matterbridge version: version: 1.23.2 73ec02ab

Additional context

[psy]

This also happens if samechannelgateway is used instead:

[[samechannelgateway]]
name="samechannel1"
enable = true
accounts = [ "rocketchat.a","rocketchat.b" ]
channels = [ "#test1"]

[andynd]

I just tested switching the rocketchat server b to using webhooks for send and receive.
This seems to work and results in the following log output:

Dec 03 15:34:24 misc-01 systemd[1]: Started Matterbridge bridge.
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Enabling debug logging." func=setupLogger file="matterbridge.go:104" prefix=main
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Running version 1.23.2 73ec02ab" func=main file="matterbridge.go:44" prefix=main
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=debug msg="enabling rocketchat" func=New file="bridge/rocketchat/rocketchat.go:49" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=debug msg="enabling rocketchat" func=New file="bridge/rocketchat/rocketchat.go:49" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Parsing gateway test-gateway1" func=Start file="gateway/router.go:66" prefix=router
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Starting bridge: rocketchat.b " func=Start file="gateway/router.go:75" prefix=router
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Connecting using webhookurl (sending) and webhookbindaddress (receiving)" func=doConnectWebhookBind file="bridge/rocketchat/helpers.go:25" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="rocketchat.b: joining #test1 (ID: #test1rocketchat.b)" func=joinChannels file="bridge/bridge.go:77" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Starting bridge: rocketchat.a " func=Start file="gateway/router.go:75" prefix=router
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Connecting using login/password (sending and receiving)" func=Connect file="bridge/rocketchat/rocketchat.go:73" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=debug msg="handling apiLogin()" func=apiLogin file="bridge/rocketchat/helpers.go:59" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: 2021/12/03 15:34:24 Listening on http://0.0.0.0:19999...
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=debug msg="Choosing webhooks based receiving" func=handleRocket file="bridge/rocketchat/handlers.go:14" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Connection succeeded" func=apiLogin file="bridge/rocketchat/helpers.go:84" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="rocketchat.a: joining #test1 (ID: #test1rocketchat.a)" func=joinChannels file="bridge/bridge.go:77" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=debug msg="Choosing login/password based receiving" func=handleRocket file="bridge/rocketchat/handlers.go:17" prefix=rocketchat
Dec 03 15:34:24 misc-01 matterbridge[87036]: time="2021-12-03T15:34:24Z" level=info msg="Gateway(s) started succesfully. Now relaying messages" func=main file="matterbridge.go:68" prefix=main

So you can use webhooks for one of the servers as a workaround.

Edit:

This does only allow you to bridge a single channel per defined server. You can workaround this by setting up a seperate server block for each channel using identical data but different webhooks. It get's very messy with just a few channels.
That all could be avoided if webhook workaround would not be needed.
Alternatively it could be allowed to not specify WebhookURL and only use the WebhookBindAddress for receiving since sending via api works just fine.

Edit again:

This workaround works, even for multiple channels per server. The WebhookURL "post in channel" restrictions seem to be ignored.

[patrick246]

I think I found the root cause:

matterbridge/vendor/github.com/matterbridge/Rocket.Chat.Go.SDK/realtime/messages.go

Line 20 in 80d3033

var messageListenerAdded = false

The Rocket.chat client has this global bool flag that checks if the subscriber has already been added. The problem is that two different clients will of course use the same bool flag and the second client also uses the same bool flag and will therefore not add a subscriber, and doesn't get notified of any messages.

I would like to provide a fix, but I don't know where exactly - the original rocketchat repo, the forked one in matterbridge/Rocket.Chat.Go.SDK or the vendored code? All these three places seem to have different code from each other.

Edit: I've implemented a fix in https://github.com/patrick246/matterbridge, right in the master branch. This modifies vendored code which I'm not so sure about :)

[tachiniererin]

@patrick246 the right place in this case would be to submit a PR in https://github.com/matterbridge/Rocket.Chat.Go.SDK and in addition in the upstream repo. the matterbridge fork is quite old, so i don't know if it would be some effort to upgrade it to the latest version.

i'll have a look today an see how much effort this is :)

[patrick246]

That's the interesting part: The Matterbridge fork of the Rocketchat go sdk is too old to contain this bug, it's only present in the vendored code and in the upstream sdk.

[tachiniererin]

hm, not keeping the vendored code and the fork specific to the project in sync is an unorthodox choice... but that just means upstreaming the fix is the best option.

[tachiniererin]

i submitted a PR in upstream rocketchat sdk (RocketChat/Rocket.Chat.Go.SDK#46) and here's my fork with the changes integrated: https://github.com/tachiniererin/matterbridge i'll create a PR for that too as soon as the upstream stuff gets merged.