[New-bugs-announce] [issue44359] test_ftplib fails as "env changes" if a socket operation times out in a thread: TimeoutError is not catched

STINNER Victor report at bugs.python.org
Wed Jun 9 03:58:31 EDT 2021 

New submission from STINNER Victor <vstinner at python.org>:

test_ftplib fails with "env changed" if a socket operation times out in a thread (in the "dummy FTP server").

Example on AMD64 Fedora Rawhide LTO 3.10:
https://buildbot.python.org/all/#/builders/653/builds/95

0:02:41 load avg: 8.20 [394/427/1] test_ftplib failed (env changed) -- running: test_lib2to3 (33.9 sec), test_peg_generator (2 min 37 sec), test_concurrent_futures (1 min 53 sec), test_gdb (1 min 37 sec)
Warning -- Uncaught thread exception: Exception
Exception in thread Thread-34:
Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asyncore.py", line 83, in read
    obj.handle_read_event()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asyncore.py", line 420, in handle_read_event
    self.handle_read()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asynchat.py", line 171, in handle_read
    self.found_terminator()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/test/test_ftplib.py", line 129, in found_terminator
    method(arg)
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/test/test_ftplib.py", line 154, in cmd_pasv
    conn, addr = sock.accept()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/socket.py", line 293, in accept
    fd, addr = self._accept()
TimeoutError: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/threading.py", line 1006, in _bootstrap_inner
    self.run()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/test/test_ftplib.py", line 292, in run
    asyncore.loop(timeout=0.1, count=1)
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asyncore.py", line 207, in loop
    poll_fun(timeout, map)
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asyncore.py", line 150, in poll
    read(obj)
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/asyncore.py", line 87, in read
    obj.handle_error()
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-x86_64.lto/build/Lib/test/test_ftplib.py", line 134, in handle_error
    raise Exception
Exception

test_abort (test.test_ftplib.TestFTPClass) ... ok
(...)
test__all__ (test.test_ftplib.MiscTestCase) ... ok

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

Ran 94 tests in 8.491s

OK (skipped=2)



A similar issue (is it the same one?) can be reproduced with attached test_ftplib_timeout.patch which sets the timeout to 1 nanosecond and the command:

$ ./python -m test test_ftplib -v --fail-env-changed -m test.test_ftplib.TestFTPClass.test_retrlines
== CPython 3.11.0a0 (heads/main:257e400a19, Jun 8 2021, 18:04:17) [GCC 11.1.1 20210531 (Red Hat 11.1.1-3)]
== Linux-5.12.8-300.fc34.x86_64-x86_64-with-glibc2.33 little-endian
== cwd: /home/vstinner/python/main/build/test_python_129053æ
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
0:00:00 load avg: 1.03 Run tests sequentially
0:00:00 load avg: 1.03 [1/1] test_ftplib
test_retrlines (test.test_ftplib.TestFTPClass) ... Warning -- Uncaught thread exception: Exception
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/home/vstinner/python/main/Lib/asyncore.py", line 83, in read
    obj.handle_read_event()
  File "/home/vstinner/python/main/Lib/asyncore.py", line 420, in handle_read_event
    self.handle_read()
  File "/home/vstinner/python/main/Lib/asynchat.py", line 171, in handle_read
    self.found_terminator()
  File "/home/vstinner/python/main/Lib/test/test_ftplib.py", line 129, in found_terminator
    method(arg)
  File "/home/vstinner/python/main/Lib/test/test_ftplib.py", line 154, in cmd_pasv
    conn, addr = sock.accept()
  File "/home/vstinner/python/main/Lib/socket.py", line 293, in accept
    fd, addr = self._accept()
TimeoutError: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/vstinner/python/main/Lib/threading.py", line 1006, in _bootstrap_inner
    self.run()
  File "/home/vstinner/python/main/Lib/test/test_ftplib.py", line 292, in run
    asyncore.loop(timeout=0.1, count=1)
  File "/home/vstinner/python/main/Lib/asyncore.py", line 207, in loop
    poll_fun(timeout, map)
  File "/home/vstinner/python/main/Lib/asyncore.py", line 150, in poll
    read(obj)
  File "/home/vstinner/python/main/Lib/asyncore.py", line 87, in read
    obj.handle_error()
  File "/home/vstinner/python/main/Lib/test/test_ftplib.py", line 134, in handle_error
    raise Exception
Exception
ERROR

======================================================================
ERROR: test_retrlines (test.test_ftplib.TestFTPClass)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vstinner/python/main/Lib/test/test_ftplib.py", line 598, in test_retrlines
    self.client.retrlines('retr', received.append)
  File "/home/vstinner/python/main/Lib/ftplib.py", line 462, in retrlines
    with self.transfercmd(cmd) as conn, \
  File "/home/vstinner/python/main/Lib/ftplib.py", line 393, in transfercmd
    return self.ntransfercmd(cmd, rest)[0]
  File "/home/vstinner/python/main/Lib/ftplib.py", line 354, in ntransfercmd
    conn = socket.create_connection((host, port), self.timeout,
  File "/home/vstinner/python/main/Lib/socket.py", line 844, in create_connection
    raise err
  File "/home/vstinner/python/main/Lib/socket.py", line 832, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

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

Ran 1 test in 0.021s

FAILED (errors=1)
test test_ftplib failed
test_ftplib failed

== Tests result: FAILURE ==

1 test failed:
    test_ftplib

Total duration: 169 ms
Tests result: FAILURE

----------
components: Tests
files: test_ftplib_timeout.patch
keywords: patch
messages: 395389
nosy: vstinner
priority: normal
severity: normal
status: open
title: test_ftplib fails as "env changes" if a socket operation times out in a thread: TimeoutError is not catched
versions: Python 3.10, Python 3.11
Added file: https://bugs.python.org/file50100/test_ftplib_timeout.patch

_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue44359>
_______________________________________

More information about the New-bugs-announce mailing list