pytest-dev/pytest-github-actions-annotate-failures

Missing annotations

amezin opened this issue · 14 comments

Sometimes annotation commands are "not working"

Example: https://github.com/ddterm/gnome-shell-extension-ddterm/actions/runs/5654874022/job/15318855551#step:13:950

There are only 2 annotations for the entire workflow - so it shouldn't be ignored because of limits.

@amezin can you confirm if the annotations are actually printed by running

export GITHUB_ACTIONS=true
<the command you use to run your tests>

locally.

I see you're using tox and setting passenv, so the problem may be the paths generated by the plugin do not match the repo structure.

the problem may be the paths generated by the plugin do not match the repo structure.

But another failure of the same test (just with different parameters) generated an annotation.

Also, I've had issues with mismatching paths once - but annotations were still generated.

When I look at raw logs I see some escape sequences preceding ::error:

2023-07-25T09:18:36.0566564Z �[39m�[31m::error file=test_extension.py,line=1066::TestWaylandHighDpi.test_unmaximize[ghcr.io/ddterm/gnome-shell-pod/archlinux:2023.07.25.0-1.0-maximize-early-bottom-monitor_config0]%0A%0AAssertionError: assert Rect(x=0, y=148, width=1920, height=762) == Rect(x=0, y=64, width=1920, height=1016)%0A  %0A  Matching attributes:%0A  ['x', 'width']%0A  Differing attributes:%0A  ['y', 'height']%0A  %0A  Drill down into differing attribute y:%0A    y: 148 != 64%0A  %0A  Drill down into differing attribute height:%0A    height: 762 != 1016%0A  Full diff:%0A  - Rect(x=0, y=64, width=1920, height=1016)%0A  ?             ^                      ^^^%0A  + Rect(x=0, y=148, width=1920, height=762)%0A  ?             ^ +                     ^ +

Could it be a race condition? (pytest-xdist is in use)

Maybe pytest_runtest_makereport is executed in the worker process, not in the main process. And terminal reporter runs in the main process. And their output gets mixed without synchronization.

TerminalReporter prints its output in pytest_runtest_logreport: https://github.com/pytest-dev/pytest/blob/main/src/_pytest/terminal.py#L567

Maybe it's a more appropriate hook?

xdist calls pytest_runtest_logreport in the main process: https://github.com/pytest-dev/pytest-xdist/blob/6f0cb26fc090bbaec3a6d32ad4d3a3bb3464b84a/src/xdist/dsession.py#L283 (and also implements it in workers - to send reports to the main process).

pytest_runtest_makereport is intended for generating per-test report data, and pytest_runtest_logreport is for processing (in this case - printing) the data.

https://pytest-xdist.readthedocs.io/en/latest/how-it-works.html#how-it-works (see item 8)

I see that the plugin was using pytest_runtest_logreport, but then switched to pytest_runtest_makereport in 9264fb4

@henryiii what was the reason?

It was part of #14, which cleaned up several things, based on pytest docs & examples. It might have been because there was an issue getting the correct line number or something like that (I don't remember exactly), but if you'd like to try using pytest_runtest_logreport, as long as it doesn't break the output, I'd be supportive.

Hmm I can actually see annotations using version v0.2.0 of this package:
Screenshot 2023-07-30 at 19 25 52

@edgarrmondragon I don't understand you comment.

The issue is about

Sometimes annotation commands are "not working"

Sometimes. Sometimes there are annotations for all failures. Sometimes some annotations are missing.

Also it looks like you have to use xdist to reproduce the issue.

@amezin Any updates on this. Apparently the current version of the plugin does not work. Yes, like most I am using xdist. I was not able to see any ::error text in raw output either.

I also raised #81 as this would be a first step that would need sorting before the others.

PS. I can help with review/merges.

Looks like somewhere (probably in a 7.x release) the line numbers started getting messed up. PyTest 6.x reports line 11 in our test suite, but pytest 7.* reports line 1168.

Looks like somewhere (probably in a 7.x release) the line numbers started getting messed up. PyTest 6.x reports line 11 in our test suite, but pytest 7.* reports line 1168.

@henryiii fwiw I narrowed it down to 7.4.0

Ah, thanks! I was trying but I think there's a bug in the new uv run:

$ uv venv
$ uv pip install -e .
$ uv pip install 'pytest==7.0.*'
$ uv run pytest
warning: `uv run` is experimental and may change without warning.
Resolved 5 packages in 8ms
   Built pytest-github-actions-annotate-failures @ file:///Users/henryschreiner/git/software/pytest-github-actions-annotate-failures                                                                    Downloaded 1 package in 1.25s
Installed 2 packages in 33ms
 - pytest==7.0.1
 + pytest==8.2.0
 - pytest-github-actions-annotate-failures==0.2.0 (from file:///Users/henryschreiner/git/software/pytest-github-actions-annotate-failures)
 + pytest-github-actions-annotate-failures==0.2.0 (from file:///Users/henryschreiner/git/software/pytest-github-actions-annotate-failures)
$ uv pip install 'pytest==6.*'
Resolved 7 packages in 145ms
Downloaded 2 packages in 68ms
Installed 2 packages in 6ms
 - pytest==7.0.1
 - pytest==8.2.0
 + pytest==6.2.5
 + toml==0.10.2

I hadn't noticed it upgrade pytest. And then there are two!

I believe ExceptionRepr now has a subclass ExceptionChainRepr.

FYI, this bug only hits some errors (chained ones?). Only one in our test suite. It causes unrealistic numbers which cause the annotation to not show up. “Some annotations disappear due to incorrect line numbers” for PyTest 7.4+ might be a better way to describe it.

I think we just need a corrected line number calculation for the chained case on 7.4+. Won’t have much time till after PyCON though.

I think this was fixed in #97.