Repository: python-telegram-bot/python-telegram-bot
Pull request: updater.py: Better handling of timeouts during getUpdates
TimedOut exception is an expected an normal event. To reduce noise and
make things more "fluent" we now:
 - Make sure that we don't sleep after the timeout but rather retry
immediately.
 - Log debug instead of error level.

Fixes #802

Problem statement:
TimedOut on get_updates
Calling get_updates consistently crashes the bot with `telegram.error.TimedOut: Timed out` .

The code:

    updates = self.bot.get_updates(
        offset=self.update_id,
        timeout=30,
        network_delay=1.0
    )

The log:

    Traceback (most recent call last):
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 402, in _make_request
        six.raise_from(e, None)
      File "<string>", line 2, in raise_from
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 398, in _make_request
        httplib_response = conn.getresponse()
      File "/app/.heroku/python/lib/python3.6/http/client.py", line 1331, in getresponse
        response.begin()
      File "/app/.heroku/python/lib/python3.6/http/client.py", line 297, in begin
        version, status, reason = self._read_status()
      File "/app/.heroku/python/lib/python3.6/http/client.py", line 258, in _read_status
        line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
      File "/app/.heroku/python/lib/python3.6/socket.py", line 586, in readinto
        return self._sock.recv_into(b)
      File "/app/.heroku/python/lib/python3.6/ssl.py", line 1002, in recv_into
        return self.read(nbytes, buffer)
      File "/app/.heroku/python/lib/python3.6/ssl.py", line 865, in read
        return self._sslobj.read(len, buffer)
      File "/app/.heroku/python/lib/python3.6/ssl.py", line 625, in read
        v = self._sslobj.read(len, buffer)
    socket.timeout: The read operation timed out
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last):
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/utils/request.py", line 174, in _request_wrapper
        resp = self._con_pool.request(*args, **kwargs)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 70, in request
        **urlopen_kw)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 148, in request_encode_body
        return self.urlopen(method, url, **extra_kw)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/poolmanager.py", line 244, in urlopen
        response = conn.urlopen(method, u.request_uri, **kw)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 666, in urlopen
        _stacktrace=sys.exc_info()[2])
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/util/retry.py", line 347, in increment
        raise six.reraise(type(error), error, _stacktrace)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/packages/six.py", line 686, in reraise
        raise value
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 617, in urlopen
        chunked=chunked)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 405, in _make_request
        exc_cls=ReadTimeoutError)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 321, in _raise_timeout
        raise exc_cls(*args)
    telegram.vendor.ptb_urllib3.urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='api.telegram.org', port=443): Read timed out. (read timeout=31.0)
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last):
      File "/app/myapp/bot.py", line 81, in update_forever
        network_delay=1.0
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/bot.py", line 52, in decorator
        result = func(self, *args, **kwargs)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/bot.py", line 1392, in get_updates
        result = self._request.post(url, data, timeout=float(read_latency) + float(timeout))
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/utils/request.py", line 252, in post
        **urlopen_kwargs)
      File "/app/.heroku/python/lib/python3.6/site-packages/telegram/utils/request.py", line 176, in _request_wrapper
        raise TimedOut()
    telegram.error.TimedOut: Timed out

Hints from issue discussion:
I encounter the same issue/error (socket.timeout). For getUpdates, _timeout_ set to anything but 0 results in errors. They are way less frequent when leaving out the _timeout_ parameter, but they still do occur.
FYI the `network_delay` parameter is deprecated (at least in the latest version), so instead you should be using the `read_latency` parameter. And perhaps choosing a higher value for this parameter could solve your issue?
I have the same issue. Changing the ```read_latency``` parameter seems to not do any work on this issue.
Hi,
I'm sorry for my very late response. 
@levzhazeschi - the problem with long polling is that you might lose connection without the application even knowing it. 
In order to debug network problems we must have much more data. The first things to check (but upon adding the data, more questions will probably rise):
1. Where do you host your bot? I see "heroku", but what region?
2. Followup to 1 - have you measured the latency towards api.telegram.org ?
3. Do you get the error you described immediately at the first `get_updates` attempt or after several successful iterations? 
4. If after several iterations:
4.1. How many iterations until failure?
4.2 How long before failure?
5. To answer 4, and in general, please enable debug logging from ptb and upload logs with more context - before and after the failure.
Hey folks! 

I've very affected by this. Is there a quickfix to just ignore these and silently reconnect, if needed?

Are patches welcome, eh? ;)
Is there any progress on this? I can still reproduce this with the newest version, I start getting the errors after about 30 minutes of inactivity.
I also have this error.
I had this issue using heroku. The problem was that my Procfile started with `web`. I changed it to `bot` and worked like a charm!

Commit message: updater.py: Better handling of timeouts during getUpdates

TimedOut exception is an expected an normal event. To reduce noise and
make things more "fluent" we now:
 - Make sure that we don't sleep after the timeout but rather retry
immediately.
 - Log debug instead of error level.

Fixes #802

Patch to review:
diff --git a/telegram/ext/updater.py b/telegram/ext/updater.py
index 5d286a6a6b6..cb89712c501 100644
--- a/telegram/ext/updater.py
+++ b/telegram/ext/updater.py
@@ -30,7 +30,7 @@
 
 from telegram import Bot, TelegramError
 from telegram.ext import Dispatcher, JobQueue
-from telegram.error import Unauthorized, InvalidToken, RetryAfter
+from telegram.error import Unauthorized, InvalidToken, RetryAfter, TimedOut
 from telegram.utils.helpers import get_signal_name
 from telegram.utils.request import Request
 from telegram.utils.webhookhandler import (WebhookServer, WebhookHandler)
@@ -267,11 +267,9 @@ def start_webhook(self,
 
     def _start_polling(self, poll_interval, timeout, read_latency, bootstrap_retries, clean,
                        allowed_updates):  # pragma: no cover
-        # """
         # Thread target of thread 'updater'. Runs in background, pulls
         # updates from Telegram and inserts them in the update queue of the
         # Dispatcher.
-        # """
 
         cur_interval = poll_interval
         self.logger.debug('Updater thread started')
@@ -288,8 +286,12 @@ def _start_polling(self, poll_interval, timeout, read_latency, bootstrap_retries
             except RetryAfter as e:
                 self.logger.info(str(e))
                 cur_interval = 0.5 + e.retry_after
+            except TimedOut as toe:
+                self.logger.debug('Timed out getting Updates: %s', toe)
+                # If getUpdates() failed due to timeout, we should retry asap.
+                cur_interval = 0
             except TelegramError as te:
-                self.logger.error("Error while getting Updates: {0}".format(te))
+                self.logger.error('Error while getting Updates: %s', te)
 
                 # Put the error into the update queue and let the Dispatcher
                 # broadcast it
@@ -310,7 +312,8 @@ def _start_polling(self, poll_interval, timeout, read_latency, bootstrap_retries
 
                 cur_interval = poll_interval
 
-            sleep(cur_interval)
+            if cur_interval:
+                sleep(cur_interval)
 
     @staticmethod
     def _increase_poll_interval(current_interval):


Code review comments:
diff_hunk: @@ -288,8 +286,12 @@ def _start_polling(self, poll_interval, timeout, read_latency, bootstrap_retries
             except RetryAfter as e:
                 self.logger.info(str(e))
                 cur_interval = 0.5 + e.retry_after
+            except TimedOut as toe:
+                self.logger.debug('Timed out getting Updates: %s', toe)
+                # If getUpdates() failed due to timeout, we should retry asap.
path: telegram/ext/updater.py
text: @user1:
get_updates() maybe?