Skip to content

ValueError: I/O operation on closed file #14

Closed
Closed
ValueError: I/O operation on closed file#14
Labels
type: bugproblem that needs to be addressed

Description

@pytestbot
pytestbot
opened on Dec 17, 2010

Originally reported by: Alfredo Deza (BitBucket: alfredodeza, GitHub: alfredodeza)

There is a problem with the logging module and py.test

Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 1472, in shutdown
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 1472, in shutdown
    h.flush()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 740, in flush
    self.stream.flush()
    h.flush()
ValueError: I/O operation on closed file

It seems that if it runs with the '-s' flag it doesn't do this anymore.

Activity

  1. pytestbot commented on Jan 12, 2011

    @pytestbot
    pytestbot
    on Jan 12, 2011
    ContributorAuthor

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

    fix issue14 : it was actually issue14 instead of issue8 that was fixed with
    the older https://bitbucket.org/hpk42/pytest/changeset/1c3eb86502b3

    please try out with the usual "pip install -i http://pypi.testrun.org -U pytest"

  2. pytestbot commented on Jan 28, 2011

    @pytestbot
    pytestbot
    on Jan 28, 2011
    ContributorAuthor

    Original comment by Adam Wagner (BitBucket: awagner83, GitHub: awagner83):

    This fixes it for me.

  3. pytestbot commented on Jan 28, 2011

    @pytestbot
    pytestbot
    on Jan 28, 2011
    ContributorAuthor

    Original comment by Alfredo Deza (BitBucket: alfredodeza, GitHub: alfredodeza):

    I can confirm this gets fixed with the update. Sorry for not reporting it sooner...

  4. pytestbot commented on Apr 9, 2011

    @pytestbot
    pytestbot
    on Apr 9, 2011
    ContributorAuthor

    Original comment by eduardo schettino (BitBucket: schettino72, GitHub: schettino72):

    there is still a problem with this when used with capsys...

    {{{
    #!python

    (py26)~/work/xxx$ cat bug14.py
    import logging
    def test_133(capsys):
    logging.error('x')

    (py26)~/work/xxx$ py.test bug14.py
    ================================================ test session starts =================================================
    platform linux2 -- Python 2.6.6 -- pytest-2.0.2
    collected 1 items

    bug14.py .

    ============================================== 1 passed in 0.01 seconds ==============================================
    Error in atexit._run_exitfuncs:
    Traceback (most recent call last):
    File "/usr/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(_targs, *_kargs)
    File "/usr/lib/python2.6/logging/init.py", line 1516, in shutdown
    h.flush()
    File "/usr/lib/python2.6/logging/init.py", line 762, in flush
    self.stream.flush()
    File "/usr/lib/python2.6/io.py", line 1488, in flush
    self.buffer.flush()
    ValueError: I/O operation on closed file.
    Error in sys.exitfunc:
    Traceback (most recent call last):
    File "/usr/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(_targs, *_kargs)
    File "/usr/lib/python2.6/logging/init.py", line 1516, in shutdown
    h.flush()
    File "/usr/lib/python2.6/logging/init.py", line 762, in flush
    self.stream.flush()
    File "/usr/lib/python2.6/io.py", line 1488, in flush
    self.buffer.flush()
    ValueError: I/O operation on closed file.

    }}}

  5. pytestbot commented on Apr 13, 2011

    @pytestbot
    pytestbot
    on Apr 13, 2011
    ContributorAuthor

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

    can you quickly try with "pip install -U -i http://pypi.testrun.org pytest" which should get you 2.0.3.dev3 and fix the issue? (To be honest, i am not yet sure why it is fixed, but i'd rather first check if it works for you as well)

  6. pytestbot commented on May 27, 2011

    @pytestbot
    pytestbot
    on May 27, 2011
    ContributorAuthor

    Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):

    still in trunk

  7. pytestbot commented on May 27, 2011

    @pytestbot
    pytestbot
    on May 27, 2011
    ContributorAuthor

    Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):

    this would probably best be fixed by integrating logcapture into pytest

  8. pytestbot commented on Mar 25, 2013

    @pytestbot
    pytestbot
    on Mar 25, 2013
    ContributorAuthor

    Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):

    as a extra note, it seems this is version specific to python2.7

  9. pytestbot commented on Sep 5, 2013

    @pytestbot
    pytestbot
    on Sep 5, 2013
    ContributorAuthor

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

    i can't reproduce this with my py27/py33 and pytest-trunk anymore

  10. pytestbot commented on Sep 24, 2013

    @pytestbot
    pytestbot
    on Sep 24, 2013
    ContributorAuthor

    Original comment by Alfredo Deza (BitBucket: alfredodeza, GitHub: alfredodeza):

    I am not consistently hitting this with Python 2.6

    #!text

 py.test -v
