Sometimes PMs from Telegram don't get received on the Matrix account that's double-puppeted

[LocalMonero]

Hey guys,

We're from LocalMonero, a P2P crypto trading platform, and we've recently decided to add Matrix as one of our social media presences.

We're using Mautrix Telegram to bridge our Telegram groups to our Matrix rooms and we also would like to switch to fully double-puppeting our staff Telegram accounts with matrix so that we can be fully Matrix-based essentially.

Unfortunately, we are currently unable to fully switch because, for some reason, the Mautrix Telegram bridge sometimes fails to fully synchronize PMs, completely missing messages in some instances. We're talking about, for example, people with whom we already have a PM history (that got backfilled/synced by the bridge) PMs with us, sending 10 messages, and only 8/10 get relayed to the double puppet account on Matrix. This doesn't happen always, but it happens regularly. Once or twice a day.

This seems to only affect PMs where there's a certain history to it. Doesn't seem to affect new PMs. But this is merely an observation, we can't say for sure.

Note, our staff Telegram accounts have many hundreds of PMs going on, so, we assume, heavy load is required to reproduce the issue.

What could the issue be? What should we provide to you guys to help debug the issue?

[tulir]

Logs corresponding to the missed messages are needed. There will probably be a stack trace with a fairly clear error message (probably "Failed to handle Telegram update"), but finding the right one might be hard if there's lots of traffic

[LocalMonero]

@tulir

Here's an error in the logs that corresponds in timing with a message in a PM room not being delivered:

Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,282] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY.network.mtprotosender] Encrypting 1 message(s) in 52 bytes for sending
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,283] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY.network.mtprotosender] Encrypted messages put in a queue to be sent
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,283] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY.network.mtprotosender] Waiting for messages to send...
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,382] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY.network.mtprotosender] Handling RPC result for message 7077650902822010560
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,382] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY.network.mtprotosender] Receiving items from the network...
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,382] [[email protected]_ID_1_TRUE_TG_ID_REDACTED_FOR_PRIVACY<->TG_ID_2_TRUE_TG_ID_REDACTED_FOR_PRIVACY] Fatal error creating Matrix room
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: Traceback (most recent call last):
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 699, in create_matrix_room
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     return await self._create_matrix_room(user, entity, invites)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 761, in _create_matrix_room
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     entity = await self.get_entity(user)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 3378, in get_entity
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     return await user.client.get_entity(self.peer)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/telethon/client/users.py", line 337, in get_entity
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     result.append(id_entity[utils.get_peer_id(x)])
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: KeyError: 1024109677
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: [2022-03-21 20:20:15,383] [[email protected].@REDACTED_USERNAME_1:agoradesk.com] Failed to handle Telegram update
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: Traceback (most recent call last):
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 252, in _update_catch
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     await self._update(update)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 312, in _update
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     await self.update_message(update)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 623, in update_message
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     return await portal.handle_telegram_message(self, sender, update)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 3144, in handle_telegram_message
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     event_id = await self._handle_telegram_text(source, intent, is_bot, evt)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 2532, in _handle_telegram_text
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     await intent.set_typing(self.mxid, is_typing=False)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix/appservice/api/intent.py", line 344, in set_typing
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     await self.ensure_joined(room_id)
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:   File "/usr/lib/python3.9/site-packages/mautrix/appservice/api/intent.py", line 500, in ensure_joined
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]:     raise ValueError("Room ID not given")
Mar 21 20:20:15 lmc matrix-mautrix-telegram[1730440]: ValueError: Room ID not given

[LocalMonero]

@tulir

More error logs for the same issue. Some help would be greatly appreciated.

Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: [2022-04-11 15:54:41,148] [[email protected]_ID_1<->TG_ID_2] Fatal error creating Matrix room
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: Traceback (most recent call last):
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 699, in create_matrix_room
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     return await self._create_matrix_room(user, entity, invites)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 761, in _create_matrix_room
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     entity = await self.get_entity(user)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 3378, in get_entity
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     return await user.client.get_entity(self.peer)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/telethon/client/users.py", line 337, in get_entity
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     result.append(id_entity[utils.get_peer_id(x)])
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: KeyError: TG_ID_2
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: [2022-04-11 15:54:41,151] [[email protected].@REDACTED:agoradesk.com] Failed to handle Telegram update
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: Traceback (most recent call last):
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 252, in _update_catch
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     await self._update(update)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 312, in _update
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     await self.update_message(update)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/abstract_user.py", line 623, in update_message
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     return await portal.handle_telegram_message(self, sender, update)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 3144, in handle_telegram_message
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     event_id = await self._handle_telegram_text(source, intent, is_bot, evt)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix_telegram/portal.py", line 2532, in _handle_telegram_text
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     await intent.set_typing(self.mxid, is_typing=False)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix/appservice/api/intent.py", line 344, in set_typing
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     await self.ensure_joined(room_id)
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:   File "/usr/lib/python3.9/site-packages/mautrix/appservice/api/intent.py", line 500, in ensure_joined
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]:     raise ValueError("Room ID not given")
Apr 11 15:54:41 lmc matrix-mautrix-telegram[3036855]: ValueError: Room ID not given

[tulir]

It's some problem in telethon or the telegram servers not returning the entity, but no idea why that would happen.

[tulir]

This might be fixed with some of the telethon changes recently

[LocalMonero]

@tulir which version?

[tulir]

0.12.0 should include all the relevant changes

[LocalMonero]

Seems to have fixed it! Thanks!