python 3.11 pytest-reportportal hijacks the fullpath in pytest log output on linux

[fenchu]

python 3.11 pytest-reportportal==5.1.2

On linux the fullpaths always use: rp_logging.py inside pytest testing. We use pyenv in linux and venv in windows:

20221107070310.530|INFO|/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/pytest_reportportal/rp_logging.py:29|phone-registration-url:https://www.hso.XXX.YYY.ZZZ/user-portal/phone
20221107070311.765|INFO|/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/pytest_reportportal/rp_logging.py:29|are we logged in
20221107070313.373|ERROR|/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/pytest_reportportal/rp_logging.py:29|error:Message: no such element: Unable to locate element: {"method":"xpath","selector":"//*[@id='username-authenticator'] | //bp-button[@text='Username']"}

But on windows it is fine. (It is the same code/same requirements.txt but it runs in linux-container in our CI system (gitlabCI):

20221107094827.924|INFO|C:\dist\work\hso-fullstack-test\tests\test_10_phone_registration_en.py:93|phone-registration-url:https://www.hso.XXX.YYY.ZZZ/user-portal/phone
20221107094829.371|INFO|C:\dist\work\hso-fullstack-test\tests\test_10_phone_registration_en.py:105|are we logged in
20221107094849.709|ERROR|C:\dist\work\hso-fullstack-test\tests\test_10_phone_registration_en.py:309|error:Message: no such element:  Unable to locate element: {"method":"xpath","selector":"//*[@id='username-authenticator'] | //bp-button[@text='Username']"}

All was fine before I upgraded to python 3.11, probably a update to logging.py

[fenchu]

This is the rp_logging.py finction that returns wrong:

    try:
        def wrap_log(original_func):
            @wraps(original_func)
            def _log(self, *args, **kwargs):
                attachment = kwargs.pop('attachment', None)
                if attachment is not None:
                    kwargs.setdefault('extra', {}).update(
                        {'attachment': attachment})
                return original_func(self, *args, **kwargs)

[fenchu]

Here is an errorstack, I catually have no idea where it happened, since rp has hijacked the stack (I believe it is a session timeout for selenium)

20221116143720|WARNING|Report Portal None request failed
Traceback (most recent call last):
  File "/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/reportportal_client/core/rp_requests.py", line 73, in make
    return RPResponse(self.session_method(
                      ^^^^^^^^^^^^^^^^^^^^
  File "/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/requests/sessions.py", line 635, in post
    return self.request("POST", url, data=data, json=json, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/requests/sessions.py", line 577, in request
    settings = self.merge_environment_settings(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/requests/sessions.py", line 759, in merge_environment_settings
    env_proxies = get_environ_proxies(url, no_proxy=no_proxy)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/root/.pyenv/versions/3.11.0/envs/base/lib/python3.11/site-packages/requests/utils.py", line 828, in get_environ_proxies
    return getproxies()
           ^^^^^^^^^^^^
  File "/root/.pyenv/versions/3.11.0/lib/python3.11/urllib/request.py", line 2505, in getproxies_environment
    for name, value in os.environ.items():
  File "<frozen _collections_abc>", line 861, in __iter__
  File "<frozen os>", line 678, in __getitem__
KeyError: 'PYTEST_CURRENT_TEST'
tests/test_07_keyregistration_en.py::TestClass::test01_frontend[test12] 

[HardNorth]

@fenchu So for python 2.7 - 3.10 everything works correctly, and for 3.11 we suddenly started "hijack" something. No way. Unless someone point me to the code I rather believe this is Python's core library bug.

[dagansandler]

@HardNorth sorry for bumping this old issue. I can open a new one on the client repo if you think it'll be more suitable.

I'm seeing some strange behavior with python 3.11 as well, and it may indeed be a result of some change in core python, but one that may require a fix in the RP client nevertheless.

Please see this issue on cpython for reference: https://github.com/python/cpython/issues/97941

What I'm seeing on reportportal client is that this line is now being returned as the caller: https://github.com/reportportal/client-Python/blob/bd50b91f55f9d8dd9ea0dab649e207562ab3a843/reportportal_client/logs/__init__.py#L65

This is probably a result of the change in cpython, which could potentially explain the "hijacking" described in this ticket too.

WDYT?

[dagansandler]

Actually, found the exact bug in the client and have a test + fix for it, will open a PR soon.