Telethon: Proper handling of updates

[Lonami]

Update: The ahead mentioned branch was merged. More discussion to enhance updates starts here.

---

If anyone is interested in collaborating, please refer to the better-updates branch. This is an open source project and personally updates don't bother me that much. If you really need updates, feel free to contribute to Telethon instead reinventing the wheel. I will happily merge.

Currently updates are not handled in their best way, duplicates may be received, we never call GetDifferenceRequest, and the managing threads or multiple connections should in general be reworked to properly accommodate this feature.

[OpaDopa]

hmmm i think it is the updates module that makes this project awesome! The rest of the Python Telegram projects doesnt have a functionality like this.. But i understand!
I cant figure out how to improve the update functionality, my python knowledge is not that good. Hope someone picks up this 👍

[Lonami]

I'm looking forward to merge update-object into master so people can give some feedback on this design approach. If you'd like to test before I merge however that would be nice. Please check out Usage Modes on the wiki and simply let me know if you can think of better names or usage modes (if you want to help).

[dimitar-petrov]

@Lonami, I have also noticed that there are unusual random delays(15-45s) when receiving updates(#151) . I have a feeling it might be related to FLOOD_WAIT from telegram api.

[Lonami]

@dimitar-petrov not sure about that, even if you do get a flood wait with a certain request, you can still send others, and Telegram should actually carry on sending updates. The ReadThread doesn't stop.

[Lonami]

Updates are pretty okay already in my opinion.

[HFDave]

The question is what is Telethon's goal? The mobile phone application or the web client shows messages immediately. On the other hand, channel messages received via Telethon/API are typically delayed between 0 - 60s. They are also often received in bursts after a delay. This could be too much for bots as well as fluent communication.

Can we get the same functionality in Telethon?
Is it even possible or does Telegram API limit us?

Please see this example:

[17:43:18] CRYPTO TROLLBOX (1129575249) (59 sec) SC targets?
[17:43:18] CRYPTO TROLLBOX (1129575249) (41 sec) I need a good binance group with trading signals, anyone??!
[17:43:18] CRYPTO TROLLBOX (1129575249) (28 sec) Add me
[17:43:18] CRYPTO TROLLBOX (1129575249) (25 sec) Short 720, later 1000
[17:43:18] CRYPTO TROLLBOX (1129575249) (14 sec) SHould i purchase etn or not
[17:43:18] CRYPTO TROLLBOX (1129575249) (12 sec) ?
[17:43:18] CRYPTO TROLLBOX (1129575249) (04 sec) Qtum smart to buy? Because of the big announcement

(Lonami: I utilized the minimalistic code we used today while fixing the previous problem to collect these messages.)

There is time the message was received via Telethon on the very left. It is 17:43:18 for all messages. Then follows channel.title, channel.id and message age computed as the difference between current time and message.date expressed in seconds.

I usually witness the phenomena that the messages always come in at the same second. Lets say new message can come at 12:10:18, 12:11:18, or 12:12:18 and so on. (With very slow forward drift, it will change to 19 in some time.)

We are, in fact, getting updated once per minute only so the messages could be aged anywhere between 0 an 60s.

[Lonami]

The question is what is Telethon's goal?

To be an easy-to-use yet powerful Telegram API wrapper, written in Python.

received via Telethon/API are typically delayed between 0 - 60s

I don't run the library for long, and when I do some quick tests, this doesn't happen. I should probably rewrite for a third? time the update handling and avoid multiple connections (as it's currently) as it might be an issue.

[HFDave]

I can offer everyday extensive testing and quick reporting of results.

I believe it is possible to get the delays on par with other platforms and I cannot see a proper solution in periodic history request calls - which work great, by the way.

The truth is that 60s delay is way too much and renders Telethon quite unusable in this field. One could easily look like an idiot when constantly replying one minute late. :) Big channels are fast paced and the chat roll forward quickly. Not speaking about bots where a 60s delay really equals to infinity.

Btw, I can make you a video. A chat which jumps like 30 lines at once every 1 minute is really hard to read. Even worse with more channels mixed in one composite output.

[Lonami]

It's okay, I guess periodic calls to getDifference would help.

[HFDave]

From what I experienced elsewhere, we should aim to receiving any message within 1 second.

When I was trying to temporarily overcome this problem using get_message_history(), I failed to find any info on Telegram API rate limits. For example Twitter has a rich documentation on this topic.

[Lonami]

Reopen if it still happens after this fix.

[Lonami]

Just as a reference, the idea of multiple connections was (sort of) introduced in #277.

[HFDave]

No visible differences with 0.16.0.8.
With 0.16.0.9, there were changes first:

The very first try:

[10:36:28] CRYPTO TROLLBOX (1129575249) (07 sec)
[10:36:28] CRYPTO TROLLBOX (1129575249) (02 sec)
[10:36:46] CRYPTO TROLLBOX (1129575249) (17 sec)
[10:36:46] CRYPTO TROLLBOX (1129575249) (09 sec)
[10:36:46] CRYPTO TROLLBOX (1129575249) (06 sec)
[10:36:46] CRYPTO TROLLBOX (1129575249) (06 sec)
[10:36:46] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:36:48] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:36:48] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:36:50] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:36:53] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:36:53] CRYPTO TROLLBOX (1129575249)
[10:37:00] CRYPTO TROLLBOX (1129575249) (08 sec)
[10:37:03] CRYPTO TROLLBOX (1129575249) (02 sec)
[10:37:07] CRYPTO TROLLBOX (1129575249) (02 sec)
[10:37:13] CRYPTO TROLLBOX (1129575249) (03 sec)
[10:37:13] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:37:13] CRYPTO TROLLBOX (1129575249) (01 sec)
[10:37:17] CRYPTO TROLLBOX (1129575249) (02 sec)
[10:37:19] CRYPTO TROLLBOX (1129575249) (03 sec)
[10:37:19] CRYPTO TROLLBOX (1129575249) (02 sec)