================================================ test session starts =================================================
platform darwin -- Python 2.6.7 -- pytest-2.3.5 -- /Users/alfredo/python/ceph-deploy/.tox/py26/bin/python2.6
collected 28 items

tests/test_cli.py:5: test_help PASSED
tests/test_cli.py:16: test_bad_command PASSED
tests/test_cli.py:28: test_bad_cluster PASSED
tests/test_cli_install.py:13: test_help PASSED
tests/test_cli_install.py:24: test_bad_no_host PASSED
tests/test_cli_install.py:36: test_simple PASSED
tests/test_cli_mon.py:13: test_help PASSED
tests/test_cli_mon.py:24: test_bad_no_conf PASSED
tests/test_cli_mon.py:36: test_bad_no_mon PASSED
tests/test_cli_mon.py:50: test_simple PASSED
tests/test_cli_new.py:13: test_help PASSED
tests/test_cli_new.py:24: test_write_global_conf_section PASSED
tests/test_cli_new.py:49: test_uuid PASSED
tests/test_cli_new.py:67: test_mons PASSED
tests/test_cli_new.py:73: test_defaults PASSED
tests/test_cli_osd.py:13: test_help PASSED
tests/test_cli_osd.py:24: test_bad_no_conf PASSED
tests/test_cli_osd.py:36: test_bad_no_disk PASSED
tests/test_cli_osd.py:49: test_simple PASSED
tests/test_conf.py:5: test_simple PASSED
tests/test_conf.py:14: test_indent_space PASSED
tests/test_conf.py:23: test_indent_tab PASSED
tests/test_conf.py:32: test_words_underscore PASSED
tests/test_conf.py:42: test_words_space PASSED
tests/test_conf.py:52: test_words_many PASSED
tests/test_mon.py:30: TestCatchCommonErrors.test_warn_if_no_intial_members PASSED
tests/test_mon.py:36: TestCatchCommonErrors.test_warn_if_not_mon_in_monmap PASSED
tests/test_mon.py:42: TestCatchCommonErrors.test_warn_if_not_public_addr_and_not_public_netw PASSED

============================================= 28 passed in 2.81 seconds ==============================================
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 1516, in shutdown
    h.flush()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 762, in flush
    self.stream.flush()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/io.py", line 1488, in flush
    self.buffer.flush()
ValueError: I/O operation on closed file.
Error in sys.exitfunc:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 1516, in shutdown
    h.flush()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/logging/__init__.py", line 762, in flush
    self.stream.flush()
  File "/System/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/io.py", line 1488, in flush
    self.buffer.flush()
ValueError: I/O operation on closed file.

    This only happens if I use capsys. As soon as I stop using it the error goes away.

  11. pytestbot
    added
    type: bugproblem that needs to be addressed
    on Jun 15, 2015
  12. pytestbot
    closed this as completedon Jun 15, 2015

  13. jfitzpatrick99 commented on Jul 9, 2015

    @jfitzpatrick99
    jfitzpatrick99
    on Jul 9, 2015

    I am hitting this with pytest 2.7.2 and python 2.7.2. The issue seems to occur if the logger I use is instantiated at the module level instead of inside a module function.

  14. nicoddemus commented on Jul 9, 2015

    @nicoddemus
    nicoddemus
    on Jul 9, 2015
    Member

    Hi @jfitzpatrick99, can you provide a small example which reproduces the problem?

  15. jfitzpatrick99 commented on Jul 9, 2015

    @jfitzpatrick99
    jfitzpatrick99
    on Jul 9, 2015

    @nicoddemus I just tried putting together a small reproducer but at the moment I can only reproduce with my entire application. I will see if I can get something together for tomorrow.

  16. 5 remaining items

  17. The-Compiler
    reopened this on Oct 30, 2015

  18. RonnyPfannschmidt commented on Oct 31, 2015

    @RonnyPfannschmidt
    RonnyPfannschmidt
    on Oct 31, 2015
    Member

    Passing a concrete captured stream that will be closed without removing its handler in teardown is bound to fail

    Not even the pending merge of log capturing can fix that particular usage pattern

  19. RonnyPfannschmidt
    closed this as completedon Oct 31, 2015

  20. bilderbuchi commented on Jan 11, 2017

    @bilderbuchi
    bilderbuchi
    on Jan 11, 2017
    Contributor

    @RonnyPfannschmidt I just hit the exact same issue as @shapiy above when testing if logging output of my package is correct. What is the correct usage pattern to do this with pytest?

  21. nicoddemus commented on Jan 12, 2017

    @nicoddemus
    nicoddemus
    on Jan 12, 2017
    Member

    What is the correct usage pattern to do this with pytest?

    Short answer (IMO) is to use pytest-catchlog which provides great integration with the logging package, including a caplog fixture to capture logging output.

    Long answer:

    The problem is (please correct me @RonnyPfannschmidt):

    logging.basicConfig(level=logging.DEBUG, stream=sys.stdout)

    sys.stdout at this point is a StringIO object installed by the capsys fixture.

    You should "undo" what logging.basicConfig does when the test finishes, possibly in a fixture or a try/finally block.

  22. bilderbuchi commented on Jan 13, 2017

    @bilderbuchi
    bilderbuchi
    on Jan 13, 2017
    Contributor

    Thank you for your pointers! I have found if I leave stream=sys.stdout out of the call in the example, it works correctly: logging.basicConfig(level=logging.DEBUG). Interestingly, in my slightly more complex usecase it still didn't work correctly despite doing that.

    In the end, I found that removing the stream handler manually afterwards was enough to make the tests run as expected:

    root_logger = logging.getLogger()
