Give Loggers Better Names (#3623)

This commit is contained in:
Bibo-Joshi 2023-04-10 17:01:35 +02:00 committed by GitHub
parent 401b2decce
commit 53093ebceb
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
18 changed files with 240 additions and 136 deletions

View file

@ -22,7 +22,6 @@ import asyncio
import contextlib import contextlib
import copy import copy
import functools import functools
import logging
import pickle import pickle
from datetime import datetime from datetime import datetime
from types import TracebackType from types import TracebackType
@ -94,6 +93,7 @@ from telegram._userprofilephotos import UserProfilePhotos
from telegram._utils.argumentparsing import parse_sequence_arg from telegram._utils.argumentparsing import parse_sequence_arg
from telegram._utils.defaultvalue import DEFAULT_NONE, DefaultValue from telegram._utils.defaultvalue import DEFAULT_NONE, DefaultValue
from telegram._utils.files import is_local_file, parse_file_input from telegram._utils.files import is_local_file, parse_file_input
from telegram._utils.logging import get_logger
from telegram._utils.types import DVInput, FileInput, JSONDict, ODVInput, ReplyMarkup from telegram._utils.types import DVInput, FileInput, JSONDict, ODVInput, ReplyMarkup
from telegram._utils.warnings import warn from telegram._utils.warnings import warn
from telegram._utils.warnings_transition import warn_about_thumb_return_thumbnail from telegram._utils.warnings_transition import warn_about_thumb_return_thumbnail
@ -206,6 +206,10 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
""" """
# This is a class variable since we want to override the logger name in ExtBot
# without having to change all places where this is used
_LOGGER = get_logger(__name__)
__slots__ = ( __slots__ = (
"_token", "_token",
"_base_url", "_base_url",
@ -213,7 +217,6 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
"_private_key", "_private_key",
"_bot_user", "_bot_user",
"_request", "_request",
"_logger",
"_initialized", "_initialized",
"_local_mode", "_local_mode",
) )
@ -239,7 +242,6 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
self._local_mode: bool = local_mode self._local_mode: bool = local_mode
self._bot_user: Optional[User] = None self._bot_user: Optional[User] = None
self._private_key: Optional[bytes] = None self._private_key: Optional[bytes] = None
self._logger = logging.getLogger(__name__)
self._initialized = False self._initialized = False
self._request: Tuple[BaseRequest, BaseRequest] = ( self._request: Tuple[BaseRequest, BaseRequest] = (
@ -361,14 +363,13 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
# TODO: After https://youtrack.jetbrains.com/issue/PY-50952 is fixed, we can revisit this and # TODO: After https://youtrack.jetbrains.com/issue/PY-50952 is fixed, we can revisit this and
# consider adding Paramspec from typing_extensions to properly fix this. Currently a workaround # consider adding Paramspec from typing_extensions to properly fix this. Currently a workaround
def _log(func: Any): # type: ignore[no-untyped-def] # skipcq: PY-D0003 def _log(func: Any): # type: ignore[no-untyped-def] # skipcq: PY-D0003
logger = logging.getLogger(func.__module__)
@functools.wraps(func) @functools.wraps(func)
async def decorator(*args, **kwargs): # type: ignore[no-untyped-def] async def decorator(self, *args, **kwargs): # type: ignore[no-untyped-def]
logger.debug("Entering: %s", func.__name__) # pylint: disable=protected-access
result = await func(*args, **kwargs) # skipcq: PYL-E1102 self._LOGGER.debug("Entering: %s", func.__name__)
logger.debug(result) result = await func(self, *args, **kwargs) # skipcq: PYL-E1102
logger.debug("Exiting: %s", func.__name__) self._LOGGER.debug(result)
self._LOGGER.debug("Exiting: %s", func.__name__)
return result return result
return decorator return decorator
@ -569,7 +570,7 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
.. versionadded:: 20.0 .. versionadded:: 20.0
""" """
if self._initialized: if self._initialized:
self._logger.debug("This Bot is already initialized.") self._LOGGER.debug("This Bot is already initialized.")
return return
await asyncio.gather(self._request[0].initialize(), self._request[1].initialize()) await asyncio.gather(self._request[0].initialize(), self._request[1].initialize())
@ -590,7 +591,7 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
.. versionadded:: 20.0 .. versionadded:: 20.0
""" """
if not self._initialized: if not self._initialized:
self._logger.debug("This Bot is already shut down. Returning.") self._LOGGER.debug("This Bot is already shut down. Returning.")
return return
await asyncio.gather(self._request[0].shutdown(), self._request[1].shutdown()) await asyncio.gather(self._request[0].shutdown(), self._request[1].shutdown())
@ -3614,9 +3615,9 @@ class Bot(TelegramObject, AsyncContextManager["Bot"]):
) )
if result: if result:
self._logger.debug("Getting updates: %s", [u["update_id"] for u in result]) self._LOGGER.debug("Getting updates: %s", [u["update_id"] for u in result])
else: else:
self._logger.debug("No new updates found.") self._LOGGER.debug("No new updates found.")
return Update.de_list(result, self) return Update.de_list(result, self)

View file

@ -18,7 +18,6 @@
# along with this program. If not, see [http://www.gnu.org/licenses/]. # along with this program. If not, see [http://www.gnu.org/licenses/].
"""This module contains an object that represents a Telegram InputFile.""" """This module contains an object that represents a Telegram InputFile."""
import logging
import mimetypes import mimetypes
from typing import IO, Optional, Union from typing import IO, Optional, Union
from uuid import uuid4 from uuid import uuid4
@ -27,7 +26,6 @@ from telegram._utils.files import load_file
from telegram._utils.types import FieldTuple from telegram._utils.types import FieldTuple
_DEFAULT_MIME_TYPE = "application/octet-stream" _DEFAULT_MIME_TYPE = "application/octet-stream"
logger = logging.getLogger(__name__)
class InputFile: class InputFile:

View file

@ -0,0 +1,49 @@
#!/usr/bin/env python
#
# A library that provides a Python interface to the Telegram Bot API
# Copyright (C) 2015-2023
# Leandro Toledo de Souza <devs@python-telegram-bot.org>
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU Lesser Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
# GNU Lesser Public License for more details.
#
# You should have received a copy of the GNU Lesser Public License
# along with this program. If not, see [http://www.gnu.org/licenses/].
"""This module contains helper functions related to logging.
Warning:
Contents of this module are intended to be used internally by the library and *not* by the
user. Changes to this module are not considered breaking changes and may not be documented in
the changelog.
"""
import logging
def get_logger(file_name: str, class_name: str = None) -> logging.Logger:
"""Returns a logger with an appropriate name.
Use as follows::
logger = get_logger(__name__)
If for example `__name__` is `telegram.ext._updater`, the logger will be named
`telegram.ext.Updater`. If `class_name` is passed, this will result in
`telegram.ext.<class_name>`. Useful e.g. for CamelCase class names.
If the file name points to a utils module, the logger name will simply be `telegram(.ext)`.
Returns:
:class:`logging.Logger`: The logger.
"""
parts = file_name.split("_")
if parts[1].startswith("utils") and class_name is None:
name = parts[0].rstrip(".")
else:
name = f"{parts[0]}{class_name or parts[1].capitalize()}"
return logging.getLogger(name)

View file

@ -21,7 +21,6 @@ library.
""" """
import asyncio import asyncio
import contextlib import contextlib
import logging
import sys import sys
from typing import Any, AsyncIterator, Callable, Coroutine, Dict, List, Optional, Union from typing import Any, AsyncIterator, Callable, Coroutine, Dict, List, Optional, Union
@ -32,6 +31,7 @@ try:
except ImportError: except ImportError:
AIO_LIMITER_AVAILABLE = False AIO_LIMITER_AVAILABLE = False
from telegram._utils.logging import get_logger
from telegram._utils.types import JSONDict from telegram._utils.types import JSONDict
from telegram.error import RetryAfter from telegram.error import RetryAfter
from telegram.ext._baseratelimiter import BaseRateLimiter from telegram.ext._baseratelimiter import BaseRateLimiter
@ -48,6 +48,9 @@ else:
yield None yield None
_LOGGER = get_logger(__name__, class_name="AIORateLimiter")
class AIORateLimiter(BaseRateLimiter[int]): class AIORateLimiter(BaseRateLimiter[int]):
""" """
Implementation of :class:`~telegram.ext.BaseRateLimiter` using the library Implementation of :class:`~telegram.ext.BaseRateLimiter` using the library
@ -118,7 +121,6 @@ class AIORateLimiter(BaseRateLimiter[int]):
"_group_limiters", "_group_limiters",
"_group_max_rate", "_group_max_rate",
"_group_time_period", "_group_time_period",
"_logger",
"_max_retries", "_max_retries",
"_retry_after_event", "_retry_after_event",
) )
@ -152,7 +154,6 @@ class AIORateLimiter(BaseRateLimiter[int]):
self._group_limiters: Dict[Union[str, int], AsyncLimiter] = {} self._group_limiters: Dict[Union[str, int], AsyncLimiter] = {}
self._max_retries: int = max_retries self._max_retries: int = max_retries
self._logger = logging.getLogger(__name__)
self._retry_after_event = asyncio.Event() self._retry_after_event = asyncio.Event()
self._retry_after_event.set() self._retry_after_event.set()
@ -247,13 +248,13 @@ class AIORateLimiter(BaseRateLimiter[int]):
) )
except RetryAfter as exc: except RetryAfter as exc:
if i == max_retries: if i == max_retries:
self._logger.exception( _LOGGER.exception(
"Rate limit hit after maximum of %d retries", max_retries, exc_info=exc "Rate limit hit after maximum of %d retries", max_retries, exc_info=exc
) )
raise exc raise exc
sleep = exc.retry_after + 0.1 sleep = exc.retry_after + 0.1
self._logger.info("Rate limit hit. Retrying after %f seconds", sleep) _LOGGER.info("Rate limit hit. Retrying after %f seconds", sleep)
# Make sure we don't allow other requests to be processed # Make sure we don't allow other requests to be processed
self._retry_after_event.clear() self._retry_after_event.clear()
await asyncio.sleep(sleep) await asyncio.sleep(sleep)

View file

@ -21,7 +21,6 @@ import asyncio
import contextlib import contextlib
import inspect import inspect
import itertools import itertools
import logging
import platform import platform
import signal import signal
from collections import defaultdict from collections import defaultdict
@ -53,6 +52,7 @@ from typing import (
from telegram._update import Update from telegram._update import Update
from telegram._utils.defaultvalue import DEFAULT_NONE, DEFAULT_TRUE, DefaultValue from telegram._utils.defaultvalue import DEFAULT_NONE, DEFAULT_TRUE, DefaultValue
from telegram._utils.logging import get_logger
from telegram._utils.types import SCT, DVType, ODVInput from telegram._utils.types import SCT, DVType, ODVInput
from telegram._utils.warnings import warn from telegram._utils.warnings import warn
from telegram.error import TelegramError from telegram.error import TelegramError
@ -77,7 +77,7 @@ _AppType = TypeVar("_AppType", bound="Application") # pylint: disable=invalid-n
_STOP_SIGNAL = object() _STOP_SIGNAL = object()
_DEFAULT_0 = DefaultValue(0) _DEFAULT_0 = DefaultValue(0)
_logger = logging.getLogger(__name__) _LOGGER = get_logger(__name__)
class ApplicationHandlerStop(Exception): class ApplicationHandlerStop(Exception):
@ -393,7 +393,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
:meth:`shutdown` :meth:`shutdown`
""" """
if self._initialized: if self._initialized:
_logger.debug("This Application is already initialized.") _LOGGER.debug("This Application is already initialized.")
return return
await self.bot.initialize() await self.bot.initialize()
@ -443,7 +443,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
raise RuntimeError("This Application is still running!") raise RuntimeError("This Application is still running!")
if not self._initialized: if not self._initialized:
_logger.debug("This Application is already shut down. Returning.") _LOGGER.debug("This Application is already shut down. Returning.")
return return
await self.bot.shutdown() await self.bot.shutdown()
@ -451,10 +451,10 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
await self.updater.shutdown() await self.updater.shutdown()
if self.persistence: if self.persistence:
_logger.debug("Updating & flushing persistence before shutdown") _LOGGER.debug("Updating & flushing persistence before shutdown")
await self.update_persistence() await self.update_persistence()
await self.persistence.flush() await self.persistence.flush()
_logger.debug("Updated and flushed persistence") _LOGGER.debug("Updated and flushed persistence")
self._initialized = False self._initialized = False
@ -557,18 +557,18 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
# TODO: Add this once we drop py3.7 # TODO: Add this once we drop py3.7
# name=f'Application:{self.bot.id}:persistence_updater' # name=f'Application:{self.bot.id}:persistence_updater'
) )
_logger.debug("Loop for updating persistence started") _LOGGER.debug("Loop for updating persistence started")
if self._job_queue: if self._job_queue:
await self._job_queue.start() # type: ignore[union-attr] await self._job_queue.start() # type: ignore[union-attr]
_logger.debug("JobQueue started") _LOGGER.debug("JobQueue started")
self.__update_fetcher_task = asyncio.create_task( self.__update_fetcher_task = asyncio.create_task(
self._update_fetcher(), self._update_fetcher(),
# TODO: Add this once we drop py3.7 # TODO: Add this once we drop py3.7
# name=f'Application:{self.bot.id}:update_fetcher' # name=f'Application:{self.bot.id}:update_fetcher'
) )
_logger.info("Application started") _LOGGER.info("Application started")
except Exception as exc: except Exception as exc:
self._running = False self._running = False
@ -601,32 +601,32 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
raise RuntimeError("This Application is not running!") raise RuntimeError("This Application is not running!")
self._running = False self._running = False
_logger.info("Application is stopping. This might take a moment.") _LOGGER.info("Application is stopping. This might take a moment.")
# Stop listening for new updates and handle all pending ones # Stop listening for new updates and handle all pending ones
await self.update_queue.put(_STOP_SIGNAL) await self.update_queue.put(_STOP_SIGNAL)
_logger.debug("Waiting for update_queue to join") _LOGGER.debug("Waiting for update_queue to join")
await self.update_queue.join() await self.update_queue.join()
if self.__update_fetcher_task: if self.__update_fetcher_task:
await self.__update_fetcher_task await self.__update_fetcher_task
_logger.debug("Application stopped fetching of updates.") _LOGGER.debug("Application stopped fetching of updates.")
if self._job_queue: if self._job_queue:
_logger.debug("Waiting for running jobs to finish") _LOGGER.debug("Waiting for running jobs to finish")
await self._job_queue.stop(wait=True) # type: ignore[union-attr] await self._job_queue.stop(wait=True) # type: ignore[union-attr]
_logger.debug("JobQueue stopped") _LOGGER.debug("JobQueue stopped")
_logger.debug("Waiting for `create_task` calls to be processed") _LOGGER.debug("Waiting for `create_task` calls to be processed")
await asyncio.gather(*self.__create_task_tasks, return_exceptions=True) await asyncio.gather(*self.__create_task_tasks, return_exceptions=True)
# Make sure that this is the *last* step of stopping the application! # Make sure that this is the *last* step of stopping the application!
if self.persistence and self.__update_persistence_task: if self.persistence and self.__update_persistence_task:
_logger.debug("Waiting for persistence loop to finish") _LOGGER.debug("Waiting for persistence loop to finish")
self.__update_persistence_event.set() self.__update_persistence_event.set()
await self.__update_persistence_task await self.__update_persistence_task
self.__update_persistence_event.clear() self.__update_persistence_event.clear()
_logger.info("Application.stop() complete") _LOGGER.info("Application.stop() complete")
def run_polling( def run_polling(
self, self,
@ -1026,7 +1026,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
# Avoid infinite recursion of error handlers. # Avoid infinite recursion of error handlers.
elif is_error_handler: elif is_error_handler:
_logger.exception( _LOGGER.exception(
"An error was raised and an uncaught error was raised while " "An error was raised and an uncaught error was raised while "
"handling the error with an error_handler.", "handling the error with an error_handler.",
exc_info=exception, exc_info=exception,
@ -1049,7 +1049,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
update = await self.update_queue.get() update = await self.update_queue.get()
if update is _STOP_SIGNAL: if update is _STOP_SIGNAL:
_logger.debug("Dropping pending updates") _LOGGER.debug("Dropping pending updates")
while not self.update_queue.empty(): while not self.update_queue.empty():
self.update_queue.task_done() self.update_queue.task_done()
@ -1057,7 +1057,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
self.update_queue.task_done() self.update_queue.task_done()
return return
_logger.debug("Processing update %s", update) _LOGGER.debug("Processing update %s", update)
if self._concurrent_updates: if self._concurrent_updates:
# We don't await the below because it has to be run concurrently # We don't await the below because it has to be run concurrently
@ -1117,13 +1117,13 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
# Stop processing with any other handler. # Stop processing with any other handler.
except ApplicationHandlerStop: except ApplicationHandlerStop:
_logger.debug("Stopping further handlers due to ApplicationHandlerStop") _LOGGER.debug("Stopping further handlers due to ApplicationHandlerStop")
break break
# Dispatch any error. # Dispatch any error.
except Exception as exc: except Exception as exc:
if await self.process_error(update=update, error=exc): if await self.process_error(update=update, error=exc):
_logger.debug("Error handler stopped further handlers.") _LOGGER.debug("Error handler stopped further handlers.")
break break
if any_blocking: if any_blocking:
@ -1451,7 +1451,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
if not self.persistence: if not self.persistence:
return return
_logger.debug("Starting next run of updating the persistence.") _LOGGER.debug("Starting next run of updating the persistence.")
coroutines: Set[Coroutine] = set() coroutines: Set[Coroutine] = set()
@ -1519,13 +1519,13 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
# *all* tasks will be done. # *all* tasks will be done.
if not new_state.done(): if not new_state.done():
if self.running: if self.running:
_logger.debug( _LOGGER.debug(
"A ConversationHandlers state was not yet resolved. Updating the " "A ConversationHandlers state was not yet resolved. Updating the "
"persistence with the current state. Will check again on next run of " "persistence with the current state. Will check again on next run of "
"Application.update_persistence." "Application.update_persistence."
) )
else: else:
_logger.warning( _LOGGER.warning(
"A ConversationHandlers state was not yet resolved. Updating the " "A ConversationHandlers state was not yet resolved. Updating the "
"persistence with the current state." "persistence with the current state."
) )
@ -1545,7 +1545,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
) )
results = await asyncio.gather(*coroutines, return_exceptions=True) results = await asyncio.gather(*coroutines, return_exceptions=True)
_logger.debug("Finished updating persistence.") _LOGGER.debug("Finished updating persistence.")
# dispatch any errors # dispatch any errors
await asyncio.gather( await asyncio.gather(
@ -1586,7 +1586,7 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
:meth:`process_error`. Defaults to :obj:`True`. :meth:`process_error`. Defaults to :obj:`True`.
""" """
if callback in self.error_handlers: if callback in self.error_handlers:
_logger.warning("The callback is already registered as an error handler. Ignoring.") _LOGGER.warning("The callback is already registered as an error handler. Ignoring.")
return return
self.error_handlers[callback] = block self.error_handlers[callback] = block
@ -1663,12 +1663,12 @@ class Application(Generic[BT, CCT, UD, CD, BD, JQ], AsyncContextManager["Applica
except ApplicationHandlerStop: except ApplicationHandlerStop:
return True return True
except Exception as exc: except Exception as exc:
_logger.exception( _LOGGER.exception(
"An error was raised and an uncaught error was raised while " "An error was raised and an uncaught error was raised while "
"handling the error with an error_handler.", "handling the error with an error_handler.",
exc_info=exc, exc_info=exc,
) )
return False return False
_logger.exception("No error handlers are registered, logging exception.", exc_info=error) _LOGGER.exception("No error handlers are registered, logging exception.", exc_info=error)
return False return False

View file

@ -19,7 +19,6 @@
"""This module contains the ConversationHandler.""" """This module contains the ConversationHandler."""
import asyncio import asyncio
import datetime import datetime
import logging
from dataclasses import dataclass from dataclasses import dataclass
from typing import ( from typing import (
TYPE_CHECKING, TYPE_CHECKING,
@ -38,6 +37,7 @@ from typing import (
from telegram import Update from telegram import Update
from telegram._utils.defaultvalue import DEFAULT_TRUE, DefaultValue from telegram._utils.defaultvalue import DEFAULT_TRUE, DefaultValue
from telegram._utils.logging import get_logger
from telegram._utils.types import DVType from telegram._utils.types import DVType
from telegram._utils.warnings import warn from telegram._utils.warnings import warn
from telegram.ext._application import ApplicationHandlerStop from telegram.ext._application import ApplicationHandlerStop
@ -56,7 +56,7 @@ if TYPE_CHECKING:
from telegram.ext import Application, Job, JobQueue from telegram.ext import Application, Job, JobQueue
_CheckUpdateType = Tuple[object, ConversationKey, BaseHandler[Update, CCT], object] _CheckUpdateType = Tuple[object, ConversationKey, BaseHandler[Update, CCT], object]
_logger = logging.getLogger(__name__) _LOGGER = get_logger(__name__, class_name="ConversationHandler")
@dataclass @dataclass
@ -102,7 +102,7 @@ class PendingState:
exc = self.task.exception() exc = self.task.exception()
if exc: if exc:
_logger.exception( _LOGGER.exception(
"Task function raised exception. Falling back to old state %s", "Task function raised exception. Falling back to old state %s",
self.old_state, self.old_state,
) )
@ -649,7 +649,7 @@ class ConversationHandler(BaseHandler[Update, CCT]):
try: try:
effective_new_state = await new_state effective_new_state = await new_state
except Exception as exc: except Exception as exc:
_logger.debug( _LOGGER.debug(
"Non-blocking handler callback raised exception. Not scheduling conversation " "Non-blocking handler callback raised exception. Not scheduling conversation "
"timeout.", "timeout.",
exc_info=exc, exc_info=exc,
@ -684,7 +684,7 @@ class ConversationHandler(BaseHandler[Update, CCT]):
data=_ConversationTimeoutContext(conversation_key, update, application, context), data=_ConversationTimeoutContext(conversation_key, update, application, context),
) )
except Exception as exc: except Exception as exc:
_logger.exception("Failed to schedule timeout.", exc_info=exc) _LOGGER.exception("Failed to schedule timeout.", exc_info=exc)
# pylint: disable=too-many-return-statements # pylint: disable=too-many-return-statements
def check_update(self, update: object) -> Optional[_CheckUpdateType[CCT]]: def check_update(self, update: object) -> Optional[_CheckUpdateType[CCT]]:
@ -719,7 +719,7 @@ class ConversationHandler(BaseHandler[Update, CCT]):
# Resolve futures # Resolve futures
if isinstance(state, PendingState): if isinstance(state, PendingState):
_logger.debug("Waiting for asyncio Task to finish ...") _LOGGER.debug("Waiting for asyncio Task to finish ...")
# check if future is finished or not # check if future is finished or not
if state.done(): if state.done():
@ -741,7 +741,7 @@ class ConversationHandler(BaseHandler[Update, CCT]):
return self.WAITING, key, handler_, check return self.WAITING, key, handler_, check
return None return None
_logger.debug("Selecting conversation %s with state %s", str(key), str(state)) _LOGGER.debug("Selecting conversation %s with state %s", str(key), str(state))
handler: Optional[BaseHandler] = None handler: Optional[BaseHandler] = None
@ -905,7 +905,7 @@ class ConversationHandler(BaseHandler[Update, CCT]):
job = cast("Job", context.job) job = cast("Job", context.job)
ctxt = cast(_ConversationTimeoutContext, job.data) ctxt = cast(_ConversationTimeoutContext, job.data)
_logger.debug( _LOGGER.debug(
"Conversation timeout was triggered for conversation %s!", ctxt.conversation_key "Conversation timeout was triggered for conversation %s!", ctxt.conversation_key
) )

View file

@ -85,6 +85,7 @@ from telegram import (
) )
from telegram._utils.datetime import to_timestamp from telegram._utils.datetime import to_timestamp
from telegram._utils.defaultvalue import DEFAULT_NONE, DefaultValue from telegram._utils.defaultvalue import DEFAULT_NONE, DefaultValue
from telegram._utils.logging import get_logger
from telegram._utils.types import DVInput, FileInput, JSONDict, ODVInput, ReplyMarkup from telegram._utils.types import DVInput, FileInput, JSONDict, ODVInput, ReplyMarkup
from telegram._utils.warnings import warn from telegram._utils.warnings import warn
from telegram.ext._callbackdatacache import CallbackDataCache from telegram.ext._callbackdatacache import CallbackDataCache
@ -156,6 +157,8 @@ class ExtBot(Bot, Generic[RLARGS]):
__slots__ = ("_callback_data_cache", "_defaults", "_rate_limiter") __slots__ = ("_callback_data_cache", "_defaults", "_rate_limiter")
_LOGGER = get_logger(__name__, class_name="ExtBot")
# using object() would be a tiny bit safer, but a string plays better with the typing setup # using object() would be a tiny bit safer, but a string plays better with the typing setup
__RL_KEY = uuid4().hex __RL_KEY = uuid4().hex
@ -324,7 +327,7 @@ class ExtBot(Bot, Generic[RLARGS]):
"connect_timeout": connect_timeout, "connect_timeout": connect_timeout,
"pool_timeout": pool_timeout, "pool_timeout": pool_timeout,
} }
self._logger.debug( self._LOGGER.debug(
"Passing request through rate limiter of type %s with rate_limit_args %s", "Passing request through rate limiter of type %s with rate_limit_args %s",
type(self.rate_limiter), type(self.rate_limiter),
rate_limit_args, rate_limit_args,

View file

@ -19,7 +19,6 @@
"""This module contains the class Updater, which tries to make creating Telegram bots intuitive.""" """This module contains the class Updater, which tries to make creating Telegram bots intuitive."""
import asyncio import asyncio
import contextlib import contextlib
import logging
import ssl import ssl
from pathlib import Path from pathlib import Path
from types import TracebackType from types import TracebackType
@ -36,6 +35,7 @@ from typing import (
) )
from telegram._utils.defaultvalue import DEFAULT_NONE from telegram._utils.defaultvalue import DEFAULT_NONE
from telegram._utils.logging import get_logger
from telegram._utils.types import ODVInput from telegram._utils.types import ODVInput
from telegram.error import InvalidToken, RetryAfter, TelegramError, TimedOut from telegram.error import InvalidToken, RetryAfter, TelegramError, TimedOut
@ -51,6 +51,7 @@ if TYPE_CHECKING:
_UpdaterType = TypeVar("_UpdaterType", bound="Updater") # pylint: disable=invalid-name _UpdaterType = TypeVar("_UpdaterType", bound="Updater") # pylint: disable=invalid-name
_LOGGER = get_logger(__name__)
class Updater(AsyncContextManager["Updater"]): class Updater(AsyncContextManager["Updater"]):
@ -97,7 +98,6 @@ class Updater(AsyncContextManager["Updater"]):
__slots__ = ( __slots__ = (
"bot", "bot",
"_logger",
"update_queue", "update_queue",
"_last_update_id", "_last_update_id",
"_running", "_running",
@ -121,7 +121,6 @@ class Updater(AsyncContextManager["Updater"]):
self._httpd: Optional[WebhookServer] = None self._httpd: Optional[WebhookServer] = None
self.__lock = asyncio.Lock() self.__lock = asyncio.Lock()
self.__polling_task: Optional[asyncio.Task] = None self.__polling_task: Optional[asyncio.Task] = None
self._logger = logging.getLogger(__name__)
@property @property
def running(self) -> bool: def running(self) -> bool:
@ -135,7 +134,7 @@ class Updater(AsyncContextManager["Updater"]):
:meth:`shutdown` :meth:`shutdown`
""" """
if self._initialized: if self._initialized:
self._logger.debug("This Updater is already initialized.") _LOGGER.debug("This Updater is already initialized.")
return return
await self.bot.initialize() await self.bot.initialize()
@ -155,12 +154,12 @@ class Updater(AsyncContextManager["Updater"]):
raise RuntimeError("This Updater is still running!") raise RuntimeError("This Updater is still running!")
if not self._initialized: if not self._initialized:
self._logger.debug("This Updater is already shut down. Returning.") _LOGGER.debug("This Updater is already shut down. Returning.")
return return
await self.bot.shutdown() await self.bot.shutdown()
self._initialized = False self._initialized = False
self._logger.debug("Shut down of Updater complete") _LOGGER.debug("Shut down of Updater complete")
async def __aenter__(self: _UpdaterType) -> _UpdaterType: async def __aenter__(self: _UpdaterType) -> _UpdaterType:
"""Simple context manager which initializes the Updater.""" """Simple context manager which initializes the Updater."""
@ -279,9 +278,9 @@ class Updater(AsyncContextManager["Updater"]):
error_callback=error_callback, error_callback=error_callback,
) )
self._logger.debug("Waiting for polling to start") _LOGGER.debug("Waiting for polling to start")
await polling_ready.wait() await polling_ready.wait()
self._logger.debug("Polling updates from Telegram started") _LOGGER.debug("Polling updates from Telegram started")
return self.update_queue return self.update_queue
except Exception as exc: except Exception as exc:
@ -302,7 +301,7 @@ class Updater(AsyncContextManager["Updater"]):
ready: asyncio.Event, ready: asyncio.Event,
error_callback: Optional[Callable[[TelegramError], None]], error_callback: Optional[Callable[[TelegramError], None]],
) -> None: ) -> None:
self._logger.debug("Updater started (polling)") _LOGGER.debug("Updater started (polling)")
# the bootstrapping phase does two things: # the bootstrapping phase does two things:
# 1) make sure there is no webhook set # 1) make sure there is no webhook set
@ -314,7 +313,7 @@ class Updater(AsyncContextManager["Updater"]):
allowed_updates=None, allowed_updates=None,
) )
self._logger.debug("Bootstrap done") _LOGGER.debug("Bootstrap done")
async def polling_action_cb() -> bool: async def polling_action_cb() -> bool:
try: try:
@ -336,7 +335,7 @@ class Updater(AsyncContextManager["Updater"]):
raise exc raise exc
except Exception as exc: except Exception as exc:
# Other exceptions should not. Let's log them for now. # Other exceptions should not. Let's log them for now.
self._logger.critical( _LOGGER.critical(
"Something went wrong processing the data received from Telegram. " "Something went wrong processing the data received from Telegram. "
"Received data was *not* processed!", "Received data was *not* processed!",
exc_info=exc, exc_info=exc,
@ -345,9 +344,9 @@ class Updater(AsyncContextManager["Updater"]):
if updates: if updates:
if not self.running: if not self.running:
self._logger.critical( _LOGGER.critical(
"Updater stopped unexpectedly. Pulled updates will be ignored and again " "Updater stopped unexpectedly. Pulled updates will be ignored and pulled "
"on restart." "again on restart."
) )
else: else:
for update in updates: for update in updates:
@ -357,7 +356,7 @@ class Updater(AsyncContextManager["Updater"]):
return True # Keep fetching updates & don't quit. Polls with poll_interval. return True # Keep fetching updates & don't quit. Polls with poll_interval.
def default_error_callback(exc: TelegramError) -> None: def default_error_callback(exc: TelegramError) -> None:
self._logger.exception("Exception happened while polling for updates.", exc_info=exc) _LOGGER.exception("Exception happened while polling for updates.", exc_info=exc)
# Start task that runs in background, pulls # Start task that runs in background, pulls
# updates from Telegram and inserts them in the update queue of the # updates from Telegram and inserts them in the update queue of the
@ -496,9 +495,9 @@ class Updater(AsyncContextManager["Updater"]):
secret_token=secret_token, secret_token=secret_token,
) )
self._logger.debug("Waiting for webhook server to start") _LOGGER.debug("Waiting for webhook server to start")
await webhook_ready.wait() await webhook_ready.wait()
self._logger.debug("Webhook server started") _LOGGER.debug("Webhook server started")
except Exception as exc: except Exception as exc:
self._running = False self._running = False
raise exc raise exc
@ -522,7 +521,7 @@ class Updater(AsyncContextManager["Updater"]):
max_connections: int = 40, max_connections: int = 40,
secret_token: str = None, secret_token: str = None,
) -> None: ) -> None:
self._logger.debug("Updater thread started (webhook)") _LOGGER.debug("Updater thread started (webhook)")
if not url_path.startswith("/"): if not url_path.startswith("/"):
url_path = f"/{url_path}" url_path = f"/{url_path}"
@ -600,7 +599,7 @@ class Updater(AsyncContextManager["Updater"]):
`action_cb`. `action_cb`.
""" """
self._logger.debug("Start network loop retry %s", description) _LOGGER.debug("Start network loop retry %s", description)
cur_interval = interval cur_interval = interval
while self.running: while self.running:
try: try:
@ -608,17 +607,17 @@ class Updater(AsyncContextManager["Updater"]):
if not await action_cb(): if not await action_cb():
break break
except RetryAfter as exc: except RetryAfter as exc:
self._logger.info("%s", exc) _LOGGER.info("%s", exc)
cur_interval = 0.5 + exc.retry_after cur_interval = 0.5 + exc.retry_after
except TimedOut as toe: except TimedOut as toe:
self._logger.debug("Timed out %s: %s", description, toe) _LOGGER.debug("Timed out %s: %s", description, toe)
# If failure is due to timeout, we should retry asap. # If failure is due to timeout, we should retry asap.
cur_interval = 0 cur_interval = 0
except InvalidToken as pex: except InvalidToken as pex:
self._logger.error("Invalid token; aborting") _LOGGER.error("Invalid token; aborting")
raise pex raise pex
except TelegramError as telegram_exc: except TelegramError as telegram_exc:
self._logger.error("Error while %s: %s", description, telegram_exc) _LOGGER.error("Error while %s: %s", description, telegram_exc)
on_err_cb(telegram_exc) on_err_cb(telegram_exc)
# increase waiting times on subsequent errors up to 30secs # increase waiting times on subsequent errors up to 30secs
@ -630,7 +629,7 @@ class Updater(AsyncContextManager["Updater"]):
await asyncio.sleep(cur_interval) await asyncio.sleep(cur_interval)
except asyncio.CancelledError: except asyncio.CancelledError:
self._logger.debug("Network loop retry %s was cancelled", description) _LOGGER.debug("Network loop retry %s was cancelled", description)
break break
async def _bootstrap( async def _bootstrap(
@ -652,16 +651,16 @@ class Updater(AsyncContextManager["Updater"]):
retries = 0 retries = 0
async def bootstrap_del_webhook() -> bool: async def bootstrap_del_webhook() -> bool:
self._logger.debug("Deleting webhook") _LOGGER.debug("Deleting webhook")
if drop_pending_updates: if drop_pending_updates:
self._logger.debug("Dropping pending updates from Telegram server") _LOGGER.debug("Dropping pending updates from Telegram server")
await self.bot.delete_webhook(drop_pending_updates=drop_pending_updates) await self.bot.delete_webhook(drop_pending_updates=drop_pending_updates)
return False return False
async def bootstrap_set_webhook() -> bool: async def bootstrap_set_webhook() -> bool:
self._logger.debug("Setting webhook") _LOGGER.debug("Setting webhook")
if drop_pending_updates: if drop_pending_updates:
self._logger.debug("Dropping pending updates from Telegram server") _LOGGER.debug("Dropping pending updates from Telegram server")
await self.bot.set_webhook( await self.bot.set_webhook(
url=webhook_url, url=webhook_url,
certificate=cert, certificate=cert,
@ -680,11 +679,11 @@ class Updater(AsyncContextManager["Updater"]):
if not isinstance(exc, InvalidToken) and (max_retries < 0 or retries < max_retries): if not isinstance(exc, InvalidToken) and (max_retries < 0 or retries < max_retries):
retries += 1 retries += 1
self._logger.warning( _LOGGER.warning(
"Failed bootstrap phase; try=%s max_retries=%s", retries, max_retries "Failed bootstrap phase; try=%s max_retries=%s", retries, max_retries
) )
else: else:
self._logger.error("Failed bootstrap phase after %s retries (%s)", retries, exc) _LOGGER.error("Failed bootstrap phase after %s retries (%s)", retries, exc)
raise exc raise exc
# Dropping pending updates from TG can be efficiently done with the drop_pending_updates # Dropping pending updates from TG can be efficiently done with the drop_pending_updates
@ -725,26 +724,26 @@ class Updater(AsyncContextManager["Updater"]):
if not self.running: if not self.running:
raise RuntimeError("This Updater is not running!") raise RuntimeError("This Updater is not running!")
self._logger.debug("Stopping Updater") _LOGGER.debug("Stopping Updater")
self._running = False self._running = False
await self._stop_httpd() await self._stop_httpd()
await self._stop_polling() await self._stop_polling()
self._logger.debug("Updater.stop() is complete") _LOGGER.debug("Updater.stop() is complete")
async def _stop_httpd(self) -> None: async def _stop_httpd(self) -> None:
"""Stops the Webhook server by calling ``WebhookServer.shutdown()``""" """Stops the Webhook server by calling ``WebhookServer.shutdown()``"""
if self._httpd: if self._httpd:
self._logger.debug("Waiting for current webhook connection to be closed.") _LOGGER.debug("Waiting for current webhook connection to be closed.")
await self._httpd.shutdown() await self._httpd.shutdown()
self._httpd = None self._httpd = None
async def _stop_polling(self) -> None: async def _stop_polling(self) -> None:
"""Stops the polling task by awaiting it.""" """Stops the polling task by awaiting it."""
if self.__polling_task: if self.__polling_task:
self._logger.debug("Waiting background polling task to finish up.") _LOGGER.debug("Waiting background polling task to finish up.")
self.__polling_task.cancel() self.__polling_task.cancel()
with contextlib.suppress(asyncio.CancelledError): with contextlib.suppress(asyncio.CancelledError):

View file

@ -25,12 +25,13 @@ Warning:
user. Changes to this module are not considered breaking changes and may not be documented in user. Changes to this module are not considered breaking changes and may not be documented in
the changelog. the changelog.
""" """
import logging
from pathlib import Path from pathlib import Path
from types import FrameType from types import FrameType
from typing import Optional from typing import Optional
_logger = logging.getLogger(__name__) from telegram._utils.logging import get_logger
_LOGGER = get_logger(__name__)
def was_called_by(frame: Optional[FrameType], caller: Path) -> bool: def was_called_by(frame: Optional[FrameType], caller: Path) -> bool:
@ -57,7 +58,7 @@ def was_called_by(frame: Optional[FrameType], caller: Path) -> bool:
try: try:
return _was_called_by(frame, caller) return _was_called_by(frame, caller)
except Exception as exc: except Exception as exc:
_logger.debug( _LOGGER.debug(
"Failed to check if frame was called by `caller`. Assuming that it was not.", "Failed to check if frame was called by `caller`. Assuming that it was not.",
exc_info=exc, exc_info=exc,
) )

View file

@ -19,7 +19,6 @@
# pylint: disable=missing-module-docstring # pylint: disable=missing-module-docstring
import asyncio import asyncio
import json import json
import logging
from http import HTTPStatus from http import HTTPStatus
from ssl import SSLContext from ssl import SSLContext
from types import TracebackType from types import TracebackType
@ -31,11 +30,15 @@ import tornado.web
from tornado.httpserver import HTTPServer from tornado.httpserver import HTTPServer
from telegram import Update from telegram import Update
from telegram._utils.logging import get_logger
from telegram.ext._extbot import ExtBot from telegram.ext._extbot import ExtBot
if TYPE_CHECKING: if TYPE_CHECKING:
from telegram import Bot from telegram import Bot
# This module is not visible to users, so we log as Updater
_LOGGER = get_logger(__name__, class_name="Updater")
class WebhookServer: class WebhookServer:
"""Thin wrapper around ``tornado.httpserver.HTTPServer``.""" """Thin wrapper around ``tornado.httpserver.HTTPServer``."""
@ -44,7 +47,6 @@ class WebhookServer:
"_http_server", "_http_server",
"listen", "listen",
"port", "port",
"_logger",
"is_running", "is_running",
"_server_lock", "_server_lock",
"_shutdown_lock", "_shutdown_lock",
@ -56,7 +58,6 @@ class WebhookServer:
self._http_server = HTTPServer(webhook_app, ssl_options=ssl_ctx) self._http_server = HTTPServer(webhook_app, ssl_options=ssl_ctx)
self.listen = listen self.listen = listen
self.port = port self.port = port
self._logger = logging.getLogger(__name__)
self.is_running = False self.is_running = False
self._server_lock = asyncio.Lock() self._server_lock = asyncio.Lock()
self._shutdown_lock = asyncio.Lock() self._shutdown_lock = asyncio.Lock()
@ -69,17 +70,17 @@ class WebhookServer:
if ready is not None: if ready is not None:
ready.set() ready.set()
self._logger.debug("Webhook Server started.") _LOGGER.debug("Webhook Server started.")
async def shutdown(self) -> None: async def shutdown(self) -> None:
async with self._shutdown_lock: async with self._shutdown_lock:
if not self.is_running: if not self.is_running:
self._logger.debug("Webhook Server is already shut down. Returning") _LOGGER.debug("Webhook Server is already shut down. Returning")
return return
self.is_running = False self.is_running = False
self._http_server.stop() self._http_server.stop()
await self._http_server.close_all_connections() await self._http_server.close_all_connections()
self._logger.debug("Webhook Server stopped") _LOGGER.debug("Webhook Server stopped")
class WebhookAppClass(tornado.web.Application): class WebhookAppClass(tornado.web.Application):
@ -104,7 +105,7 @@ class WebhookAppClass(tornado.web.Application):
class TelegramHandler(tornado.web.RequestHandler): class TelegramHandler(tornado.web.RequestHandler):
"""BaseHandler that processes incoming requests from Telegram""" """BaseHandler that processes incoming requests from Telegram"""
__slots__ = ("bot", "update_queue", "_logger", "secret_token") __slots__ = ("bot", "update_queue", "secret_token")
SUPPORTED_METHODS = ("POST",) # type: ignore[assignment] SUPPORTED_METHODS = ("POST",) # type: ignore[assignment]
@ -113,10 +114,9 @@ class TelegramHandler(tornado.web.RequestHandler):
# pylint: disable=attribute-defined-outside-init # pylint: disable=attribute-defined-outside-init
self.bot = bot self.bot = bot
self.update_queue = update_queue # skipcq: PYL-W0201 self.update_queue = update_queue # skipcq: PYL-W0201
self._logger = logging.getLogger(__name__) # skipcq: PYL-W0201
self.secret_token = secret_token # skipcq: PYL-W0201 self.secret_token = secret_token # skipcq: PYL-W0201
if secret_token: if secret_token:
self._logger.debug( _LOGGER.debug(
"The webhook server has a secret token, expecting it in incoming requests now" "The webhook server has a secret token, expecting it in incoming requests now"
) )
@ -126,25 +126,25 @@ class TelegramHandler(tornado.web.RequestHandler):
async def post(self) -> None: async def post(self) -> None:
"""Handle incoming POST request""" """Handle incoming POST request"""
self._logger.debug("Webhook triggered") _LOGGER.debug("Webhook triggered")
self._validate_post() self._validate_post()
json_string = self.request.body.decode() json_string = self.request.body.decode()
data = json.loads(json_string) data = json.loads(json_string)
self.set_status(HTTPStatus.OK) self.set_status(HTTPStatus.OK)
self._logger.debug("Webhook received data: %s", json_string) _LOGGER.debug("Webhook received data: %s", json_string)
try: try:
update = Update.de_json(data, self.bot) update = Update.de_json(data, self.bot)
except Exception as exc: except Exception as exc:
self._logger.critical( _LOGGER.critical(
"Something went wrong processing the data received from Telegram. " "Something went wrong processing the data received from Telegram. "
"Received data was *not* processed!", "Received data was *not* processed!",
exc_info=exc, exc_info=exc,
) )
if update: if update:
self._logger.debug( _LOGGER.debug(
"Received Update with ID %d on Webhook", "Received Update with ID %d on Webhook",
# For some reason pylint thinks update is a general TelegramObject # For some reason pylint thinks update is a general TelegramObject
update.update_id, # pylint: disable=no-member update.update_id, # pylint: disable=no-member
@ -165,12 +165,12 @@ class TelegramHandler(tornado.web.RequestHandler):
if self.secret_token is not None: if self.secret_token is not None:
token = self.request.headers.get("X-Telegram-Bot-Api-Secret-Token") token = self.request.headers.get("X-Telegram-Bot-Api-Secret-Token")
if not token: if not token:
self._logger.debug("Request did not include the secret token") _LOGGER.debug("Request did not include the secret token")
raise tornado.web.HTTPError( raise tornado.web.HTTPError(
HTTPStatus.FORBIDDEN, reason="Request did not include the secret token" HTTPStatus.FORBIDDEN, reason="Request did not include the secret token"
) )
if token != self.secret_token: if token != self.secret_token:
self._logger.debug("Request had the wrong secret token: %s", token) _LOGGER.debug("Request had the wrong secret token: %s", token)
raise tornado.web.HTTPError( raise tornado.web.HTTPError(
HTTPStatus.FORBIDDEN, reason="Request had the wrong secret token" HTTPStatus.FORBIDDEN, reason="Request had the wrong secret token"
) )
@ -182,7 +182,7 @@ class TelegramHandler(tornado.web.RequestHandler):
tb: Optional[TracebackType], tb: Optional[TracebackType],
) -> None: ) -> None:
"""Override the default logging and instead use our custom logging.""" """Override the default logging and instead use our custom logging."""
self._logger.debug( _LOGGER.debug(
"%s - %s", "%s - %s",
self.request.remote_ip, self.request.remote_ip,
"Exception in TelegramHandler", "Exception in TelegramHandler",

View file

@ -17,12 +17,12 @@
# You should have received a copy of the GNU Lesser Public License # You should have received a copy of the GNU Lesser Public License
# along with this program. If not, see [http://www.gnu.org/licenses/]. # along with this program. If not, see [http://www.gnu.org/licenses/].
"""This module contains methods to make POST and GET requests using the httpx library.""" """This module contains methods to make POST and GET requests using the httpx library."""
import logging
from typing import Optional, Tuple from typing import Optional, Tuple
import httpx import httpx
from telegram._utils.defaultvalue import DefaultValue from telegram._utils.defaultvalue import DefaultValue
from telegram._utils.logging import get_logger
from telegram._utils.types import ODVInput from telegram._utils.types import ODVInput
from telegram.error import NetworkError, TimedOut from telegram.error import NetworkError, TimedOut
from telegram.request._baserequest import BaseRequest from telegram.request._baserequest import BaseRequest
@ -33,7 +33,7 @@ from telegram.request._requestdata import RequestData
# https://www.python-httpx.org/contributing/#development-proxy-setup (also saved on archive.org) # https://www.python-httpx.org/contributing/#development-proxy-setup (also saved on archive.org)
# That also works with socks5. Just pass `--mode socks5` to mitmproxy # That also works with socks5. Just pass `--mode socks5` to mitmproxy
_logger = logging.getLogger(__name__) _LOGGER = get_logger(__name__, "HTTPXRequest")
class HTTPXRequest(BaseRequest): class HTTPXRequest(BaseRequest):
@ -166,7 +166,7 @@ class HTTPXRequest(BaseRequest):
async def shutdown(self) -> None: async def shutdown(self) -> None:
"""See :meth:`BaseRequest.shutdown`.""" """See :meth:`BaseRequest.shutdown`."""
if self._client.is_closed: if self._client.is_closed:
_logger.debug("This HTTPXRequest is already shut down. Returning.") _LOGGER.debug("This HTTPXRequest is already shut down. Returning.")
return return
await self._client.aclose() await self._client.aclose()

View file

@ -56,6 +56,7 @@ class TestStack:
assert not was_called_by(inspect.currentframe(), None) assert not was_called_by(inspect.currentframe(), None)
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[0].name == "telegram.ext"
assert caplog.records[0].levelno == logging.DEBUG assert caplog.records[0].levelno == logging.DEBUG
assert caplog.records[0].getMessage().startswith("Failed to check") assert caplog.records[0].getMessage().startswith("Failed to check")
assert caplog.records[0].exc_info[0] is RuntimeError assert caplog.records[0].exc_info[0] is RuntimeError

View file

@ -803,6 +803,7 @@ class TestApplication:
with caplog.at_level(logging.DEBUG): with caplog.at_level(logging.DEBUG):
app.add_error_handler(self.error_handler_context) app.add_error_handler(self.error_handler_context)
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[-1].name == "telegram.ext.Application"
assert caplog.records[-1].getMessage().startswith("The callback is already registered") assert caplog.records[-1].getMessage().startswith("The callback is already registered")
async def test_error_handler_that_raises_errors(self, app, caplog): async def test_error_handler_that_raises_errors(self, app, caplog):
@ -826,11 +827,11 @@ class TestApplication:
assert self.count == 0 assert self.count == 0
assert self.received is None assert self.received is None
assert len(caplog.records) > 0 assert len(caplog.records) > 0
log_messages = (record.getMessage() for record in caplog.records)
assert any( assert any(
"uncaught error was raised while handling the error with an error_handler" "uncaught error was raised while handling the error with an error_handler"
in message in record.getMessage()
for message in log_messages and record.name == "telegram.ext.Application"
for record in caplog.records
) )
await app.update_queue.put("1") await app.update_queue.put("1")
@ -988,6 +989,7 @@ class TestApplication:
assert ( assert (
caplog.records[-1].getMessage().startswith("No error handlers are registered") caplog.records[-1].getMessage().startswith("No error handlers are registered")
) )
assert caplog.records[-1].name == "telegram.ext.Application"
await app.stop() await app.stop()
@pytest.mark.parametrize("handler_block", [True, False]) @pytest.mark.parametrize("handler_block", [True, False])
@ -1090,6 +1092,7 @@ class TestApplication:
await app.update_queue.put(1) await app.update_queue.put(1)
await asyncio.sleep(0.05) await asyncio.sleep(0.05)
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[-1].name == "telegram.ext.Application"
assert ( assert (
caplog.records[-1] caplog.records[-1]
.getMessage() .getMessage()

View file

@ -405,7 +405,7 @@ class TestBasePersistence:
assert bot.callback_data_cache is None assert bot.callback_data_cache is None
assert papp.persistence.set_bot(bot) is None assert papp.persistence.set_bot(bot) is None
def test_construction_with_bad_persistence(self, caplog, bot): def test_construction_with_bad_persistence(self, bot):
class MyPersistence: class MyPersistence:
def __init__(self): def __init__(self):
self.store_data = PersistenceInput(False, False, False, False) self.store_data = PersistenceInput(False, False, False, False)
@ -1128,6 +1128,7 @@ class TestBasePersistence:
assert len(caplog.records) == 6 assert len(caplog.records) == 6
assert test_flag == [True, True, True, True, True, True] assert test_flag == [True, True, True, True, True, True]
for record in caplog.records: for record in caplog.records:
assert record.name == "telegram.ext.Application"
message = record.getMessage() message = record.getMessage()
assert message.startswith("An error was raised and an uncaught") assert message.startswith("An error was raised and an uncaught")
@ -1199,8 +1200,8 @@ class TestBasePersistence:
assert not papp.persistence.updated_chat_ids assert not papp.persistence.updated_chat_ids
assert not papp.persistence.updated_conversations assert not papp.persistence.updated_conversations
async def test_non_blocking_conversations(self, bot): async def test_non_blocking_conversations(self, bot, caplog):
papp = build_papp(token=bot.token) papp = build_papp(token=bot.token, update_interval=100)
event = asyncio.Event() event = asyncio.Event()
async def callback(_, __): async def callback(_, __):
@ -1220,6 +1221,7 @@ class TestBasePersistence:
papp.add_handler(conversation) papp.add_handler(conversation)
async with papp: async with papp:
await papp.start()
assert papp.persistence.updated_conversations == {} assert papp.persistence.updated_conversations == {}
await papp.process_update( await papp.process_update(
@ -1227,19 +1229,43 @@ class TestBasePersistence:
) )
assert papp.persistence.updated_conversations == {} assert papp.persistence.updated_conversations == {}
with caplog.at_level(logging.DEBUG):
await papp.update_persistence() await papp.update_persistence()
await asyncio.sleep(0.01) await asyncio.sleep(0.01)
# Conversation should have been updated with the current state, i.e. None # Conversation should have been updated with the current state, i.e. None
assert papp.persistence.updated_conversations == {"conv": ({(1, 1): 1})} assert papp.persistence.updated_conversations == {"conv": ({(1, 1): 1})}
assert papp.persistence.conversations == {"conv": {(1, 1): None}} assert papp.persistence.conversations == {"conv": {(1, 1): None}}
# Ensure that we warn the user about this!
found_record = None
for record in caplog.records:
message = record.getMessage()
if message.startswith("A ConversationHandlers state was not yet resolved"):
assert "Will check again on next run" in record.getMessage()
assert record.name == "telegram.ext.Application"
found_record = record
break
assert found_record is not None
caplog.clear()
papp.persistence.reset_tracking() papp.persistence.reset_tracking()
event.set() event.set()
await asyncio.sleep(0.01) await asyncio.sleep(0.01)
with caplog.at_level(logging.DEBUG):
await papp.update_persistence() await papp.update_persistence()
# Conversation should have been updated with the resolved state now and hence
# there should be no warning
assert not any(
record.getMessage().startswith("A ConversationHandlers state was not yet")
for record in caplog.records
)
assert papp.persistence.updated_conversations == {"conv": {(1, 1): 1}} assert papp.persistence.updated_conversations == {"conv": {(1, 1): 1}}
assert papp.persistence.conversations == {"conv": {(1, 1): HandlerStates.STATE_1}} assert papp.persistence.conversations == {"conv": {(1, 1): HandlerStates.STATE_1}}
await papp.stop()
async def test_non_blocking_conversations_raises_Exception(self, bot): async def test_non_blocking_conversations_raises_Exception(self, bot):
papp = build_papp(token=bot.token) papp = build_papp(token=bot.token)
@ -1371,6 +1397,8 @@ class TestBasePersistence:
found_record = None found_record = None
for record in caplog.records: for record in caplog.records:
if record.getMessage().startswith("A ConversationHandlers state was not yet resolved"): if record.getMessage().startswith("A ConversationHandlers state was not yet resolved"):
assert "will check again" not in record.getMessage()
assert record.name == "telegram.ext.Application"
found_record = record found_record = record
break break
assert found_record is not None assert found_record is not None

View file

@ -1090,6 +1090,7 @@ class TestConversationHandler:
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[0].message == "Failed to schedule timeout." assert caplog.records[0].message == "Failed to schedule timeout."
assert caplog.records[0].name == "telegram.ext.ConversationHandler"
assert str(caplog.records[0].exc_info[1]) == "job error" assert str(caplog.records[0].exc_info[1]) == "job error"
await app.stop() await app.stop()
@ -1143,6 +1144,7 @@ class TestConversationHandler:
assert handler.check_update(Update(0, message=message)) assert handler.check_update(Update(0, message=message))
if test_type == "exception": if test_type == "exception":
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[0].name == "telegram.ext.ConversationHandler"
assert ( assert (
caplog.records[0].message caplog.records[0].message
== "Task function raised exception. Falling back to old state 1" == "Task function raised exception. Falling back to old state 1"
@ -1189,6 +1191,7 @@ class TestConversationHandler:
# This also makes sure that we're still in the same state # This also makes sure that we're still in the same state
assert handler.check_update(Update(0, message=message)) assert handler.check_update(Update(0, message=message))
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[0].name == "telegram.ext.ConversationHandler"
assert ( assert (
caplog.records[0].message caplog.records[0].message
== "Task function raised exception. Falling back to old state None" == "Task function raised exception. Falling back to old state None"

View file

@ -557,6 +557,7 @@ class TestJobQueue:
await job.run(app) await job.run(app)
assert len(caplog.records) == 1 assert len(caplog.records) == 1
rec = caplog.records[-1] rec = caplog.records[-1]
assert rec.name == "telegram.ext.Application"
assert "No error handlers are registered" in rec.getMessage() assert "No error handlers are registered" in rec.getMessage()
async def test_custom_context(self, bot, job_queue): async def test_custom_context(self, bot, job_queue):

View file

@ -399,8 +399,11 @@ class TestUpdater:
assert self.received == error assert self.received == error
else: else:
assert len(caplog.records) > 0 assert len(caplog.records) > 0
records = (record.getMessage() for record in caplog.records) assert any(
assert "Error while getting Updates: TestMessage" in records "Error while getting Updates: TestMessage" in record.getMessage()
and record.name == "telegram.ext.Updater"
for record in caplog.records
)
# Make sure that get_updates was called # Make sure that get_updates was called
assert get_updates_event.is_set() assert get_updates_event.is_set()
@ -418,8 +421,11 @@ class TestUpdater:
assert self.received == error assert self.received == error
else: else:
assert len(caplog.records) > 0 assert len(caplog.records) > 0
records = (record.getMessage() for record in caplog.records) assert any(
assert "Error while getting Updates: TestMessage" in records "Error while getting Updates: TestMessage" in record.getMessage()
and record.name == "telegram.ext.Updater"
for record in caplog.records
)
await updater.stop() await updater.stop()
async def test_start_polling_unexpected_shutdown(self, updater, monkeypatch, caplog): async def test_start_polling_unexpected_shutdown(self, updater, monkeypatch, caplog):
@ -451,8 +457,11 @@ class TestUpdater:
await asyncio.sleep(0.1) await asyncio.sleep(0.1)
assert caplog.records assert caplog.records
records = (record.getMessage() for record in caplog.records) assert any(
assert any("Updater stopped unexpectedly." in record for record in records) "Updater stopped unexpectedly." in record.getMessage()
and record.name == "telegram.ext.Updater"
for record in caplog.records
)
# Make sure that the update_id offset wasn't increased # Make sure that the update_id offset wasn't increased
assert self.message_count == 2 assert self.message_count == 2
@ -503,6 +512,7 @@ class TestUpdater:
assert len(caplog.records) > 0 assert len(caplog.records) > 0
for record in caplog.records: for record in caplog.records:
assert record.getMessage().startswith("Something went wrong processing") assert record.getMessage().startswith("Something went wrong processing")
assert record.name == "telegram.ext.Updater"
# Make sure that everything works fine again when receiving proper updates # Make sure that everything works fine again when receiving proper updates
raise_exception = False raise_exception = False
@ -914,6 +924,7 @@ class TestUpdater:
assert len(caplog.records) == 1 assert len(caplog.records) == 1
assert caplog.records[-1].getMessage().startswith("Something went wrong processing") assert caplog.records[-1].getMessage().startswith("Something went wrong processing")
assert caplog.records[-1].name == "telegram.ext.Updater"
# Make sure that everything works fine again when receiving proper updates # Make sure that everything works fine again when receiving proper updates
caplog.clear() caplog.clear()

View file

@ -377,10 +377,13 @@ class TestBotWithoutRequest:
re.match(rf"\s*\@\_log\s*async def {bot_method_name}", source) re.match(rf"\s*\@\_log\s*async def {bot_method_name}", source)
), f"{bot_method_name} is missing the @_log decorator" ), f"{bot_method_name} is missing the @_log decorator"
async def test_log_decorator(self, bot: PytestExtBot, caplog): @pytest.mark.parametrize(
("cls", "logger_name"), [(Bot, "telegram.Bot"), (ExtBot, "telegram.ext.ExtBot")]
)
async def test_log_decorator(self, bot: PytestExtBot, cls, logger_name, caplog):
# Second argument makes sure that we ignore logs from e.g. httpx # Second argument makes sure that we ignore logs from e.g. httpx
with caplog.at_level(logging.DEBUG, logger="telegram"): with caplog.at_level(logging.DEBUG, logger="telegram"):
await ExtBot(bot.token).get_me() await cls(bot.token).get_me()
# Only for stabilizing this test- # Only for stabilizing this test-
if len(caplog.records) == 4: if len(caplog.records) == 4:
for idx, record in enumerate(caplog.records): for idx, record in enumerate(caplog.records):
@ -390,6 +393,8 @@ class TestBotWithoutRequest:
if record.getMessage().startswith("Task exception was never retrieved"): if record.getMessage().startswith("Task exception was never retrieved"):
caplog.records.pop(idx) caplog.records.pop(idx)
assert len(caplog.records) == 3 assert len(caplog.records) == 3
assert all(caplog.records[i].name == logger_name for i in [-1, 0])
assert caplog.records[0].getMessage().startswith("Entering: get_me") assert caplog.records[0].getMessage().startswith("Entering: get_me")
assert caplog.records[-1].getMessage().startswith("Exiting: get_me") assert caplog.records[-1].getMessage().startswith("Exiting: get_me")
@ -963,7 +968,7 @@ class TestBotWithoutRequest:
assert await bot.answer_inline_query(1234, results=inline_results, current_offset=0) assert await bot.answer_inline_query(1234, results=inline_results, current_offset=0)
async def test_answer_inline_query_current_offset_callback(self, monkeypatch, bot, caplog): async def test_answer_inline_query_current_offset_callback(self, monkeypatch, bot):
# For now just test that our internals pass the correct data # For now just test that our internals pass the correct data
async def make_assertion(url, request_data: RequestData, *args, **kwargs): async def make_assertion(url, request_data: RequestData, *args, **kwargs):
data = request_data.parameters data = request_data.parameters