message on Matrix not marked as read, re-bridged back from other side of matrix-NCTalk bridge.

[yetiinabox]

Describe the bug
When a message is posted on the matrix side of a matrix<-> NCTalk bridge, the message appears twice, the second time as a bridged message returning from the NCTalk side.

This appears to happen because matterbridge cannot POST a json string to a matrix endpoint that marks the message as read; matrix responds to the POST from matterbridge saying it is not json. (see debug log)

To Reproduce
Run matterbridge with a correctly configured bridge between matrix and NCTalk.
Post a message on the matrix side.

The error does not happen when the original message is on the NCTalk side.

Possibly important extra information:
If the matterbridge process is run on the same machine as the matrix-synapse server, the same error is reported in the logs but the double message on the matrix chatroom does not occur.

Expected behavior
A message is posted exactly once on each channel.

Screenshots/debug logs
Transcript of matrix chat:

okay, let's create an error.
[21:10]

matterbridge
[nctalk] <matterbridge (matterbridge)> [matrix] okay, let's create an error.
[21:10]

Debug log:
[0026] DEBUG matrix: [handleEvent:bridge/matrix/matrix.go:457] == Receiving event: &gomatrix.Event{StateKey:(*string)(nil), Sender:"@Wbtd:tending.to", Type:"m.room.message", Timestamp:1647810622920, ID:"$KWjHolUMsyOqjQXR4JGoylp0UlsT5lyyjt7ZOsFJs6I", RoomID:"!XbbbRBTHwuDzqCqBJQ:tending.to", Redacts:"", Unsigned:map[string]interface {}{"age":379}, Content:map[string]interface {}{"body":"okay, let's create an error.", "msgtype":"m.text", "org.matrix.msc1767.text":"okay, let's create an error."}, PrevContent:map[string]interface {}(nil)}
[0027] DEBUG matrix: [handleEvent:bridge/matrix/matrix.go:522] <= Sending message from @Wbtd:tending.to on matrix.mymatrix to gateway
[0027] DEBUG gateway: [SendMessage:gateway/gateway.go:482] => Sending config.Message{Text:"okay, let's create an error.", Channel:"#yetichats:tending.to", Username:"Mossbeard", UserID:"@Wbtd:tending.to", Avatar:"https://tending.to:8448/_matrix/media/r0/thumbnail/tending.to/ztrboLoEyslrUSDBrmupOhFC?width=37&height=37&method=crop", Account:"matrix.mymatrix", Event:"", Protocol:"matrix", Gateway:"gateway1", ParentID:"", Timestamp:time.Date(2022, time.March, 20, 21, 10, 23, 590400663, time.Local), ID:"$KWjHolUMsyOqjQXR4JGoylp0UlsT5lyyjt7ZOsFJs6I", Extra:map[string][]interface {}(nil)} from matrix.mymatrix (#yetichats:tending.to) to nctalk.yetis (69ajy2tu)
[0027] ERROR matrix: [handleEvent:bridge/matrix/matrix.go:527] couldn't mark message as read contents=[123 34 101 114 114 99 111 100 101 34 58 34 77 95 78 79 84 95 74 83 79 78 34 44 34 101 114 114 111 114 34 58 34 67 111 110 116 101 110 116 32 110 111 116 32 74 83 79 78 46 34 125] msg=Failed to POST JSON to /_matrix/client/r0/rooms/!XbbbRBTHwuDzqCqBJQ:tending.to/receipt/m.read/$KWjHolUMsyOqjQXR4JGoylp0UlsT5lyyjt7ZOsFJs6I code=400 wrapped=M_NOT_JSON: Content not JSON.
[0029] DEBUG gateway: [SendMessage:gateway/gateway.go:501] mID nctalk.yetis: 257
[0029] DEBUG gateway: [func1:gateway/gateway.go:491] => Send from matrix.mymatrix (#yetichats:tending.to) to nctalk.yetis (69ajy2tu) took 2.49497269s
[0030] DEBUG nctalk: [handleSendingMessage:bridge/nctalk/nctalk.go:240] <= Message is config.Message{Text:"[matrix] okay, let's create an error.", Channel:"69ajy2tu", Username:"matterbridge (matterbridge)", UserID:"ad7e1390-b252-103a-9876-31a1d76feef8", Avatar:"", Account:"nctalk.yetis", Event:"", Protocol:"", Gateway:"", ParentID:"", Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), ID:"257", Extra:map[string][]interface {}(nil)}
[0030] DEBUG gateway: [SendMessage:gateway/gateway.go:482] => Sending config.Message{Text:"[matrix] okay, let's create an error.", Channel:"69ajy2tu", Username:"matterbridge (matterbridge)", UserID:"ad7e1390-b252-103a-9876-31a1d76feef8", Avatar:"", Account:"nctalk.yetis", Event:"", Protocol:"nctalk", Gateway:"gateway1", ParentID:"", Timestamp:time.Date(2022, time.March, 20, 21, 10, 26, 811513471, time.Local), ID:"257", Extra:map[string][]interface {}(nil)} from nctalk.yetis (69ajy2tu) to matrix.mymatrix (#yetichats:tending.to)
[0030] DEBUG matrix: [Send:bridge/matrix/matrix.go:144] => Receiving config.Message{Text:"[matrix] okay, let's create an error.", Channel:"#yetichats:tending.to", Username:"[nctalk] <matterbridge (matterbridge)> ", UserID:"ad7e1390-b252-103a-9876-31a1d76feef8", Avatar:"", Account:"nctalk.yetis", Event:"", Protocol:"nctalk", Gateway:"gateway1", ParentID:"", Timestamp:time.Date(2022, time.March, 20, 21, 10, 26, 811513471, time.Local), ID:"", Extra:map[string][]interface {}(nil)}
[0030] DEBUG matrix: [Send:bridge/matrix/matrix.go:147] Channel #yetichats:tending.to maps to channel id !XbbbRBTHwuDzqCqBJQ:tending.to
[0030] DEBUG gateway: [SendMessage:gateway/gateway.go:501] mID matrix.mymatrix: $fzxZNSqYUsZM9POTuDYx6q0kQ_SgB6nTzF6b79QqzAo
[0030] DEBUG gateway: [func1:gateway/gateway.go:491] => Send from nctalk.yetis (69ajy2tu) to matrix.mymatrix (#yetichats:tending.to) took 463.052672ms
[0031] DEBUG matrix: [handleEvent:bridge/matrix/matrix.go:457] == Receiving event: &gomatrix.Event{StateKey:(*string)(nil), Sender:"@matterbridge:tending.to", Type:"m.room.message", Timestamp:1647810626937, ID:"$fzxZNSqYUsZM9POTuDYx6q0kQ_SgB6nTzF6b79QqzAo", RoomID:"!XbbbRBTHwuDzqCqBJQ:tending.to", Redacts:"", Unsigned:map[string]interface {}{"age":371, "transaction_id":"go1647810626812034481"}, Content:map[string]interface {}{"body":"[nctalk] <matterbridge (matterbridge)> [matrix] okay, let's create an error.", "format":"org.matrix.custom.html", "formatted_body":"[nctalk] <matterbridge (matterbridge)> [matrix] okay, let's create an error.", "msgtype":"m.text"}, PrevContent:map[string]interface {}(nil)}

Environment (please complete the following information):

• OS: Debian bookworm/sid (matterbridge and NextCloud 22.2.3); Ubuntu 20.04 (Matrix-synapse 1.54)
• Matterbridge version: 1.24.1-dev 24bc0f1

Additional context
Please add your configuration file (be sure to exclude or anonymize private data (tokens/passwords))
[matrix.mymatrix]
#Server is your homeserver (eg https://matrix.org)
Server="https://tending.to:8448"

#login/pass of your bot.
#Use a dedicated user for this and not your own!
#Messages sent from this user will not be relayed to avoid loops.
Login="matterbridge"
Password="XXXXXXX"

RemoteNickFormat="[{PROTOCOL}] <{NICK}> "
PrefixMessagesWithNick="true"

#Whether to send the homeserver suffix. eg ":matrix.org" in @username:matrix.org
#to other bridges, or only send "username".(true only sends username)
#OPTIONAL (default false)
NoHomeServerSuffix=true

[nctalk.yetis]
Server="https://nc.g.yetinivas.net" #this might not work from Tending?
Login="matterbridge"
Password="XXXXXXX"
RemoteNickFormat="[{PROTOCOL}] <{NICK}> "
PrefixMessagesWithNick="true"

[[gateway]]
name="gateway1"
enable=true

[[gateway.inout]]
account="matrix.mymatrix"
channel="#yetichats:tending.to"

[[gateway.inout]]
account="nctalk.yetis"
channel="69ajy2tu"

[yetiinabox]

Could this be related to matrix-nio/matrix-nio#290 ?

[42wim]

@yetiinabox thanks for the pointer, the same fix is now in master.