Skip to content
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

ValueError warning in test_urllib due to io.IOBase destructor #81099

Closed
tirkarthi opened this issue May 14, 2019 · 8 comments
Closed

ValueError warning in test_urllib due to io.IOBase destructor #81099

tirkarthi opened this issue May 14, 2019 · 8 comments
Labels
3.8 only security fixes 3.9 only security fixes topic-IO type-bug An unexpected behavior, bug, or error

Comments

@tirkarthi
Copy link
Member

BPO 36918
Nosy @vstinner, @serhiy-storchaka, @miss-islington, @tirkarthi
PRs
  • bpo-36918: Don't close the object which is again closed by destructor #13317
  • bpo-36918, test_urllib: Silence FakeHTTPConnection destructor errors #13955
  • bpo-36918: Fix "Exception ignored in" in test_urllib #13996
  • [3.8] bpo-36918: Fix "Exception ignored in" in test_urllib (GH-13996) #13998
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2019-06-12.02:42:40.104>
    created_at = <Date 2019-05-14.17:55:07.967>
    labels = ['type-bug', '3.8', '3.9', 'expert-IO']
    title = 'ValueError warning in test_urllib due to io.IOBase destructor'
    updated_at = <Date 2019-06-12.02:42:40.100>
    user = 'https://github.com/tirkarthi'

    bugs.python.org fields:

    activity = <Date 2019-06-12.02:42:40.100>
    actor = 'vstinner'
    assignee = 'none'
    closed = True
    closed_date = <Date 2019-06-12.02:42:40.104>
    closer = 'vstinner'
    components = ['IO']
    creation = <Date 2019-05-14.17:55:07.967>
    creator = 'xtreak'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 36918
    keywords = ['patch']
    message_count = 8.0
    messages = ['342492', '342708', '342709', '342710', '345164', '345167', '345297', '345299']
    nosy_count = 4.0
    nosy_names = ['vstinner', 'serhiy.storchaka', 'miss-islington', 'xtreak']
    pr_nums = ['13317', '13955', '13996', '13998']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue36918'
    versions = ['Python 3.8', 'Python 3.9']

    @tirkarthi
    Copy link
    Member Author

    Issue for https://bugs.python.org/issue18748#msg340059.

    comment :

    Is there someone interested to debug remaining "Exception ignored:" logs in test_urllib?

    test_invalid_redirect (test.test_urllib.urlopen_HttpTests) ...
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24be0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    ok
    
    test_read_bogus (test.test_urllib.urlopen_HttpTests) ...
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24cd0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    ok
    
    test_redirect_limit_independent (test.test_urllib.urlopen_HttpTests) ...
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24cd0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24c30>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24460>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f24a50>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f247d0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52ea95f0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52ea99b0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f2f820>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f2fbe0>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    Exception ignored in: <http.client.HTTPResponse object at 0x7fca52f2fd70>
    Traceback (most recent call last):
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 402, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 415, in flush
        self.fp.flush()
    ValueError: I/O operation on closed file.
    ok

    It's unclear to be if it's a bug in http.client, a bug in the test... or something else.

    @tirkarthi tirkarthi added tests Tests in the Lib/test dir 3.8 only security fixes type-bug An unexpected behavior, bug, or error labels May 14, 2019
    @serhiy-storchaka
    Copy link
    Member

    I think this is a bug in BasicIO. close() should be idempotent. Calling it on the closed file should have no effect.

    @serhiy-storchaka serhiy-storchaka added topic-IO and removed tests Tests in the Lib/test dir labels May 17, 2019
    @serhiy-storchaka
    Copy link
    Member

    No, BasicIO.close() is correct.

    This is a bug in the garbage collector: the underlying file is closed before closing HTTPResponse. The HTTPResponse instance has a reference to the file object, the file object does not have a reference to the HTTPResponse instance, therefore the HTTPResponse instance should be destroyed first.

    @tirkarthi
    Copy link
    Member Author

    My analysis was that close was called on fakesocket which is internally closed when it's counter resets to zero and the destructor was trying to flush on a closed object during destructor call.

    Comment from https://bugs.python.org/issue18748#msg341106

    The ValueError warnings in test_urllib noted in msg340059 feels like an issue with the test where FakeSocket calls close by itself once it's internal io_refs counter is 0 and during destructor again close is called on an already closed object causing the ValueError.

    • The test uses fakehttp() creating FakeSocket starting with io_refs as 1 [1]
    • During the test in urlopen, sock.makefile() (io_refs += 1) is called increasing the io_refs to be 2.
    • HTTPConnection.close calls sock.close (fakesocket.close) [3] calling io_refs -= 1 and to fakesocket.io_ref to be 1.
    • This test uses raises status 302 with http_error_302 which calls self.redirect_internal where self.close is again called causing fp.io_refs == 0 and subsequently calling io.BytesIO.close(self) to close the object. [4]
    • During the end of the test destructor is called on the above closed fakesocket object and trying to flush on a closed object causes the ValueError warnings .

    Maybe a check could be added during flush to make sure the object is not closed by testing for self.closed but I am not sure if closed attribute is guaranteed to be present. Removing the manual call to close in fakesocket could help since the destructor should be taking care of it and I could see no test failures or warnings removing the close as io_refs gets to 0.

    [1]

    io_refs = 1

    [2]
    self.io_refs += 1

    [3]
    sock.close() # close it manually... there may be other refs

    [4]
    fp.close()

    @vstinner
    Copy link
    Member

    Well, maybe Python GC can be enhanced. In the meanwhile, I would like to make these warnings quiet since they are very annoying when I have to analyze buildbot warnings. Moreover, this issues blocks my bpo-37069.

    Maybe open a separated issue to propose to enhance the GC, if you have an idea how to change it.

    @vstinner
    Copy link
    Member

    I proposed PR 13955: a fix in 2 lines.

    @vstinner
    Copy link
    Member

    New changeset eb976e4 by Victor Stinner in branch 'master':
    bpo-36918: Fix "Exception ignored in" in test_urllib (GH-13996)
    eb976e4

    @miss-islington
    Copy link
    Contributor

    New changeset 9d37ae0 by Miss Islington (bot) in branch '3.8':
    bpo-36918: Fix "Exception ignored in" in test_urllib (GH-13996)
    9d37ae0

    @vstinner vstinner added the 3.9 only security fixes label Jun 12, 2019
    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.8 only security fixes 3.9 only security fixes topic-IO type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    4 participants