"Event loop is closed" error in `_provide_clean_event_loop()`

[link2xt]

The error sometimes happens during the test teardown.

Here is an example of a failure:
https://github.com/deltachat/deltachat-core-rust/actions/runs/5022838715/jobs/9006825246

Slightly cleaned up (removed git clone progress) log:

Failure log

2023-05-19T09:30:28.1963672Z Requested labels: ubuntu-latest
2023-05-19T09:30:28.1964098Z Job defined at: deltachat/deltachat-core-rust/.github/workflows/ci.yml@refs/heads/master
2023-05-19T09:30:28.1964303Z Waiting for a runner to pick up this job...
2023-05-19T09:30:28.4092092Z Job is waiting for a hosted runner to come online.
2023-05-19T09:30:32.4334700Z Job is about to start running on the hosted runner: GitHub Actions 12 (hosted)
2023-05-19T09:30:35.3312448Z Current runner version: '2.304.0'
2023-05-19T09:30:35.3347520Z ##[group]Operating System
2023-05-19T09:30:35.3348307Z Ubuntu
2023-05-19T09:30:35.3348674Z 22.04.2
2023-05-19T09:30:35.3349170Z LTS
2023-05-19T09:30:35.3349597Z ##[endgroup]
2023-05-19T09:30:35.3350020Z ##[group]Runner Image
2023-05-19T09:30:35.3350496Z Image: ubuntu-22.04
2023-05-19T09:30:35.3350915Z Version: 20230507.1
2023-05-19T09:30:35.3351980Z Included Software: https://github.com/actions/runner-images/blob/ubuntu22/20230507.1/images/linux/Ubuntu2204-Readme.md
2023-05-19T09:30:35.3352827Z Image Release: https://github.com/actions/runner-images/releases/tag/ubuntu22%2F20230507.1
2023-05-19T09:30:35.3353982Z ##[endgroup]
2023-05-19T09:30:35.3354554Z ##[group]Runner Image Provisioner
2023-05-19T09:30:35.3355023Z 2.0.171.1
2023-05-19T09:30:35.3355372Z ##[endgroup]
2023-05-19T09:30:35.3357299Z ##[group]GITHUB_TOKEN Permissions
2023-05-19T09:30:35.3358333Z Actions: write
2023-05-19T09:30:35.3358772Z Checks: write
2023-05-19T09:30:35.3359528Z Contents: write
2023-05-19T09:30:35.3360103Z Deployments: write
2023-05-19T09:30:35.3360573Z Discussions: write
2023-05-19T09:30:35.3361006Z Issues: write
2023-05-19T09:30:35.3361408Z Metadata: read
2023-05-19T09:30:35.3361871Z Packages: write
2023-05-19T09:30:35.3362228Z Pages: write
2023-05-19T09:30:35.3362659Z PullRequests: write
2023-05-19T09:30:35.3363121Z RepositoryProjects: write
2023-05-19T09:30:35.3363653Z SecurityEvents: write
2023-05-19T09:30:35.3364091Z Statuses: write
2023-05-19T09:30:35.3364471Z ##[endgroup]
2023-05-19T09:30:35.3369362Z Secret source: Actions
2023-05-19T09:30:35.3370021Z Prepare workflow directory
2023-05-19T09:30:35.4547198Z Prepare all required actions
2023-05-19T09:30:35.4808637Z Getting action download info
2023-05-19T09:30:35.7249563Z Download action repository 'actions/checkout@v3' (SHA:8e5e7e5ab8b370d6c329ec480221332ada57f0ab)
2023-05-19T09:30:36.5159282Z Download action repository 'actions/setup-python@v4' (SHA:57ded4d7d5e986d7296eab16560982c6dd7c923b)
2023-05-19T09:30:37.1693596Z Download action repository 'actions/download-artifact@v3' (SHA:9bc31d5ccc31df68ecc42ccf4149144866c47d8a)
2023-05-19T09:30:37.8234314Z Complete job name: Async Python tests (ubuntu-latest, 3.7)
2023-05-19T09:30:37.9510800Z ##[group]Run actions/checkout@v3
2023-05-19T09:30:37.9511610Z with:
2023-05-19T09:30:37.9511972Z   repository: deltachat/deltachat-core-rust
2023-05-19T09:30:37.9512906Z   token: ***
2023-05-19T09:30:37.9513264Z   ssh-strict: true
2023-05-19T09:30:37.9513743Z   persist-credentials: true
2023-05-19T09:30:37.9514119Z   clean: true
2023-05-19T09:30:37.9514571Z   fetch-depth: 1
2023-05-19T09:30:37.9514847Z   lfs: false
2023-05-19T09:30:37.9515170Z   submodules: false
2023-05-19T09:30:37.9515580Z   set-safe-directory: true
2023-05-19T09:30:37.9515948Z env:
2023-05-19T09:30:37.9516336Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:30:37.9516620Z ##[endgroup]
2023-05-19T09:30:38.3231535Z Syncing repository: deltachat/deltachat-core-rust
2023-05-19T09:30:38.3233732Z ##[group]Getting Git version info
2023-05-19T09:30:38.3234399Z Working directory is '/home/runner/work/deltachat-core-rust/deltachat-core-rust'
2023-05-19T09:30:38.3235058Z [command]/usr/bin/git version
2023-05-19T09:30:38.3380949Z git version 2.40.1
2023-05-19T09:30:38.3422401Z ##[endgroup]
2023-05-19T09:30:38.3452555Z Temporarily overriding HOME='/home/runner/work/_temp/391bc45e-d9af-41b1-942e-e25cfd34c11b' before making global git config changes
2023-05-19T09:30:38.3453724Z Adding repository directory to the temporary git global config as a safe directory
2023-05-19T09:30:38.3454982Z [command]/usr/bin/git config --global --add safe.directory /home/runner/work/deltachat-core-rust/deltachat-core-rust
2023-05-19T09:30:38.3522544Z Deleting the contents of '/home/runner/work/deltachat-core-rust/deltachat-core-rust'
2023-05-19T09:30:38.3527848Z ##[group]Initializing the repository
2023-05-19T09:30:38.3534027Z [command]/usr/bin/git init /home/runner/work/deltachat-core-rust/deltachat-core-rust
2023-05-19T09:30:38.3712980Z hint: Using 'master' as the name for the initial branch. This default branch name
2023-05-19T09:30:38.3713911Z hint: is subject to change. To configure the initial branch name to use in all
2023-05-19T09:30:38.3715558Z hint: of your new repositories, which will suppress this warning, call:
2023-05-19T09:30:38.3715990Z hint: 
2023-05-19T09:30:38.3716460Z hint: 	git config --global init.defaultBranch <name>
2023-05-19T09:30:38.3716772Z hint: 
2023-05-19T09:30:38.3717940Z hint: Names commonly chosen instead of 'master' are 'main', 'trunk' and
2023-05-19T09:30:38.3718541Z hint: 'development'. The just-created branch can be renamed via this command:
2023-05-19T09:30:38.3718863Z hint: 
2023-05-19T09:30:38.3719165Z hint: 	git branch -m <name>
2023-05-19T09:30:38.3719718Z Initialized empty Git repository in /home/runner/work/deltachat-core-rust/deltachat-core-rust/.git/
2023-05-19T09:30:38.3721793Z [command]/usr/bin/git remote add origin https://github.com/deltachat/deltachat-core-rust
2023-05-19T09:30:38.3805279Z ##[endgroup]
2023-05-19T09:30:38.3806252Z ##[group]Disabling automatic garbage collection
2023-05-19T09:30:38.3809769Z [command]/usr/bin/git config --local gc.auto 0
2023-05-19T09:30:38.3861340Z ##[endgroup]
2023-05-19T09:30:38.3862345Z ##[group]Setting up auth
2023-05-19T09:30:38.3879671Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2023-05-19T09:30:38.3931286Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :"
2023-05-19T09:30:38.4427300Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2023-05-19T09:30:38.4450179Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :"
2023-05-19T09:30:38.4770974Z [command]/usr/bin/git config --local http.https://github.com/.extraheader AUTHORIZATION: basic ***
2023-05-19T09:30:38.4833597Z ##[endgroup]
2023-05-19T09:30:38.4834657Z ##[group]Fetching the repository
2023-05-19T09:30:38.4847315Z [command]/usr/bin/git -c protocol.version=2 fetch --no-tags --prune --progress --no-recurse-submodules --depth=1 origin +10b2aa535087ee13ab06b0eb9f60ed24a46b68ea:refs/remotes/origin/master
2023-05-19T09:30:38.8491303Z remote: Enumerating objects: 884, done.        
2023-05-19T09:30:38.8553420Z remote: Counting objects:   0% (1/884)        
2023-05-19T09:30:38.8600882Z remote: Counting objects: 100% (884/884), done.        
2023-05-19T09:30:38.8601266Z remote: Compressing objects:   0% (1/695)        
2023-05-19T09:30:39.0149100Z remote: Compressing objects: 100% (695/695), done.        
2023-05-19T09:30:39.0184866Z Receiving objects:   0% (1/884)
2023-05-19T09:30:39.2552524Z Receiving objects:  98% (867/884)
2023-05-19T09:30:39.2553324Z remote: Total 884 (delta 155), reused 603 (delta 141), pack-reused 0        
2023-05-19T09:30:39.2553683Z Receiving objects:  99% (876/884)
2023-05-19T09:30:39.2553953Z Receiving objects: 100% (884/884)
2023-05-19T09:30:39.2554287Z Receiving objects: 100% (884/884), 2.43 MiB | 10.29 MiB/s, done.
2023-05-19T09:30:39.2555154Z Resolving deltas:   0% (0/155)
2023-05-19T09:30:39.2696293Z Resolving deltas: 100% (155/155), done.
2023-05-19T09:30:39.2904022Z From https://github.com/deltachat/deltachat-core-rust
2023-05-19T09:30:39.2905345Z  * [new ref]         10b2aa535087ee13ab06b0eb9f60ed24a46b68ea -> origin/master
2023-05-19T09:30:39.2969402Z ##[endgroup]
2023-05-19T09:30:39.2970666Z ##[group]Determining the checkout info
2023-05-19T09:30:39.2971454Z ##[endgroup]
2023-05-19T09:30:39.2972410Z ##[group]Checking out the ref
2023-05-19T09:30:39.2973380Z [command]/usr/bin/git checkout --progress --force -B master refs/remotes/origin/master
2023-05-19T09:30:39.3728849Z Reset branch 'master'
2023-05-19T09:30:39.3738570Z branch 'master' set up to track 'origin/master'.
2023-05-19T09:30:39.3744318Z ##[endgroup]
2023-05-19T09:30:39.3803614Z [command]/usr/bin/git log -1 --format='%H'
2023-05-19T09:30:39.3841220Z '10b2aa535087ee13ab06b0eb9f60ed24a46b68ea'
2023-05-19T09:30:39.4310085Z ##[group]Run actions/setup-python@v4
2023-05-19T09:30:39.4310428Z with:
2023-05-19T09:30:39.4310662Z   python-version: 3.7
2023-05-19T09:30:39.4311024Z   check-latest: false
2023-05-19T09:30:39.4311695Z   token: ***
2023-05-19T09:30:39.4311963Z   update-environment: true
2023-05-19T09:30:39.4312262Z   allow-prereleases: false
2023-05-19T09:30:39.4312517Z env:
2023-05-19T09:30:39.4312737Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:30:39.4313267Z ##[endgroup]
2023-05-19T09:30:39.6510728Z ##[group]Installed versions
2023-05-19T09:30:39.6644342Z Successfully set up CPython (3.7.16)
2023-05-19T09:30:39.6645416Z ##[endgroup]
2023-05-19T09:30:39.6797284Z ##[group]Run pip install tox
2023-05-19T09:30:39.6797704Z �[36;1mpip install tox�[0m
2023-05-19T09:30:39.6870868Z shell: /usr/bin/bash -e {0}
2023-05-19T09:30:39.6871996Z env:
2023-05-19T09:30:39.6872298Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:30:39.6872660Z   pythonLocation: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:39.6873071Z   PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib/pkgconfig
2023-05-19T09:30:39.6873478Z   Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:39.6873865Z   Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:39.6874241Z   Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:39.6874623Z   LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib
2023-05-19T09:30:39.6874965Z ##[endgroup]
2023-05-19T09:30:42.7333282Z Collecting tox
2023-05-19T09:30:42.8806678Z   Downloading tox-4.5.1-py3-none-any.whl (148 kB)
2023-05-19T09:30:42.9364504Z      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 149.0/149.0 kB 2.8 MB/s eta 0:00:00
2023-05-19T09:30:43.0565031Z Collecting cachetools>=5.3 (from tox)
2023-05-19T09:30:43.0712649Z   Downloading cachetools-5.3.0-py3-none-any.whl (9.3 kB)
2023-05-19T09:30:43.1165197Z Collecting chardet>=5.1 (from tox)
2023-05-19T09:30:43.1323856Z   Downloading chardet-5.1.0-py3-none-any.whl (199 kB)
2023-05-19T09:30:43.1608953Z      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 199.1/199.1 kB 7.9 MB/s eta 0:00:00
2023-05-19T09:30:43.2132142Z Collecting colorama>=0.4.6 (from tox)
2023-05-19T09:30:43.2279585Z   Downloading colorama-0.4.6-py2.py3-none-any.whl (25 kB)
2023-05-19T09:30:43.2896384Z Collecting filelock>=3.11 (from tox)
2023-05-19T09:30:43.3047409Z   Downloading filelock-3.12.0-py3-none-any.whl (10 kB)
2023-05-19T09:30:43.4314938Z Collecting importlib-metadata>=6.4.1 (from tox)
2023-05-19T09:30:43.4459639Z   Downloading importlib_metadata-6.6.0-py3-none-any.whl (22 kB)
2023-05-19T09:30:43.5148508Z Collecting packaging>=23.1 (from tox)
2023-05-19T09:30:43.5293097Z   Downloading packaging-23.1-py3-none-any.whl (48 kB)
2023-05-19T09:30:43.5374830Z      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.9/48.9 kB 9.2 MB/s eta 0:00:00
2023-05-19T09:30:43.5902526Z Collecting platformdirs>=3.2 (from tox)
2023-05-19T09:30:43.6047133Z   Downloading platformdirs-3.5.1-py3-none-any.whl (15 kB)
2023-05-19T09:30:43.6585628Z Collecting pluggy>=1 (from tox)
2023-05-19T09:30:43.6726563Z   Downloading pluggy-1.0.0-py2.py3-none-any.whl (13 kB)
2023-05-19T09:30:43.7171718Z Collecting pyproject-api>=1.5.1 (from tox)
2023-05-19T09:30:43.7316184Z   Downloading pyproject_api-1.5.1-py3-none-any.whl (12 kB)
2023-05-19T09:30:43.7857066Z Collecting tomli>=2.0.1 (from tox)
2023-05-19T09:30:43.8000456Z   Downloading tomli-2.0.1-py3-none-any.whl (12 kB)
2023-05-19T09:30:43.8463671Z Collecting typing-extensions>=4.5 (from tox)
2023-05-19T09:30:43.8612579Z   Downloading typing_extensions-4.5.0-py3-none-any.whl (27 kB)
2023-05-19T09:30:44.0691919Z Collecting virtualenv>=20.21 (from tox)
2023-05-19T09:30:44.0860314Z   Downloading virtualenv-20.23.0-py3-none-any.whl (3.3 MB)
2023-05-19T09:30:44.3254533Z      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3.3/3.3 MB 13.8 MB/s eta 0:00:00
2023-05-19T09:30:44.4724794Z Collecting zipp>=0.5 (from importlib-metadata>=6.4.1->tox)
2023-05-19T09:30:44.4869047Z   Downloading zipp-3.15.0-py3-none-any.whl (6.8 kB)
2023-05-19T09:30:44.6708304Z Collecting distlib<1,>=0.3.6 (from virtualenv>=20.21->tox)
2023-05-19T09:30:44.6858913Z   Downloading distlib-0.3.6-py2.py3-none-any.whl (468 kB)
2023-05-19T09:30:44.7188761Z      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 468.5/468.5 kB 16.1 MB/s eta 0:00:00
2023-05-19T09:30:45.0830439Z Installing collected packages: distlib, zipp, typing-extensions, tomli, packaging, filelock, colorama, chardet, cachetools, pyproject-api, platformdirs, importlib-metadata, virtualenv, pluggy, tox
2023-05-19T09:30:45.9799127Z Successfully installed cachetools-5.3.0 chardet-5.1.0 colorama-0.4.6 distlib-0.3.6 filelock-3.12.0 importlib-metadata-6.6.0 packaging-23.1 platformdirs-3.5.1 pluggy-1.0.0 pyproject-api-1.5.1 tomli-2.0.1 tox-4.5.1 typing-extensions-4.5.0 virtualenv-20.23.0 zipp-3.15.0
2023-05-19T09:30:46.3211905Z 
2023-05-19T09:30:46.3213767Z [notice] A new release of pip is available: 22.0.4 -> 23.1.2
2023-05-19T09:30:46.3214335Z [notice] To update, run: pip install --upgrade pip
2023-05-19T09:30:46.4849888Z ##[group]Run actions/download-artifact@v3
2023-05-19T09:30:46.4850235Z with:
2023-05-19T09:30:46.4850543Z   name: ubuntu-latest-deltachat-rpc-server
2023-05-19T09:30:46.4850864Z   path: target/debug
2023-05-19T09:30:46.4851106Z env:
2023-05-19T09:30:46.4851331Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:30:46.4851670Z   pythonLocation: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:46.4852082Z   PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib/pkgconfig
2023-05-19T09:30:46.4852509Z   Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:46.4852891Z   Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:46.4853269Z   Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:30:46.4854553Z   LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib
2023-05-19T09:30:46.4854931Z ##[endgroup]
2023-05-19T09:30:46.5718270Z Starting download for ubuntu-latest-deltachat-rpc-server
2023-05-19T09:31:18.2813568Z Directory structure has been setup for the artifact
2023-05-19T09:31:18.2820370Z Total number of files that will be downloaded: 1
2023-05-19T09:31:19.2829798Z Total file count: 1 ---- Processed file #0 (0.0%)
2023-05-19T09:31:19.3266688Z Artifact ubuntu-latest-deltachat-rpc-server was downloaded to /home/runner/work/deltachat-core-rust/deltachat-core-rust/target/debug
2023-05-19T09:31:19.3283755Z Artifact download has finished successfully
2023-05-19T09:31:19.3362138Z ##[group]Run chmod +x target/debug/deltachat-rpc-server
2023-05-19T09:31:19.3362590Z �[36;1mchmod +x target/debug/deltachat-rpc-server�[0m
2023-05-19T09:31:19.3430795Z shell: /usr/bin/bash -e {0}
2023-05-19T09:31:19.3431069Z env:
2023-05-19T09:31:19.3431809Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:31:19.3432149Z   pythonLocation: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3432564Z   PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib/pkgconfig
2023-05-19T09:31:19.3432969Z   Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3433348Z   Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3433727Z   Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3434109Z   LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib
2023-05-19T09:31:19.3434406Z ##[endgroup]
2023-05-19T09:31:19.3571806Z ##[group]Run echo /home/runner/work/deltachat-core-rust/deltachat-core-rust/target/debug >> $GITHUB_PATH
2023-05-19T09:31:19.3572432Z �[36;1mecho /home/runner/work/deltachat-core-rust/deltachat-core-rust/target/debug >> $GITHUB_PATH�[0m
2023-05-19T09:31:19.3636016Z shell: /usr/bin/bash -e {0}
2023-05-19T09:31:19.3636285Z env:
2023-05-19T09:31:19.3636534Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:31:19.3636870Z   pythonLocation: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3637377Z   PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib/pkgconfig
2023-05-19T09:31:19.3637779Z   Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3638167Z   Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3638544Z   Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3638925Z   LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib
2023-05-19T09:31:19.3639219Z ##[endgroup]
2023-05-19T09:31:19.3768955Z ##[group]Run tox -e py
2023-05-19T09:31:19.3769269Z �[36;1mtox -e py�[0m
2023-05-19T09:31:19.3834692Z shell: /usr/bin/bash -e {0}
2023-05-19T09:31:19.3834980Z env:
2023-05-19T09:31:19.3835547Z   RUSTFLAGS: -Dwarnings
2023-05-19T09:31:19.3835906Z   pythonLocation: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3836307Z   PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib/pkgconfig
2023-05-19T09:31:19.3836710Z   Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3837091Z   Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3837466Z   Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.7.16/x64
2023-05-19T09:31:19.3837846Z   LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.7.16/x64/lib
2023-05-19T09:31:19.3838421Z   DCC_NEW_TMP_EMAIL: ***
2023-05-19T09:31:19.3838681Z ##[endgroup]
2023-05-19T09:31:20.2990043Z py: install_deps> python -I -m pip install aiodns aiohttp pytest pytest-asyncio pytest-timeout
2023-05-19T09:31:28.2868021Z .pkg: install_requires> python -I -m pip install 'setuptools>=45' 'setuptools_scm[toml]>=6.2'
2023-05-19T09:31:31.0151406Z .pkg: _optional_hooks> python /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-05-19T09:31:31.3967209Z .pkg: get_requires_for_build_sdist> python /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-05-19T09:31:32.2180306Z .pkg: freeze> python -m pip freeze --all
2023-05-19T09:31:32.7056495Z .pkg: importlib-metadata==6.6.0,packaging==23.1,pip==23.1.2,setuptools==67.7.2,setuptools-scm==7.1.0,tomli==2.0.1,typing_extensions==4.5.0,wheel==0.40.0,zipp==3.15.0
2023-05-19T09:31:32.7064486Z .pkg: build_sdist> python /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-05-19T09:31:32.9239918Z py: install_package_deps> python -I -m pip install aiodns aiohttp
2023-05-19T09:31:34.0865330Z py: install_package> python -I -m pip install --force-reinstall --no-deps /home/runner/work/deltachat-core-rust/deltachat-core-rust/deltachat-rpc-client/.tox/.tmp/package/1/deltachat-rpc-client-0.1.dev1+g10b2aa5.tar.gz
2023-05-19T09:31:42.3358793Z py: freeze> python -m pip freeze --all
2023-05-19T09:31:42.9021674Z py: aiodns==3.0.0,aiohttp==3.8.4,aiosignal==1.3.1,async-timeout==4.0.2,asynctest==0.13.0,attrs==23.1.0,cffi==1.15.1,charset-normalizer==3.1.0,deltachat-rpc-client @ file:///home/runner/work/deltachat-core-rust/deltachat-core-rust/deltachat-rpc-client/.tox/.tmp/package/1/deltachat-rpc-client-0.1.dev1%2Bg10b2aa5.tar.gz#sha256=00c1eaf328300b9a1f8df442339db949a6edd4e23e63cb74e6b89cd7383bbd1b,exceptiongroup==1.1.1,frozenlist==1.3.3,idna==3.4,importlib-metadata==6.6.0,iniconfig==2.0.0,multidict==6.0.4,packaging==23.1,pip==23.1.2,pluggy==1.0.0,pycares==4.3.0,pycparser==2.21,pytest==7.3.1,pytest-asyncio==0.21.0,pytest-timeout==2.1.0,setuptools==67.7.2,tomli==2.0.1,typing_extensions==4.5.0,wheel==0.40.0,yarl==1.9.2,zipp==3.15.0
2023-05-19T09:31:42.9030827Z py: commands[0]> pytest
2023-05-19T09:31:43.7411800Z ============================= test session starts ==============================
2023-05-19T09:31:43.7412732Z platform linux -- Python 3.7.16, pytest-7.3.1, pluggy-1.0.0
2023-05-19T09:31:43.7413118Z cachedir: .tox/py/.pytest_cache
2023-05-19T09:31:43.7413670Z rootdir: /home/runner/work/deltachat-core-rust/deltachat-core-rust/deltachat-rpc-client
2023-05-19T09:31:43.7414052Z configfile: tox.ini
2023-05-19T09:31:43.7414560Z plugins: deltachat-rpc-client-0.1.dev1+g10b2aa5, timeout-2.1.0, asyncio-0.21.0
2023-05-19T09:31:43.7414944Z timeout: 60.0s
2023-05-19T09:31:43.7415207Z timeout method: signal
2023-05-19T09:31:43.7415488Z timeout func_only: False
2023-05-19T09:31:43.7415742Z asyncio: mode=strict
2023-05-19T09:31:43.7416086Z collected 13 items
2023-05-19T09:31:43.7416243Z 
2023-05-19T09:33:09.6068144Z tests/test_something.py .E...........                                    [ 92%]
2023-05-19T09:33:18.3089313Z tests/test_webxdc.py .                                                   [100%]
2023-05-19T09:33:18.3090086Z 
2023-05-19T09:33:18.3091572Z ==================================== ERRORS ====================================
2023-05-19T09:33:18.3092619Z ____________________ ERROR at teardown of test_system_info _____________________
2023-05-19T09:33:18.3093366Z 
2023-05-19T09:33:18.3094081Z     def _provide_clean_event_loop() -> None:
2023-05-19T09:33:18.3094599Z         # At this point, the event loop for the current thread is closed.
2023-05-19T09:33:18.3095191Z         # When a user calls asyncio.get_event_loop(), they will get a closed loop.
2023-05-19T09:33:18.3095953Z         # In order to avoid this side effect from pytest-asyncio, we need to replace
2023-05-19T09:33:18.3096754Z         # the current loop with a fresh one.
2023-05-19T09:33:18.3097238Z         # Note that we cannot set the loop to None, because get_event_loop only creates
2023-05-19T09:33:18.3098276Z         # a new loop, when set_event_loop has not been called.
2023-05-19T09:33:18.3098945Z         policy = asyncio.get_event_loop_policy()
2023-05-19T09:33:18.3099538Z         new_loop = policy.new_event_loop()
2023-05-19T09:33:18.3099902Z >       policy.set_event_loop(new_loop)
2023-05-19T09:33:18.3100135Z 
2023-05-19T09:33:18.3100592Z .tox/py/lib/python3.7/site-packages/pytest_asyncio/plugin.py:460: 
2023-05-19T09:33:18.3101059Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2023-05-19T09:33:18.3101675Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py:1134: in set_event_loop
2023-05-19T09:33:18.3102176Z     self._watcher.attach_loop(loop)
2023-05-19T09:33:18.3102684Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py:889: in attach_loop
2023-05-19T09:33:18.3103159Z     self._do_waitpid_all()
2023-05-19T09:33:18.3103609Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py:959: in _do_waitpid_all
2023-05-19T09:33:18.3104133Z     self._do_waitpid(pid)
2023-05-19T09:33:18.3104611Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py:993: in _do_waitpid
2023-05-19T09:33:18.3105100Z     callback(pid, returncode, *args)
2023-05-19T09:33:18.3105644Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py:204: in _child_watcher_callback
2023-05-19T09:33:18.3106252Z     self.call_soon_threadsafe(transp._process_exited, returncode)
2023-05-19T09:33:18.3106758Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_events.py:736: in call_soon_threadsafe
2023-05-19T09:33:18.3107239Z     self._check_closed()
2023-05-19T09:33:18.3107642Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2023-05-19T09:33:18.3107872Z 
2023-05-19T09:33:18.3108195Z self = <_UnixSelectorEventLoop running=False closed=True debug=False>
2023-05-19T09:33:18.3108646Z 
2023-05-19T09:33:18.3108805Z     def _check_closed(self):
2023-05-19T09:33:18.3109241Z         if self._closed:
2023-05-19T09:33:18.3110494Z >           raise RuntimeError('Event loop is closed')
2023-05-19T09:33:18.3110953Z E           RuntimeError: Event loop is closed
2023-05-19T09:33:18.3111452Z 
2023-05-19T09:33:18.3112081Z /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_events.py:479: RuntimeError
2023-05-19T09:33:18.3112809Z ----------------------------- Captured stderr call -----------------------------
2023-05-19T09:33:18.3113674Z [2023-05-19T09:31:43Z INFO  deltachat_rpc_server] Starting with accounts directory `/tmp/pytest-of-runner/pytest-0/test_system_info0/accounts`.
2023-05-19T09:33:18.3114388Z [2023-05-19T09:31:43Z INFO  deltachat_rpc_server] Creating JSON-RPC API.
2023-05-19T09:33:18.3115094Z --------------------------- Captured stderr teardown ---------------------------
2023-05-19T09:33:18.3115632Z [2023-05-19T09:31:43Z INFO  deltachat_rpc_server] got SIGTERM
2023-05-19T09:33:18.3116092Z =========================== short test summary info ============================
2023-05-19T09:33:18.3117191Z ERROR tests/test_something.py::test_system_info - RuntimeError: Event loop is...
2023-05-19T09:33:18.3117783Z ==================== 13 passed, 1 error in 94.67s (0:01:34) ====================
2023-05-19T09:33:18.3633421Z Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7fbbe8f78290>
2023-05-19T09:33:18.3634002Z Traceback (most recent call last):
2023-05-19T09:33:18.3647159Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_subprocess.py", line 127, in __del__
2023-05-19T09:33:18.3647884Z     self.close()
2023-05-19T09:33:18.3648502Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_subprocess.py", line 104, in close
2023-05-19T09:33:18.3649017Z     proto.pipe.close()
2023-05-19T09:33:18.3649503Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py", line 718, in close
2023-05-19T09:33:18.3650005Z     self.write_eof()
2023-05-19T09:33:18.3650640Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/unix_events.py", line 704, in write_eof
2023-05-19T09:33:18.3651193Z     self._loop.call_soon(self._call_connection_lost, None)
2023-05-19T09:33:18.3651778Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_events.py", line 691, in call_soon
2023-05-19T09:33:18.3652277Z     self._check_closed()
2023-05-19T09:33:18.3652883Z   File "/opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/asyncio/base_events.py", line 479, in _check_closed
2023-05-19T09:33:18.3728614Z ##[error]    raise RuntimeError('Event loop is closed')
2023-05-19T09:33:18.3739537Z RuntimeError: Event loop is closed
2023-05-19T09:33:18.3789949Z py: exit 1 (95.47 seconds) /home/runner/work/deltachat-core-rust/deltachat-core-rust/deltachat-rpc-client> pytest pid=1847
2023-05-19T09:33:18.3836020Z .pkg: _exit> python /opt/hostedtoolcache/Python/3.7.16/x64/lib/python3.7/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-05-19T09:33:18.4393198Z   py: FAIL code 1 (118.61=setup[23.14]+cmd[95.47] seconds)
2023-05-19T09:33:18.4393686Z   evaluation failed :( (118.81 seconds)
2023-05-19T09:33:18.4846387Z ##[error]Process completed with exit code 1.
2023-05-19T09:33:18.4918359Z Post job cleanup.
2023-05-19T09:33:18.6327096Z [command]/usr/bin/git version
2023-05-19T09:33:18.6413776Z git version 2.40.1
2023-05-19T09:33:18.6485874Z Temporarily overriding HOME='/home/runner/work/_temp/198e0afd-acdd-4d76-84e1-8d329f4578bc' before making global git config changes
2023-05-19T09:33:18.6488226Z Adding repository directory to the temporary git global config as a safe directory
2023-05-19T09:33:18.6498871Z [command]/usr/bin/git config --global --add safe.directory /home/runner/work/deltachat-core-rust/deltachat-core-rust
2023-05-19T09:33:18.6572092Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2023-05-19T09:33:18.6627955Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :"
2023-05-19T09:33:18.6987089Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2023-05-19T09:33:18.7032917Z http.https://github.com/.extraheader
2023-05-19T09:33:18.7038470Z [command]/usr/bin/git config --local --unset-all http.https://github.com/.extraheader
2023-05-19T09:33:18.7085401Z [command]/usr/bin/git submodule foreach --recursive sh -c "git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :"
2023-05-19T09:33:18.7670777Z Cleaning up orphan processes

[seifertm]

Thanks for providing the logs and the link to the project sources.

Unfortunately, I cannot reproduce the error locally. After building deltachat-rpc-server I was able to run tox run -- -k test_system_info successfully multiple times on Python 3.7 and Python 3.11.

From the top of my head there are two things you can do. If the error occurs with Python 3.7 only, you may consider testing with Python 3.8. Major parts of asyncio have been rewritten in Python 3.8 and Python 3.7 will reach end-of-life in roughly 6 weeks.

Alternatively, you can try to isolate the error in a simpler example. Your setup is quite complex and involves building executables and creating online accounts to run the tests. If you can create a minimal example that reproduces the issue, chances are much higher that we can help you.

[link2xt]

I also cannot reproduce it locally, it happens randomly on GitHub Actions. Maybe GitHub runner pauses the processes or otherwise triggers race conditions that do not happen when you run the tests on a dev machine.

I mostly hoped that something can be figured out of the backtrace.

This seems to be somehow related to having a subprocess, and deltachat-rpc-client Python library indeed starts a deltachat-rpc-server Rust binary as a subprocess.

The backtrace in a better form:

• asyncio/unix_events.py:1134: in _UnixDefaultEventLoopPolicy.set_event_loop, call self._watcher.attach_loop(loop)
• asyncio/unix_events.py:889: in BaseChildWatcher.attach_loop(), call self._do_waitpid_all()
• asyncio/unix_events.py:959: in SafeChildWatcher._do_waitpid_all(), call self._do_waitpid(pid)
• asyncio/unix_events.py:993: in SafeChildWatcher._do_waitpid(), call callback(pid, returncode, *args)
• asyncio/unix_events.py:204: in _UnixSelectorEventLoop._child_watcher_callback(), call self.call_soon_threadsafe(transp._process_exited, returncode)
• asyncio/base_events.py:736: in BaseEventLoop.call_soon_threadsafe(): self._check_closed()

So attach_loop of the child watcher is called here:
https://github.com/python/cpython/blob/v3.7.16/Lib/asyncio/unix_events.py#L1134

Then new loop is set and _do_waitpid_all is called: https://github.com/python/cpython/blob/v3.7.16/Lib/asyncio/unix_events.py#L887-L889
Note the comment about the race condition.

Apparently this race condition happens and a child indeed terminated but was not handled while previous loop was set. So we are handling it now, right after switching to a new loop.

A child handler callback is called, which is actually a _child_watcher_callback. This callback only calls self.call_soon_threadsafe which expects the current loop to be open. And it indeed should be open because we have just created and set it. I don't understand what is wrong there.

[link2xt]

There is indeed something different about how setting event loop is handled in Python 3.7. I have created an example:

import subprocess
import asyncio
import time
import signal

async def main():
    policy = asyncio.get_event_loop_policy()
    new_loop = policy.new_event_loop()

    subprocess = await asyncio.create_subprocess_exec("sleep", "5")
    policy.set_event_loop(new_loop)

if __name__ == "__main__":
    asyncio.run(main())

This produces a warning "RuntimeWarning: A loop is being detached from a child watcher with pending handlers" with Python 3.7, but not with Python 3.8.

The warning about loop being detached is produced when the loop is set to None:
https://github.com/python/cpython/blob/v3.7.16/Lib/asyncio/unix_events.py#L874-L878

So somehow with Python 3.7 policy.set_event_loop() is setting the loop to None in this case. This is different from the bug observed in the log though, where the loop is not None, but closed. Maybe old loop is used for some reason.

One difference I see comparing 3.8.0 to 3.7.16 is that default child watcher is changed to ThreadedChildWatcher. As of 3.11 it is still the default child watcher: https://docs.python.org/3.11/library/asyncio-policy.html
The change was introduced in python/cpython#14344
It is indeed a big difference, I will try to replace Python 3.7 with Python 3.8 as the minimum supported version and see if this error appears.

As for pytest-asyncio, maybe it is possible to somehow avoid setting global/thread-local variables and make it less stateful to avoid such problems on the architectural level? Just a thought, I did not even read the whole asyncio documentation.

[link2xt]

I am going to drop support for Python 3.7 at chatmail/core#4410

If getting rid of set_event_loop() call is not feasible, feel free to close the issue.

[seifertm]

Thanks for the thorough investigation and summary!

This sounds like a duplicate of #114. The issue was closed a couple of months ago, because it's unlikely that anyone is going to backport the asyncio.ThreadedChildWatcher to Python 3.7.

As for pytest-asyncio, maybe it is possible to somehow avoid setting global/thread-local variables and make it less stateful to avoid such problems on the architectural level? Just a thought, I did not even read the whole asyncio documentation.

If getting rid of set_event_loop() call is not feasible, feel free to close the issue.

Right now, pytest-asyncio uses get_event_loop() during setup of the event_loop fixture. Unfortunately, get_event_loop creates a new loop when no loop has been set or returns the old loop when set_event_loop was called. The goal is to get rid of both get_event_loop and set_event_loop calls, especially due to recent changes to get_event_loop. [0]

The problem is that pytest-asyncio currently uses _get_event_loop to clean up unclosed event loops for the users. Technically, this is "bad loop hygene", but we cannot just remove the functionality without warning. Therefore, pytest-asyncio emits a DeprecationWarning since v0.21 when it closes an event loop for the user. The plan is to remove that functionality in future versions of pytest-asyncio.

I'll close this as a duplicate of #114. Feel free to continue the discussion, though.

[0] python/cpython#93453