Skip to content

Fix flaky durations test #4144

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Oct 14, 2018

Conversation

nicoddemus
Copy link
Member

Unfortunately due to fluctuations in runtime "test_something"
might still appear in the final message.

Example failure:

https://ci.appveyor.com/project/pytestbot/pytest/builds/19494829/job/8lx847u0c78m63wf

Unfortunately due to fluctuations in runtime "test_something"
might still appear in the final message.

Example failure:

https://ci.appveyor.com/project/pytestbot/pytest/builds/19494829/job/8lx847u0c78m63wf
@blueyed
Copy link
Contributor

blueyed commented Oct 14, 2018

Why is that? I mean, how does it appear there then? Is it taking a little bit long enough?

Wouldn't/shouldn't the next assertion then also fail?
I mean that the msg should only be shown if anything was hidden (but have not checked the code).

@nicoddemus
Copy link
Member Author

nicoddemus commented Oct 14, 2018

Here's the output from the failing test:

========================== slowest 10 test durations ==========================
0.03s call     test_calls.py::test_3
0.02s call     test_calls.py::test_2
0.02s call     test_calls.py::test_1
0.02s teardown test_calls.py::test_something

(0.00 durations hidden.  Use -vv to show these durations.)
========================== 4 passed in 0.09 seconds ===========================

Why is that? I mean, how does it appear there then? Is it taking a little bit long enough?

Yep, it seems that due to fluctuations on CI time sometimes test_something setup, call, or teardown might take more than 0.01s. I've seen this just yesterday as well during "setup" of test_something. So we really cannot rely on that, I'm afraid.

In theory all calls might take more than 0.01s and the "durations hidden" message won't appear (and the test will fail), but let's see that happen first before also removing that check (or hacking around it).

@coveralls
Copy link

coveralls commented Oct 14, 2018

Coverage Status

Coverage increased (+0.2%) to 94.04% when pulling 4808145 on nicoddemus:fix-flaky-durations-test into c6c326f on pytest-dev:master.

@blueyed
Copy link
Contributor

blueyed commented Oct 14, 2018

Looks like there is another flaky one?!
https://travis-ci.org/pytest-dev/pytest/jobs/441305926#L545

E       Failed: nomatch: '* 1 passed in *'
E           and: u'============================= test session starts =============================='
E           and: u'platform linux2 -- Python 2.7.6, pytest-3.8.3.dev69+g7ea1efd, py-1.7.0, pluggy-0.7.1'
E           and: u"hypothesis profile 'default' -> database=DirectoryBasedExampleDatabase('/home/travis/build/pytest-dev/pytest/.hypothesis/examples')"
E           and: u'rootdir: /tmp/pytest-of-travis/pytest-0/popen-gw37/test_request_garbage0, inifile:'
E           and: u'plugins: xdist-1.23.2, forked-0.2, hypothesis-3.76.0'
E           and: u'collected 1 item'
E           and: u''
E           and: u'test_request_garbage.py .E                                               [100%]'
E           and: u''
E           and: u'==================================== ERRORS ===================================='
E           and: u'________________________ ERROR at teardown of test_func ________________________'
E           and: u''
E           and: u"request = <SubRequest 'something' for <Function 'test_func'>>"
E           and: u''
E           and: u'    @pytest.fixture(autouse=True)'
E           and: u'    def something(request):'
E           and: u'        original = gc.get_debug()'
E           and: u'        gc.set_debug(gc.DEBUG_SAVEALL)'
E           and: u'        gc.collect()'
E           and: u'    '
E           and: u'        yield'
E           and: u'    '
E           and: u'        try:'
E           and: u'            gc.collect()'
E           and: u'            leaked_types = sum(1 for _ in gc.garbage'
E           and: u'                               if isinstance(_, PseudoFixtureDef))'
E           and: u'    '
E           and: u'            # debug leaked types if the test fails'
E           and: u'            print(leaked_types)'
E           and: u'    '
E           and: u'            gc.garbage[:] = []'
E           and: u'    '
E           and: u'>           assert leaked_types == 0'
E           and: u'E           assert 2 == 0'
E           and: u''
E           and: u'test_request_garbage.py:24: AssertionError'
E           and: u'--------------------------- Captured stdout teardown ---------------------------'
E           and: u'2'
E           and: u'====================== 1 passed, 1 error in 4.12 seconds ======================='
E           and: u''
E       remains unmatched: '* 1 passed in *'
…
FAIL testing/python/fixture.py::TestRequestBasic::()::test_request_garbage

@nicoddemus
Copy link
Member Author

Yeah, that one fails sometimes when running in xdist...

I will skip that test when we are running under xdist then. 👍

@codecov
Copy link

codecov bot commented Oct 14, 2018

Codecov Report

Merging #4144 into master will increase coverage by 0.45%.
The diff coverage is n/a.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #4144      +/-   ##
==========================================
+ Coverage   94.48%   94.94%   +0.45%     
==========================================
  Files         109      109              
  Lines       23824    23823       -1     
  Branches     2352     2352              
==========================================
+ Hits        22511    22619     +108     
+ Misses       1004      906      -98     
+ Partials      309      298      -11
Flag Coverage Δ
#linux 94.94% <ø> (+0.6%) ⬆️
#nobyte 47.35% <ø> (+47.35%) ⬆️
#numpy 28.07% <ø> (-0.01%) ⬇️
#pexpect 25.12% <ø> (+25.12%) ⬆️
#py27 93.19% <ø> (+0.52%) ⬆️
#py34 92.24% <ø> (+0.11%) ⬆️
#py35 92.25% <ø> (+0.11%) ⬆️
#py36 93.17% <ø> (+0.47%) ⬆️
#py37 92.41% <ø> (+0.07%) ⬆️
#trial 31.15% <ø> (-0.16%) ⬇️
#windows ?
#xdist 93.66% <ø> (+75.13%) ⬆️
Impacted Files Coverage Δ
testing/acceptance_test.py 97.59% <ø> (-0.23%) ⬇️
testing/test_paths.py 86.36% <0%> (-13.64%) ⬇️
src/_pytest/paths.py 91.3% <0%> (-8.7%) ⬇️
testing/test_tmpdir.py 95.06% <0%> (-4.94%) ⬇️
src/_pytest/nodes.py 93.69% <0%> (-0.85%) ⬇️
src/_pytest/pytester.py 85.71% <0%> (-0.31%) ⬇️
testing/test_capture.py 98.94% <0%> (-0.31%) ⬇️
src/_pytest/fixtures.py 97.02% <0%> (-0.28%) ⬇️
src/_pytest/capture.py 90.16% <0%> (+0.22%) ⬆️
... and 11 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update c6c326f...4808145. Read the comment docs.

@nicoddemus nicoddemus merged commit 49defa2 into pytest-dev:master Oct 14, 2018
@nicoddemus nicoddemus deleted the fix-flaky-durations-test branch October 14, 2018 21:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants