Issue 36131: test.test_urllib2net.TimeoutTest ftp related tests fail due to ftp://www.pythontest.net/ being unavailable (original) (raw)

Issue36131

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
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 . 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:11 admin set github: 80312
2019-03-19 02:27:43 pablogsal set messages: +
2019-02-28 17:42:14 vstinner set status: open -> closedresolution: fixedmessages: + stage: resolved
2019-02-28 05:50:12 pablogsal set messages: +
2019-02-28 05:14:00 xtreak set messages: +
2019-02-27 17:23:35 pablogsal set messages: +
2019-02-27 11:45:19 xtreak set messages: +
2019-02-27 11:01:18 vstinner set messages: +
2019-02-27 10:59:20 vstinner set messages: +
2019-02-27 10:41:44 vstinner set messages: +
2019-02-27 06:56:51 xtreak set messages: +
2019-02-27 06:34:35 pablogsal set priority: normal -> highversions: + Python 2.7, Python 3.6, Python 3.7
2019-02-27 06:34:14 pablogsal set messages: +
2019-02-27 05:06:02 xtreak create