This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: test.test_urllib2net.TimeoutTest ftp related tests fail due to ftp://www.pythontest.net/ being unavailable
Type: behavior Stage: resolved
Components: Tests Versions: Python 3.8, Python 3.7, Python 3.6, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: benjamin.peterson, pablogsal, vstinner, xtreak
Priority: high Keywords:

Created on 2019-02-27 05:06 by xtreak, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Messages (12)
msg336729 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-02-27 05:06
I am seeing this error on Windows and Mac CI builds where FTP related tests in test.test_urllib2net.TimeoutTest are failing. It's reproducible locally too where the tests are skipped on Mac and Ubuntu. Not sure if it's random since several PRs in the last few hours fail with this.

Appveyor : 

* https://ci.appveyor.com/project/python/cpython/builds/22675425#L2817

VSTS builds : 

* https://dev.azure.com/Python/cpython/_build/results?buildId=38631
* https://dev.azure.com/Python/cpython/_build/results?buildId=38625

$ ./python.exe -m unittest -vv test.test_urllib2net.TimeoutTest
test_ftp_basic (test.test_urllib2net.TimeoutTest) ... skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_ftp_default_timeout (test.test_urllib2net.TimeoutTest) ... skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_ftp_no_timeout (test.test_urllib2net.TimeoutTest) ... /Users/karthikeyansingaravelan/stuff/python/cpython/Lib/encodings/idna.py:163: ResourceWarning: unclosed <socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.3.111', 49633), raddr=('159.89.235.38', 21)>
  for label in labels[:-1]:
ResourceWarning: Enable tracemalloc to get the object allocation traceback
/Users/karthikeyansingaravelan/stuff/python/cpython/Lib/encodings/idna.py:163: ResourceWarning: unclosed <socket.socket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.3.111', 49635), raddr=('159.89.235.38', 21)>
  for label in labels[:-1]:
ResourceWarning: Enable tracemalloc to get the object allocation traceback
/Users/karthikeyansingaravelan/stuff/python/cpython/Lib/encodings/idna.py:163: ResourceWarning: unclosed <socket.socket fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.3.111', 49639), raddr=('159.89.235.38', 21)>
  for label in labels[:-1]:
ResourceWarning: Enable tracemalloc to get the object allocation traceback
/Users/karthikeyansingaravelan/stuff/python/cpython/Lib/encodings/idna.py:163: ResourceWarning: unclosed <socket.socket fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.3.111', 49641), raddr=('159.89.235.38', 21)>
  for label in labels[:-1]:
ResourceWarning: Enable tracemalloc to get the object allocation traceback
/Users/karthikeyansingaravelan/stuff/python/cpython/Lib/encodings/idna.py:163: ResourceWarning: unclosed <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.3.111', 49643), raddr=('159.89.235.38', 21)>
  for label in labels[:-1]:
ResourceWarning: Enable tracemalloc to get the object allocation traceback
skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_ftp_timeout (test.test_urllib2net.TimeoutTest) ... skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_http_basic (test.test_urllib2net.TimeoutTest) ... ok
test_http_default_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_http_no_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_http_timeout (test.test_urllib2net.TimeoutTest) ... ok

----------------------------------------------------------------------
Ran 8 tests in 33.617s

OK (skipped=4)
msg336730 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-02-27 06:34
Several buildbots are failing due to this problem. Some examples:

https://buildbot.python.org/all/#builders/33/builds/520
https://buildbot.python.org/all/#builders/72/builds/503
https://buildbot.python.org/all/#builders/78/builds/419
msg336731 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-02-27 06:56
These tests were skipped in Travis with issue35411
msg336739 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-02-27 10:41
Right now, ftp://www.pythontest.net/ fails with "500 OOPS: vsf_sysutil_bind" according to Firefox. It's not the first time that I see this error.
msg336740 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-02-27 10:59
> https://buildbot.python.org/all/#builders/33/builds/520

