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

test_fileno of test_urllibnet intermittently fails #65268

Closed
dfarrell07 mannequin opened this issue Mar 26, 2014 · 24 comments
Closed

test_fileno of test_urllibnet intermittently fails #65268

dfarrell07 mannequin opened this issue Mar 26, 2014 · 24 comments
Labels
tests Tests in the Lib/test dir type-bug An unexpected behavior, bug, or error

Comments

@dfarrell07
Copy link
Mannequin

dfarrell07 mannequin commented Mar 26, 2014

BPO 21069
Nosy @orsenthil, @vstinner, @ned-deily, @bitdancer, @berkerpeksag, @vadmium
Files
  • test_failures.txt: Output of make test, shows test failures
  • issue21069.patch: Patch to change example URL, fixes this issue
  • test_success_after_patch.txt: Successful test run after applying two relevant patches to latest code
  • rewrite-fileno.patch: Test HTTPResponse, use CONNECT
  • 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 2016-04-09.22:27:15.901>
    created_at = <Date 2014-03-26.08:10:37.504>
    labels = ['type-bug', 'tests']
    title = 'test_fileno of test_urllibnet intermittently fails'
    updated_at = <Date 2016-04-09.22:27:15.900>
    user = 'https://bugs.python.org/dfarrell07'

    bugs.python.org fields:

    activity = <Date 2016-04-09.22:27:15.900>
    actor = 'martin.panter'
    assignee = 'none'
    closed = True
    closed_date = <Date 2016-04-09.22:27:15.901>
    closer = 'martin.panter'
    components = ['Tests']
    creation = <Date 2014-03-26.08:10:37.504>
    creator = 'dfarrell07'
    dependencies = []
    files = ['34626', '34630', '34631', '42351']
    hgrepos = []
    issue_num = 21069
    keywords = ['patch', 'buildbot']
    message_count = 24.0
    messages = ['214882', '214897', '214898', '214900', '214901', '214918', '214919', '214924', '214925', '214942', '214945', '214947', '216400', '216416', '216429', '216430', '216438', '242576', '262733', '262785', '262816', '262822', '263074', '263099']
    nosy_count = 9.0
    nosy_names = ['orsenthil', 'vstinner', 'ned.deily', 'Arfrever', 'r.david.murray', 'python-dev', 'berker.peksag', 'martin.panter', 'dfarrell07']
    pr_nums = []
    priority = 'high'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue21069'
    versions = ['Python 3.5', 'Python 3.6']

    @dfarrell07
    Copy link
    Mannequin Author

    dfarrell07 mannequin commented Mar 26, 2014

    I'm seeing quite a few unit test failures in urllib ("urlopen error unknown url type: https"). From what I've gathered on IRC, this seems to be because I'm missing the ssl module. I'm seeing these errors in 3.4.0, after a simple ./configure; make; make test. Test results: http://pastebin.com/5LBAjkVW

    I'm not seeing them after hg clone http://hg.python.org/cpython; ./configure --with-pydebug && make -j2; ./python -m test -j3, via http://docs.python.org/devguide/#quick-start.

    bpo-20939 is the closest thing I've found to this, but it seems to be more narrowly scoped (http -> https change at python.org). Nice people on IRC suggest that this is a different enough problem to warrant a new issue.

    I'm on an up-to-date Fedora 20 install.

    @bitdancer
    Copy link
    Member

    What makes you think this is a different issue? It sounds like a duplicate to me.

    @bitdancer
    Copy link
    Member

    Ah, in case I wasn't clear: what unittest failures that you are seeing are not covered by bpo-20939? In order to diagnose this issue, we'll need to know that :)

    @dfarrell07
    Copy link
    Mannequin Author

    dfarrell07 mannequin commented Mar 26, 2014

    Ah, in case I wasn't clear: what unittest failures that you are seeing are not covered by bpo-20939?

    The unit test failures I'm seeing are different in at least two ways: 1) A larger set of tests failing than mentioned in bpo-20939; 2) Their failure was an assertion FAIL, mine are ERRORS related to https being an unknown URL type.

    Here are the unit tests that are failing, extracted from that massive dump of info.

    The following block are all failing with "urllib.error.URLError: <urlopen error unknown url type: https>":

    test_license_exists_at_url (test.test_site.ImportSideEffectTests) ... ERROR
    <...>
    test_issue16464 (test.test_urllib2.MiscTests) ... ERROR
    <...>
    test_close (test.test_urllib2net.CloseSocketTest) ... ERRO
    <...>
    test_http_basic (test.test_urllib2net.TimeoutTest) ... ERROR
    test_http_default_timeout (test.test_urllib2net.TimeoutTest) ... ERROR
    test_http_no_timeout (test.test_urllib2net.TimeoutTest) ... ERROR
    test_http_timeout (test.test_urllib2net.TimeoutTest) ... ERROR
    <...>
    testURLread (test.test_urllibnet.URLTimeoutTest) ... ERROR
    test_basic (test.test_urllibnet.urlopenNetworkTests) ... ERROR
    test_fileno (test.test_urllibnet.urlopenNetworkTests) ... ERROR
    <...>
    test_geturl (test.test_urllibnet.urlopenNetworkTests) ... ERROR
    test_info (test.test_urllibnet.urlopenNetworkTests) ... ERROR
    test_readlines (test.test_urllibnet.urlopenNetworkTests) ... ERROR
    test_basic (test.test_urllibnet.urlretrieveNetworkTests) ... ERROR
    test_data_header (test.test_urllibnet.urlretrieveNetworkTests) ... ERROR
    test_header (test.test_urllibnet.urlretrieveNetworkTests) ... ERROR
    test_reporthook (test.test_urllibnet.urlretrieveNetworkTests) ... ERROR
    test_specified_path (test.test_urllibnet.urlretrieveNetworkTests) ... ERROR

    This one is failing with the very similar "OSError: [Errno url error] unknown url type: 'https":

    test_getcode (test.test_urllibnet.urlopenNetworkTests) ... ERROR

    @bitdancer
    Copy link
    Member

    Well, I just looked at one of those tests at random, and it is using an http://www.python.org url, so it would be covered by 20939. Can you re-run your tests after applying the patches from that issue?

    @dfarrell07
    Copy link
    Mannequin Author

    dfarrell07 mannequin commented Mar 26, 2014

    Interestingly, using the configure/make/test options given in the devguide doesn't show these failures, but running on the exact same codebase (hg checkout v3.4.0) with the configure/make/test options in the README consistently shows them. That seems...not good. What are those flags doing that could suppress errors?

    Can you re-run your tests after applying the patches from that issue?

    Initial results are that I'm seeing some failures, but not as many and somewhat different ones. Digging into the details now.

    @bitdancer
    Copy link
    Member

    Network tests are only run if the 'network' resource is enabled. The devguide does not suggest setting network, but make test does do so. (I personally always use -uall when running the tests).

    @dfarrell07
    Copy link
    Mannequin Author

    dfarrell07 mannequin commented Mar 27, 2014

    Running the unit tests against the latest code (hg clone <url>; ./configure; make; make test) shows the same errors I described earlier. Patching the code with issue20939_all_3x.patch fixes all related errors except one.

    =======================================================================
    FAIL: test_fileno (test.test_urllibnet.urlopenNetworkTests)
    ----------------------------------------------------------------------

    Traceback (most recent call last):
      File "/home/daniel/cpython/Lib/test/test_urllibnet.py", line 107, in test_fileno
        self.assertTrue(f.read(), "reading from file created using fd "
    AssertionError: b'' is not true : reading from file created using fd returned by fileno failed

    Something funky is going on with example.com for this test. I imagine one of you awesome people will understand this failure quickly. Until then, using a different non-HTTPS URL seems to work (see attached patch).

    @dfarrell07
    Copy link
    Mannequin Author

    dfarrell07 mannequin commented Mar 27, 2014

    Note that bpo-21069.patch depends on issue20939_all_3x.patch (if that wasn't clear).

    [/cpython]$ hg import issue20939_all_3x.patch
    applying issue20939_all_3x.patch
    patching file Lib/test/test_urllib2.py
    Hunk #1 succeeded at 1447 with fuzz 1 (offset 6 lines).
    [
    /cpython]$ hg import bpo-21069.patch
    applying bpo-21069.patch
    [/cpython]$ ./configure
    <snip>
    [
    /cpython]$ make
    <snip>
    [~/cpython]$ make test &> ~/test_success_after_patch.txt
    <snip>

    See attached output.

    @ned-deily ned-deily self-assigned this Mar 27, 2014
    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Mar 27, 2014

    New changeset adf1e04478b4 by Ned Deily in branch '3.4':
    Issue bpo-21069: Temporarily use www.google.com while investigating
    http://hg.python.org/cpython/rev/adf1e04478b4

    New changeset 8d4cace71113 by Ned Deily in branch 'default':
    bpo-21069: merge from 3.4
    http://hg.python.org/cpython/rev/8d4cace71113

    @ned-deily
    Copy link
    Member

    After pushing the changes for bpo-20939, many of the buildbots started experiencing the test_fileno failure using www.example.com. The interesting thing is that not all of them do, including my primary development system (OS X 10.9) which is why I didn't see a problem during the initial testing. On another dev system (Debian Linux on a VM), the test fails intermittently. So, yes, something funky *is* going on. One obvious difference is that the read from www.python.org returns 44000+ byes while www.example.com returns only 162 bytes. There could be a race condition with the TCP connection close. I've temporarily changed the test to use www.google.com pending resolution. Thanks for the report and investigation, Daniel.

    @ned-deily ned-deily changed the title urllib unit tests failing without ssl module test_fileno of test_urllibnet intermittently fails when using www.example.com Mar 27, 2014
    @ned-deily
    Copy link
    Member

    After looking at why the 2.7 version of the test does not fail, the problem became apparent. In 2.7, test_errno tests urlopen() of the original deprecated urllib module. In 3.x, the test was ported over but now uses urlopen() of urllib.request which is based on urllib2() of 2.x.

    2.7:
    >>> x = urllib.urlopen("http://www.example.com")
    [79234 refs]
    >>> x
    <addinfourl at 3068742324L whose fp = <socket._fileobject object at 0xb6e7eea4>>
    [79234 refs]
    >>> os.fdopen(x.fileno()).read()
    '<!doctype html>\n<html>\n<head>\n    <title>Example Domain</title>\n\n    <meta charset="utf-8" />\n    <meta http-equiv="Content-type" content="text/html; charset=utf-8" />\n    <meta name="viewport" content="width=device-width, initial-scale=1" />\n    <style type="text/css">\n    body {\n        background-color: #f0f0f2;\n        margin: 0;\n        padding: 0;\n        font-family: "Open Sans", "Helvetica Neue", Helvetica, Arial, sans-serif;\n        \n    }\n    div {\n        width: 600px;\n        margin: 5em auto;\n        padding: 50px;\n        background-color: #fff;\n        border-radius: 1em;\n    }\n    a:link, a:visited {\n        color: #38488f;\n        text-decoration: none;\n    }\n    @media (max-width: 700px) {\n        body {\n            background-color: #fff;\n        }\n        div {\n            width: auto;\n            margin: 0 auto;\n            border-radius: 0;\n            padding: 1em;\n        }\n    }\n    </style>    \n</head>\n\n<body>\n<div>\n    <h1>Example Domain</h1>\n    <p>This domain is established to be used for illustrative examples in documents. You may use this\n    domain in examples without prior coordination or asking for permission.</p>\n    <p><a href="http://www.iana.org/domains/example">More information...</a></p>\n</div>\n</body>\n</html>\n'
    [79234 refs]
    
    3.4 (when the read doesn't fail):
    >>> x = urllib.request.urlopen("http://www.example.com")
    >>> x
    <http.client.HTTPResponse object at 0xb6bc7114>
    >>> os.fdopen(x.fileno()).read()
    __main__:1: ResourceWarning: unclosed file <_io.TextIOWrapper name=4 mode='r' encoding='UTF-8'>
    ' without prior coordination or asking for permission.</p>\n    <p><a href="http://www.iana.org/domains/example">More information...</a></p>\n</div>\n</body>\n</html>\n'

    In the 3.x case (and the 2.7 urllib2 case), the read from the file descriptor starts at mid-response or at the end (returning an empty byte string). In the past, the test passed because of the amount of data returned by the previous test URL. Now, with the short response from www.example.com, it's clear that the file descriptor read is not returning the whole response. I don't know whether the file descriptor read is expected to be meaningful for urllib2/urllib.request.

    Senthil, what do you think?

    @orsenthil
    Copy link
    Member

    I am getting to this late.

    > I don't know whether the file descriptor read is expected to be meaningful for urllib2/urllib.request.
    > Senthil, what do you think?

    It should be meaningful no matter what the length is. I am looking further into this now.

    @orsenthil
    Copy link
    Member

    This is the best way I found to reproduce the failure.

    I changed the resource to www.example.com and then ran this.

    $ ./python.exe -m test -m "*fileno*" -u all -v -F test_urllibnet

    @orsenthil
    Copy link
    Member

    This is turning out be trickier than I ever thought.

    fileno() returning b'' is just random error. The underlying issue is, *directly* reading from the fp of the socket() is returning a incomplete output at all times. The correct way to read the output is by using HTTPResponse read() method only it seems.

    Here is a small snippet that will fail for every url.

    from urllib.request import urlopen
    
    import os
    
    web = "http://www.example.org"
    
    open_url = urlopen(web)
    fd = open_url.fileno()
    with os.fdopen(fd, 'rb') as f:
        file_read_len = len(f.read())
    
    req = urlopen(web)
    res_len = len(req.read())

    assert file_read_len == res_len

    @orsenthil
    Copy link
    Member

    Ned Deily had done the correct analysis in the msg214947 and has this question -

    I don't know whether the file descriptor read is expected to be meaningful for urllib2/urllib.request.

    I can see that this test case was for the old behavior where we created a file like object to read using addinfourl and fileno /fp was explicitly set. We have to determine if this expectation that we can access the socket's fp using HTTPResponse object is a right one.

    @ned-deily
    Copy link
    Member

    Senthil, thanks for looking into this. Since it is turning out to be more of a urllib design issue, I'm going to deassign myself from it.

    @ned-deily ned-deily removed their assignment Apr 16, 2014
    @BreamoreBoy
    Copy link
    Mannequin

    BreamoreBoy mannequin commented May 4, 2015

    I tried reproducing this on Windows 8.1 with the code snippet from msg216429 but got

    Traceback (most recent call last):
      File "C:\Users\Mark\Documents\MyPython\mytest.py", line 9, in <module>
        with os.fdopen(fd, 'rb') as f:
      File "c:\python34\lib\os.py", line 980, in fdopen
        return io.open(fd, *args, **kwargs)
    OSError: [Errno 9] Bad file descriptor

    Is there something else that I can try? Is this still an issue that needs looking into?

    @vadmium
    Copy link
    Member

    vadmium commented Apr 1, 2016

    Mark: My understanding is on Windows, winsock file descriptors and C library file descriptors are different beasts; see <https://docs.python.org/3/library/socket.html#socket.socket.fileno\>. Perhaps the test should call socket functions like socket.recv() on the FD rather than C library functions via os.fdopen().

    Victor: The test in this bug has started failing again, very likely due to your revision 7bd4736195ce enabling a timeout on the HTTP request. I guess this causes the socket to be in non-blocking mode, and read() to return None. This is what bpo-10119 tried to fix. Example:

    http://buildbot.python.org/all/builders/AMD64%20Debian%20root%203.x/builds/3404/steps/test/logs/stdio
    ======================================================================
    FAIL: test_fileno (test.test_urllibnet.urlopenNetworkTests)
    ----------------------------------------------------------------------

    Traceback (most recent call last):
      File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/test_urllibnet.py", line 110, in test_fileno
        self.assertTrue(f.read(), "reading from file created using fd "
    AssertionError: None is not true : reading from file created using fd returned by fileno failed

    A less serious and long-standing problem with the test is that it attempts to close the socket twice. We are just lucky that socket.close() is called second, which does not raise any errors: <https://hg.python.org/cpython/annotate/8938b3132caa/Modules/socketmodule.c#l259\>.

    Regarding the purpose and use cases of fileno(), I agree with Senthil that using it to read the HTTP response behind the HTTPResponse object’s back in Python 3 is a bad idea, and I don’t think it is practical to make this work without losing the benefits of buffering. But there are probably other valid use cases such as calling getsockname() on the socket, or sending and receiving non-HTTP data after setting up a CONNECT tunnel.

    Proposals:

    1. Change the test to do use socket(fileno=...), rather than os.fdopen(...), so that it will be usable on Windows.

    2. Ensure that the secondary socket object is not closed; use socket.detach()

    3. Rewrite the test to test http.client directly, rather than indirectly through urlopen(). As far as I can see the purpose is only to test HTTPResponse.fileno(), not urlopen().

    4. Rewrite the test to test a local server run in a background thread, rather than relying external web sites (currently Google, previously IETF, and Python). This would eliminate the need for setting a timeout.

    5. Rewrite to the test for a more realistic use case that does not depend on specific internal HTTPResponse buffering and the HTTP protocol. I suggest mocking a CONNECT request, and uploading some non-HTTP data through the proxy.

    @vadmium vadmium added the tests Tests in the Lib/test dir label Apr 1, 2016
    @vadmium vadmium changed the title test_fileno of test_urllibnet intermittently fails when using www.example.com test_fileno of test_urllibnet intermittently fails Apr 1, 2016
    @vadmium vadmium added the type-bug An unexpected behavior, bug, or error label Apr 1, 2016
    @vadmium
    Copy link
    Member

    vadmium commented Apr 2, 2016

    Here is a patch implementing my ideas. Let me know what you think of the ideas and/or the patch :)

    If people think this change is too much for 3.5, I could try making a more minimal patch that calls something like socket.getpeername() rather than read(). That should also avoid the non-blocking problem.

    @vstinner
    Copy link
    Member

    vstinner commented Apr 3, 2016

    I added a timeout because test_urllibnet fails with a timeout after 15 minutes on the ARM buildbot and other tests of the same file also use a timeout.

    I tried but failed to reproduce the timeout.

    I ran the test after my change and it passes so I considered that it was ok. I understand your rationale for timeout, non blocking socket and read() returning None.

    Can we modify the test to use a selector to wait until the socket is ready and only read available bytes, rather than reading all data?

    Using a local server would also avoid blocking too long (take less than 15 min).

    @vadmium
    Copy link
    Member

    vadmium commented Apr 3, 2016

    Yes using select() would be another way to fix the immediate problem of read() returning None. In the long term I was hoping to use something like my patch to avoid the problems with reading the HTTP response (already discussed in this report) at the same time.

    @berkerpeksag
    Copy link
    Member

    I saw test_fileno failure again on the Gentoo buildbot: http://buildbot.python.org/all/builders/x86%20Gentoo%20Installed%20with%20X%203.x/builds/459/steps/test/logs/stdio

    rewrite-fileno.patch looks good to me.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Apr 9, 2016

    New changeset 00240ddce1d0 by Martin Panter in branch '3.5':
    Issue bpo-21069: Move test_fileno() from test_urllibnet and rewrite it
    https://hg.python.org/cpython/rev/00240ddce1d0

    New changeset 4c19396bd4a0 by Martin Panter in branch 'default':
    Issue bpo-21069: Merge test_fileno() from 3.5
    https://hg.python.org/cpython/rev/4c19396bd4a0

    @vadmium vadmium closed this as completed Apr 9, 2016
    @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
    tests Tests in the Lib/test dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    6 participants