Timeout on TelegramClient.connect()

[mwpenny]

Hello, I'm trying to use the library from within the Python interpreter to experiment with Telegram's API. However, when I try to establish the initial connection, the request times out. I've tried increasing the timeout value and switching to another data center - neither solves the problem.

This was working very well previously (last week) with version 0.11.3. I've also reproduced this with the latest release (version 0.11.5; installed via pip) as well as the latest commit to the master branch (manually installed).

I can use the Telegram app via my Android phone over WiFi on the same network as the PC in question. I've also verified (via Wireshark) that Telegram's server is in fact sending back a response to the library's requests. The only other thing I can think of is that I'm possibly being blocked/throttled by Telegram, but when this happened to me previously (too many SMS authentication requests) the server acknowledged the throttle with a FLOOD_WAIT_X error. Here, it appears that no response is detected at all.

Below are the steps I took to reproduce the problem, I am using Python version 3.6.1:

>>> import telethon
>>> API_ID = xxxxxx  # Obscured
>>> API_HASH = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'  # Obscured
>>> SESSION_NAME = 'test'
>>> client = telethon.TelegramClient(SESSION_NAME, API_ID, API_HASH)
>>> client.session.server_address
'91.108.56.165'  # DC5
>>> client.connect()
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/telethon/extensions/tcp_client.py", line 97, in read
    partial = self._socket.recv(bytes_left)
BlockingIOError: [Errno 35] Resource temporarily unavailable

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

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/telethon/telegram_client.py", line 140, in connect
    return super().connect()
  File "/usr/local/lib/python3.6/site-packages/telethon/telegram_bare_client.py", line 132, in connect
    layer=layer, query=request
  File "/usr/local/lib/python3.6/site-packages/telethon/telegram_client.py", line 205, in invoke
    request, updates=updates
  File "/usr/local/lib/python3.6/site-packages/telethon/telegram_bare_client.py", line 276, in invoke
    self._sender.receive(request, updates=updates)
  File "/usr/local/lib/python3.6/site-packages/telethon/network/mtproto_sender.py", line 104, in receive
    seq, body = self.transport.receive(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/telethon/network/tcp_transport.py", line 56, in receive
    packet_length_bytes = self.tcp_client.read(4, timeout)
  File "/usr/local/lib/python3.6/site-packages/telethon/extensions/tcp_client.py", line 115, in read
    'The read operation exceeded the timeout.') from error
TimeoutError: The read operation exceeded the timeout.

I see that a similar issue was opened (#158). @88ee55 said they solved the problem by creating a new account, however this occurs before user authentication. If they mean "new session", I have tried that as well.

Thanks

[Lonami]

I must say this issue was nicely written out, haha, a pleasure to read. Are you using Windows? I only have a Linux machine to test it on, and I know most people having trouble connecting use Windows. It seems to be the same issue as #61.

I wonder if changing the socket to blocking would solve the problem, or using the socket's timeout (which I don't use because I need to be able to .cancel_receive(), though I'm working on getting rid of that) instead a hand-crafted one. It's strange however that it works on v0.11.3 and not on later versions.

These are the changes between the two versions. After reviewing every change introduced, I couldn't find anything that modified the TcpClient or any other "low"-level part of the library. I'm a bit clueless :/

Does it work if you downgrade to v0.11.3?

[mwpenny]

Haha good to hear! I'm using OSX (Sierra 10.12.5). I think I wasn't clear: it used to work wonderfully (last week) on v0.11.3, but now it doesn't connect on v0.11.3 or the current version (neither pip nor upstream). I just did some further debugging based on your suggestions:

1. I downgraded to v0.11.3 and received the same error as my original post. Additionally (on both v0.11.3 and v0.11.5) I now sometimes receive this error instead of the TimeoutError:

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/Cellar/python3/3.6.1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/site-packages/Telethon-0.11.3-py3.6.egg/telethon/telegram_client.py", line 140, in connect
  File "/usr/local/Cellar/python3/3.6.1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/site-packages/Telethon-0.11.3-py3.6.egg/telethon/telegram_bare_client.py", line 106, in connect
  File "/usr/local/Cellar/python3/3.6.1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/site-packages/Telethon-0.11.3-py3.6.egg/telethon/network/authenticator.py", line 212, in do_authentication
AssertionError: Invalid new nonce hash

So far, I have only experienced the above error when creating a new session for the first time, and not even every time I do that. The error in my original post is what happens the large majority of the time.

---

2. I tried changing the log level to DEBUG before connecting, and the following is output just before the TimeoutError is raised (and not before the above AssertionError):

DEBUG:telethon.network.mtproto_sender:send() acquired the lock
DEBUG:telethon.network.mtproto_sender:send() released the lock
DEBUG:telethon.network.mtproto_sender:receive() acquired the lock
DEBUG:telethon.network.mtproto_sender:Trying to .receive() the request result...
DEBUG:telethon.network.mtproto_sender:Handling bad server salt
DEBUG:telethon.network.mtproto_sender:send() acquired the lock
DEBUG:telethon.network.mtproto_sender:send() released the lock
DEBUG:telethon.network.mtproto_sender:Trying to .receive() the request result...
DEBUG:telethon.network.mtproto_sender:Handling bad message notification
DEBUG:telethon.network.mtproto_sender:Read Bad Message error: (BadMessageError(...), 'msg_id too high (similar to the previous case, the client time has to be synchronized, and the message re-sent with the correct msg_id).')
DEBUG:telethon.network.mtproto_sender:Attempting to use the correct time offset.
DEBUG:telethon.network.mtproto_sender:Trying to .receive() the request result...
DEBUG:telethon.network.mtproto_sender:Handling bad message notification
DEBUG:telethon.network.mtproto_sender:Read Bad Message error: (BadMessageError(...), 'msg_id too high (similar to the previous case, the client time has to be synchronized, and the message re-sent with the correct msg_id).')
DEBUG:telethon.network.mtproto_sender:Attempting to use the correct time offset.
DEBUG:telethon.network.mtproto_sender:Trying to .receive() the request result...

Looks like there are some bad responses from the server in the beginning (maybe this is common?).

---

3. I changed the socket to blocking (I did it on this line), and it just hangs as if it's waiting for a response that it never receives. I waited ~5 minutes before stopping execution. I also added a print() to TCPClient.connect() right before the line in the previous link and it looks like the method is being called twice (my string is printed twice).

---

Any input is much appreciated, Telegram and their protocol makes it a pain to get anything up and running, even for basic testing, without a library like yours.

[Lonami]

DEBUG:telethon.network.mtproto_sender:Read Bad Message error: (BadMessageError(...), 'msg_id too high (similar to the previous case, the client time has to be synchronized, and the message re-sent with the correct msg_id).')

I guess "the client time has to be synchronized" is not working quite properly… See #95, commit 7f84374 may not be working as intended. Is the time on your machine correctly synchronized? Besides this, it's a bug that should be fixed.

Anyway, the session does not save the ._last_msg_id so every time it starts, it should be a fresh start.

Telegram is probably ignoring these messages with "incorrect" IDs.

Telegram and their protocol makes it a pain to get anything up and running

It really is 😅

---

Edit: Related to the messages ID is commit b0173c3. Maybe try v0.11 before this change was introduced?

[mwpenny]

My system time was out of sync. I am behind a fairly strict firewall, so my machine cannot reach any of the default NTP servers OSX uses (I do it manually with the ntpdate command-line utility). My system time had drifted ahead by less than a minute, so it seemed to match my other devices and I didn't notice. Evidently this was enough of a difference for Telegram. Perhaps the drift was too small for 7f84374 to handle properly.

Thank you very much!

[Lonami]

No problem, though I will reopen #95 because I may be doing something wrong with it. Not sure.