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.

Author vstinner
Recipients corona10, erlendaasland, giovanniwijaya, gvanrossum, lukasz.langa, orsenthil, shihai1991, terry.reedy, vstinner
Date 2022-02-02.01:11:38
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1643764299.52.0.018457262934.issue44359@roundup.psfhosted.org>
In-reply-to
Content
On Fedora Rawhide x64-64, I can reproduce the test_ftplib test_makeport() issue in reliable way.

On Python 3.9, the test also logs the exception but the test is marked as a success:
---
$ ./python -m test -u all test_ftplib -v -m test_makeport
(...)
test_makeport (test.test_ftplib.TestFTPClass) ... ok
test_makeport (test.test_ftplib.TestIPv6Environment) ... ok
test_makeport (test.test_ftplib.TestTLS_FTPClassMixin) ... Exception in thread Thread-3:
Traceback (most recent call last):
  File "/home/vstinner/python/3.9/Lib/asyncore.py", line 83, in read
    obj.handle_read_event()
  File "/home/vstinner/python/3.9/Lib/test/test_ftplib.py", line 377, in handle_read_event
    self._do_ssl_handshake()
  File "/home/vstinner/python/3.9/Lib/test/test_ftplib.py", line 338, in _do_ssl_handshake
    self.socket.do_handshake()
  File "/home/vstinner/python/3.9/Lib/ssl.py", line 1309, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLZeroReturnError: TLS/SSL connection has been closed (EOF) (_ssl.c:1129)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/vstinner/python/3.9/Lib/threading.py", line 973, in _bootstrap_inner
    self.run()
  File "/home/vstinner/python/3.9/Lib/test/test_ftplib.py", line 291, in run
    asyncore.loop(timeout=0.1, count=1)
  File "/home/vstinner/python/3.9/Lib/asyncore.py", line 207, in loop
    poll_fun(timeout, map)
  File "/home/vstinner/python/3.9/Lib/asyncore.py", line 150, in poll
    read(obj)
  File "/home/vstinner/python/3.9/Lib/asyncore.py", line 87, in read
    obj.handle_error()
  File "/home/vstinner/python/3.9/Lib/test/test_ftplib.py", line 414, in handle_error
    raise Exception
Exception
ok
(...)
Tests result: SUCCESS
---

make buildbottest uses -W option which hides the test output unless the test failed.

In this case, the unhandled threading exception is siently ignored:
---
$ ./python -m test -u all test_ftplib -W -m test_makeport -j1
(...)
0:00:00 load avg: 0.75 [1/1] test_ftplib passed
(...)
Tests result: SUCCESS
---

On Python 3.10 and newer, libregrtest sets a threading excepthook to (1) log the exception (2) mark that the note "altered the environmen": mark the test as "ENV CHANGED". I did that to detect unhandled exceptions like this one.

In this case, unhandled exceptions come from the four handle_error() method of test_ftplib dispatcher classes, like SSLConnection, which are implemented as:

    def handle_error(self):
        raise Exception

test_ftplib closes sockets in TestFTPClass.tearDown() method:

    def tearDown(self):
        self.client.close()
        self.server.stop()
        # Explicitly clear the attribute to prevent dangling thread
        self.server = None
        asyncore.close_all(ignore_all=True)

The problem is that the code doesn't implement any kind of error handling. If asyncore gets a socket exception, it calls handle_error() which raises an a new Exception instance. That's it.

IMO it's not worth it to bother with handling socket errors in test_ftplib. The server is implemented with asyncore which is deprecated since Python 3.6. The FTP protocol itself is legacy.

Attached PR simply ignores socket erors rather than logging unhandled threading exceptions.
History
Date User Action Args
2022-02-02 01:11:39vstinnersetrecipients: + vstinner, gvanrossum, terry.reedy, orsenthil, lukasz.langa, corona10, shihai1991, erlendaasland, giovanniwijaya
2022-02-02 01:11:39vstinnersetmessageid: <1643764299.52.0.018457262934.issue44359@roundup.psfhosted.org>
2022-02-02 01:11:39vstinnerlinkissue44359 messages
2022-02-02 01:11:38vstinnercreate