XMPP loosing connectivity after a while

[micw]

The bridge to XMPP stops to work from time to time. Matterbridge "thinks" that it's still connected, so when sending a message from matrix, it still tries to deliver to xmpp but on xmpp end, nothing is received. A log of this situation can be found below.

Pings are also still sent to xmpp. Messages from xmpp are not seen by matterbridge.

It may be related/same issue as #1552 but i have no evidence that it correlates to a restart of the XMPP server.

Fri, Mar 11 2022 6:49:49 pm | time="2022-03-11T18:49:49+01:00" level=debug msg=PING func=func1 file="bridge/xmpp/xmpp.go:265" prefix=xmpp
Fri, Mar 11 2022 6:51:18 pm | time="2022-03-11T18:51:18+01:00" level=debug msg=PING func=func1 file="bridge/xmpp/xmpp.go:265" prefix=xmpp
Fri, Mar 11 2022 6:52:48 pm | time="2022-03-11T18:52:48+01:00" level=debug msg=PING func=func1 file="bridge/xmpp/xmpp.go:265" prefix=xmpp
Fri, Mar 11 2022 6:54:19 pm | time="2022-03-11T18:54:19+01:00" level=debug msg=PING func=func1 file="bridge/xmpp/xmpp.go:265" prefix=xmpp
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="== Receiving event: &gomatrix.Event{StateKey:(*string)(nil), Sender:"@mwyraz:matrix.wyraz.de", Type:"m.room.message", Timestamp:1647021304437, ID:"$GKBmtzeNLUBGxbLpDjg8o8crLkHx0I2IfbhQq_eTWYQ", RoomID:"!YBXlBFCiElKxNMhLBv:chat.dezentrale.space", Redacts:"", Unsigned:map[string]interface {}{"age":77}, Content:map[string]interface {}{"body":"Ich versuche das Matterbridge-Thema mal zu debuggen", "msgtype":"m.text", "org.matrix.msc1767.text":"Ich versuche das Matterbridge-Thema mal zu debuggen"}, PrevContent:map[string]interface {}(nil)}" func=handleEvent file="bridge/matrix/matrix.go:457" prefix=matrix
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="<= Sending message from @mwyraz:matrix.wyraz.de on matrix.wyraz to gateway" func=handleEvent file="bridge/matrix/matrix.go:522" prefix=matrix
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="=> Sending config.Message{Text:"Ich versuche das Matterbridge-Thema mal zu debuggen", Channel:"!YBXlBFCiElKxNMhLBv:chat.dezentrale.space", Username:"Michael Wyraz", UserID:"@mwyraz:matrix.wyraz.de", Avatar:"", Account:"matrix.wyraz", Event:"", Protocol:"matrix", Gateway:"Freifunk Leipzig", ParentID:"", Timestamp:time.Date(2022, time.March, 11, 18, 55, 4, 569451501, time.Local), ID:"$GKBmtzeNLUBGxbLpDjg8o8crLkHx0I2IfbhQq_eTWYQ", Extra:map[string][]interface {}(nil)} from matrix.wyraz (!YBXlBFCiElKxNMhLBv:chat.dezentrale.space) to xmpp.jabberccc (leipzig.freifunk.net)" func=SendMessage file="gateway/gateway.go:482" prefix=gateway
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="=> Receiving config.Message{Text:"Ich versuche das Matterbridge-Thema mal zu debuggen", Channel:"leipzig.freifunk.net", Username:"╠ Michael Wyraz ╣\n", UserID:"@mwyraz:matrix.wyraz.de", Avatar:"", Account:"matrix.wyraz", Event:"", Protocol:"matrix", Gateway:"Freifunk Leipzig", ParentID:"", Timestamp:time.Date(2022, time.March, 11, 18, 55, 4, 569451501, time.Local), ID:"", Extra:map[string][]interface {}(nil)}" func=Send file="bridge/xmpp/xmpp.go:80" prefix=xmpp
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="=> Sending message config.Message{Text:"Ich versuche das Matterbridge-Thema mal zu debuggen", Channel:"leipzig.freifunk.net", Username:"╠ Michael Wyraz ╣\n", UserID:"@mwyraz:matrix.wyraz.de", Avatar:"", Account:"matrix.wyraz", Event:"", Protocol:"matrix", Gateway:"Freifunk Leipzig", ParentID:"", Timestamp:time.Date(2022, time.March, 11, 18, 55, 4, 569451501, time.Local), ID:"", Extra:map[string][]interface {}(nil)}" func=Send file="bridge/xmpp/xmpp.go:133" prefix=xmpp
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="mID xmpp.jabberccc: c8lopu2u06i4mb4o51sg" func=SendMessage file="gateway/gateway.go:501" prefix=gateway
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=debug msg="=> Send from matrix.wyraz (!YBXlBFCiElKxNMhLBv:chat.dezentrale.space) to xmpp.jabberccc (leipzig.freifunk.net) took 311.936µs" func=func1 file="gateway/gateway.go:491" prefix=gateway
Fri, Mar 11 2022 6:55:04 pm | time="2022-03-11T18:55:04+01:00" level=error msg="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/!YBXlBFCiElKxNMhLBv:chat.dezentrale.space/receipt/m.read/$GKBmtzeNLUBGxbLpDjg8o8crLkHx0I2IfbhQq_eTWYQ code=400 wrapped=M_NOT_JSON: Content not JSON." func=handleEvent file="bridge/matrix/matrix.go:527" prefix=matrix

[micw]

@42wim Can I provide some more information to debug this? It happens regulary.

[42wim]

nope, no idea