Tox raises an exception when parsing logs containing the 0x85 character (…)

[franknarf8]

Dear Tox maintainers,

We are using Tox with pipenv, and it currently raises an exception when pipenv writes the … character in the logs. (which is pretty much everywhere). Tox successfully executes though, so for us it is mainly an aesthetic problem, but it might hide other issues.

Sounds like an encoding problem.

Here is a repro repo : https://github.com/franknarf8/tox-issue-repro

(I am encountering this behavior on Windows 10)

here is the output of tox -rvv :

>tox -rvv
using tox.ini: C:\code\test-tox\tox.ini (pid 2816)
  removing C:\code\test-tox\.tox\log
using tox-3.14.3 from c:\python38\lib\site-packages\tox\__init__.py (pid 2816)
py38 start: getenv C:\code\test-tox\.tox\py38
py38 cannot reuse: -r flag
py38 create: C:\code\test-tox\.tox\py38
py38 uses c:\python38\python.exe
  removing C:\code\test-tox\.tox\py38
setting PATH=C:\code\test-tox\.tox\py38\Scripts;C:\Python38\Scripts\;C:\Python38\;C:\PYTHON37\SCRIPTS\;C:\PYTHON37\;C:\USERS\FRANK\.PYENV\PYENV-WIN\BIN;C:\USERS\FRANK\.PYENV\PYENV-WIN\SHIMS;C:\Windows\SYSTEM32;C:\Windows;C:\Windows\SYSTEM32\WBEM;C:\Windows\SYSTEM32\WINDOWSPOWERSHELL\V1.0\;C:\Windows\SYSTEM32\OPENSSH\;C:\PROGRAMDATA\CHOCOLATEY\BIN;C:\PROGRAM FILES\MICROSOFT VS CODE\BIN;C:\PROGRAM FILES (X86)\YARN\BIN\;C:\PROGRAM FILES\GIT\CMD;C:\PROGRAM FILES\GIT\MINGW64\BIN;C:\PROGRAM FILES\GIT\USR\BIN;C:\USERS\FRANK\.BIN;C:\PROGRAM FILES (X86)\SUBVERSION\BIN;C:\PROGRAM FILES\JAVA\JDK-13.0.1\BIN;C:\TEXLIVE\2019\BIN\WIN32;C:\PROGRAM FILES (X86)\INSTALLAWARE\INSTALLAWARE 8;C:\ProgramData\chocolatey\lib\maven\apache-maven-3.6.2\BIN;C:\Program Files\VMware\VMware OVF Tool;C:\Users\Frank\AppData\Local\Microsoft\WindowsApps;C:\Users\Frank\AppData\Local\Yarn\bin
[12148] C:\code\test-tox\.tox$ 'c:\python38\python.exe' -m virtualenv --no-download --python 'c:\python38\python.exe' py38
Already using interpreter c:\python38\python.exe
Using base prefix 'c:\\python38'
New python executable in C:\code\test-tox\.tox\py38\Scripts\python.exe
Installing setuptools, pip, wheel...
done.
py38 installdeps: pipenv
setting PATH=C:\code\test-tox\.tox\py38\Scripts;C:\Python38\Scripts\;C:\Python38\;C:\PYTHON37\SCRIPTS\;C:\PYTHON37\;C:\USERS\FRANK\.PYENV\PYENV-WIN\BIN;C:\USERS\FRANK\.PYENV\PYENV-WIN\SHIMS;C:\Windows\SYSTEM32;C:\Windows;C:\Windows\SYSTEM32\WBEM;C:\Windows\SYSTEM32\WINDOWSPOWERSHELL\V1.0\;C:\Windows\SYSTEM32\OPENSSH\;C:\PROGRAMDATA\CHOCOLATEY\BIN;C:\PROGRAM FILES\MICROSOFT VS CODE\BIN;C:\PROGRAM FILES (X86)\YARN\BIN\;C:\PROGRAM FILES\GIT\CMD;C:\PROGRAM FILES\GIT\MINGW64\BIN;C:\PROGRAM FILES\GIT\USR\BIN;C:\USERS\FRANK\.BIN;C:\PROGRAM FILES (X86)\SUBVERSION\BIN;C:\PROGRAM FILES\JAVA\JDK-13.0.1\BIN;C:\TEXLIVE\2019\BIN\WIN32;C:\PROGRAM FILES (X86)\INSTALLAWARE\INSTALLAWARE 8;C:\ProgramData\chocolatey\lib\maven\apache-maven-3.6.2\BIN;C:\Program Files\VMware\VMware OVF Tool;C:\Users\Frank\AppData\Local\Microsoft\WindowsApps;C:\Users\Frank\AppData\Local\Yarn\bin
[10720] C:\code\test-tox$ 'C:\code\test-tox\.tox\py38\Scripts\python.EXE' -m pip install pipenv
Looking in indexes: https://artifactory.ni.team/artifactory/api/pypi/python/simple
Collecting pipenv
  Using cached https://artifactory.ni.team/artifactory/api/pypi/python/packages/packages/13/b4/3ffa55f77161cff9a5220f162670f7c5eb00df52e00939e203f601b0f579/pipenv-2018.11.26-py3-none-any.whl
Collecting certifi
  Using cached https://artifactory.ni.team/artifactory/api/pypi/python/packages/packages/b9/63/df50cac98ea0d5b006c55a399c3bf1db9da7b5a24de7890bc9cfd5dd9e99/certifi-2019.11.28-py2.py3-none-any.whl
Requirement already satisfied: setuptools>=36.2.1 in c:\code\test-tox\.tox\py38\lib\site-packages (from pipenv) (42.0.2)
Requirement already satisfied: pip>=9.0.1 in c:\code\test-tox\.tox\py38\lib\site-packages (from pipenv) (19.3.1)
Collecting virtualenv-clone>=0.2.5
  Using cached https://artifactory.ni.team/artifactory/api/pypi/python/packages/packages/ba/f8/50c2b7dbc99e05fce5e5b9d9a31f37c988c99acd4e8dedd720b7b8d4011d/virtualenv_clone-0.5.3-py2.py3-none-any.whl
Collecting virtualenv
  Using cached https://artifactory.ni.team/artifactory/api/pypi/python/packages/packages/05/f1/2e07e8ca50e047b9cc9ad56cf4291f4e041fa73207d000a095fe478abf84/virtualenv-16.7.9-py2.py3-none-any.whl
Installing collected packages: certifi, virtualenv-clone, virtualenv, pipenv
Successfully installed certifi-2019.11.28 pipenv-2018.11.26 virtualenv-16.7.9 virtualenv-clone-0.5.3
WARNING: You are using pip version 19.3.1; however, version 20.0.1 is available.
You should consider upgrading via the 'python -m pip install --upgrade pip' command.
py38 finish: getenv C:\code\test-tox\.tox\py38 after 36.42 seconds
py38 start: finishvenv
write config to C:\code\test-tox\.tox\py38\.tox-config1 as '926dd6c2c8c5bffea13c030a417d87576cb6bda7b346c24f5a3cf2e4a8fbc46e c:\\python38\\python.exe\n3.14.3 0 0 0\n00000000000000000000000000000000 pipenv'
py38 finish: finishvenv  after 0.01 seconds
py38 start: envreport
setting PATH=C:\code\test-tox\.tox\py38\Scripts;C:\Python38\Scripts\;C:\Python38\;C:\PYTHON37\SCRIPTS\;C:\PYTHON37\;C:\USERS\FRANK\.PYENV\PYENV-WIN\BIN;C:\USERS\FRANK\.PYENV\PYENV-WIN\SHIMS;C:\Windows\SYSTEM32;C:\Windows;C:\Windows\SYSTEM32\WBEM;C:\Windows\SYSTEM32\WINDOWSPOWERSHELL\V1.0\;C:\Windows\SYSTEM32\OPENSSH\;C:\PROGRAMDATA\CHOCOLATEY\BIN;C:\PROGRAM FILES\MICROSOFT VS CODE\BIN;C:\PROGRAM FILES (X86)\YARN\BIN\;C:\PROGRAM FILES\GIT\CMD;C:\PROGRAM FILES\GIT\MINGW64\BIN;C:\PROGRAM FILES\GIT\USR\BIN;C:\USERS\FRANK\.BIN;C:\PROGRAM FILES (X86)\SUBVERSION\BIN;C:\PROGRAM FILES\JAVA\JDK-13.0.1\BIN;C:\TEXLIVE\2019\BIN\WIN32;C:\PROGRAM FILES (X86)\INSTALLAWARE\INSTALLAWARE 8;C:\ProgramData\chocolatey\lib\maven\apache-maven-3.6.2\BIN;C:\Program Files\VMware\VMware OVF Tool;C:\Users\Frank\AppData\Local\Microsoft\WindowsApps;C:\Users\Frank\AppData\Local\Yarn\bin
[12992] C:\code\test-tox$ 'C:\code\test-tox\.tox\py38\Scripts\python.EXE' -m pip freeze >.tox\py38\log\py38-0.log
___________________________________________________________________________________________ summary ____________________________________________________________________________________________
  py38: commands succeeded
  congratulations :)
Traceback (most recent call last):
  File "c:\python38\lib\runpy.py", line 193, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "c:\python38\lib\runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "C:\Python38\Scripts\tox.exe\__main__.py", line 9, in <module>
  File "c:\python38\lib\site-packages\tox\session\__init__.py", line 44, in cmdline
    main(args)
  File "c:\python38\lib\site-packages\tox\session\__init__.py", line 68, in main
    exit_code = session.runcommand()
  File "c:\python38\lib\site-packages\tox\session\__init__.py", line 192, in runcommand
    return self.subcommand_test()
  File "c:\python38\lib\site-packages\tox\session\__init__.py", line 220, in subcommand_test
    run_sequential(self.config, self.venv_dict)
  File "c:\python38\lib\site-packages\tox\session\commands\run\sequential.py", line 20, in run_sequential
    runenvreport(venv, config)
  File "c:\python38\lib\site-packages\tox\session\commands\run\sequential.py", line 60, in runenvreport
    packages = config.pluginmanager.hook.tox_runenvreport(venv=venv, action=action)
  File "c:\python38\lib\site-packages\pluggy\hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "c:\python38\lib\site-packages\pluggy\manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "c:\python38\lib\site-packages\pluggy\manager.py", line 84, in <lambda>
    self._inner_hookexec = lambda hook, methods, kwargs: hook.multicall(
  File "c:\python38\lib\site-packages\pluggy\callers.py", line 208, in _multicall
    return outcome.get_result()
  File "c:\python38\lib\site-packages\pluggy\callers.py", line 80, in get_result
    raise ex[1].with_traceback(ex[2])
  File "c:\python38\lib\site-packages\pluggy\callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "c:\python38\lib\site-packages\tox\venv.py", line 782, in tox_runenvreport
    output = venv._pcall(args, cwd=venv.envconfig.config.toxinidir, action=action, returnout=True)
  File "c:\python38\lib\site-packages\tox\venv.py", line 567, in _pcall
    return action.popen(
  File "c:\python38\lib\site-packages\tox\action.py", line 107, in popen
    lines = out_path.w("UTF-8").split("\n")
AttributeError: 'LocalPath' object has no attribute 'w'

Have fun debugging this and thank you for maintaining this awesome tool!

• Frank

[asottile]

I can't reproduce, the line in that stacktrace doesn't exist at the latest version:

tox/src/tox/action.py

Line 107 in 1b8f302

lines = out_path.read_text("UTF-8").split("\n")

(notice yours says out_path.w(...) and the actual code says out_path.read_text(...))

I suspect you've corrupted your installation of tox (perhaps through some errant IDE-based refactor?) and should reinstall

[franknarf8]

Mmm, true, I can't even reproduce it;
Sorry for the false positive :S

[franknarf8]

Oh actually, I broke the tox installation while debugging it, but there was indeed a problem, the stacktrace I initially wrote was wrong.

With the repro repo, you should see the error using the parallel flag : tox -p auto
Here's the stacktrace :

tox -p auto
✔ OK py38 in 10.328 seconds
Exception in thread Thread-3:
Traceback (most recent call last):
  File "c:\python38\lib\threading.py", line 932, in _bootstrap_inner
    self.run()
  File "c:\python38\lib\threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "c:\python38\lib\site-packages\tox\session\commands\run\parallel.py", line 56, in run_in_thread
    output = action.popen(
  File "c:\python38\lib\site-packages\tox\action.py", line 107, in popen
    lines = out_path.read_text("UTF-8").split("\n")
  File "c:\python38\lib\site-packages\py\_path\common.py", line 171, in read_text
    return f.read()
  File "c:\python38\lib\codecs.py", line 322, in decode
    (result, consumed) = self._buffer_decode(data, self.errors, final)
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x85 in position 833: invalid start byte
_______________________________________________________ summary _______________________________________________________
  py38: commands succeeded
  congratulations :)

[asottile]

I still can't reproduce, though I suspect it's because you're on windows (and perhaps have locale misconfigured?) -- can you try setting LANG=C.UTF-8

the root cause is the underlying thing (I believe in this case pipenv?) is printing cp1252 code points:

>>> b'\x85'.decode('cp1252')
'…'

it should be producing the UTF-8 sequence ('\xe2\x80\xa6')

[franknarf8]

I've tried setting my locale; both outside and within tox, but pipenv keeps printing 0x85 instead of its utf-8 equivalent...

I can confirm that this is definitely a Windows problem; I can't reproduce it on either Linux nor Mac.

It might be a pipenv problem, but I thought this might be tox related since there are no errors when I run tox in sequential mode (tox), only when I run tox in parallel (tox -p auto).

[asottile]

hmm that is an interesting point, didn't realize this was different parallel vs not -- I guess if we're handling this properly serially we should fix parallel -- thanks for the issue and we can dig into the root cause 👍