(Message content suppressed)

Somewhat erratic but much much better than it has ever been. I will have to investigate the missing date case as I have seen this before.

Then, I hit ^C and commit a second run. No changes to code or anything. Just ^C, up arrow, enter.

[10:39:21] CRYPTO TROLLBOX (1129575249) (59 sec)
[10:39:21] CRYPTO TROLLBOX (1129575249) (48 sec)
[10:39:21] CRYPTO TROLLBOX (1129575249) (33 sec)
[10:39:21] CRYPTO TROLLBOX (1129575249) (30 sec)
[10:39:21] CRYPTO TROLLBOX (1129575249) (18 sec)
[10:39:21] CRYPTO TROLLBOX (1129575249) (07 sec)

The standard burts is back.
Even trying completely independent code with the same results.

CRYPTO TROLLBOX (51)  
CRYPTO TROLLBOX (41)  
CRYPTO TROLLBOX (7)  
CRYPTO TROLLBOX (6)  
CRYPTO TROLLBOX (2)  

CRYPTO TROLLBOX (60)  
CRYPTO TROLLBOX (45)  
CRYPTO TROLLBOX (18)

... and so on.

Interesting, I have restarted two independent codes about five times each and cannot repeat the very first significantly better behavior. Some cache? I am not exactly a Python guru but trying: rm -rf __pycache__

Maybe looks better (?) ...

[10:55:50] CRYPTO TROLLBOX (1129575249) (07 sec)
[10:56:15] CRYPTO TROLLBOX (1129575249) (06 sec)
[10:57:15] CRYPTO TROLLBOX (1129575249) (25 sec)
[10:57:16] CRYPTO TROLLBOX (1129575249) (09 sec)
[10:57:26] CRYPTO TROLLBOX (1129575249) (07 sec)
[10:57:40] CRYPTO TROLLBOX (1129575249) (12 sec)
[10:57:40] CRYPTO TROLLBOX (1129575249) (05 sec)
[10:58:20] CRYPTO TROLLBOX (1129575249) (04 sec)
[10:58:53] CRYPTO TROLLBOX (1129575249) (01 sec)

... but after a little while ...

[11:00:24] CRYPTO TROLLBOX (1129575249) (53 sec)
[11:00:24] CRYPTO TROLLBOX (1129575249) (42 sec)
[11:00:24] CRYPTO TROLLBOX (1129575249) (19 sec)
...
[11:01:24] CRYPTO TROLLBOX (1129575249) (49 sec)
[11:01:24] CRYPTO TROLLBOX (1129575249) (40 sec)
[11:01:24] CRYPTO TROLLBOX (1129575249) (24 sec)
[11:01:24] CRYPTO TROLLBOX (1129575249) (03 sec)
[11:01:24] CRYPTO TROLLBOX (1129575249) (02 sec)

