Traceback from Selenium driver printed twice

[osuzdalev]

@Delgan Hi!

First off thank you for the wonderful lib!

I am working on a telegram bot that uses Selenium. Everytime an error is raised, it is first printed in the terminal window beautifully as intended:

[2023-12-21 11:52:27] [ERROR] [app.something | somefunction() | line 152] Phone login failed: Message: invalid argument: invalid locator
  (Session info: chrome=120.0.6099.109)
Stacktrace:
0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780
1   chromedriver                        0x0000000104fa0664 chromedriver + 4130404
2   chromedriver                        0x0000000104bf7bc0 chromedriver + 293824
3   chromedriver                        0x0000000104c3dc50 chromedriver + 580688
4   chromedriver                        0x0000000104c7dab0 chromedriver + 842416
5   chromedriver                        0x0000000104c316bc chromedriver + 530108
6   chromedriver                        0x0000000104c32930 chromedriver + 534832
7   chromedriver                        0x0000000104f6de08 chromedriver + 3923464
8   chromedriver                        0x0000000104f723dc chromedriver + 3941340
9   chromedriver                        0x0000000104f56038 chromedriver + 3825720
10  chromedriver                        0x0000000104f72f3c chromedriver + 3944252
11  chromedriver                        0x0000000104f486f4 chromedriver + 3770100
12  chromedriver                        0x0000000104f8f980 chromedriver + 4061568
13  chromedriver                        0x0000000104f8faf8 chromedriver + 4061944
14  chromedriver                        0x0000000104fa02e4 chromedriver + 4129508
15  libsystem_pthread.dylib             0x000000018b8d5034 _pthread_start + 136
16  libsystem_pthread.dylib             0x000000018b8cfe3c thread_start + 8

