Skip to content

TestStdCaptureFD tests failing with "4 FD leackage detected" (sic; s/leackage/leakage/) #492

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

Closed
pytestbot opened this issue Mar 28, 2014 · 12 comments
Labels
type: bug problem that needs to be addressed

Comments

@pytestbot
Copy link
Contributor

Originally reported by: Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo)


I am periodically seeing failures due to file descriptor leakage in both builds on Drone.io (e.g.: https://drone.io/bitbucket.org/msabramo/pytest/6) and locally using tox:

From https://drone.io/bitbucket.org/msabramo/pytest/6:

==================================== ERRORS ====================================
 ERROR at teardown of TestStdCaptureFD.test_capturing_readouterr_decode_error_handling 

item = <Function 'test_capturing_readouterr_decode_error_handling'>
__multicall__ = <MultiCall 0 results, 0 meths, kwargs={'nextitem': <Function 'test_reset_twice_error'>, 'item': <Function 'test_capturing_readouterr_decode_error_handling'>}>

    def pytest_runtest_teardown(item, __multicall__):
        item.config._basedir.chdir()
        if hasattr(item.config, '_numfiles'):
            x = __multicall__.execute()
>           check_open_files(item.config)

conftest.py:50: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

config = <_pytest.config.Config object at 0x7f9230096290>

    def check_open_files(config):
        out2 = py.process.cmdexec("lsof -p %d" % pid)
        lines2 = getopenfiles(out2)
        if len(lines2) > config._numfiles + 3:
            error = []
            error.append("***** %s FD leackage detected" %
        (len(lines2)-config._numfiles))
            error.extend(lines2)
            error.append(error[0])
            # update numfile so that the overall test run continuess
            config._numfiles = len(lines2)
>           raise AssertionError("\n".join(error))
E           AssertionError: ***** 4 FD leackage detected
E           py.test 1283 ubuntu    0r   CHR    1,3      0t0  1445164 /dev/null
E           py.test 1283 ubuntu    8r   REG  253,0        3     3929 /tmp/pytest-0/testdir/test_writeorg0/test_writeorg.py
E           py.test 1283 ubuntu    9r   CHR    1,3      0t0  1445164 /dev/null
E           py.test 1283 ubuntu   11r   CHR    1,3      0t0  1445164 /dev/null
E           ***** 4 FD leackage detected

conftest.py:44: AssertionError

From a local tox run:

==================================================================================== ERRORS ====================================================================================
_______________________________________________________ ERROR at teardown of TestStdCaptureFD.test_capturing_done_simple _______________________________________________________

item = <Function 'test_capturing_done_simple'>
__multicall__ = <MultiCall 0 results, 0 meths, kwargs={'item': <Function 'test_capturing_done_simple'>, 'nextitem': <Function 'test_capturing_reset_simple'>}>

    def pytest_runtest_teardown(item, __multicall__):
        item.config._basedir.chdir()
        if hasattr(item.config, '_numfiles'):
            x = __multicall__.execute()
>           check_open_files(item.config)

conftest.py:50:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

config = <_pytest.config.Config object at 0x1013c4350>

    def check_open_files(config):
        out2 = py.process.cmdexec("lsof -p %d" % pid)
        lines2 = getopenfiles(out2)
        if len(lines2) > config._numfiles + 3:
            error = []
            error.append("***** %s FD leackage detected" %
        (len(lines2)-config._numfiles))
            error.extend(lines2)
            error.append(error[0])
            # update numfile so that the overall test run continuess
            config._numfiles = len(lines2)
>           raise AssertionError("\n".join(error))
E           AssertionError: ***** 4 FD leackage detected
E           python3.3 99001 marca    0r    CHR                3,2        0t0      305 /dev/null
E           python3.3 99001 marca    1u    REG                1,2          0 29288704 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpn1zy1r
E           python3.3 99001 marca    2u    REG                1,2          0 29288705 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp1ho8lz
E           python3.3 99001 marca    3w    REG                1,2       3681 29266158 /Users/marca/dev/hg-repos/pytest/.tox/py26/log/py26-0.log
E           python3.3 99001 marca    6w    REG                1,2       3819 29276170 /Users/marca/dev/hg-repos/pytest/.tox/py27/log/py27-0.log
E           python3.3 99001 marca    7w    REG                1,2       3841 29286174 /Users/marca/dev/hg-repos/pytest/.tox/py33/log/py33-0.log
E           python3.3 99001 marca    8u    CHR               16,3 0t11092970      811 /dev/ttys003
E           python3.3 99001 marca    9u    REG                1,2          0 29288704 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpn1zy1r
E           python3.3 99001 marca   10u    REG                1,2          0 29288705 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp1ho8lz
E           python3.3 99001 marca   11u    CHR               16,3 0t11092970      811 /dev/ttys003
E           python3.3 99001 marca   12u    CHR               16,3 0t11092970      811 /dev/ttys003
E           python3.3 99001 marca   13u    REG                1,2          3 29290273 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/pytest-205/testdir/test_writeorg0/test_writeorg.py
E           python3.3 99001 marca   14r    CHR                3,2        0t0      305 /dev/null
E           python3.3 99001 marca   15u    REG                1,2          0 29288704 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpn1zy1r
E           python3.3 99001 marca   17u    REG                1,2          0 29288705 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp1ho8lz
E           ***** 4 FD leackage detected

conftest.py:44: AssertionError

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Pull request #135 fixes the typo: "leack" => "leak".

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Now that we have an issue for the leaks, I wonder if the tests should be marked as xfail?

I like it when I'm working on a change and tox is all green. :-)

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Pull request to fix the "leackage" typo: https://bitbucket.org/hpk42/pytest/pull-request/135/fix-typo-fd-leackage-fd-leakage/diff

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Random idea: Pull out of pytest the logic for detecting file descriptor leaks and make it into a py.test plugin so that it can be used by other projects. Sort of like drippy (https://launchpad.net/drippy) for nose.

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Note: the most interesting leak in the output above is this one:

E           py.test 1283 ubuntu    8r   REG  253,0        3     3929 /tmp/pytest-0/testdir/test_writeorg0/test_writeorg.py

It appears to be a link of a temp file in test_writeorg.

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Pull request #136 may or may not fix the test_writeorg leak.

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Here's something interesting. If running only a subset of the tests, this problem may or may not show up. Here's how things look.

$ tox -e py27 -- testing/test_capture.py -k test_writeorg
...
(No leak)
$ tox -e py27 -- testing/test_capture.py -k test_capturing_done_simple
...
(No leak)
$ tox -e py27 -- testing/test_capture.py -k 'test_writeorg or test_capturing_done_simple'
...
config = <_pytest.config.Config object at 0x1006d8890>

    def check_open_files(config):
        out2 = py.process.cmdexec("lsof -p %d" % pid)
        lines2 = getopenfiles(out2)
        if len(lines2) > config._numfiles + 3:
            error = []
            error.append("***** %s FD leackage detected" %
        (len(lines2)-config._numfiles))
            error.extend(lines2)
            error.append(error[0])
            # update numfile so that the overall test run continuess
            config._numfiles = len(lines2)
>           raise AssertionError("\n".join(error))
E           AssertionError: ***** 4 FD leackage detected
E           python  25420 marca    0r    CHR                3,2       0t0      305 /dev/null
E           python  25420 marca    1u    REG                1,2         0 29733688 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp6INeWL
E           python  25420 marca    2u    REG                1,2         0 29733689 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpZFA6xh
E           python  25420 marca    5u    CHR               16,2  0t260510      835 /dev/ttys002
E           python  25420 marca    6u    REG                1,2         0 29733688 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp6INeWL
E           python  25420 marca    7u    REG                1,2         0 29733689 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpZFA6xh
E           python  25420 marca    8u    CHR               16,2  0t260510      835 /dev/ttys002
E           python  25420 marca    9u    CHR               16,2  0t260510      835 /dev/ttys002
E           python  25420 marca   10u    REG                1,2         3 29733698 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/pytest-40/testdir/test_writeorg0/test_writeorg.py
E           python  25420 marca   11r    CHR                3,2       0t0      305 /dev/null
E           python  25420 marca   12u    REG                1,2         0 29733688 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmp6INeWL
E           python  25420 marca   14u    REG                1,2         0 29733689 /private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/tmpZFA6xh
E           ***** 4 FD leackage detected

conftest.py:44: AssertionError

Interesting that it only happens if those two tests are run together.

  • test_writeorg
  • test_capturing_done_simple

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


Pull request #137 changes the fd leak detection to use psutil instead of lsof and it results in cleaner, more focused output that should aid in debugging this issue and future fd leak issues.

E           AssertionError: ***** 1 FD leackage detected
E           popenfile(path='/private/var/folders/gw/w0clrs515zx9x_55zgtpv4mm0000gp/T/pytest-44/testdir/test_writeorg0/test_writeorg.py', fd=10)
E           ***** 1 FD leackage detected

conftest.py:43: AssertionError

Note how this points out clearly that the issue here is:

  • filename: test_writeorg.py
  • fd: 10

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


pull request #139 appears to fix the leak of test_writeorg.py (file descriptor 10).

@pytestbot
Copy link
Contributor Author

Original comment by Marc Abramowitz (BitBucket: msabramo, GitHub: msabramo):


pull request #140 appears to fix a leak in test_capturing_readouterr_decode_error_handling

@pytestbot
Copy link
Contributor Author

Original comment by holger krekel (BitBucket: hpk42, GitHub: hpk42):


fix issue492: avoid leak in test_writeorg. Thanks Marc Abramowitz.

@pytestbot
Copy link
Contributor Author

Original comment by holger krekel (BitBucket: hpk42, GitHub: hpk42):


fix issue492: avoid leak in test_writeorg

@pytestbot pytestbot added the type: bug problem that needs to be addressed label Jun 15, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug problem that needs to be addressed
Projects
None yet
Development

No branches or pull requests

1 participant