search

ehForwarderBot / efb-telegram-master

EFB Telegram Master Channel, a channel for EH Forwarder Bot.
GNU Affero General Public License v3.0
223 stars 78 forks source link

[BUG] send message failed with time out #118

Closed QQ-War closed 2 years ago

QQ-War commented 2 years ago

sometimes message forward to telegram_master time out and failed, but only if you check on wechat, you don't know it. if possible, can add some machanism to handle it? like cache and push, or push one failure notification?

Describe the bug
2022-04-05 20:29:40,295 [ERROR]: efb_telegram_master.slave_message (slave_message.send_message; slave_message.py:121) Error occurred while processing message from slave channel. Message: <****> TimedOut() Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 402, in _make_request six.raise_from(e, None) File "", line 2, in raise_from File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 398, in _make_request httplib_response = conn.getresponse() File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse response.begin() File "/usr/lib/python3.8/http/client.py", line 316, in begin version, status, reason = self._read_status() File "/usr/lib/python3.8/http/client.py", line 277, in _read_status line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1") File "/usr/lib/python3.8/socket.py", line 669, in readinto return self._sock.recv_into(b) File "/usr/lib/python3.8/ssl.py", line 1241, in recv_into return self.read(nbytes, buffer) File "/usr/lib/python3.8/ssl.py", line 1099, in read return self._sslobj.read(len, buffer) socket.timeout: The read operation timed out

Package Version

APScheduler 3.6.3 attrs 19.3.0 Automat 0.8.0 backports.zoneinfo 0.2.1 beautifulsoup4 4.10.0 blinker 1.4 bs4 0.0.1 bullet 2.2.0 cachetools 4.2.2 certifi 2019.11.28 chardet 3.0.4 CJKwrap 2.2 click 8.1.2 cloud-init 22.1 colorama 0.4.3 command-not-found 0.3 configobj 5.0.6 constantly 15.1.0 cryptography 2.8 dbus-python 1.2.16 distro 1.4.0 distro-info 0.23ubuntu1 efb-mp-instantview-middleware 0.3.2 efb-telegram-master 2.2.4 efb-wechat-pc-slave 2.0.3.dev3 efb-wechat-slave 0.0.2.post12.dev1 ehforwarderbot 2.1.1 entrypoints 0.3 ffmpeg 1.4 ffmpeg-python 0.2.0 Flask 2.1.1 future 0.18.2 httplib2 0.14.0 humanize 4.0.0 hyperlink 19.0.0 idna 2.8 importlib-metadata 4.11.3 incremental 16.10.1 itsdangerous 2.1.2 Jinja2 3.1.1 jsonpatch 1.22 jsonpointer 2.0 jsonschema 3.2.0 keyring 18.0.1 language-selector 0.1 language-tags 1.1.0 launchpadlib 1.10.13 lazr.restfulclient 0.14.2 lazr.uri 1.0.3 lxml 4.8.0 MarkupSafe 2.1.1 more-itertools 4.2.0 netifaces 0.10.4 oauthlib 3.1.0 peewee 3.14.10 pexpect 4.6.0 Pillow 9.0.1 pip 20.0.2 pyasn1 0.4.2 pyasn1-modules 0.2.1 pydantic 1.9.0 pydub 0.25.1 PyGObject 3.36.0 PyHamcrest 1.9.0 PyJWT 1.7.1 pymacaroons 0.13.0 PyNaCl 1.3.0 pyOpenSSL 19.0.0 PyQRCode 1.2.1 pyrsistent 0.15.5 pyserial 3.4 PySocks 1.7.1 python-apt 2.0.0+ubuntu0.20.4.7 python-CuteCat-iHttp 0.0.2.dev1 python-debian 0.1.36ubuntu1 python-magic 0.4.25 python-telegram-bot 13.11 pytz 2022.1 pytz-deprecation-shim 0.1.0.post0 PyYAML 5.3.1 requests 2.22.0 requests-unixsocket 0.2.0 retrying 1.3.3 ruamel.yaml 0.17.21 ruamel.yaml.clib 0.2.6 SecretStorage 2.3.1 service-identity 18.1.0 setuptools 45.2.0 simplejson 3.16.0 six 1.14.0 sos 4.3 soupsieve 2.3.1 ssh-import-id 5.10 systemd-python 234 tornado 6.1 Twisted 18.9.0 typing-extensions 4.1.1 tzdata 2022.1 tzlocal 4.1 ubuntu-advantage-tools 27.7 ufw 0.36 unattended-upgrades 0.1 urllib3 1.25.8 wadllib 1.3.3 websockets 10.2 wechatPc 0.0.2.dev2 Werkzeug 2.1.1 wheel 0.34.2 zipp 1.0.0 zope.interface 4.7.1

