Add middleware for logging outgoing requests (#716)

* add middleware for logging outgoing requests

* add middleware description

* fix RequestMiddlewareType callable signature

* undo `fix`, update signatures in tests

* remove repeating code

* accept proposed changes

Co-authored-by: Alex Root Junior <jroot.junior@gmail.com>

* update tests

* add patchnote

Co-authored-by: Alex Root Junior <jroot.junior@gmail.com>

CHANGES/716.feature

@@ -0,0 +1,3 @@
+Breaking: Changed the signature of the session middlewares
+Breaking: Renamed AiohttpSession.make_request method parameter from call to method to match the naming in the base class
+Added middleware for logging outgoing requests

aiogram/client/session/aiohttp.py

@@ -133,11 +133,11 @@ class AiohttpSession(BaseSession):
         return form
 
     async def make_request(
-        self, bot: Bot, call: TelegramMethod[TelegramType], timeout: Optional[int] = None
+        self, bot: Bot, method: TelegramMethod[TelegramType], timeout: Optional[int] = None
     ) -> TelegramType:
         session = await self.create_session()
 
-        request = call.build_request(bot)
+        request = method.build_request(bot)
         url = self.api.api_url(token=bot.token, method=request.method)
         form = self.build_form_data(request)
 
@@ -147,10 +147,10 @@ class AiohttpSession(BaseSession):
             ) as resp:
                 raw_result = await resp.text()
         except asyncio.TimeoutError:
-            raise TelegramNetworkError(method=call, message="Request timeout error")
+            raise TelegramNetworkError(method=method, message="Request timeout error")
         except ClientError as e:
-            raise TelegramNetworkError(method=call, message=f"{type(e).__name__}: {e}")
+            raise TelegramNetworkError(method=method, message=f"{type(e).__name__}: {e}")
-        response = self.check_response(method=call, status_code=resp.status, content=raw_result)
+        response = self.check_response(method=method, status_code=resp.status, content=raw_result)
         return cast(TelegramType, response.result)
 
     async def stream_content(

aiogram/client/session/base.py

@@ -39,6 +39,7 @@ from ...methods import Response, TelegramMethod
 from ...methods.base import TelegramType
 from ...types import UNSET, TelegramObject
 from ..telegram import PRODUCTION, TelegramAPIServer
+from .middlewares.base import BaseRequestMiddleware
 
 if TYPE_CHECKING:
     from ..bot import Bot
@@ -48,15 +49,19 @@ _JsonDumps = Callable[..., str]
 NextRequestMiddlewareType = Callable[
     ["Bot", TelegramMethod[TelegramObject]], Awaitable[Response[TelegramObject]]
 ]
-RequestMiddlewareType = Callable[
+
-    [NextRequestMiddlewareType, "Bot", TelegramMethod[TelegramType]],
+RequestMiddlewareType = Union[
-    Awaitable[Response[TelegramType]],
+    BaseRequestMiddleware,
+    Callable[
+        [NextRequestMiddlewareType, "Bot", TelegramMethod[TelegramType]],
+        Awaitable[Response[TelegramType]],
+    ],
 ]
 
 
 class BaseSession(abc.ABC):
     api: Default[TelegramAPIServer] = Default(PRODUCTION)
-    """Telegra Bot API URL patterns"""
+    """Telegram Bot API URL patterns"""
     json_loads: Default[_JsonLoads] = Default(json.loads)
     """JSON loader"""
     json_dumps: Default[_JsonDumps] = Default(json.dumps)
@@ -183,7 +188,7 @@ class BaseSession(abc.ABC):
     ) -> TelegramType:
         middleware = partial(self.make_request, timeout=timeout)
         for m in reversed(self.middlewares):
-            middleware = partial(m, make_request=middleware)  # type: ignore
+            middleware = partial(m, middleware)  # type: ignore
         return await middleware(bot, method)
 
     async def __aenter__(self) -> BaseSession:

aiogram/client/session/middlewares/base.py

@@ -0,0 +1,37 @@
+from abc import ABC, abstractmethod
+from typing import TYPE_CHECKING, Awaitable, Callable
+
+from aiogram.methods import Response, TelegramMethod
+from aiogram.types import TelegramObject
+
+if TYPE_CHECKING:
+    from ...bot import Bot
+
+
+NextRequestMiddlewareType = Callable[
+    ["Bot", TelegramMethod[TelegramObject]], Awaitable[Response[TelegramObject]]
+]
+
+
+class BaseRequestMiddleware(ABC):
+    """
+    Generic middleware class
+    """
+
+    @abstractmethod
+    async def __call__(
+        self,
+        make_request: NextRequestMiddlewareType,
+        bot: "Bot",
+        method: TelegramMethod[TelegramObject],
+    ) -> Response[TelegramObject]:
+        """
+        Execute middleware
+
+        :param make_request: Wrapped make_request in middlewares chain
+        :param bot: bot for request making
+        :param method: Request method (Subclass of :class:`aiogram.methods.base.TelegramMethod`)
+
+        :return: :class:`aiogram.methods.Response`
+        """
+        pass

aiogram/client/session/middlewares/request_logging.py

@@ -0,0 +1,38 @@
+import logging
+from typing import TYPE_CHECKING, Any, List, Optional, Type
+
+from aiogram import loggers
+from aiogram.methods import TelegramMethod
+from aiogram.methods.base import Response
+from aiogram.types import TelegramObject
+
+from .base import BaseRequestMiddleware, NextRequestMiddlewareType
+
+if TYPE_CHECKING:
+    from ...bot import Bot
+
+logger = logging.getLogger(__name__)
+
+
+class RequestLogging(BaseRequestMiddleware):
+    def __init__(self, ignore_methods: Optional[List[Type[TelegramMethod[Any]]]] = None):
+        """
+        Middleware for logging outgoing requests
+
+        :param ignore_methods: methods to ignore in logging middleware
+        """
+        self.ignore_methods = ignore_methods if ignore_methods else []
+
+    async def __call__(
+        self,
+        make_request: NextRequestMiddlewareType,
+        bot: "Bot",
+        method: TelegramMethod[TelegramObject],
+    ) -> Response[TelegramObject]:
+        if type(method) not in self.ignore_methods:
+            loggers.middlewares.info(
+                "Make request with method=%r by bot id=%d",
+                type(method).__name__,
+                bot.id,
+            )
+        return await make_request(bot, method)

tests/test_api/test_client/test_session/test_base_session.py

@@ -245,14 +245,14 @@ class TestBaseSession:
         flag_after = False
 
         @bot.session.middleware
-        async def my_middleware(b, method, make_request):
+        async def my_middleware(make_request, b, method):
             nonlocal flag_before, flag_after
             flag_before = True
             try:
                 assert isinstance(b, Bot)
                 assert isinstance(method, TelegramMethod)
 
-                return await make_request(bot, method)
+                return await make_request(b, method)
             finally:
                 flag_after = True
 

tests/test_api/test_client/test_session/test_middlewares/test_request_logging.py

@@ -0,0 +1,42 @@
+import datetime
+import logging
+
+import pytest
+
+from aiogram.client.session.middlewares.request_logging import RequestLogging
+from aiogram.methods import GetMe, SendMessage
+from aiogram.types import Chat, Message, User
+from tests.mocked_bot import MockedBot
+
+pytestmark = pytest.mark.asyncio
+
+
+class TestRequestLogging:
+    async def test_use_middleware(self, bot: MockedBot, caplog):
+        caplog.set_level(logging.INFO)
+        bot.session.middleware(RequestLogging())
+
+        bot.add_result_for(GetMe, ok=True, result=User(id=42, is_bot=True, first_name="Test"))
+        assert await bot.get_me()
+        assert "Make request with method='GetMe' by bot id=42" in caplog.text
+
+    async def test_ignore_methods(self, bot: MockedBot, caplog):
+        caplog.set_level(logging.INFO)
+        bot.session.middleware(RequestLogging(ignore_methods=[GetMe]))
+
+        bot.add_result_for(GetMe, ok=True, result=User(id=42, is_bot=True, first_name="Test"))
+        assert await bot.get_me()
+        assert "Make request with method='GetMe' by bot id=42" not in caplog.text
+
+        bot.add_result_for(
+            SendMessage,
+            ok=True,
+            result=Message(
+                message_id=42,
+                date=datetime.datetime.now(),
+                text="test",
+                chat=Chat(id=42, type="private"),
+            ),
+        )
+        assert await bot.send_message(chat_id=1, text="Test")
+        assert "Make request with method='SendMessage' by bot id=42" in caplog.text