ValueError warning in test_urllib due to io.IOBase destructor

@vstinner

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']

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.

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

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.

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]

cpython/Lib/test/test_urllib.py

Line 61 in be6dbfb

io_refs = 1

[2]

cpython/Lib/test/test_urllib.py

Line 67 in be6dbfb

self.io_refs += 1

[3]

cpython/Lib/http/client.py

Line 919 in be6dbfb

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

[4]

cpython/Lib/urllib/request.py

Line 2145 in be6dbfb

fp.close()

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.

I proposed PR 13955: a fix in 2 lines.

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

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

Navigation Menu

Repository navigation

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

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

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

Description

Activity

tirkarthi commented on May 14, 2019

serhiy-storchaka commented on May 17, 2019

serhiy-storchaka commented on May 17, 2019

tirkarthi commented on May 17, 2019

vstinner commented on Jun 11, 2019

vstinner commented on Jun 11, 2019

vstinner commented on Jun 12, 2019

miss-islington commented on Jun 12, 2019

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions