Skip to content

Commit 40d7198

Browse files
committed
Fix logging issue (#2627)
1 parent 04e9411 commit 40d7198

4 files changed

Lines changed: 105 additions & 22 deletions

File tree

‎telebot/__init__.py‎

Lines changed: 18 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -1171,15 +1171,15 @@ def infinity_polling(self, timeout: Optional[int]=20, skip_pending: Optional[boo
11711171
logger_level=logger_level, allowed_updates=allowed_updates, restart_on_change=False,
11721172
*args, **kwargs)
11731173
except Exception as e:
1174-
if logger_level and logger_level >= logging.ERROR:
1174+
if logger_level and logger_level <= logging.ERROR:
11751175
logger.error("Infinity polling exception: %s", self.__hide_token(str(e)))
1176-
if logger_level and logger_level >= logging.DEBUG:
1176+
if logger_level and logger_level <= logging.DEBUG:
11771177
logger.error("Exception traceback:\n%s", self.__hide_token(traceback.format_exc()))
11781178
time.sleep(3)
11791179
continue
1180-
if logger_level and logger_level >= logging.INFO:
1180+
if logger_level and logger_level <= logging.INFO:
11811181
logger.error("Infinity polling: polling exited")
1182-
if logger_level and logger_level >= logging.INFO:
1182+
if logger_level and logger_level <= logging.INFO:
11831183
logger.error("Break infinity polling")
11841184

11851185

@@ -1274,7 +1274,7 @@ def __threaded_polling(self, non_stop = False, interval = 0, timeout = None, lon
12741274
warning = "\n Warning: this message appearance will be changed. Set logger_level=logging.INFO to continue seeing it."
12751275
else:
12761276
warning = ""
1277-
#if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1277+
#if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
12781278
logger.info('Started polling.' + warning)
12791279
self.__stop_polling.clear()
12801280
error_interval = 0.25
@@ -1297,16 +1297,16 @@ def __threaded_polling(self, non_stop = False, interval = 0, timeout = None, lon
12971297
except apihelper.ApiException as e:
12981298
handled = self._handle_exception(e)
12991299
if not handled:
1300-
if logger_level and logger_level >= logging.ERROR:
1300+
if logger_level and logger_level <= logging.ERROR:
13011301
logger.error("Threaded polling exception: %s", self.__hide_token(str(e)))
1302-
if logger_level and logger_level >= logging.DEBUG:
1302+
if logger_level and logger_level <= logging.DEBUG:
13031303
logger.error("Exception traceback:\n%s", self.__hide_token(traceback.format_exc()))
13041304
if not non_stop:
13051305
self.__stop_polling.set()
1306-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1306+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13071307
logger.info("Exception occurred. Stopping." + warning)
13081308
else:
1309-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1309+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13101310
logger.info("Waiting for {0} seconds until retry".format(error_interval) + warning)
13111311
time.sleep(error_interval)
13121312
if error_interval * 2 < 60:
@@ -1320,7 +1320,7 @@ def __threaded_polling(self, non_stop = False, interval = 0, timeout = None, lon
13201320
polling_thread.clear_exceptions() #*
13211321
self.worker_pool.clear_exceptions() #*
13221322
except KeyboardInterrupt:
1323-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1323+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13241324
logger.info("KeyboardInterrupt received." + warning)
13251325
self.__stop_polling.set()
13261326
break
@@ -1339,7 +1339,7 @@ def __threaded_polling(self, non_stop = False, interval = 0, timeout = None, lon
13391339
polling_thread.stop()
13401340
polling_thread.clear_exceptions()
13411341
self.worker_pool.clear_exceptions()
1342-
#if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1342+
#if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13431343
logger.info('Stopped polling.' + warning)
13441344

13451345

@@ -1349,7 +1349,7 @@ def __non_threaded_polling(self, non_stop=False, interval=0, timeout=None, long_
13491349
warning = "\n Warning: this message appearance will be changed. Set logger_level=logging.INFO to continue seeing it."
13501350
else:
13511351
warning = ""
1352-
#if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1352+
#if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13531353
logger.info('Started polling.' + warning)
13541354
self.__stop_polling.clear()
13551355
error_interval = 0.25
@@ -1361,23 +1361,23 @@ def __non_threaded_polling(self, non_stop=False, interval=0, timeout=None, long_
13611361
except apihelper.ApiException as e:
13621362
handled = self._handle_exception(e)
13631363
if not handled:
1364-
if logger_level and logger_level >= logging.ERROR:
1364+
if logger_level and logger_level <= logging.ERROR:
13651365
logger.error("Polling exception: %s", str(e))
1366-
if logger_level and logger_level >= logging.DEBUG:
1366+
if logger_level and logger_level <= logging.DEBUG:
13671367
logger.error("Exception traceback:\n%s", traceback.format_exc())
13681368
if not non_stop:
13691369
self.__stop_polling.set()
1370-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1370+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13711371
logger.info("Exception occurred. Stopping." + warning)
13721372
else:
1373-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1373+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13741374
logger.info("Waiting for {0} seconds until retry".format(error_interval) + warning)
13751375
time.sleep(error_interval)
13761376
error_interval *= 2
13771377
else:
13781378
time.sleep(error_interval)
13791379
except KeyboardInterrupt:
1380-
# if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1380+
# if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13811381
logger.info("KeyboardInterrupt received." + warning)
13821382
self.__stop_polling.set()
13831383
break
@@ -1387,7 +1387,7 @@ def __non_threaded_polling(self, non_stop=False, interval=0, timeout=None, long_
13871387
raise e
13881388
else:
13891389
time.sleep(error_interval)
1390-
#if logger_level and logger_level >= logging.INFO: # enable in future releases. Change output to logger.error
1390+
#if logger_level and logger_level <= logging.INFO: # enable in future releases. Change output to logger.error
13911391
logger.info('Stopped polling.' + warning)
13921392

13931393

‎telebot/async_telebot.py‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -386,15 +386,15 @@ async def infinity_polling(self, timeout: Optional[int]=20, skip_pending: Option
386386
await self._process_polling(non_stop=True, timeout=timeout, request_timeout=request_timeout,
387387
allowed_updates=allowed_updates, *args, **kwargs)
388388
except Exception as e:
389-
if logger_level and logger_level >= logging.ERROR:
389+
if logger_level and logger_level <= logging.ERROR:
390390
logger.error("Infinity polling exception: %s", self.__hide_token(str(e)))
391-
if logger_level and logger_level >= logging.DEBUG:
391+
if logger_level and logger_level <= logging.DEBUG:
392392
logger.error("Exception traceback:\n%s", self.__hide_token(traceback.format_exc()))
393393
await asyncio.sleep(3)
394394
continue
395-
if logger_level and logger_level >= logging.INFO:
395+
if logger_level and logger_level <= logging.INFO:
396396
logger.error("Infinity polling: polling exited")
397-
if logger_level and logger_level >= logging.INFO:
397+
if logger_level and logger_level <= logging.INFO:
398398
logger.error("Break infinity polling")
399399

400400
async def _handle_exception(self, exception: Exception) -> bool:

‎tests/test_async_telebot.py‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,8 +5,12 @@
55
network I/O.
66
"""
77
import asyncio
8+
import logging
9+
10+
import pytest
811

912
from telebot import types
13+
import telebot.async_telebot as async_telebot
1014
from telebot.async_telebot import AsyncTeleBot
1115

1216

@@ -19,6 +23,46 @@ def _make_fake_me() -> types.User:
1923
})
2024

2125

26+
@pytest.mark.parametrize(
27+
'logger_level, expected_count, includes_traceback',
28+
[
29+
(logging.DEBUG, 3, True),
30+
(logging.INFO, 2, False),
31+
(logging.ERROR, 1, False),
32+
(None, 0, False),
33+
],
34+
)
35+
def test_infinity_polling_honors_logger_level(
36+
monkeypatch, logger_level, expected_count, includes_traceback):
37+
class RecordingLogger:
38+
def __init__(self):
39+
self.messages = []
40+
41+
def error(self, message, *args):
42+
self.messages.append(message % args if args else message)
43+
44+
bot = AsyncTeleBot('1:fake', validate_token=False)
45+
logger = RecordingLogger()
46+
47+
async def fail_polling(*args, **kwargs):
48+
bot._polling = False
49+
raise RuntimeError('polling failed')
50+
51+
async def no_sleep(_seconds):
52+
return None
53+
54+
monkeypatch.setattr(async_telebot, 'logger', logger)
55+
monkeypatch.setattr(async_telebot.asyncio, 'sleep', no_sleep)
56+
monkeypatch.setattr(bot, '_process_polling', fail_polling)
57+
58+
asyncio.run(bot.infinity_polling(logger_level=logger_level))
59+
60+
assert len(logger.messages) == expected_count
61+
if logger_level:
62+
assert logger.messages[0] == 'Infinity polling exception: polling failed'
63+
assert any('Exception traceback:' in message for message in logger.messages) is includes_traceback
64+
65+
2266
def test_process_polling_retains_update_processing_tasks():
2367
"""Regression test for issue #2572.
2468

‎tests/test_telebot.py‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
# -*- coding: utf-8 -*-
22
import sys
33
import warnings
4+
import logging
45

56
sys.path.append('../')
67

@@ -34,6 +35,44 @@ def deprecated2_new_function():
3435
def deprecated2_old_function():
3536
print("deprecated2_old_function")
3637

38+
39+
@pytest.mark.parametrize(
40+
'logger_level, expected_count, includes_traceback',
41+
[
42+
(logging.DEBUG, 3, True),
43+
(logging.INFO, 2, False),
44+
(logging.ERROR, 1, False),
45+
(None, 0, False),
46+
],
47+
)
48+
def test_infinity_polling_honors_logger_level(
49+
monkeypatch, logger_level, expected_count, includes_traceback):
50+
class RecordingLogger:
51+
def __init__(self):
52+
self.messages = []
53+
54+
def error(self, message, *args):
55+
self.messages.append(message % args if args else message)
56+
57+
bot = telebot.TeleBot('1:fake', validate_token=False)
58+
logger = RecordingLogger()
59+
60+
def fail_polling(*args, **kwargs):
61+
bot._TeleBot__stop_polling.set()
62+
raise RuntimeError('polling failed')
63+
64+
monkeypatch.setattr(telebot, 'logger', logger)
65+
monkeypatch.setattr(telebot.time, 'sleep', lambda _seconds: None)
66+
monkeypatch.setattr(bot, 'polling', fail_polling)
67+
68+
bot.infinity_polling(logger_level=logger_level)
69+
70+
assert len(logger.messages) == expected_count
71+
if logger_level:
72+
assert logger.messages[0] == 'Infinity polling exception: polling failed'
73+
assert any('Exception traceback:' in message for message in logger.messages) is includes_traceback
74+
75+
3776
@pytest.mark.skipif(should_skip, reason="No environment variables configured")
3877
class TestTeleBot:
3978
def test_message_listener(self):

0 commit comments

Comments
 (0)