Traceback (most recent call last):

  File "Some/path/common/action_decorator.py", line 19, in command_func
    return await func(self, update, context, *args, **kwargs)
                 │    │     │       │         │       └ {}
                 │    │     │       │         └ ()
                 │    │     │       └ <telegram.ext._callbackcontext.CallbackContext object at 0x105aa0890>
                 │    │     └ Update(message=Message(channel_chat_created=False, chat=Chat(first_name='Oleg', id=178716280, last_name='Suzdalev', type=<Cha...
                 │    └ <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>
                 └ <function Tinder.some_functions at 0x10609a280>

> File "Some/path/web/dating_platform/tinder/tinder.py", line 148, in some_functions
    if await self.discover_element(By.ID, "MODAL_LOGIN"):
             │    │                │  └ 'id'
             │    │                └ <class 'selenium.webdriver.common.by.By'>
             │    └ <function Platform.discover_element at 0x1060a68b0>
             └ <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>

  File "Some/path/web/dating_platform/dating_platform.py", line 112, in discover_element
    return await loop.run_in_executor(
                 │    └ <function BaseEventLoop.run_in_executor at 0x104810430>
                 └ <_UnixSelectorEventLoop running=True closed=False debug=False>

  File "/opt/homebrew/Cellar/python@3.9/3.9.17/Frameworks/Python.framework/Versions/3.9/lib/python3.9/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             │        │            └ None
             │        └ None
             └ None

  File "Some/path/web/dating_platform/dating_platform.py", line 114, in <lambda>
    lambda: WebDriverWait(self.driver, timeout).until(
            │             │    │       └ 5
            │             │    └ <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>
            │             └ <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>
            └ <class 'selenium.webdriver.support.wait.WebDriverWait'>

  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/wait.py", line 92, in until
    value = method(self._driver)
            │      │    └ <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>
            │      └ <selenium.webdriver.support.wait.WebDriverWait (session="883fdd7ae3913bcf503e901a90cef732")>
            └ <function presence_of_element_located.<locals>._predicate at 0x104d53820>
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/expected_conditions.py", line 80, in _predicate
    return driver.find_element(*locator)
           │      │             └ ('MODAL_LOGIN', 'id')
           │      └ <function WebDriver.find_element at 0x104df7c10>
           └ <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 740, in find_element
    return self.execute(Command.FIND_ELEMENT, {"using": by, "value": value})["value"]
           │    │       │       │                       │            └ 'id'
           │    │       │       │                       └ 'MODAL_LOGIN'
           │    │       │       └ 'findElement'
           │    │       └ <class 'selenium.webdriver.remote.command.Command'>
           │    └ <function WebDriver.execute at 0x104df39d0>
           └ <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 346, in execute
    self.error_handler.check_response(response)
    │    │             │              └ {'status': 400, 'value': '{"value":{"error":"invalid argument","message":"invalid argument: invalid locator\\n  (Session info...
    │    │             └ <function ErrorHandler.check_response at 0x104dab040>
    │    └ <selenium.webdriver.remote.errorhandler.ErrorHandler object at 0x105b331c0>
    └ <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/errorhandler.py", line 229, in check_response
    raise exception_class(message, screen, stacktrace)
          │               │        │       └ ['0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780', '1   chromedriver                      ...
          │               │        └ None
          │               └ 'invalid argument: invalid locator\n  (Session info: chrome=120.0.6099.109)'
          └ <class 'selenium.common.exceptions.InvalidArgumentException'>

selenium.common.exceptions.InvalidArgumentException: Message: invalid argument: invalid locator
  (Session info: chrome=120.0.6099.109)
Stacktrace:
0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780
1   chromedriver                        0x0000000104fa0664 chromedriver + 4130404
2   chromedriver                        0x0000000104bf7bc0 chromedriver + 293824
3   chromedriver                        0x0000000104c3dc50 chromedriver + 580688
4   chromedriver                        0x0000000104c7dab0 chromedriver + 842416
5   chromedriver                        0x0000000104c316bc chromedriver + 530108
6   chromedriver                        0x0000000104c32930 chromedriver + 534832
7   chromedriver                        0x0000000104f6de08 chromedriver + 3923464
8   chromedriver                        0x0000000104f723dc chromedriver + 3941340
9   chromedriver                        0x0000000104f56038 chromedriver + 3825720
10  chromedriver                        0x0000000104f72f3c chromedriver + 3944252
11  chromedriver                        0x0000000104f486f4 chromedriver + 3770100
12  chromedriver                        0x0000000104f8f980 chromedriver + 4061568
13  chromedriver                        0x0000000104f8faf8 chromedriver + 4061944
14  chromedriver                        0x0000000104fa02e4 chromedriver + 4129508
15  libsystem_pthread.dylib             0x000000018b8d5034 _pthread_start + 136
16  libsystem_pthread.dylib             0x000000018b8cfe3c thread_start + 8

But it is then followed by this right after:

--- Logging error ---
Traceback (most recent call last):
  File "Some/path/web/dating_platform/tinder/tinder.py", line 148, in some_functions
    if await self.discover_element(By.ID, "MODAL_LOGIN"):
  File "Some/path/web/dating_platform/dating_platform.py", line 112, in discover_element
    return await loop.run_in_executor(
  File "/opt/homebrew/Cellar/python@3.9/3.9.17/Frameworks/Python.framework/Versions/3.9/lib/python3.9/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "Some/path/web/dating_platform/dating_platform.py", line 114, in <lambda>
    lambda: WebDriverWait(self.driver, timeout).until(
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/wait.py", line 92, in until
    value = method(self._driver)
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/expected_conditions.py", line 80, in _predicate
    return driver.find_element(*locator)
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 740, in find_element
    return self.execute(Command.FIND_ELEMENT, {"using": by, "value": value})["value"]
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 346, in execute
    self.error_handler.check_response(response)
  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/errorhandler.py", line 229, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.InvalidArgumentException: Message: invalid argument: invalid locator
  (Session info: chrome=120.0.6099.109)
Stacktrace:
0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780
1   chromedriver                        0x0000000104fa0664 chromedriver + 4130404
2   chromedriver                        0x0000000104bf7bc0 chromedriver + 293824
3   chromedriver                        0x0000000104c3dc50 chromedriver + 580688
4   chromedriver                        0x0000000104c7dab0 chromedriver + 842416
5   chromedriver                        0x0000000104c316bc chromedriver + 530108
6   chromedriver                        0x0000000104c32930 chromedriver + 534832
7   chromedriver                        0x0000000104f6de08 chromedriver + 3923464
8   chromedriver                        0x0000000104f723dc chromedriver + 3941340
9   chromedriver                        0x0000000104f56038 chromedriver + 3825720
10  chromedriver                        0x0000000104f72f3c chromedriver + 3944252
11  chromedriver                        0x0000000104f486f4 chromedriver + 3770100
12  chromedriver                        0x0000000104f8f980 chromedriver + 4061568
13  chromedriver                        0x0000000104f8faf8 chromedriver + 4061944
14  chromedriver                        0x0000000104fa02e4 chromedriver + 4129508
15  libsystem_pthread.dylib             0x000000018b8d5034 _pthread_start + 136
16  libsystem_pthread.dylib             0x000000018b8cfe3c thread_start + 8

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "Some/path/venv/lib/python3.9/site-packages/notifiers/logging.py", line 50, in emit
    self.provider.notify(raise_on_errors=True, **data)
  File "Some/path/venv/lib/python3.9/site-packages/notifiers/core.py", line 303, in notify
    data = self._process_data(**kwargs)
  File "Some/path/venv/lib/python3.9/site-packages/notifiers/core.py", line 235, in _process_data
    self._validate_data(data)
  File "Some/path/venv/lib/python3.9/site-packages/notifiers/core.py", line 208, in _validate_data
    raise BadArguments(validation_error=msg, provider=self.name, data=data)
notifiers.exceptions.BadArguments: Error with sent data: SecretStr('**********') is not valid under any of the given schemas
Call stack:
  File "Some/path/common/action_decorator.py", line 19, in command_func
    return await func(self, update, context, *args, **kwargs)
  File "Some/path/web/dating_platform/tinder/tinder.py", line 152, in some_functions
    logger.exception(f"Phone login failed: {e}")
  File "Some/path/venv/lib/python3.9/site-packages/loguru/_logger.py", line 2065, in exception
    __self._log("ERROR", False, options, __message, args, kwargs)
  File "Some/path/venv/lib/python3.9/site-packages/loguru/_logger.py", line 2032, in _log
    handler.emit(log_record, level_id, from_decorator, raw, colored_message)
  File "Some/path/venv/lib/python3.9/site-packages/loguru/_handler.py", line 206, in emit
    self._sink.write(str_record)
  File "Some/path/venv/lib/python3.9/site-packages/loguru/_simple_sinks.py", line 51, in write
    self._handler.handle(record)
  File "/opt/homebrew/Cellar/python@3.9/3.9.17/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 952, in handle
    self.emit(record)
  File "Some/path/venv/lib/python3.9/site-packages/notifiers/logging.py", line 52, in emit
    self.handleError(record)
Message: '2023-12-21 11:52:27.835 | ERROR    | app.something:some_functions:152 - Phone login failed: Message: invalid argument: invalid locator\n  (Session info: chrome=120.0.6099.109)\nStacktrace:\n0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780\n1   chromedriver                        0x0000000104fa0664 chromedriver + 4130404\n2   chromedriver                        0x0000000104bf7bc0 chromedriver + 293824\n3   chromedriver                        0x0000000104c3dc50 chromedriver + 580688\n4   chromedriver                        0x0000000104c7dab0 chromedriver + 842416\n5   chromedriver                        0x0000000104c316bc chromedriver + 530108\n6   chromedriver                        0x0000000104c32930 chromedriver + 534832\n7   chromedriver                        0x0000000104f6de08 chromedriver + 3923464\n8   chromedriver                        0x0000000104f723dc chromedriver + 3941340\n9   chromedriver                        0x0000000104f56038 chromedriver + 3825720\n10  chromedriver                        0x0000000104f72f3c chromedriver + 3944252\n11  chromedriver                        0x0000000104f486f4 chromedriver + 3770100\n12  chromedriver                        0x0000000104f8f980 chromedriver + 4061568\n13  chromedriver                        0x0000000104f8faf8 chromedriver + 4061944\n14  chromedriver                        0x0000000104fa02e4 chromedriver + 4129508\n15  libsystem_pthread.dylib             0x000000018b8d5034 _pthread_start + 136\n16  libsystem_pthread.dylib             0x000000018b8cfe3c thread_start + 8\n\nTraceback (most recent call last):\n\n  File "Some/path/common/action_decorator.py", line 19, in command_func\n    return await func(self, update, context, *args, **kwargs)\n                 |    |     |       |         |       -> {}\n                 |    |     |       |         -> ()\n                 |    |     |       -> <telegram.ext._callbackcontext.CallbackContext object at 0x105aa0890>\n                 |    |     -> Update(message=Message(channel_chat_created=False, chat=Chat(first_name=\'Oleg\', id=178716280, last_name=\'Suzdalev\', type=<Cha...\n                 |    -> <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>\n                 -> <function Tinder.some_functions at 0x10609a280>\n\n> File "Some/path/web/dating_platform/tinder/tinder.py", line 148, in some_functions\n    if await self.discover_element(By.ID, "MODAL_LOGIN"):\n             |    |                |  -> \'id\'\n             |    |                -> <class \'selenium.webdriver.common.by.By\'>\n             |    -> <function Platform.discover_element at 0x1060a68b0>\n             -> <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>\n\n  File "Some/path/web/dating_platform/dating_platform.py", line 112, in discover_element\n    return await loop.run_in_executor(\n                 |    -> <function BaseEventLoop.run_in_executor at 0x104810430>\n                 -> <_UnixSelectorEventLoop running=True closed=False debug=False>\n\n  File "/opt/homebrew/Cellar/python@3.9/3.9.17/Frameworks/Python.framework/Versions/3.9/lib/python3.9/concurrent/futures/thread.py", line 58, in run\n    result = self.fn(*self.args, **self.kwargs)\n             |        |            -> None\n             |        -> None\n             -> None\n\n  File "Some/path/web/dating_platform/dating_platform.py", line 114, in <lambda>\n    lambda: WebDriverWait(self.driver, timeout).until(\n            |             |    |       -> 5\n            |             |    -> <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>\n            |             -> <app.autoswiper.web.dating_platform.tinder.tinder.Tinder object at 0x105acb2e0>\n            -> <class \'selenium.webdriver.support.wait.WebDriverWait\'>\n\n  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/wait.py", line 92, in until\n    value = method(self._driver)\n            |      |    -> <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>\n            |      -> <selenium.webdriver.support.wait.WebDriverWait (session="883fdd7ae3913bcf503e901a90cef732")>\n            -> <function presence_of_element_located.<locals>._predicate at 0x104d53820>\n  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/support/expected_conditions.py", line 80, in _predicate\n    return driver.find_element(*locator)\n           |      |             -> (\'MODAL_LOGIN\', \'id\')\n           |      -> <function WebDriver.find_element at 0x104df7c10>\n           -> <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>\n  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 740, in find_element\n    return self.execute(Command.FIND_ELEMENT, {"using": by, "value": value})["value"]\n           |    |       |       |                       |            -> \'id\'\n           |    |       |       |                       -> \'MODAL_LOGIN\'\n           |    |       |       -> \'findElement\'\n           |    |       -> <class \'selenium.webdriver.remote.command.Command\'>\n           |    -> <function WebDriver.execute at 0x104df39d0>\n           -> <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>\n  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/webdriver.py", line 346, in execute\n    self.error_handler.check_response(response)\n    |    |             |              -> {\'status\': 400, \'value\': \'{"value":{"error":"invalid argument","message":"invalid argument: invalid locator\\\\n  (Session info...\n    |    |             -> <function ErrorHandler.check_response at 0x104dab040>\n    |    -> <selenium.webdriver.remote.errorhandler.ErrorHandler object at 0x105b331c0>\n    -> <selenium.webdriver.chrome.webdriver.WebDriver (session="883fdd7ae3913bcf503e901a90cef732")>\n  File "Some/path/venv/lib/python3.9/site-packages/selenium/webdriver/remote/errorhandler.py", line 229, in check_response\n    raise exception_class(message, screen, stacktrace)\n          |               |        |       -> [\'0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780\', \'1   chromedriver                      ...\n          |               |        -> None\n          |               -> \'invalid argument: invalid locator\\n  (Session info: chrome=120.0.6099.109)\'\n          -> <class \'selenium.common.exceptions.InvalidArgumentException\'>\n\nselenium.common.exceptions.InvalidArgumentException: Message: invalid argument: invalid locator\n  (Session info: chrome=120.0.6099.109)\nStacktrace:\n0   chromedriver                        0x0000000104fa84dc chromedriver + 4162780\n1   chromedriver                        0x0000000104fa0664 chromedriver + 4130404\n2   chromedriver                        0x0000000104bf7bc0 chromedriver + 293824\n3   chromedriver                        0x0000000104c3dc50 chromedriver + 580688\n4   chromedriver                        0x0000000104c7dab0 chromedriver + 842416\n5   chromedriver                        0x0000000104c316bc chromedriver + 530108\n6   chromedriver                        0x0000000104c32930 chromedriver + 534832\n7   chromedriver                        0x0000000104f6de08 chromedriver + 3923464\n8   chromedriver                        0x0000000104f723dc chromedriver + 3941340\n9   chromedriver                        0x0000000104f56038 chromedriver + 3825720\n10  chromedriver                        0x0000000104f72f3c chromedriver + 3944252\n11  chromedriver                        0x0000000104f486f4 chromedriver + 3770100\n12  chromedriver                        0x0000000104f8f980 chromedriver + 4061568\n13  chromedriver                        0x0000000104f8faf8 chromedriver + 4061944\n14  chromedriver                        0x0000000104fa02e4 chromedriver + 4129508\n15  libsystem_pthread.dylib             0x000000018b8d5034 _pthread_start + 136\n16  libsystem_pthread.dylib             0x000000018b8cfe3c thread_start + 8\n\n'
Arguments: ()

What's confusing is that in the log file only the correct version is written...

Here is how I setup my logging:

def setup_logging(log_level: str, log_file: str, pushover_defaults: Dict):
    """
    Configures and sets up the logging for the application.

    - Removes any existing logger configurations.
    - Sets color codes for various logging levels.
    - Adds stdout as a logger output with a specified format and log level.

    Attributes Utilized:
        log_level: The level of logging to capture (e.g., DEBUG, INFO).

    Note:
        This method relies on the logger from an external library, and uses its methods
        for configuring the logging behavior.
    """
    logger.remove()

    logger.level("DEBUG", color="<cyan>")
    logger.level("INFO", color="<blue>")
    logger.level("SUCCESS", color="<green>")
    logger.level("WARNING", color="<yellow>")
    logger.level("ERROR", color="<red>")
    logger.level("CRITICAL", color="<RED><bg #f8bbd0>")

    # Initialize the standard logging
    logging.basicConfig(
        format="[%(asctime)s] [%(levelname)s] [%(name)s | %(funcName)s() | line %(lineno)d] %(levelname)s - %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S",
        level=log_level,
        handlers=[InterceptHandler()],
    )
    # Remove the standard error logging to avoid repeated messages
    error_logger = logger.add(sys.stderr)
    logger.remove(error_logger)
    # Logger to get the messages from the Telegram API
    logger.add(
        sys.stdout,
        level=f"{log_level}",
        colorize=True,
        format=LOGGING_FORMAT,
    )
    # Remove the standard error logging to avoid repeated messages
    error_logger = logger.add(sys.stderr)
    logger.remove(error_logger)

    # Loguru file logger
    logger.add(
        log_file,
        level=f"{log_level}",
        colorize=False,
        serialize=False,
        format=LOGGING_FORMAT,
    )

    # Set up Selenium logging to pass through the standard logging
    selenium_logger.setLevel(log_level)
    selenium_logger.error()
    for handler in logging.root.handlers:
        selenium_logger.addHandler(handler)

    pushover_handler = NotificationHandler("pushover", defaults=pushover_defaults)
    logger.add(pushover_handler, level="ERROR")

    logger.debug("Loguru setup done")

Thanks a lot in advance!

[osuzdalev]

These are the culprits for sure. When removed it prints properly in the terminal:

# Set up Selenium logging to pass through the standard logging
    selenium_logger.setLevel(log_level)
    selenium_logger.error()
    for handler in logging.root.handlers:
        selenium_logger.addHandler(handler)

    pushover_handler = NotificationHandler("pushover", defaults=pushover_defaults)
    logger.add(pushover_handler, level="ERROR")

I also removed the unnecessary

# Remove the standard error logging to avoid repeated messages
    error_logger = logger.add(sys.stderr)
    logger.remove(error_logger)

[Delgan]

Hi @osuzdalev.

The "--- Logging error ---" header indicates that an unexpected error happened while a message was logged by one of your configured handler. This is not directly related to the "Phone login failed" error you're reporting, it's just that the faulty handler is your pushover_handler, and it's configured with level="ERROR" therefore the two stack traces appear at the same time.

Based on what you shared, it seems to be a problem with the way you configured pushover:

notifiers.exceptions.BadArguments: Error with sent data: SecretStr('**********') is not valid under any of the given schemas

Something is likely wrong in your pushover_default config, or this is a bug in the notifiers library.

See documentation: https://notifiers.readthedocs.io/en/latest/providers/pushover.html.

[osuzdalev]

@Delgan Thanks a lot for your help!