[py] Added more internal logging for CDP

[shbenzer]

User description

Python implementation of #14558

Description

Added more logging for cdp in python

Motivation and Context

Issue #14547

Types of changes

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Breaking change (fix or feature that would cause existing functionality to change)

Checklist

• I have read the contributing document.
• My change requires a change to the documentation.
• I have updated the documentation accordingly.
• I have added tests to cover my changes.
• All new and existing tests passed.

---

PR Type

enhancement

---

Description

• Added debug logging to track the sending and receiving of CDP messages in the execute method.
• Logged exceptions raised during the handling of CDP messages to aid in debugging.

---

PRDescriptionHeader.CHANGES_WALKTHROUGH

	Relevant files
Enhancement	cdp.py Add debug logging for CDP message handling                              py/selenium/webdriver/common/bidi/cdp.py Added debug logging for sending and receiving CDP messages. Logged exceptions raised during CDP message handling. +6/-0

---

💡 PR-Agent usage: Comment /help "your question" on any pull request to receive relevant information

[codiumai-pr-agent-pro]

PR Reviewer Guide 🔍

Here are some key observations to aid the review process:

⏱️ Estimated effort to review: 2 🔵🔵⚪⚪⚪

🧪 No relevant tests

🔒 No security concerns identified

⚡ Recommended focus areas for review Performance Concern The added debug logging might impact performance if left enabled in production. Consider using a more efficient logging approach or ensuring it's disabled in production environments.

[codiumai-pr-agent-pro]

PR Code Suggestions ✨

Explore these optional code suggestions:

Category	Suggestion	Score
Best practice	Use a context manager to ensure proper cleanup of resources in case of exceptions Consider using a context manager for the cmd_id to ensure proper cleanup of inflight_cmd in case of exceptions. py/selenium/webdriver/common/bidi/cdp.py [208-213] cmd_id = next(self.cmd_id) cmd_event = asyncio.Event() -self.inflight_cmd[cmd_id] = cmd, cmd_event -request = next(cmd) -request["id"] = cmd_id -if self.session_id: - request["sessionId"] = self.session_id -request_str = json.dumps(request) +with contextlib.ExitStack() as stack: + stack.callback(self.inflight_cmd.pop, cmd_id, None) + self.inflight_cmd[cmd_id] = cmd, cmd_event + request = next(cmd) + request["id"] = cmd_id + if self.session_id: + request["sessionId"] = self.session_id + request_str = json.dumps(request) Apply this suggestion Suggestion importance[1-10]: 8 Why: Using a context manager to ensure proper cleanup of resources is a robust practice that enhances code reliability and maintainability, especially in asynchronous contexts where exceptions might occur.	8
Performance	Consolidate multiple debug logging statements into a single statement to improve performance and readability Consider using a single logging statement with a formatted string instead of multiple conditional checks. This can improve performance and readability. py/selenium/webdriver/common/bidi/cdp.py [214-226] -if logger.isEnabledFor(logging.DEBUG): - logger.debug(f"Sending CDP message: {cmd_id} {cmd_event}: {request_str}") +log_msg = f"Sending CDP message: {cmd_id} {cmd_event}: {request_str}" try: await self.ws.send_message(request_str) except WsConnectionClosed as wcc: raise CdpConnectionClosed(wcc.reason) from None await cmd_event.wait() response = self.inflight_result.pop(cmd_id) -if logger.isEnabledFor(logging.DEBUG): - logger.debug(f"Received CDP message: {response}") +log_msg += f"\nReceived CDP message: {response}" if isinstance(response, Exception): - if logger.isEnabledFor(logging.DEBUG): - logger.debug(f"Exception raised by {cmd_event} message: {type(response).__name__}") + log_msg += f"\nException raised by {cmd_event} message: {type(response).__name__}" +logger.debug(log_msg) if logger.isEnabledFor(logging.DEBUG) else None Apply this suggestion Suggestion importance[1-10]: 5 Why: The suggestion to consolidate logging statements into a single one can improve readability and slightly enhance performance by reducing the number of conditional checks. However, it may reduce clarity by combining unrelated log messages into one.	5

💡 Need additional feedback ? start a PR chat

[shbenzer]

@VietND96 //py:common-chrome-test/selenium/webdriver/common/upload_tests.py passes locally for me, could you run it again? The pr doesn't affect that test, but I figure we might as well be sure.

[shbenzer]