QQ-War commented 2 years ago

more logs: 2022-04-06 09:00:29,881 [ERROR]: efb_telegram_master.slave_message (slave_message.send_message; slave_message.py:121) Error occurred while processing message from slave channel. (((message****)))) TimedOut() Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 402, in _make_request six.raise_from(e, None) File "", line 2, in raise_from File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 398, in _make_request httplib_response = conn.getresponse() File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse response.begin() File "/usr/lib/python3.8/http/client.py", line 316, in begin version, status, reason = self._read_status() File "/usr/lib/python3.8/http/client.py", line 277, in _read_status line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1") File "/usr/lib/python3.8/socket.py", line 669, in readinto return self._sock.recv_into(b) File "/usr/lib/python3.8/ssl.py", line 1241, in recv_into return self.read(nbytes, buffer) File "/usr/lib/python3.8/ssl.py", line 1099, in read return 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 "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 259, in _request_wrapper resp = self._con_pool.request(*args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 68, in request return self.request_encode_body(method, url, fields=fields, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 148, in request_encode_body return self.urlopen(method, url, extra_kw) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/poolmanager.py", line 244, in urlopen response = conn.urlopen(method, u.request_uri, *kw) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 665, in urlopen retries = retries.increment(method, url, error=e, _pool=self, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/util/retry.py", line 347, in increment raise six.reraise(type(error), error, _stacktrace) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/packages/six.py", line 686, in reraise raise value File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 614, in urlopen httplib_response = self._make_request(conn, method, url, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 404, in _make_request self._raise_timeout(err=e, url=url, timeout_value=read_timeout, File "/home/linux/.local/lib/python3.8/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=15)

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

Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 119, in send_message self.dispatch_message(msg, msg_template, old_msg_id, tg_dest, silent) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 170, in dispatch_message tg_msg = self.slave_message_text(msg, tg_dest, msg_template, reactions, old_msg_id, target_msg_id, File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 318, in slave_message_text self.bot.send_chat_action(tg_dest, ChatAction.TYPING) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/bot_manager.py", line 130, in retry_on_chat_migration_wrap return fn(self, *args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/bot_manager.py", line 454, in send_chat_action return self.updater.bot.send_chat_action(*args, *kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 130, in decorator result = func(args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 2140, in send_chat_action result = self._post('sendChatAction', data, timeout=timeout, api_kwargs=api_kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 295, in _post return self.request.post( File "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 361, in post result = self._request_wrapper( File "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 261, in _request_wrapper raise TimedOut() from error telegram.error.TimedOut: Timed out

2022-04-06 09:00:29,892 [INFO]: werkzeug (_internal._log; _internal.py:224) 127.0.0.1 - - [06/Apr/2022 09:00:29] "POST /event HTTP/1.1" 200 -

QQ-War commented 2 years ago

closed，add some parameter and test:

flags:

option_one: 10

option_two: false

option_three: "foobar"

send_to_last_chat: "enabled"
retry_on_error: "true"
network_error_prompt_interval: 1

[Network Configurations]

request_kwargs: read_timeout: 30 connect_timeout: 30

QQ-War commented 2 years ago

test, still failed, even with the configuration.

NetworkError() Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 614, in urlopen httplib_response = self._make_request(conn, method, url, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 402, in _make_request six.raise_from(e, None) File "", line 2, in raise_from File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 398, in _make_request httplib_response = conn.getresponse() File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse response.begin() File "/usr/lib/python3.8/http/client.py", line 316, in begin version, status, reason = self._read_status() File "/usr/lib/python3.8/http/client.py", line 285, in _read_status raise RemoteDisconnected("Remote end closed connection without" http.client.RemoteDisconnected: Remote end closed connection without response

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 259, in _request_wrapper resp = self._con_pool.request(*args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 68, in request return self.request_encode_body(method, url, fields=fields, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/request.py", line 148, in request_encode_body return self.urlopen(method, url, extra_kw) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/poolmanager.py", line 244, in urlopen response = conn.urlopen(method, u.request_uri, **kw) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 665, in urlopen retries = retries.increment(method, url, error=e, _pool=self, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/util/retry.py", line 347, in increment raise six.reraise(type(error), error, _stacktrace) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/packages/six.py", line 685, in reraise raise value.with_traceback(tb) File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 614, in urlopen httplib_response = self._make_request(conn, method, url, File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 402, in _make_request six.raise_from(e, None) File "", line 2, in raise_from File "/home/linux/.local/lib/python3.8/site-packages/telegram/vendor/ptb_urllib3/urllib3/connectionpool.py", line 398, in _make_request httplib_response = conn.getresponse() File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse response.begin() File "/usr/lib/python3.8/http/client.py", line 316, in begin version, status, reason = self._read_status() File "/usr/lib/python3.8/http/client.py", line 285, in _read_status raise RemoteDisconnected("Remote end closed connection without" telegram.vendor.ptb_urllib3.urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))

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

Traceback (most recent call last): File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 119, in send_message self.dispatch_message(msg, msg_template, old_msg_id, tg_dest, silent) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 170, in dispatch_message tg_msg = self.slave_message_text(msg, tg_dest, msg_template, reactions, old_msg_id, target_msg_id, File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/slave_message.py", line 318, in slave_message_text self.bot.send_chat_action(tg_dest, ChatAction.TYPING) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/bot_manager.py", line 130, in retry_on_chat_migration_wrap return fn(self, *args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/efb_telegram_master/bot_manager.py", line 454, in send_chat_action return self.updater.bot.send_chat_action(*args, *kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 130, in decorator result = func(args, kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 2140, in send_chat_action result = self._post('sendChatAction', data, timeout=timeout, api_kwargs=api_kwargs) File "/home/linux/.local/lib/python3.8/site-packages/telegram/bot.py", line 295, in _post return self.request.post( File "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 361, in post result = self._request_wrapper( File "/home/linux/.local/lib/python3.8/site-packages/telegram/utils/request.py", line 265, in _request_wrapper raise NetworkError(f'urllib3 HTTPError {error}') from error telegram.error.NetworkError: urllib3 HTTPError ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))

2022-04-06 16:27:44,045 [INFO]: werkzeug (_internal._log; _internal.py:224) 127.0.0.1 - - [06/Apr/2022 16:27:44] "POST /event HTTP/1.1" 200 -

blueset commented 2 years ago

When the server has a poor connection to the Telegram API, ETM has no way inform the user through the bot, as all communication would go through the same poor connection.

Retries are not feasible in this case as we have no method to confirm if a message is sent idempotently. Please see this wiki page for details.

QQ-War commented 2 years ago

Yes, fully understand. But what I wan confused is the flag: network_error_prompt_interval And retry_on_error

So, it seems it has some mechanism to know it failed. If it has, can it try back to cache the failed message and try again or notify after a period?

blueset commented 2 years ago

The “error” state would only tell us that we did not receive an expected response from the server, but not if the server has properly processed the request.

Please read section 2.2.3 of this page for details.

The 2 parameters are provided by the upstream library Python Telegram Bot, and they are not owned by ETM.

QQ-War commented 2 years ago

Ok, get it