Telethon: timeout and authKeyUnregisteredError

[hnikaein]

Hi,
sometimes, during big downloads I get this exception:

  File "/usr/local/lib/python3.5/dist-packages/telethon/extensions/tcp_client.py", line 94, in read
    partial = self._socket.recv(bytes_left)
BlockingIOError: [Errno 11] Resource temporarily unavailable

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/elenoon/telegram-chanel-copier/channel_copier.py", line 112, in main
    client.download_msg_media(msg.media, 'media/{}_{}'.format(entity.id, msg.id))
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 594, in download_msg_media
    add_extension, progress_callback)
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 672, in download_document
    progress_callback=progress_callback
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 724, in download_file
    progress_callback=progress_callback
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_bare_client.py", line 313, in download_file
    GetFileRequest(input_location, offset, part_size))
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 247, in invoke
    request, timeout=timeout, updates=updates)
  File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_bare_client.py", line 189, in invoke
    self.sender.receive(request, timeout, updates=updates)
  File "/usr/local/lib/python3.5/dist-packages/telethon/network/mtproto_sender.py", line 100, in receive
    seq, body = self._transport.receive(timeout)
  File "/usr/local/lib/python3.5/dist-packages/telethon/network/tcp_transport.py", line 45, in receive
    packet_length_bytes = self.tcp_client.read(4, timeout)
  File "/usr/local/lib/python3.5/dist-packages/telethon/extensions/tcp_client.py", line 111, in read
    'The read operation exceeded the timeout.') from error
TimeoutError: The read operation exceeded the timeout.

And after that, if I try to invoke anything it will give me "you must be connected" error, and if I try to disconnect and connect it needs to re sign in.

any idea?

thanks

[Lonami]

I tried downloading a 100MiB file and it stopped for some seconds on these steps:

Downloaded 10.38MB out of 100.00MB (10.38%)
...
Downloaded 12.00MB out of 100.00MB (12.00%)

So maybe Telegram is slowing us down, in your case, enough for the timeout to trigger. I wonder if timeouts could be handled inside the function and keep retrying forever. The problem would be differentiating between a real timeout or, if I'm right, those which occur when Telegram slows us down.

Eventually, I managed to download such file.

[hnikaein]

Unfortunately when I try to retry download, it needs reconnect, and when I do reconnect, it needs re sign in!

[nnehdi-zz]

HI.
I have the same problem. I was repeating downloading some media, some of them done successfully but for some I get this exception:
ValueError: You must be connected to invoke requests!
Any suggestion??

[Lonami]

I have no clue… it worked on my machine so it's not something I can reproduce. You should try adding a try/except TimeoutError around the faulty method and somehow fix it so I can implement the fix.

My only suggestions is, try reconnecting? Only connecting? Simply reinvoking the request? I have no clue.

[nnehdi-zz]

This my code:
`

session_file_path = "/opt/telegram_session/00989027599326"
client = TelegramClient(
                        session_file_path,
                        API_ID,
                        API_HASH)

client.connect()
channel_username = "VahidOnline"
resolution_info = client.invoke(ResolveUsernameRequest(channel_username), timeout=timedelta(seconds=20))
user_id = resolution_info.peer.channel_id
access_hash = resolution_info.chats[0].access_hash
entity = InputPeerChannel(user_id, access_hash)
message_list = client.get_message_history(entity)

base_file_path = "/opt/telegram_media_share"
# download media for each message
for message in message_list[1]:
    print(str(message))
    media = message.media
    if not media:
        continue
    download_res = client.download_msg_media(media, base_file_path + str(message.id))
    print("download done : {}".format(download_res))

`

and the error is :

Could not stabilise initial connection: CONNECTION_APP_VERSION_EMPTY (code 400)

ValueError: You must be connected to invoke requests!

TelegramClient connect correctly and get_message_history() return messages.

[Lonami]

CONNECTION_APP_VERSION_EMPTY

See https://github.com/LonamiWebs/Telethon/commit/2af962230f3642f2821dba9a8b0b2805246d7ac9. Guess I better push that new version to pip.

Edit: Done. Please upgrade and try again.

[nnehdi-zz]

Thanks, that's make it better, but we still get this error sometime and this is very strange!
ValueError: You must be connected to invoke requests!

[Lonami]

ValueError: You must be connected to invoke requests

But after a timeout? Did you try reconnecting as I suggested?

[hnikaein]

I tried. But after reconnecting it forces me to re sign in.

[toioski]

Sorry for the little off topic, but why the download speed with big files is so slow? I made some test and I have seen that a 200MB file download at 20KB/s with Telethon, while using the desktop client for MacOS the average is more than 1MB/s!

P.S. if necessary I will open a separate issue

[Lonami]

but why the download speed with big files is so slow?

No idea, official clients may use a separate connection, or several to get different parts at the same time, or maybe request larger chunk sizes…

[Lonami]

but why the download speed with big files is so slow?

Oh, now I was just thinking about this. Perhaps is due to that sort of arbitrary sleep(0.1) I have on the very base. If you're good with both Python and sockets, and know another way to make a socket .cancel()able (which I need if I want to keep receiving updates– or maybe not?), please let me know so we can get rid of that sleep… Maybe open an issue.

[hnikaein]

an update,
when I using multiple threads to download multiple dialogs concurrently, there is no exception!

[hnikaein]

Can you please take a look at this log:

2017-07-10 17:20:47_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:20:47_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:20:47_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:20:47_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:52_root_WARNING: Catched: The read operation exceeded the timeout.
2017-07-10 17:20:52_root_WARNING: Traceback (most recent call last):
File "/usr/local/lib/python3.5/dist-packages/telethon/extensions/tcp_client.py", line 97, in read
partial = self._socket.recv(bytes_left)
BlockingIOError: [Errno 11] Resource temporarily unavailable

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
File "/home/elenoon/telegram-chanel-copier/channel_copier.py", line 133, in main
while not client.is_user_authorized():
File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 307, in is_user_authorized
return self.session and self.get_me() is not None
File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 397, in get_me
return self.invoke(GetUsersRequest([InputUserSelf()]))[0]
File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_client.py", line 261, in invoke
request, updates=updates
File "/usr/local/lib/python3.5/dist-packages/telethon/telegram_bare_client.py", line 220, in invoke
self._sender.receive(request, updates=updates)
File "/usr/local/lib/python3.5/dist-packages/telethon/network/mtproto_sender.py", line 104, in receive
seq, body = self.transport.receive(**kwargs)
File "/usr/local/lib/python3.5/dist-packages/telethon/network/tcp_transport.py", line 62, in receive
body = self.tcp_client.read(packet_length - 12, timeout)
File "/usr/local/lib/python3.5/dist-packages/telethon/extensions/tcp_client.py", line 114, in read
'The read operation exceeded the timeout.') from error
TimeoutError: The read operation exceeded the timeout.

2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:20:57_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: Handling bad server salt
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:20:57_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:57_telethon.network.mtproto_sender_DEBUG: Ignored update for new_session_created#9ec20908 first_msg_id:long unique_id:long server_salt:long = NewSessio
2017-07-10 17:20:57_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: Reading request response
2017-07-10 17:20:58_telethon.network.mtproto_sender_INFO: Request result received
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: receive() released the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:20:58_telethon.network.mtproto_sender_WARNING: Read RPC error: (AuthKeyUnregisteredError(...), 'The key is not registered in the system.')
2017-07-10 17:20:58_root_WARNING: calling is_user_authorized()
2017-07-10 17:20:58_root_WARNING: calling send_code_request()
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:20:58_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:20:59_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:20:59_telethon.network.mtproto_sender_WARNING: Read RPC error: (PhoneMigrateError(...), 'The phone number a user is trying to use for authorization is ass
2017-07-10 17:20:59_telethon.telegram_bare_client_INFO: DC error when invoking request, attempting to reconnect at DC 4
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:21:05_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: Handling bad server salt
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:21:05_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:05_telethon.network.mtproto_sender_DEBUG: Ignored update for new_session_created#9ec20908 first_msg_id:long unique_id:long server_salt:long = NewSessio
2017-07-10 17:21:05_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: Reading request response
2017-07-10 17:21:06_telethon.network.mtproto_sender_INFO: Request result received
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: receive() released the lock
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:21:06_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: Reading request response
2017-07-10 17:21:06_telethon.network.mtproto_sender_INFO: Request result received
2017-07-10 17:21:06_telethon.network.mtproto_sender_DEBUG: receive() released the lock
2017-07-10 17:21:06_root_WARNING: waiting for user enter code
2017-07-10 17:21:36_root_WARNING: calling sign_in()
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:21:36_telethon.network.mtproto_sender_WARNING: Read RPC error: (PhoneCodeInvalidError(...), 'The phone code entered was invalid.')
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: send() acquired the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: send() released the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: receive() acquired the lock
2017-07-10 17:21:36_telethon.network.mtproto_sender_INFO: Trying to .receive() the request result...
2017-07-10 17:21:36_telethon.network.mtproto_sender_DEBUG: Handling RPC result
2017-07-10 17:21:36_telethon.network.mtproto_sender_WARNING: Read RPC error: (AuthKeyUnregisteredError(...), 'The key is not registered in the system.')

[Lonami]

AuthKeyUnregisteredError(...), 'The key is not registered in the system.'

Regarding that error, it probably has been fixed on https://github.com/LonamiWebs/Telethon/commit/ceb37cd4c55d67f5b1669860f18a447a668588df. Here's another relevant screenshot for future references (from October's 25th):