feat: Make timeout error log cleaner

src/crawlee/crawlers/_basic/_basic_crawler.py

@@ -3,10 +3,12 @@
 
 import asyncio
 import logging
+import re
 import signal
 import sys
 import tempfile
 import threading
+import traceback
 from asyncio import CancelledError
 from collections.abc import AsyncGenerator, Awaitable, Iterable, Sequence
 from contextlib import AsyncExitStack, suppress
@@ -54,7 +56,6 @@
 from ._context_pipeline import ContextPipeline
 
 if TYPE_CHECKING:
-    import re
     from contextlib import AbstractAsyncContextManager
 
     from crawlee._types import ConcurrencySettings, HttpMethod, JsonSerializable
@@ -211,6 +212,7 @@ class BasicCrawler(Generic[TCrawlingContext, TStatisticsState]):
     """
 
     _CRAWLEE_STATE_KEY = 'CRAWLEE_STATE'
+    _request_handler_timeout_text = 'Request handler timed out after'
 
     def __init__(
         self,
@@ -945,7 +947,8 @@ async def _handle_request_error(self, context: TCrawlingContext | BasicCrawlingC
             context.session.mark_bad()
 
     async def _handle_failed_request(self, context: TCrawlingContext | BasicCrawlingContext, error: Exception) -> None:
-        self._logger.exception('Request failed and reached maximum retries', exc_info=error)
+        error_message = self._get_message_from_error(error)
+        self._logger.error(f'Request failed and reached maximum retries\n {error_message}')
         await self._statistics.error_tracker.add(error=error, context=context)
 
         if self._failed_request_handler:
@@ -954,6 +957,40 @@ async def _handle_failed_request(self, context: TCrawlingContext | BasicCrawling
             except Exception as e:
                 raise UserDefinedErrorHandlerError('Exception thrown in user-defined failed request handler') from e
 
+    def _get_message_from_error(self, error: Exception) -> str:
+        """Get error message summary from exception.
+
+        Custom processing to reduce the irrelevant traceback clutter in some cases.
+        """
+        full_error_lines = traceback.format_exception(type(error), value=error, tb=error.__traceback__, chain=True)
+
+        if (
+            isinstance(error, asyncio.exceptions.TimeoutError)
+            and self._request_handler_timeout_text in full_error_lines[-1]
+        ):
+            # Get only innermost error
+            inner_error = self._get_only_inner_most_exception(error)
+            filtered_error_lines = traceback.format_exception(
+                type(inner_error), value=inner_error, tb=inner_error.__traceback__, chain=True
+            )
+
+            # Remove asyncio internal stack trace lines.
+            asyncio_pattern = r'[\\/]{1}asyncio[\\/]{1}'
+            filtered_error_lines = [line for line in filtered_error_lines if not re.findall(asyncio_pattern, line)]
+            filtered_error_lines.append(full_error_lines[-1])
+            return '\n'.join(filtered_error_lines)
+
+        return '\n'.join(full_error_lines)
+
+    def _get_only_inner_most_exception(self, error: BaseException) -> BaseException:
+        """Get innermost exception by following __cause__ and __context__ attributes of exception."""
+        if error.__cause__:
+            return self._get_only_inner_most_exception(error.__cause__)
+        if error.__context__:
+            return self._get_only_inner_most_exception(error.__context__)
+        # No __cause__ and no __context__, this is as deep as it can get.
+        return error
+
     def _prepare_send_request_function(
         self,
         session: Session | None,
@@ -1209,7 +1246,8 @@ async def _run_request_handler(self, context: BasicCrawlingContext) -> None:
         await wait_for(
             lambda: self._context_pipeline(context, self.router),
             timeout=self._request_handler_timeout,
-            timeout_message=f'Request handler timed out after {self._request_handler_timeout.total_seconds()} seconds',
+            timeout_message=f'{self._request_handler_timeout_text}'
+            f' {self._request_handler_timeout.total_seconds()} seconds',
             logger=self._logger,
         )
 

tests/unit/crawlers/_basic/test_basic_crawler.py

@@ -1291,3 +1291,25 @@ async def error_req_hook(context: BasicCrawlingContext, error: Exception) -> Non
     await crawler.run(requests)
 
     assert error_handler_mock.call_count == 1
+
+
+async def test_reduced_logs_from_timed_out_request_handler(
+    monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture
+) -> None:
+    caplog.set_level(logging.INFO)
+    crawler = BasicCrawler(configure_logging=False, request_handler_timeout=timedelta(seconds=1))
+
+    @crawler.router.default_handler
+    async def handler(context: BasicCrawlingContext) -> None:
+        await asyncio.sleep(10)  # Some very custom comment
+
+    await crawler.run([Request.from_url('http://a.com/')])
+
+    for record in caplog.records:
+        if record.funcName == '_handle_failed_request':
+            full_message = (record.message or '') + (record.exc_text or '')
+            assert Counter(full_message)['\n'] < 20
+            assert '# Some very custom comment' in full_message
+            break
+    else:
+        raise AssertionError('Expected log message about request handler error was not found.')