Badiboy
commented
3 years ago Bot is threaded or not threaded?
Closed ModischFabrications closed 3 years ago
Badiboy
commented
3 years ago Bot is threaded or not threaded?
Badiboy
commented
3 years ago BTW. Could you please try to use the most recent branch:
pip install -U git+https://github.com/eternnoir/pyTelegramBotAPI.git#egg=pyTelegramBotAPI
There were updates in polling exceptions handling.
ModischFabrications
commented
3 years ago threaded I think so, I am using default settings.
recent branch I installed it from there, but I am unsure if the bot has received the correct version. version does not exist, is there another place the current version is noted?
The way it looks right now is it that I can't replicate the problem while testing, I will check with the production system tomorrow.
ModischFabrications
commented
3 years ago I tested around, looks like the problem is not from the collision but from something else, I did not spot the 20min difference in the logs. I will investigate further, looks like there are two problems on a long running instance (>30min), might be similar to #1057, but I could not confirm yet.
Problem 1 is causing restarts without any hints in the log, Problem 2 leads to a recursion error and then restarts as seen below:
Im still on the current release instead of the newest git version (need to resolve some conflicts first). Probably another cause, but no recovery as a result either. Will try to test with the newest version the next few days.
File "/home/minecraft/.local/share/virtualenvs/MineGramBot-lr3Vf42U/lib/python3.6/site-packages/telebot/util.py", line 242, in <lambda>
e.set = lambda: or_set(e)
File "/home/minecraft/.local/share/virtualenvs/MineGramBot-lr3Vf42U/lib/python3.6/site-packages/telebot/util.py", line 229, in or_set
self._set()
File "/home/minecraft/.local/share/virtualenvs/MineGramBot-lr3Vf42U/lib/python3.6/site-packages/telebot/util.py", line 242, in <lambda>
e.set = lambda: or_set(e)
File "/home/minecraft/.local/share/virtualenvs/MineGramBot-lr3Vf42U/lib/python3.6/site-packages/telebot/util.py", line 229, in or_set
self._set()
RecursionError: maximum recursion depth exceeded
2021-01-02 22:09:50,725 (__init__.py:460 MainThread) INFO - TeleBot: "Started polling."
2021-01-02 22:09:53,728 (__init__.py:460 MainThread) INFO - TeleBot: "Started polling."
2021-01-02 22:09:56,733 (__init__.py:460 MainThread) INFO - TeleBot: "Started polling."
2021-01-02 22:09:59,738 (__init__.py:460 MainThread) INFO - TeleBot: "Started polling."
2021-01-02 22:10:02,744 (__init__.py:460 MainThread) INFO - TeleBot: "Started polling."Okay, installed and tested it, but had to remove the egg. It still occurs, the newest version still contains these (2?) bugs with the same effect that restarting is an endless loop. @Badiboy any other ideas?
Badiboy
commented
3 years ago @ModischFabrications I'll try to check, had no time yet. But I will. :)
ModischFabrications
commented
3 years ago Hey, do you have an estimate on when you can look into it? No pressure, I'm just evaluating when my bot is available to be deployed permanently.
Badiboy
commented
3 years ago I cannot reproduce the problem.
Badiboy
commented
3 years ago On Raspbian.
Badiboy
commented
3 years ago recent branch I installed it from there, but I am unsure if the bot has received the correct version. version does not exist, is there another place the current version is noted?
3.7.5 is released several days ago. You can try general update to be sure it's the latest. Version is in file version.py
ModischFabrications
commented
3 years ago Can't reproduce
Sorry, seems like a misunderstanding. I could not reproduce the error from the collision either, but had it on a long running instance (>30min). https://github.com/eternnoir/pyTelegramBotAPI/issues/1058#issuecomment-753527244 described it best it think. Your test setup seems to be very similar, have you tried to let it run for longer? Thanks for the thorough investigation!
I will test the newest version now and update this comment as soon as I hit the bug.
-- Update: recursion error still hits, see the stack trace:
C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\Scripts\python.exe D:/Kreativ/Programme/Python/MineGramBot/main.py
2021-01-12 22:49:06,925 (__init__.py:485 MainThread) INFO - TeleBot: "Started polling."
Starting up...
My API status: {'id': 1480424537, 'is_bot': True, 'first_name': 'ModischMinecraftBot', 'username': 'ModischMinecraftBot', 'last_name': None, 'language_code': None, 'can_join_groups': True, 'can_read_all_group_messages': False, 'supports_inline_queries': False}
Press CTRL+C to stop server
Old attempt from 457188097
2021-01-12 23:38:18,031 (__init__.py:459 MainThread) ERROR - TeleBot: "Infinity polling exception: ('Connection aborted.', ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None))"
2021-01-12 23:38:21,037 (__init__.py:485 MainThread) INFO - TeleBot: "Started polling."
2021-01-12 23:40:06,192 (__init__.py:510 MainThread) ERROR - TeleBot: "A request to the Telegram API was unsuccessful. Error code: 409. Description: Conflict: terminated by other getUpdates request; make sure that only one bot instance is running"
2021-01-12 23:40:06,193 (__init__.py:517 MainThread) INFO - TeleBot: "Waiting for 0.25 seconds until retry"
2021-01-12 23:40:06,456 (__init__.py:459 MainThread) ERROR - TeleBot: "Infinity polling exception: maximum recursion depth exceeded"
[...experiments...]
2021-01-12 23:43:52,574 (__init__.py:510 MainThread) ERROR - TeleBot: "A request to the Telegram API was unsuccessful. Error code: 409. Description: Conflict: terminated by other getUpdates request; make sure that only one bot instance is running"
2021-01-12 23:43:52,574 (__init__.py:517 MainThread) INFO - TeleBot: "Waiting for 0.25 seconds until retry"
2021-01-12 23:43:52,833 (__init__.py:459 MainThread) ERROR - TeleBot: "Infinity polling exception: maximum recursion depth exceeded"
2021-01-12 23:43:55,833 (__init__.py:485 MainThread) INFO - TeleBot: "Started polling."
Exception in thread WorkerThread1:
Traceback (most recent call last):
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 699, in urlopen
httplib_response = self._make_request(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 445, in _make_request
six.raise_from(e, None)
File "<string>", line 3, in raise_from
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 440, in _make_request
httplib_response = conn.getresponse()
File "c:\program files\python39\lib\http\client.py", line 1347, in getresponse
response.begin()
File "c:\program files\python39\lib\http\client.py", line 307, in begin
version, status, reason = self._read_status()
File "c:\program files\python39\lib\http\client.py", line 268, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "c:\program files\python39\lib\socket.py", line 704, in readinto
return self._sock.recv_into(b)
File "c:\program files\python39\lib\ssl.py", line 1241, in recv_into
return self.read(nbytes, buffer)
File "c:\program files\python39\lib\ssl.py", line 1099, in read
return self._sslobj.read(len, buffer)
ConnectionResetError: [WinError 10054] An existing connection was forcibly closed by the remote host
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\requests\adapters.py", line 439, in send
resp = conn.urlopen(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 755, in urlopen
retries = retries.increment(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\util\retry.py", line 531, in increment
raise six.reraise(type(error), error, _stacktrace)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\packages\six.py", line 734, in reraise
raise value.with_traceback(tb)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 699, in urlopen
httplib_response = self._make_request(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 445, in _make_request
six.raise_from(e, None)
File "<string>", line 3, in raise_from
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\urllib3\connectionpool.py", line 440, in _make_request
httplib_response = conn.getresponse()
File "c:\program files\python39\lib\http\client.py", line 1347, in getresponse
response.begin()
File "c:\program files\python39\lib\http\client.py", line 307, in begin
version, status, reason = self._read_status()
File "c:\program files\python39\lib\http\client.py", line 268, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "c:\program files\python39\lib\socket.py", line 704, in readinto
return self._sock.recv_into(b)
File "c:\program files\python39\lib\ssl.py", line 1241, in recv_into
return self.read(nbytes, buffer)
File "c:\program files\python39\lib\ssl.py", line 1099, in read
return self._sslobj.read(len, buffer)
urllib3.exceptions.ProtocolError: ('Connection aborted.', ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None))
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 69, in run
task(*args, **kwargs)
File "D:\Kreativ\Programme\Python\MineGramBot\modules\bot_commands.py", line 140, in status_command
msg_send = bot.send_message(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\__init__.py", line 734, in send_message
apihelper.send_message(self.token, chat_id, text, disable_web_page_preview, reply_to_message_id,
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\apihelper.py", line 206, in send_message
return _make_request(token, method_url, params=payload, method='post')
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\apihelper.py", line 107, in _make_request
result = _get_req_session().request(
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\requests\sessions.py", line 542, in request
resp = self.send(prep, **send_kwargs)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\requests\sessions.py", line 655, in send
r = adapter.send(request, **kwargs)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\requests\adapters.py", line 498, in send
raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None))
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:\program files\python39\lib\threading.py", line 950, in _bootstrap_inner
self.run()
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 79, in run
self.exception_callback(self, self.exception_info)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 112, in on_exception
self.exception_event.set()
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 241, in <lambda>
e.set = lambda: or_set(e)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 228, in or_set
self._set()
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 241, in <lambda>
e.set = lambda: or_set(e)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 228, in or_set
self._set()
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 241, in <lambda>
e.set = lambda: or_set(e)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 228, in or_set
self._set()
[...]
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 241, in <lambda>
e.set = lambda: or_set(e)
File "C:\Users\MMF\.virtualenvs\MineGramBot-7yiiMmm7\lib\site-packages\telebot\util.py", line 228, in or_set
self._set()
RecursionError: maximum recursion depth exceeded
Process finished with exit code -1
Problem 1 is causing restarts without any hints in the log
This is the problem 1? I don't see any problem here. When long polling there may "ConnectionResetError" occur. Nobody know who raise it somewhere downstairs. infinity_polling restart the polling loop and should work well after it. No hints in log... Yes, there was no hints. No there are. But the behaviour is the same.
It's very hard to catch what IS THE PROBLEM. Problem 1, problem 2, cannot reproduce, not this problem...
ModischFabrications
commented
3 years ago Sorry, it's a mix-up of language barrier, wrong assumptions (that it was caused by a collision) and problems that are difficult to trace (>30min runtime). The collision is not a problem anymore, infinity_polling handles that restart. The ConnectionResetError is also circumvented by using infinity_polling, which I am using, so it shouldn't be part of the problem either.
Let me try to explain the problem better:
Yes, there was no hints. No there are. But the behavior is the same.
I'm not sure I understand that correctly. Do you mean you added more logging and the problem should be more visible now while testing with the newest version?
Would it have been easier to follow if I had fixed the wrong assumptions at the start instead of appending new discoveries? I am still testing to see if it comes up again in *.5.
Badiboy
commented
3 years ago 2021-01-13 02:01:23,617 INFO True
2021-01-13 02:01:38,780 ERROR Infinity polling exception: HTTPSConnectionPool(host='api.telegram.org', port=443): Read timed out. (read timeout=11)
2021-01-13 02:01:52,866 ERROR Infinity polling exception: maximum recursion depth exceeded
2021-01-13 02:02:23,084 ERROR Infinity polling exception: maximum recursion depth exceeded
2021-01-13 02:02:37,176 ERROR Infinity polling exception: maximum recursion depth exceeded
2021-01-13 02:02:51,256 ERROR Infinity polling exception: maximum recursion depth exceeded
2021-01-13 02:03:08,535 ERROR Infinity polling exception: maximum recursion depth exceededHmmm, seems I see it also. I'll go deeper.
Badiboy
commented
3 years ago Seems that I got it.
Try the GIT version.
pip install -U git+https://github.com/eternnoir/pyTelegramBotAPI.git
Version should be 3.7.5.u1.
ModischFabrications
commented
3 years ago Awesome! Looks like the recursion error is fixed in the new version.
Version is '3.7.5.u2' btw, but it worked, so no problem there.
Long running instances still encounter a ConnectionReset on the first message after a long runtime/break and drop the affected message even with the newer version, but this is a new problem in of itself and deserves a new issue:
2021-01-14 16:39:10,918 (__init__.py:490 MainThread) INFO - TeleBot: "Started polling."
...
2021-01-14 17:06:03,262 (__init__.py:463 MainThread) ERROR - TeleBot: "Infinity polling exception: ('Connection aborted.', ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None))"
2021-01-14 17:06:06,265 (__init__.py:490 MainThread) INFO - TeleBot: "Started polling."For clarification: The restart itself works, the dropped message is the problem.
Badiboy
commented
3 years ago Version u2 appears later with aniother fix, so it's ok :) Fine that main problem is gone.
Regarding this: 'An existing connection was forcibly closed by the remote host'
Currently I have a bot running for ~20 hours in polling mode (usually I use webhooks): faced no problems yet...
ModischFabrications
commented
3 years ago dropped message
The closed connection exception is only triggered when sending a message to the bot. This is how I trigger it:
Should I post this as it's own issue? This issue is unrelated to the recovery from the start and others looking for the same problem won't find it here.
Badiboy
commented
3 years ago Currently I have a bot running for ~20 hours in polling mode (usually I use webhooks): faced no problems yet...
I know that some users face the problem, but I cannot see it myself.
Can you run bot with "DEBUG" logging level? It should log traceback on exception now, may be we'll see something helpful there...
ModischFabrications
commented
3 years ago This is the error with a stack trace, feel free to tell me if you need more. It went on with more "another exception occurred", but this should capture the essential parts.
Badiboy
commented
3 years ago @ModischFabrications
I see here that error occurs not when library queries the updates, but when your bot answering to user. So to avoid reply lost when sending message you can catch thhis exception and re-send the message.
If you want to go deeper to the reasons. When library sends any request it creates the requests session and stores it. When you send next request library uses existing session for optimization. It seems that for rarely used bots and the Session may die while waiting. I suppose it may depend on various operationg system settings: for some cases it happens, for some it does not.
As far as this problem occurs for some library users, I think it may be reasonable to create an option for rarely used bots which will force re-creation of session on every request. It should help for cases like yours. If you think it will help for your case - we can try implementing this.
ModischFabrications
commented
3 years ago answering to user / Session may die while waiting
Good eye! Session timeout makes sense, this also explains why the error occurs only when answering after a long delay. For reference: This error happened both on Win10 and Raspbian. I can only agree with your way of thought that fixing it will improve stability, especially for newcomers.
As for the flag for a forced recreation of sessions on every message: Recreating for every request will fix the problem, but will introduce a tradeoff decision between stability and performance, which might hinder dynamic upscaling with usage. If I understand the situation correctly, there are ways to combine both without compromising: A: Track timestamps and check last usage of session prior to sending a message, forcing recreation if it exceeds a threshold (10min?). B: Treat this ConnectionResetError as a notification that the current session has timed out and force recreation (max 3 tries?)
I haven't looked into the code to evaluate these options, so please take these suggestions with a grain of salt. Option B feels like the cleanest imho. I would appreciate either solution.
Badiboy
commented
3 years ago https://github.com/eternnoir/pyTelegramBotAPI/pull/1077 Try this. Version 3.7.5.u4.
A: Track timestamps and check last usage of session prior to sending a message, forcing recreation if it exceeds a threshold (10min?).
I went exactly to the same point. apihelper.SESSION_TIME_TO_LIVE - configurable Session TTL.
Let me know if that help you to find your way. :)
ModischFabrications
commented
3 years ago Good news: I set the session time to 5min and it seems like the ConnectionReset is gone.
Bad news: From time to time the bot shows a collision with another instance without me actually starting another one. This happened on u2 as well, I just thought it was human error. I will doublecheck that it isn't a human error, nonetheless all the other fixes are looking good.
ModischFabrications
commented
3 years ago Oh crap, I see the problem now, the bot ID and secret token is printed in plaintext in the logs. I requested a new token, this will fix both a forgotten running instance and someone else trying to misuse my token.
Im going to test it with a long running instance tomorrow, but I think all those bugs should be resolved now :)
Badiboy
commented
3 years ago 2021-01-16 23:57:15,352 (apihelper.py:130 PollingThread) DEBUG - TeleBot: "The server returned: 'b'{"ok":false,"error_code":409,"description":"Conflict: terminated by other getUpdates request; make sure that only one bot instance is running"}''"
Yep, I don't like this. "We need to go deeper" (c)
I set the session time to 5min
Please check: did you really set it for 5 minutes (SESSION_TIME_TO_LIVE = 300)? Not to 5?
ModischFabrications
commented
3 years ago I checked, seems to be correct.
...
apihelper.ENABLE_MIDDLEWARE = True
apihelper.SESSION_TIME_TO_LIVE = 5 * 60
bot = telebot.TeleBot(config.TOKEN)
...I will doublecheck that it isn't a human error
I'm pretty certain that it was a human error, requesting a new token (due to the assumed leak from the log) seems to have fixed it. I will test more extensively tomorrow, but everything should be resolved.
Badiboy
commented
3 years ago OK, thank you. Seems that we are very close to the victory. :)
ModischFabrications
commented
3 years ago I haven't found any more occurrences of the bugs, which means we were victorious at last 🎉
I am happy that we were able to find and fix all these issues. I will send in another pull request with additions (bot reference and apihelper settings) once the new version is released and I was able to finish my bot.
Feel free to close this issue.
Badiboy
commented
3 years ago Gratz. 👍
AlexanderSurbashev
commented
1 year ago Seems that I got it.
Try the GIT version.
pip install -U git+https://github.com/eternnoir/pyTelegramBotAPI.gitVersion should be 3.7.5.u1.
THX!! it save my day.
What version of pyTelegramBotAPI are you using? 3.7.4
What OS are you using? Raspbian
What version of python are you using? 3.6.9
Testing out
bot.infinity_polling()as recommended in #1057 I noticed a bug in the recovery from exceptions:It seems like the bot does not recover completely from a collision from another bot instance. It crashes and restarts successfully, which is nice, but it seems to get stuck in a restart loop every 3s (sleep time on recovery). I would guess there is an implicit state that carries over the restart that still contains the cancel instruction, but I haven't found anything obvious.
This bug can be bypassed by not starting another instance with the same token, but I assume that the same bug will also strike with other exceptions, unrelated to this cause.
Reproduction:
bot.infinity_polling()and logging.INFOlog instance 1:
log instance 2:
PS: Happy new year and thanks for the fast responses!