ERROR: test_ftp_basic (test.test_urllib2net.TimeoutTest)
ERROR: test_ftp_default_timeout (test.test_urllib2net.TimeoutTest)
ERROR: test_ftp_no_timeout (test.test_urllib2net.TimeoutTest)
ERROR: test_ftp_timeout (test.test_urllib2net.TimeoutTest)

Example:

ERROR: test_ftp_basic (test.test_urllib2net.TimeoutTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\buildarea\2.7.ware-win81-release.refleak\build\lib\test\test_urllib2net.py", line 300, in test_ftp_basic
    u = _urlopen_with_retry(self.FTP_HOST)
  File "D:\buildarea\2.7.ware-win81-release.refleak\build\lib\test\test_urllib2net.py", line 25, in wrapped
    return _retry_thrice(func, exc, *args, **kwargs)
  File "D:\buildarea\2.7.ware-win81-release.refleak\build\lib\test\test_urllib2net.py", line 21, in _retry_thrice
    raise last_exc
URLError: <urlopen error ftp error: [Errno 10061] No connection could be made because the target machine actively refused it>
msg336741 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-02-27 11:01
$ ./python -m test -v test_urllib2net -u all

...
test_ftp (test.test_urllib2net.OtherNetworkTests) ... skipped "Resource 'ftp://www.pythontest.net/README' is not available"
test_redirect_url_withfrag (test.test_urllib2net.OtherNetworkTests) ... ok
test_sites_no_connection_close (test.test_urllib2net.OtherNetworkTests) ... skipped 'XXX: http://www.imdb.com is gone'
test_urlwithfrag (test.test_urllib2net.OtherNetworkTests) ... ok
test_ftp_basic (test.test_urllib2net.TimeoutTest) ... skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_ftp_default_timeout (test.test_urllib2net.TimeoutTest) ... skipped "Resource 'ftp://www.pythontest.net/' is not available"
test_ftp_no_timeout (test.test_urllib2net.TimeoutTest) ... ERROR
test_ftp_timeout (test.test_urllib2net.TimeoutTest) ... ERROR
...

ERROR: test_ftp_no_timeout (test.test_urllib2net.TimeoutTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 1540, in ftp_open
    fp, retrlen = fw.retrfile(file, type)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 2425, in retrfile
    conn, retrlen = self.ftp.ntransfercmd(cmd)
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 359, in ntransfercmd
    host, port = self.makepasv()
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 337, in makepasv
    host, port = parse227(self.sendcmd('PASV'))
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 273, in sendcmd
    return self.getresp()
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 246, in getresp
    raise error_perm(resp)
ftplib.error_perm: 500 OOPS: vsf_sysutil_bind

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/vstinner/prog/python/master/Lib/test/test_urllib2net.py", line 327, in test_ftp_no_timeout
    u = _urlopen_with_retry(self.FTP_HOST, timeout=None)
  File "/home/vstinner/prog/python/master/Lib/test/test_urllib2net.py", line 27, in wrapped
    return _retry_thrice(func, exc, *args, **kwargs)
  File "/home/vstinner/prog/python/master/Lib/test/test_urllib2net.py", line 23, in _retry_thrice
    raise last_exc
  File "/home/vstinner/prog/python/master/Lib/test/test_urllib2net.py", line 19, in _retry_thrice
    return func(*args, **kwargs)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 525, in open
    response = self._open(req, data)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 542, in _open
    result = self._call_chain(self.handle_open, protocol, protocol +
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 1551, in ftp_open
    raise exc.with_traceback(sys.exc_info()[2])
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 1540, in ftp_open
    fp, retrlen = fw.retrfile(file, type)
  File "/home/vstinner/prog/python/master/Lib/urllib/request.py", line 2425, in retrfile
    conn, retrlen = self.ftp.ntransfercmd(cmd)
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 359, in ntransfercmd
    host, port = self.makepasv()
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 337, in makepasv
    host, port = parse227(self.sendcmd('PASV'))
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 273, in sendcmd
    return self.getresp()
  File "/home/vstinner/prog/python/master/Lib/ftplib.py", line 246, in getresp
    raise error_perm(resp)
urllib.error.URLError: <urlopen error ftp error: error_perm('500 OOPS: vsf_sysutil_bind')>
msg336746 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-02-27 11:45
> Right now, ftp://www.pythontest.net/ fails with "500 OOPS: vsf_sysutil_bind" according to Firefox. It's not the first time that I see this error.

Related issue in the past due to disk space issue35386 . When I first created the issue opening the FTP URL on Firefox used to give me result or raise 425 Bad IP error but now it's now consistently returning "500 OOPS: vsf_sysutil_bind" consistently.
msg336773 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-02-27 17:23
Almost all buildbots have failed due to this issue. It seems that is fixed now:

❯ ./python.exe -m test -v test_urllib2net -u all
== CPython 3.8.0a2+ (heads/master:d5a551c269, Feb 27 2019, 09:17:08) [Clang 10.0.0 (clang-1000.10.44.4)]
== macOS-10.14.3-x86_64-i386-64bit little-endian
== cwd: /Users/pgalindo3/github/cpython/build/test_python_15573
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 load avg: 2.02 [1/1] test_urllib2net
test_close (test.test_urllib2net.CloseSocketTest) ... ok
test_custom_headers (test.test_urllib2net.OtherNetworkTests) ... ok
test_file (test.test_urllib2net.OtherNetworkTests) ... ok
test_ftp (test.test_urllib2net.OtherNetworkTests) ... ok
test_redirect_url_withfrag (test.test_urllib2net.OtherNetworkTests) ... ok
test_sites_no_connection_close (test.test_urllib2net.OtherNetworkTests) ... skipped 'XXX: http://www.imdb.com is gone'
test_urlwithfrag (test.test_urllib2net.OtherNetworkTests) ... ok
test_ftp_basic (test.test_urllib2net.TimeoutTest) ... ok
test_ftp_default_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_ftp_no_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_ftp_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_http_basic (test.test_urllib2net.TimeoutTest) ... ok
test_http_default_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_http_no_timeout (test.test_urllib2net.TimeoutTest) ... ok
test_http_timeout (test.test_urllib2net.TimeoutTest) ... ok

----------------------------------------------------------------------

Ran 15 tests in 9.531s

OK (skipped=1)

== Tests result: SUCCESS ==

1 test OK.

Total duration: 10 sec 17 ms
Tests result: SUCCESS

I am going to re-trigger a build in all affected buildbots.
msg336801 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-02-28 05:14
Just curious if it was some regression or infrastructure related issue in pythontest.net ?
msg336802 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-02-28 05:50
That was my impression.
msg336857 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-02-28 17:42
I discussed with Ernest on #python-infra. It was an issue with the DNS "resolving the host back to 127.0.1.1 (...) so vsftpd is telling users to connect back to themselves".
msg338311 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-03-19 02:27
A similar issue happened again on s390x SLES 2.7:

https://buildbot.python.org/all/#/builders/66/builds/373
History
Date User Action Args
2022-04-11 14:59:11adminsetgithub: 80312
2019-03-19 02:27:43pablogsalsetmessages: + msg338311
2019-02-28 17:42:14vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg336857

stage: resolved
2019-02-28 05:50:12pablogsalsetmessages: + msg336802
2019-02-28 05:14:00xtreaksetmessages: + msg336801
2019-02-27 17:23:35pablogsalsetmessages: + msg336773
2019-02-27 11:45:19xtreaksetmessages: + msg336746
2019-02-27 11:01:18vstinnersetmessages: + msg336741
2019-02-27 10:59:20vstinnersetmessages: + msg336740
2019-02-27 10:41:44vstinnersetmessages: + msg336739
2019-02-27 06:56:51xtreaksetmessages: + msg336731
2019-02-27 06:34:35pablogsalsetpriority: normal -> high
versions: + Python 2.7, Python 3.6, Python 3.7
2019-02-27 06:34:14pablogsalsetmessages: + msg336730
2019-02-27 05:06:02xtreakcreate