The last block looks even worse than before. It looks like it bursted two minutes of data at once.

[11:03:27] CRYPTO TROLLBOX (1129575249) (56 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (51 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (50 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (38 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (30 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (22 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (15 sec)
[11:03:27] CRYPTO TROLLBOX (1129575249) (11 sec)

So, I have actually no idea if it is completely random or not. There are also differences in how much and fast people are chatting between the tests. IDK if it can affect the results.

[HFDave]

Watching .7 and .9 at the same time comparing the outputs, I can say that .7 and probably also earlier versions were clearly losing some messages at all. Message delays .7 vs. .9 are actually about the same.

[Lonami]

Note that while the update may have been received in time, it might be delayed until it gets processed. I can't do much about CPython's GIL (which I presume could be part of the issue). Rather than using a handler, try patching this:
https://github.com/LonamiWebs/Telethon/blob/3c686fecdfc22a2ed7eb3c97f7bd1c156eff94d7/telethon/update_state.py#L120

Adding a print() or similar to see if updates are received at the right time but processed later. You may want to look at that (or ask questions) if you wish to investigate further. Here it gets called (as soon as an update is received):
https://github.com/LonamiWebs/Telethon/blob/3c686fecdfc22a2ed7eb3c97f7bd1c156eff94d7/telethon/network/mtproto_sender.py#L249-L250

And here is received (a tight loop, no delays apparently…):
https://github.com/LonamiWebs/Telethon/blob/3c686fecdfc22a2ed7eb3c97f7bd1c156eff94d7/telethon/telegram_bare_client.py#L848

[HFDave]

Lonami, I edited the first file (update_state.py) and added printing of all the updates. We will see if there is a difference. I will let you know.

I think that this issue must be resolved because one minute delays render this part of telethon unusable for the most of things.

[HFDave]

The update/message is already dated when it enters process(self, update) on line 120 in update_state.py. From process() it only takes about 20 ms to hit my own code.

[Lonami]

Not a clue really then. The library constantly is reading items (including Updates) from the network…

[HFDave]

That really is a very bad news. With minute delays, it is not a chat, I can send e-mails faster. :( I would like to know if it is even possible to solve this problem. It could be Telegram discriminating API clients or suboptimal implementation on the Telethon's end. Is there Telegram API documentation anywhere?

It is also interesting that it is possible to get the messages immediately with virtually zero delays using get_message_history() so the Telegram API is definitely able to server fresh content.

[Lonami]

Maybe if the library periodically called getDifference, I haven't tested. Maybe it works, maybe it doesn't, but code would need more changes.

[HFDave]

Will you try, please? I can offer all my limited ability to help. :)

[Lonami]

See https://core.telegram.org/method/updates.getDifference and https://core.telegram.org/api/updates, some information from the official documentation is relevant. You could try calling this yourself periodically. The current state is held by client.updates.

[dimitar-petrov]

Hi guys,

I have switched to https://github.com/danog/MadelineProto and it is handling updates better. I don't see similar delays over there. @Lonami, I guess you could have a quick chat with the lead developer of MProto and exchange some ideas (@danog)

[Lonami]

Yeah thanks @dimitar-petrov, I'm already in a chat with @danog and have talked about several things regarding MtProto development already.

[amirRamirfatahi]

so do you think you'll fix it in a new patch or should we fix it in our code?

[Lonami]

Should definitely be part of the library, so if you fix it in your code please make a pull request.

[HFDave]

Really guys, take a look at it someone, please. I tried what Lonami suggested but it is beyond my actual Python experience and project knowledge.

[Lonami]

After v0.17, https://github.com/LonamiWebs/Telethon/commit/341fb38136418c9ba616b70103618be390d9d1cb (Invoke getState after the server kicks us idling for updates) and https://github.com/LonamiWebs/Telethon/commit/fd08d5325393e1f650e682ef3cb9427507ea0d2b (Trust the server will not send duplicates) and the fact that I made and merged #595 just earlier… I think we can close this already. There's not much more we can do. There's a thread that is constantly reading every item from the socket, including updates, which are put in a queue, and then popped by one or more callbacks on different threads. It's as fast as it can get. Calling getDifference only makes a difference to get updates while we were offline, or if we ever get UpdatesTooLong. But we'll get to that.

If any of you have more ideas let me know.

[Ameobea]

I've been encountering this same issue. The more servers/messages that the account is subscribed to, the more cutouts there are. After enabling debug output, I've found that there are lots of log messages regarding networking errors printed out:

DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
DEBUG:telethon.extensions.tcp_client:socket.timeout "timed out" while reading data
DEBUG:telethon.telegram_bare_client:Receiving items from the network timed out
DEBUG:telethon.telegram_bare_client:Receiving items from the network...

I'm nearly certain that this isn't due to network connectivity issues, at least not on my end. My first thought is that there's some kind of rate-limiting or anti-DDOS that's going on on the Telegram side that's causing them to cut our requests off when we make too many polls for new messages or something similar.

Could this be related to rate limiting from other calls such as GetUsersRequest that are causing Telegram to put our client on cooldown or something?

[Lonami]

Would you say you received over 1,000 updates before this happened @Ameobea?

[Ameobea]

@Lonami no, this happens almost immediately.

I've done some more extensive looking through logs, and it looks like a ton of GetDialogsRequests are getting spewed out. This is indeed triggering ratelimiting, which seems to coincide with the cutouts:

DEBUG:telethon.network.mtproto_sender:Sending requests with IDs: GetDialogsRequest: 6532451062478031024
DEBUG:telethon.network.mtproto_sender:Processing Remote Procedure Call result
DEBUG:telethon.network.mtproto_sender:Received response for request with ID 6532451061536950928
DEBUG:telethon.network.mtproto_sender:Confirmed GetDialogsRequest through error A wait of 25 seconds is required
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
WARNING:telethon.telegram_bare_client:Request invoked too often, wait 25s
DEBUG:telethon.network.mtproto_sender:Processing Remote Procedure Call result
DEBUG:telethon.network.mtproto_sender:Received response for request with ID 6532451062478031024
DEBUG:telethon.network.mtproto_sender:Confirmed GetDialogsRequest through error A wait of 25 seconds is required
DEBUG:telethon.telegram_bare_client:Receiving items from the network...
WARNING:telethon.telegram_bare_client:Request invoked too often, wait 25s

[Lonami]

I iterate over the dialogs if .get_entity() fails to find an user. I should limit that.

Edit here we are https://github.com/LonamiWebs/Telethon/commit/1ff5826c26c0da5cd9dcccc1874dbd5ed03f56eb.

[vitalibr]

I'm going through the same issue, I get all messages from some channels and from others I receive only part of the messages.
I've spent several hours in the last few days trying to pinpoint where the problem is, but I did not find out. @amirRamirfatahi Are you still using the library in PHP instead of the telethon?

[Lonami]

@vitalibr if you figure out a way for me to reproduce this issue I'd be more than glad to help.

[vitalibr]

I tried creating some channels and getting spamming message to see if the behavior occurred, but without success.
Today, in my account this is occurring in only 2 channels of the 6 channels that I am member. I tried to figure out the difference of the 2 channels for the rest, or up to a standard, but without success, I definitely do not understand. I tried to debug the telethon code but it just does not seem to receive updates from the telegram.

I thought about using the library (MadelineProto) quoted by @amirRamirfatahi , and check if the problem really is the telethon or the telegram. Because I do not doubt that the problem is the telegram

If I can reproduce effectively, I'll let you know @Lonami
Thanks

[Lonami]

@vitalibr if I recall correctly the library you mention pulls updates (last time I checked anyway) by using getDifference. Telethon currently relies on Telegram delivering these updates, but it doesn't yet handle PTS holes (which is like saying, sometimes an update is missed and you need to fetch it, most commonly while reconnecting).

[vitalibr]

Now it makes sense where the "hole" in the library might be. As soon as I can, I'll try to make a modification and make requests using getDifference. I'll let you know if I have news. Thanks!

[Lonami]

catch_up was supposed to do that (catch up on missed updates). However after some discussion it seems like that should only be used over short periods, like after a reconnection. Furthermore, I didn't manage to make it work 100%, not even @danog himself was able to explain why it was working weirdly :sweat_smile: It would always return a difference and never a difference empty which is what clients use to determine when to stop.

So, the idea would be to save the update state in memory and getDifference on reconnection or such, which isn't done yet in the master asyncio rewrite.