fix(tracing): apiName calculation for route handlers (microsoft#1409)

test: clean up tracing tests

playwright/_impl/_connection.py

@@ -50,7 +50,7 @@ async def send_return_as_dict(self, method: str, params: Dict = None) -> Any:
         )
 
     def send_no_reply(self, method: str, params: Dict = None) -> None:
-        self._connection.wrap_api_call(
+        self._connection.wrap_api_call_sync(
             lambda: self._connection._send_message_to_server(
                 self._guid, method, {} if params is None else params
             )
@@ -355,26 +355,35 @@ def _replace_guids_with_channels(self, payload: Any) -> Any:
             return result
         return payload
 
-    def wrap_api_call(self, cb: Callable[[], Any], is_internal: bool = False) -> Any:
+    async def wrap_api_call(
+        self, cb: Callable[[], Any], is_internal: bool = False
+    ) -> Any:
         if self._api_zone.get():
-            return cb()
+            return await cb()
         task = asyncio.current_task(self._loop)
         st: List[inspect.FrameInfo] = getattr(task, "__pw_stack__", inspect.stack())
         metadata = _extract_metadata_from_stack(st, is_internal)
         if metadata:
             self._api_zone.set(metadata)
-        result = cb()
-
-        async def _() -> None:
-            try:
-                return await result
-            finally:
-                self._api_zone.set(None)
+        try:
+            return await cb()
+        finally:
+            self._api_zone.set(None)
 
-        if asyncio.iscoroutine(result):
-            return _()
-        self._api_zone.set(None)
-        return result
+    def wrap_api_call_sync(
+        self, cb: Callable[[], Any], is_internal: bool = False
+    ) -> Any:
+        if self._api_zone.get():
+            return cb()
+        task = asyncio.current_task(self._loop)
+        st: List[inspect.FrameInfo] = getattr(task, "__pw_stack__", inspect.stack())
+        metadata = _extract_metadata_from_stack(st, is_internal)
+        if metadata:
+            self._api_zone.set(metadata)
+        try:
+            return cb()
+        finally:
+            self._api_zone.set(None)
 
 
 def from_channel(channel: Channel) -> Any:
@@ -388,6 +397,12 @@ def from_nullable_channel(channel: Optional[Channel]) -> Optional[Any]:
 def _extract_metadata_from_stack(
     st: List[inspect.FrameInfo], is_internal: bool
 ) -> Optional[Dict]:
+    if is_internal:
+        return {
+            "apiName": "",
+            "stack": [],
+            "internal": True,
+        }
     playwright_module_path = str(Path(playwright.__file__).parents[0])
     last_internal_api_name = ""
     api_name = ""
@@ -419,6 +434,5 @@ def _extract_metadata_from_stack(
         return {
             "apiName": api_name,
             "stack": stack,
-            "isInternal": is_internal,
         }
     return None

playwright/_impl/_network.py

@@ -14,6 +14,7 @@
 
 import asyncio
 import base64
+import inspect
 import json
 import mimetypes
 from collections import defaultdict
@@ -343,11 +344,14 @@ async def continue_route() -> None:
                     params["headers"] = serialize_headers(params["headers"])
                 if post_data_for_wire is not None:
                     params["postData"] = post_data_for_wire
-                await self._race_with_page_close(
-                    self._channel.send(
-                        "continue",
-                        params,
-                    )
+                await self._connection.wrap_api_call(
+                    lambda: self._race_with_page_close(
+                        self._channel.send(
+                            "continue",
+                            params,
+                        )
+                    ),
+                    is_internal,
                 )
             except Exception as e:
                 if not is_internal:
@@ -369,6 +373,14 @@ async def _race_with_page_close(self, future: Coroutine) -> None:
             # Note that page could be missing when routing popup's initial request that
             # does not have a Page initialized just yet.
             fut = asyncio.create_task(future)
+            # Rewrite the user's stack to the new task which runs in the background.
+            setattr(
+                fut,
+                "__pw_stack__",
+                getattr(
+                    asyncio.current_task(self._loop), "__pw_stack__", inspect.stack()
+                ),
+            )
             await asyncio.wait(
                 [fut, page._closed_or_crashed_future],
                 return_when=asyncio.FIRST_COMPLETED,

playwright/_impl/_wait_helper.py

@@ -48,7 +48,7 @@ def _wait_for_event_info_before(self, wait_id: str, event: str) -> None:
         )
 
     def _wait_for_event_info_after(self, wait_id: str, error: Exception = None) -> None:
-        self._channel._connection.wrap_api_call(
+        self._channel._connection.wrap_api_call_sync(
             lambda: self._channel.send_no_reply(
                 "waitForEventInfo",
                 {
@@ -127,7 +127,7 @@ def result(self) -> asyncio.Future:
     def log(self, message: str) -> None:
         self._logs.append(message)
         try:
-            self._channel._connection.wrap_api_call(
+            self._channel._connection.wrap_api_call_sync(
                 lambda: self._channel.send_no_reply(
                     "waitForEventInfo",
                     {

tests/async/test_tracing.py

@@ -89,8 +89,13 @@ async def test_should_collect_trace_with_resources_but_no_js(
     await page.mouse.dblclick(30, 30)
     await page.keyboard.insert_text("abc")
     await page.wait_for_timeout(2000)  # Give it some time to produce screenshots.
-    await page.route("**/empty.html", lambda route: route.continue_())
+    await page.route(
+        "**/empty.html", lambda route: route.continue_()
+    )  # should produce a route.continue_ entry.
     await page.goto(server.EMPTY_PAGE)
+    await page.goto(
+        server.PREFIX + "/one-style.html"
+    )  # should not produce a route.continue_ entry since we continue all routes if no match.
     await page.close()
     trace_file_path = tmpdir / "trace.zip"
     await context.tracing.stop(path=trace_file_path)
@@ -107,8 +112,8 @@ async def test_should_collect_trace_with_resources_but_no_js(
         "Page.wait_for_timeout",
         "Page.route",
         "Page.goto",
-        # FIXME: https://github.com/microsoft/playwright-python/issues/1397
-        "Channel.send",
+        "Route.continue_",
+        "Page.goto",
         "Page.close",
         "Tracing.stop",
     ]
@@ -215,7 +220,13 @@ def parse_trace(path: Path) -> Tuple[Dict[str, bytes], List[Any]]:
 
 def get_actions(events: List[Any]) -> List[str]:
     action_events = sorted(
-        list(filter(lambda e: e["type"] == "action", events)),
+        list(
+            filter(
+                lambda e: e["type"] == "action"
+                and e["metadata"].get("internal", False) is False,
+                events,
+            )
+        ),
         key=lambda e: e["metadata"]["startTime"],
     )
     return [e["metadata"]["apiName"] for e in action_events]

tests/sync/test_tracing.py

@@ -89,8 +89,13 @@ def test_should_collect_trace_with_resources_but_no_js(
     page.mouse.dblclick(30, 30)
     page.keyboard.insert_text("abc")
     page.wait_for_timeout(2000)  # Give it some time to produce screenshots.
-    page.route("**/empty.html", lambda route: route.continue_())
+    page.route(
+        "**/empty.html", lambda route: route.continue_()
+    )  # should produce a route.continue_ entry.
     page.goto(server.EMPTY_PAGE)
+    page.goto(
+        server.PREFIX + "/one-style.html"
+    )  # should not produce a route.continue_ entry since we continue all routes if no match.
     page.close()
     trace_file_path = tmpdir / "trace.zip"
     context.tracing.stop(path=trace_file_path)
@@ -107,8 +112,8 @@ def test_should_collect_trace_with_resources_but_no_js(
         "Page.wait_for_timeout",
         "Page.route",
         "Page.goto",
-        # FIXME: https://github.com/microsoft/playwright-python/issues/1397
-        "Channel.send",
+        "Route.continue_",
+        "Page.goto",
         "Page.close",
         "Tracing.stop",
     ]
@@ -215,7 +220,13 @@ def parse_trace(path: Path) -> Tuple[Dict[str, bytes], List[Any]]:
 
 def get_actions(events: List[Any]) -> List[str]:
     action_events = sorted(
-        list(filter(lambda e: e["type"] == "action", events)),
+        list(
+            filter(
+                lambda e: e["type"] == "action"
+                and e["metadata"].get("internal", False) is False,
+                events,
+            )
+        ),
         key=lambda e: e["metadata"]["startTime"],
     )
     return [e["metadata"]["apiName"] for e in action_events]