Unclosed socket in urllib when ftp request times out after connect

[cmaloney]

Bug report

Bug description:

Spotted in the log of "Log from "buildbot/ARM64 macOS 3.x"; this doesn't fix the ftp test but when the operation times out in the test CPython should close the socket

This seems to be originating here:

cpython/Lib/urllib/request.py

Lines 1539 to 1556 in f5394c2

	fw = self.connect_ftp(user, passwd, host, port, dirs, req.timeout)
	type = file and 'I' or 'D'
	for attr in attrs:
	attr, value = _splitvalue(attr)
	if attr.lower() == 'type' and \
	value in ('a', 'A', 'i', 'I', 'd', 'D'):
	type = value.upper()
	fp, retrlen = fw.retrfile(file, type)
	headers = ""
	mtype = mimetypes.guess_type(req.full_url)[0]
	if mtype:
	headers += "Content-type: %s\n" % mtype
	if retrlen is not None and retrlen >= 0:
	headers += "Content-length: %d\n" % retrlen
	headers = email.message_from_string(headers)
	return addinfourl(fp, headers, req.full_url)
	except ftplib.all_errors as exp:
	raise URLError(f"ftp error: {exp}") from exp

In particular, fw = self.connect_ftp succeeds which means fw contains an open connection but fp, retrlen = fw.retrfile(file, type) fails and the except doesn't result in a fw.close().

Log from "buildbot/ARM64 macOS 3.x"

Exception ignored while finalizing socket <socket.socket fd=6, family=2, type=1, proto=6, laddr=('192.168.0.101', 57993), raddr=('68.183.26.59', 21)>:
Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1546, in ftp_open
    fp, retrlen = fw.retrfile(file, type)
                  ~~~~~~~~~~~^^^^^^^^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1826, in retrfile
    conn, retrlen = self.ftp.ntransfercmd(cmd)
                    ~~~~~~~~~~~~~~~~~~~~~^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/ftplib.py", line 354, in ntransfercmd
    conn = socket.create_connection((host, port), self.timeout,
                                    source_address=self.source_address)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/socket.py", line 879, in create_connection
    raise exceptions[0]
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/socket.py", line 864, in create_connection
    sock.connect(sa)
    ~~~~~~~~~~~~^^^^
TimeoutError: [Errno 60] Operation timed out

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/test/test_urllib2net.py", line 20, in _retry_thrice
    return func(*args, **kwargs)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 187, in urlopen
    return opener.open(url, data, timeout)
           ~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 487, in open
    response = self._open(req, data)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 504, in _open
    result = self._call_chain(self.handle_open, protocol, protocol +
                              '_open', req)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 464, in _call_chain
    result = func(*args)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1556, in ftp_open
    raise URLError(f"ftp error: {exp}") from exp
urllib.error.URLError: <urlopen error ftp error: [Errno 60] Operation timed out>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/test/test_urllib2net.py", line 22, in _retry_thrice
    last_exc = e
    ^^^^^^^^
ResourceWarning: unclosed <socket.socket fd=6, family=2, type=1, proto=6, laddr=('192.168.0.101', 57993), raddr=('68.183.26.59', 21)>
Warning -- Unraisable exception
Exception ignored while finalizing socket <socket.socket fd=8, family=2, type=1, proto=6, laddr=('192.168.0.101', 58055), raddr=('68.183.26.59', 21)>:
Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1546, in ftp_open
    fp, retrlen = fw.retrfile(file, type)
                  ~~~~~~~~~~~^^^^^^^^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1826, in retrfile
    conn, retrlen = self.ftp.ntransfercmd(cmd)
                    ~~~~~~~~~~~~~~~~~~~~~^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/ftplib.py", line 354, in ntransfercmd
    conn = socket.create_connection((host, port), self.timeout,
                                    source_address=self.source_address)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/socket.py", line 879, in create_connection
    raise exceptions[0]
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/socket.py", line 864, in create_connection
    sock.connect(sa)
    ~~~~~~~~~~~~^^^^
TimeoutError: [Errno 60] Operation timed out

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/test/test_urllib2net.py", line 20, in _retry_thrice
    return func(*args, **kwargs)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 187, in urlopen
    return opener.open(url, data, timeout)
           ~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 487, in open
    response = self._open(req, data)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 504, in _open
    result = self._call_chain(self.handle_open, protocol, protocol +
                              '_open', req)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 464, in _call_chain
    result = func(*args)
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/urllib/request.py", line 1556, in ftp_open
    raise URLError(f"ftp error: {exp}") from exp
urllib.error.URLError: <urlopen error ftp error: [Errno 60] Operation timed out>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.pablogsal-macos-m1.macos-with-brew/build/Lib/test/test_urllib2net.py", line 22, in _retry_thrice
    last_exc = e
    ^^^^^^^^
ResourceWarning: unclosed <socket.socket fd=8, family=2, type=1, proto=6, laddr=('192.168.0.101', 58055), raddr=('68.183.26.59', 21)>

CPython versions tested on:

CPython main branch

Operating systems tested on:

macOS

Linked PRs

• gh-140691: Close FTP connection on error in urllib.request #140694
• gh-140691: urllib.request: Close FTP control socket if data socket can't connect #140835
• [3.14] gh-140691: urllib.request: Close FTP control socket if data socket can't connect (GH-140835) #141555
• [3.13] gh-140691: urllib.request: Close FTP control socket if data socket can't connect (GH-140835) #141657

[encukou]

Just investigating this too!

The issue happens when the control connection (port 21) succeeds but the data connection (to a port specified by the server, in the PASV response) times out.

Here's a quick patch to simulate this without firewall:

diff --git a/Lib/socket.py b/Lib/socket.py
index 3073c012b19..78b88ff1866 100644
--- a/Lib/socket.py
+++ b/Lib/socket.py
@@ -861,6 +861,9 @@ def create_connection(address, timeout=_GLOBAL_DEFAULT_TIMEOUT,
                 sock.settimeout(timeout)
             if source_address:
                 sock.bind(source_address)
+            print(f'{port=}')
+            if port != 21:
+                raise TimeoutError('Operation timed out')
             sock.connect(sa)
             # Break explicitly a reference cycle
             exceptions.clear()

And here's a test (for OtherNetworkTests in test/test_urllib2net.py):

    @support.requires_resource('walltime')
    def test_ftp_no_leak(self):
        # gh-140691: When the data connection (but not control connection)
        # cannot be made established, we should not leak resources.
        # This test simulates the situation, relying on normal leak detection
        # to catch the issue.

        orig_create_connection = socket.create_connection
        def patched_create_connection(address, *args, **kwargs):
            """Simulate REJECTing connections to ports other than 21"""
            host, port = address
            if port != 21:
                raise TimeoutError('Artificial timeout')
            return orig_create_connection(address, *args, **kwargs)

        with mock.patch('socket.create_connection', patched_create_connection):
            with self.assertRaises(TimeoutError):
                self._test_urls(['ftp://www.pythontest.net/README'],
                                self._extra_handlers())

[encukou]

The merged PR adds a test that is skipped on PPC64LE. The failure seems to be specific to the buildbot worker. That test should be fixed and un-skipped.