weird - they pass locally for me, and that edge test passed in the last run so it has nothing to do with my code... Wonder if upload_tests.py is having trouble with the ci/cd pipeline.

[shbenzer]

@VietND96 can you see the log files? I can't figure out which test is failing/what the error message is

[VietND96]

Can you see this link? https://gypsum.cluster.engflow.com/invocations/default/6f30e2cd-e307-4fb8-9a44-a77abff4035a#highlights
See console logs of each test

[VietND96]

I'm checking a local run, test passed here. I tried to update the branch one more time to see.

[shbenzer]

Can you see this link? https://gypsum.cluster.engflow.com/invocations/default/6f30e2cd-e307-4fb8-9a44-a77abff4035a#highlights See console logs of each test

I had, but couldn't see how to find the log file - I just figured it out.

So it looks like the upload_tests.py is having these errors:

_________________________ test_can_upload_file[chrome] _________________________
driver = <selenium.webdriver.chrome.webdriver.WebDriver (session="4282a38894728d08ede6aa5133d70dd2")>
pages = <conftest.pages.<locals>.Pages object at 0x7ff41da98a30>
get_local_path = <function get_local_path.<locals>.wrapped at 0x7ff41df11e50>
    def test_can_upload_file(driver, pages, get_local_path):
        pages.load("upload.html")
    
        driver.find_element(By.ID, "upload").send_keys(get_local_path("test_file.txt"))
        driver.find_element(By.ID, "go").click()
        driver.switch_to.frame(driver.find_element(By.ID, "upload_target"))
        body = driver.find_element(By.CSS_SELECTOR, "body").text
    
>       assert "test_file.txt" in body
E       AssertionError: assert 'test_file.txt' in ''
py/test/selenium/webdriver/common/upload_tests.py:44: AssertionError
py/test/selenium/webdriver/common/upload_tests.py::test_can_upload_two_files[chrome] FAILED [ 66%]
______________________ test_can_upload_two_files[chrome] _______________________
driver = <selenium.webdriver.chrome.webdriver.WebDriver (session="d42f152b4f592601b5dfe55acf095a04")>
pages = <conftest.pages.<locals>.Pages object at 0x7ff41df70850>
get_local_path = <function get_local_path.<locals>.wrapped at 0x7ff41df21820>
    def test_can_upload_two_files(driver, pages, get_local_path):
        pages.load("upload.html")
        two_file_paths = get_local_path("test_file.txt") + "\n" + get_local_path("test_file2.txt")
        driver.find_element(By.ID, "upload").send_keys(two_file_paths)
        driver.find_element(By.ID, "go").click()
        driver.switch_to.frame(driver.find_element(By.ID, "upload_target"))
        body = driver.find_element(By.CSS_SELECTOR, "body").text
    
>       assert "test_file.txt" in body
E       AssertionError: assert 'test_file.txt' in ''
py/test/selenium/webdriver/common/upload_tests.py:55: AssertionError

and the edge test got an invalid selector here:

py/test/selenium/webdriver/common/bidi_tests.py::test_collect_log_mutations[edge] FAILED [100%]
_______________________ test_collect_log_mutations[edge] _______________________
driver = <selenium.webdriver.edge.webdriver.WebDriver (session="61ed4e08a3b96e3ba3c893bb59c3a825")>
pages = <conftest.pages.<locals>.Pages object at 0x7f632b28c160>
    @pytest.mark.xfail_firefox
    @pytest.mark.xfail_safari
    @pytest.mark.xfail_remote
    async def test_collect_log_mutations(driver, pages):
        async with driver.bidi_connection() as session:
            log = Log(driver, session)
            async with log.mutation_events() as event:
                pages.load("dynamic.html")
                driver.find_element(By.ID, "reveal").click()
                WebDriverWait(driver, 10).until(
                    lambda d: d.find_element(By.ID, "revealed").value_of_css_property("display") != "none"
                )
>               WebDriverWait(driver, 5).until(EC.visibility_of(driver.find_element(By.ID, "revealed")))
py/test/selenium/webdriver/common/bidi_tests.py:79: 

@VietND96 both of these pass locally, and do not touch the code I added. Do you know what may be causing this? I'm honestly not sure what could be causing the upload error.

[VietND96]

I will merge this, since status is fine

All tests passed but there were other errors during the build.
(14:09:53) INFO: Streaming build results to: https://gypsum.cluster.engflow.com/invocation/28c145cd-3b88-4bf6-a2e1-94917e669af0

[VietND96]

Thank you, @shbenzer !