Task statistics collection is racy
Michael Tokarev reported that debusine's CI is repeatedly failing on s390x in https://tracker.debian.org/pkg/qemu. I looked into the test artifacts and found that a piuparts task is failing like this:
```
Apr 29 08:55:11 ci-119-8f3f099c debusine-worker[11188]: Work request 13: Cleaning up
Apr 29 08:55:11 ci-119-8f3f099c debusine-worker[11188]: Uploading /var/lib/debusine/worker/workdir/WR-13-1amm65qn/logs/cmd-output.log to https://ci-119-8f3f099c.localdomain/api/1.0/artifact/19/files/cmd-output.log/
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: Uploading /var/lib/debusine/worker/workdir/WR-13-1amm65qn/logs/install.log to https://ci-119-8f3f099c.localdomain/api/1.0/artifact/19/files/install.log/
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: Server notification channel closed
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: + Exception Group Traceback (most recent call last):
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/bin/debusine-worker", line 8, in <module>
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | sys.exit(entry_point())
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/__main__.py", line 67, in entry_point
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | main(sys.argv[1:])
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/__main__.py", line 62, in main
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | asyncio.run(async_main())
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3.13/asyncio/runners.py", line 195, in run
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | return runner.run(main)
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3.13/asyncio/runners.py", line 118, in run
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | return self._loop.run_until_complete(task)
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3.13/asyncio/base_events.py", line 725, in run_until_complete
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | return future.result()
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~~~^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/__main__.py", line 60, in async_main
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | await worker.main()
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/_worker.py", line 340, in main
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | if event := await self.process_notifications():
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/_worker.py", line 355, in process_notifications
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | async with asyncio.TaskGroup() as tg:
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~~~~~~~^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3.13/asyncio/taskgroups.py", line 71, in __aexit__
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | return await self._aexit(et, exc)
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3.13/asyncio/taskgroups.py", line 173, in _aexit
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | raise BaseExceptionGroup(
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ...<2 lines>...
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ) from None
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: +-+---------------- 1 ----------------
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | Traceback (most recent call last):
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/_worker.py", line 511, in _request_and_execute_work_request
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | result = await runner.execute()
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ^^^^^^^^^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/task_runner.py", line 265, in execute
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | async with CollectStatistics(self.task, self.statistics):
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/task_runner.py", line 110, in __aexit__
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | await self.collect_task
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/task_runner.py", line 118, in collect
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | self.gather()
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | ~~~~~~~~~~~^^
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/worker/task_runner.py", line 89, in gather
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | statistics = self.task.executor.get_statistics(
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | self.task.executor_instance
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | )
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | File "/usr/lib/python3/dist-packages/debusine/tasks/executors/unshare.py", line 134, in get_statistics
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | statvfs = os.statvfs(instance._root)
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: | FileNotFoundError: [Errno 2] No such file or directory: '/var/lib/debusine/worker/workdir/WR-13-1amm65qn/unshare-5d9jdja1/root'
Apr 29 08:55:12 ci-119-8f3f099c debusine-worker[11188]: +------------------------------------
Apr 29 08:55:14 ci-119-8f3f099c systemd[1]: debusine-worker.service: Main process exited, code=exited, status=1/FAILURE
```
The code here looks racy to me. `CollectStatistics.collect` calls `CollectStatistics.gather` in a loop while the task is running, which calls the `get_statistics` method on the executor. But both the unshare and Incus implementations of `get_statistics` have a similar bug: they check `instance.is_started` and then look up various properties of the instance, but because this is running in parallel with the task it's possible that the task will be cleaned up between the `is_started` check and the statistics queries themselves.
All `get_statistics` implementations need to guard against this. It's probably simplest for them to just try the actual statistics queries and catch exceptions, rather than their current look-before-you-leap approach.
issue