root_logger.setLevel(logging.INFO)
hdlr = logging.StreamHandler()
root_logger.addHandler(hdlr)
# run stuff here...
root_logger.removeHandler(hdlr)

  23. nicoddemus commented on Jan 13, 2017

    @nicoddemus
    nicoddemus
    on Jan 13, 2017
    Member

    Glad you found a solution!

    Notice that you can add that to a fixture and even make it autouse so all tests do that logging setup/tear down automatically.

    Out of curiosity, did you try to use pytest-catchlog?

  24. bilderbuchi commented on Jan 13, 2017

    @bilderbuchi
    bilderbuchi
    on Jan 13, 2017
    Contributor

    Yeah I know I could do a fixture, but it's just for those two tests, if I use it more I'll definitely refactor it.
    No, I didn't try pytest-catchlog at first, I didn't want to incur another dependency if I could avoid it.

  25. nicoddemus commented on Jan 13, 2017

    @nicoddemus
    nicoddemus
    on Jan 13, 2017
    Member

    OK, thanks!

  26. bilderbuchi commented on Jan 13, 2017

    @bilderbuchi
    bilderbuchi
    on Jan 13, 2017
    Contributor

    By the way, thank you for a great tool, all you pytest devs!
    Now I'll shut up and stop spamming. ^.^

  27. nicoddemus commented on Jan 13, 2017

    @nicoddemus
    nicoddemus
    on Jan 13, 2017
    Member

    Thanks, we appreciate it. 😁

  28. fkohlgrueber
    added a commit that references this issue on Oct 27, 2018

    Fix spurious extra spaces after opening parentheses and in default ar…

    da3c2f3

  30. gaborbernat commented on Aug 15, 2019

    @gaborbernat
    gaborbernat
    on Aug 15, 2019
    Contributor

    @nicoddemus @asottile

    This is still an issue with the latest pytest across tests (e.g. when one tests change the logging config and add a stream handler pointing to stdout, a subsequent test that doesn't setup logging and tries to write to logging will fail).

    I think the issue boils down to the fact that if you set up a Stream Handler and you enable capsys the actual output stream will be a pytest stream that will be closed and thrown away at the next test in the test suite. So when a subsequent test tries to write to it you get this error. Adding the following fixture fixed this:

    LOGGER = logging.getLogger()

@pytest.fixture(autouse=True)
def ensure_logging_framework_not_altered():
    before_handlers = list(LOGGER.handlers)
    yield
    LOGGER.handlers = before_handlers

    Should this be automatically done always by pytest? Granted for this to work ideally you would need to do it for all loggers, not just the root one. In this case, for me, this was enough as I was only set up a custom stream logger onto the root logger.

    In an ideal world, I would expect though pytest to cleanup loggig configurations at the end tests that requested the caplog fixture.

  31. nicoddemus commented on Aug 15, 2019

    @nicoddemus
    nicoddemus
    on Aug 15, 2019
    Member

    @gaborbernat thanks for the detailed description! I've created #5743 to track this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    type: bugproblem that needs to be addressed

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions