Percentages don't align correctly

[ghost]

This is a really petty issue, so please excuse it. I know it isn't overly important compared to most issues here.

The percentages for execution logging do not align when there is a large number of tests being run. This leads to the lines of . overflowing to the next line, which makes the graph become difficult to read.

I have had a poke around in the code, but I do not feel comfortable trying to fix this without more time to understand what the code is doing, unfortunately.

Thanks for taking the time to look into this, greatly appreciated, we rely on Pytest heavily in our project! 👍

This was for the following raw output:

............................................................................................ [  3%]
............................................................................................ [  6%]
............................................................................................ [  9%]
............................................................................................ [ 13%]
............................................................................................ [ 16%]
............................................................................................ [ 19%]
............................................................................................ [ 23%]
............................................................................................ [ 26%]
............................................................................................ [ 29%]
............................................................................................ [ 33%]
............................................................................................ [ 36%]
............................................................................................ [ 39%]
............................................................................................ [ 43%]
............................................................................................. [ 46%]
............................................................................................. [ 49%]
............................................................................................ [ 53%]
............................................................................................ [ 56%]
............................................................................................ [ 59%]
............................................................................................ [ 63%]
............................................................................................. [ 66%]
............................................................................................. [ 69%]
............................................................................................ [ 73%]
............................................................................................. [ 76%]
............................................................................................ [ 79%]
............................................................................................ [ 83%]
............................................................................................ [ 86%]
............................................................................................ [ 89%]
............................................................................................ [ 93%]
............................................................................................ [ 96%]
............................................................................................ [ 99%]
....                                                                                         [100%]
Coverage.py warning: No data was collected. (no-data-collected)

...for a total of 2,769 test cases, which leads me to think this is possibly a simple rounding issue somewhere.

Typeface: Jetbrains mono, but can repro on Droid Sans Mono and Fira Code Retina as well. The raw output suggests it isn't an issue with fonts but an issue with the number of . being printed -- I haven't bothered counting every single one yet. Can reproduce this on multiple terminals, such as the ones embedded in VSCode and IntelliJ IDEA.

[ghost]

EDIT: forgot the most important info you probably need.

This is pytest version 5.4.1, imported from /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest/__init__.py
setuptools registered plugins:
  pytest-metadata-1.8.0 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_metadata/plugin.py
  pytest-asyncio-0.12.0 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_asyncio/plugin.py
  pytest-html-2.1.1 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_html/plugin.py
  pytest-forked-1.1.3 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_forked/__init__.py
  pytest-xdist-1.32.0 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/xdist/plugin.py
  pytest-xdist-1.32.0 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/xdist/looponfail.py
  pytest-cov-2.8.1 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_cov/plugin.py
  pytest-randomly-3.3.1 at /home/nekokatt/code/hikari/.venv/lib/python3.8/site-packages/pytest_randomly.py

CPython 3.8.2 (GCC), Manjaro Linux.

[bluetech]

I think I have seen this a few times as well.

Does it happen every time, or only some times?

If it happens every time, a reproduction would be helpful.

[nicoddemus]

I've seen this as well with xdist.

It seems random unfortunately, I've seen it happen, and then running the same test suite again without changing anything, for the problem to disappear.

I suspect it is related to terminal character counting in py somehow.

[ghost]

@bluetech it happens every time, but not on our CI: https://gitlab.com/nekokatt/hikari/-/jobs/539198398

I can try and find time to put one together, but it might not be for a few days.

I suspect it is related to terminal character counting in py somehow.

could it be a thread-safety/multiprocessing-safety issue somewhere?

This just made me realise our CI runs a single xdist runner... so this supports that hypothesis as to why it seems to only occur on xdist :)

[asottile]

I believe this is an xdist-specific issue, I've only seen it when using that -- should we move this issue to there?

[RonnyPfannschmidt]

i suspect we may have a off by one error in case more than one test is in flight, which would be actually a core issue

[bluetech]

If I had to guess why this happens, it'd be that xdist issues e.g. the following sequence:

• pytest_runtest_logreport (of worker 1)
• pytest_runtest_logreport (of worker 2)
• pytest_runtest_logfinish (of worker 1)
• pytest_runtest_logfinish (of worker 2)

The way pytest works, it prints the . on pytest_runtest_logreport, but only prints the \n (if reached the edge of the terminal) on pytest_runtest_logfinish.

I haven't verified this, maybe xdist does synchronize the runtest protocol between items and it's something else anyway.

[Eduard-gan]

I wonder if this percentage feature can be completely disabled?
I just run into the case where it was handy to me to see just raw output of one heavily parametrized test to see the test matrix. And the test name and percentage peretty much ruined the whole output making me to copy the output and apply some replacements on it manually so it can look little bit more alligned and understanable.

Thanks!

[The-Compiler]

I wonder if this percentage feature can be completely disabled?

See the console_output_style config option

[bluetech]

I confirmed that the cause is as described in my previous comment #7166 (comment).

Possible solutions I can think of:

Solution 1: Change pytest-xdist to not intermix hook calls for different item's runtestprotocol hooks.
I didn't assess this, seems desirable in some respects (probably there are other plugins which get confused by this), but probably has some ill effects as well, with respect to "lying" about the ordering and delaying.

Solution 2: change pytest to not have this split printing between logreport and logfinish. So either: do everything in logfinish, but then printing the . is delayed waiting for teardown; or do everything in logreport, but then we print 100% and then seem "stuck" waiting for possibly-lengthy session teardown (instead of the 100% not showing until teardown is complete).

Solution 3: always display the progress at the end of the line (updated on each .), not just when reaching the end of the line, then there is no question of when to show it. The TerminalReporter/TerminalWriter are currently "append only" and not really built for this as far as I can see, so will need some reworking.

I'm thinking the 2nd solution with moving the progress reporting to logreport + a special case for the 100%.