classification
Title: test_logging: "OSError: [Errno 9] Bad file descriptor" logged on FreeBSD
Type: Stage: resolved
Components: Tests Versions: Python 3.10, Python 3.9, Python 3.8
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: vstinner
Priority: normal Keywords: patch

Created on 2021-04-14 11:15 by vstinner, last changed 2021-04-16 14:37 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 25436 merged vstinner, 2021-04-16 12:08
PR 25437 merged vstinner, 2021-04-16 12:36
PR 25440 merged vstinner, 2021-04-16 14:08
Messages (5)
msg391057 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-04-14 11:15
Random error seen on FreeBSD:

0:05:54 load avg: 5.75 [340/427/1] test_logging passed -- running: test_pydoc (34.4 sec)

Exception in thread Thread-25 (serve_forever):
Traceback (most recent call last):
  File "/usr/home/vstinner/python/master/Lib/threading.py", line 990, in _bootstrap_inner
    self.run()
  File "/usr/home/vstinner/python/master/Lib/threading.py", line 928, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/home/vstinner/python/master/Lib/test/test_logging.py", line 863, in serve_forever
    asyncore.loop(poll_interval, map=self._map)
  File "/usr/home/vstinner/python/master/Lib/asyncore.py", line 203, in loop
    poll_fun(timeout, map)
  File "/usr/home/vstinner/python/master/Lib/asyncore.py", line 144, in poll
    r, w, e = select.select(r, w, e, timeout)
OSError: [Errno 9] Bad file descriptor
msg391186 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-04-16 11:58
There is a race condition. The main thread closes a file descriptor which is part of the asyncore loop "map", a thread polls on the asyncore "map" file descriptors.

-- Main thread --

Close a socket:

  File "/usr/home/vstinner/python/master/Lib/test/test_logging.py", line 1072, in test_basic                                                                   
    server.stop()                                                              
  File "/usr/home/vstinner/python/master/Lib/test/test_logging.py", line 870, in stop                                                                          
    self.close()                                                               

-- TestSMTPServer thread --

Wait in asyncore.loop():
                      
Exception in thread Thread-1 (serve_forever):                                                                                                                  
Traceback (most recent call last):                                             
  File "/usr/home/vstinner/python/master/Lib/threading.py", line 990, in _bootstrap_inner                                                                      
    self.run()                                                                 
  File "/usr/home/vstinner/python/master/Lib/threading.py", line 928, in run                                                                                   
    self._target(*self._args, **self._kwargs)                                  
  File "/usr/home/vstinner/python/master/Lib/test/test_logging.py", line 863, in serve_forever                                                                 
    asyncore.loop(poll_interval, map=self._map)                                
  File "/usr/home/vstinner/python/master/Lib/asyncore.py", line 211, in loop                                                                                   
    poll_fun(timeout, map)                                                     
  File "/usr/home/vstinner/python/master/Lib/asyncore.py", line 145, in poll                                                                                   
    r, w, e = select.select(r, w, e, timeout)                                  
OSError: [Errno 9] Bad file descriptor
msg391187 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-04-16 12:32
New changeset 75ec103b3adbb7c619a0e22fa60f3d34c5a9e603 by Victor Stinner in branch 'master':
bpo-43842: Fix race condition in test_logging SMTP test (GH-25436)
https://github.com/python/cpython/commit/75ec103b3adbb7c619a0e22fa60f3d34c5a9e603
msg391200 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-04-16 14:06
New changeset e1903e11a3d42512effe336026e0c67f602e5848 by Victor Stinner in branch '3.9':
bpo-43842: Fix race condition in test_logging SMTP test (GH-25436) (GH-25437)
https://github.com/python/cpython/commit/e1903e11a3d42512effe336026e0c67f602e5848
msg391204 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-04-16 14:37
New changeset 816da333c8ee848dab7c830c561b8df0b8d23915 by Victor Stinner in branch '3.8':
bpo-43842: Fix race condition in test_logging SMTP test (GH-25436) (GH-25437) (GH-25440)
https://github.com/python/cpython/commit/816da333c8ee848dab7c830c561b8df0b8d23915
History
Date User Action Args
2021-04-16 14:37:42vstinnersetstatus: open -> closed
stage: patch review -> resolved
resolution: fixed
versions: + Python 3.8, Python 3.9
2021-04-16 14:37:13vstinnersetmessages: + msg391204
2021-04-16 14:08:56vstinnersetpull_requests: + pull_request24170
2021-04-16 14:06:46vstinnersetmessages: + msg391200
2021-04-16 12:36:39vstinnersetpull_requests: + pull_request24167
2021-04-16 12:32:06vstinnersetmessages: + msg391187
2021-04-16 12:08:57vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request24166
2021-04-16 11:58:36vstinnersetmessages: + msg391186
2021-04-14 11:15:16vstinnercreate