Skip to content

Skip cleaning named disp - #867

Draft
ben-grande wants to merge 12 commits into
QubesOS:mainfrom
ben-grande:skip-cleaning-named-disp
Draft

ben-grande wants to merge 12 commits into
QubesOS:mainfrom
ben-grande:skip-cleaning-named-disp

Conversation

@ben-grande

@ben-grande ben-grande commented Aug 10, 2026

Copy link
Copy Markdown
Contributor

See commit messages.

Fixes: QubesOS/qubes-issues#11042
Fixes: QubesOS/qubes-issues#10928


Tests locally with:

% cat ~/run-tests
#!/bin/sh
set -eu
exit_trap(){
  systemctl restart qubesd
}
trap exit_trap EXIT
systemctl stop qubesd
sudo -E python3 -m qubes.tests.run "$@"
% ~/run-tests -o /dev/stdout -L INFO qubes.tests.integ.dispvm/TC_10_DispVM_Misc/test_

@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm

@codecov

codecov Bot commented Aug 10, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 20.75472% with 84 lines in your changes missing coverage. Please review.
✅ Project coverage is 70.62%. Comparing base (109bc0b) to head (36faf42).
⚠️ Report is 19 commits behind head on main.

Files with missing lines Patch % Lines
qubes/vm/qubesvm.py 15.78% 32 Missing ⚠️
qubes/vm/dispvm.py 11.53% 23 Missing ⚠️
qubes/log.py 5.88% 16 Missing ⚠️
qubes/tools/qmemmand.py 0.00% 12 Missing ⚠️
qubes/vm/mix/dvmtemplate.py 0.00% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #867      +/-   ##
==========================================
- Coverage   70.72%   70.62%   -0.11%     
==========================================
  Files          61       61              
  Lines       14315    14418     +103     
==========================================
+ Hits        10124    10182      +58     
- Misses       4191     4236      +45     
Flag Coverage Δ
unittests 70.62% <20.75%> (-0.11%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@qubesos-bot

qubesos-bot commented Aug 10, 2026

Copy link
Copy Markdown

OpenQA test summary

Complete test suite and dependencies: https://openqa.qubes-os.org/tests/overview?distri=qubesos&version=4.3&build=202609100837-devel&flavor=pull-requests

Test run included the following:

Upload failures

  • system_tests_qrexec_perf@hw1
    • system_tests: wait_serial (unknown)
      # Command: testfunc qubes.tests.integ.qrexec_perf...

    • system_tests: Failed (test died + timed out)
      # Test died: command 'testfunc qubes.tests.integ.qrexec_perf' timed...

New failures, excluding unstable

Compared to: https://openqa.qubes-os.org/tests/overview?distri=qubesos&version=4.3&build=2026050504-devel&flavor=update

  • system_tests_audio

  • system_tests_gpu_passthrough@hw13

    • gpu_passthrough: Failed (test died)
      # Test died: command 'ansible-playbook -i inventory -e pci_devices=...

Failed tests

6 failures
  • system_tests_whonix

    • [unstable] whonixcheck: fail (unknown)
      Whonixcheck for anon-whonix failed...

    • [unstable] whonixcheck: Failed (test died)
      # Test died: systemcheck failed at qubesos/tests/whonixcheck.pm lin...

  • system_tests_basic_vm_qrexec_gui

  • system_tests_network_updates

    • [unstable] TC_00_Dom0Upgrade_whonix-gateway-18: test_001_update_check (failure)
      ^... AssertionError: '' is not true
  • system_tests_audio

  • system_tests_gpu_passthrough@hw13

    • gpu_passthrough: Failed (test died)
      # Test died: command 'ansible-playbook -i inventory -e pci_devices=...

Fixed failures

Compared to: https://openqa.qubes-os.org/tests/176874#dependencies

38 fixed
  • system_tests_pvgrub_salt_storage

    • system_tests: Fail (unknown)
      Tests qubes.tests.integ.grub failed (exit code 1), details reported...

    • system_tests: Failed (test died)
      # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...

    • TC_41_HVMGrub_debian-13-xfce: test_000_standalone_vm (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_41_HVMGrub_debian-13-xfce: test_001_standalone_vm_dracut (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_41_HVMGrub_debian-13-xfce: test_010_template_based_vm (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_41_HVMGrub_debian-13-xfce: test_011_template_based_vm_dracut (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_41_HVMGrub_fedora-43-xfce: test_010_template_based_vm (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

  • system_tests_extra

    • system_tests: Fail (unknown)
      Tests qubes.tests.extra failed (exit code 1), details reported sepa...

    • system_tests: Failed (test died)
      # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...

    • TC_01_InputProxyExclude_debian-13-xfce: test_000_qemu_tablet (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_01_InputProxyExclude_fedora-43-xfce: test_000_qemu_tablet (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

    • TC_00_QVCTest_fedora-43-xfce: test_010_screenshare (failure + cleanup)
      ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^... AssertionError: 1179648 != 0

    • TC_00_QVCTest_whonix-gateway-18: test_010_screenshare (failure + cleanup)
      AssertionError: 2.3156185715769593 not less than 2.0

    • TC_00_PDFConverter_fedora-43-xfce: test_004_cancel_stops_conversion (failure)
      AssertionError: DispVM not cleaned up 10s after cancel: {<DispVM at...

  • system_tests_usbproxy

    • system_tests: Fail (unknown)
      Tests qubes.tests.extra failed (exit code 1), details reported sepa...

    • system_tests: Failed (test died)
      # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...

    • system_tests: wait_serial (wait serial expected)
      # wait_serial expected: qr/h3uXO-\d+-/...

    • TC_20_USBProxy_core3_fedora-43-xfce: test_090_attach_stubdom (error)
      qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...

  • system_tests_network_ipv6

    • system_tests: Fail (unknown)
      Tests qubes.tests.integ.network_ipv6 failed (exit code 1), details ...

    • system_tests: Failed (test died)
      # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...

    • VmIPv6Networking_fedora-43-xfce: test_001_simple_networking_paused_from_none_to_existent (error)
      raise TimeoutError from exc_val... TimeoutError

  • system_tests_audio

  • system_tests_audio@hw1

    • system_tests: Fail (unknown)
      Tests qubes.tests.integ.audio failed (exit code 1), details reporte...

    • system_tests: Failed (test died)
      # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...

    • TC_20_AudioVM_Pulse_debian-13-xfce: test_222_audio_rec_unmuted_pulseaudio (failure)
      AssertionError: only silence detected, no useful audio data

  • system_tests_guivm_gpu_gui_interactive@hw13

    • shutdown: unnamed test (unknown)
    • shutdown: Failed (test died)
      # Test died: no candidate needle with tag(s) 'text-logged-in-root' ...
  • system_tests_whonix@hw1

    • whonixcheck: fail (unknown)
      Whonixcheck for sys-whonix failed...

    • whonixcheck: Failed (test died)
      # Test died: systemcheck failed at qubesos/tests/whonixcheck.pm lin...

  • system_tests_qwt_win10@hw13

    • windows_install: Failed (test died)
      # Test died: Install failed with code 1 at qubesos/tests/windows_in...
  • system_tests_qwt_win10_seamless@hw13

    • windows_clipboard_and_filecopy: unnamed test (unknown)
    • windows_clipboard_and_filecopy: Failed (test died)
      # Test died: no candidate needle with tag(s) 'windows-Edge-address-...
  • system_tests_qwt_win11@hw13

    • windows_install: Failed (test died)
      # Test died: Install failed with code 1 at qubesos/tests/windows_in...

Unstable tests

Details
  • system_tests_whonix

    whonixcheck/Failed (1/5 times with errors)
    • job 195145 # Test died: command 'qvm-run -ap anon-whonix 'LC_ALL=C whonixchec...
    whonixcheck/Failed (1/5 times with errors)
    • job 194984 # Test died: command 'qvm-run -ap whonix-gateway-18 'LC_ALL=C whon...
    whonixcheck/fail (1/5 times with errors)
    • job 194984 Whonixcheck for anon-whonix failed...
    whonixcheck/wait_serial (1/5 times with errors)
    • job 195145 # Command: qvm-run -ap anon-whonix 'LC_ALL=C whonixcheck --verbose...
    whonixcheck/wait_serial (1/5 times with errors)
    • job 194984 # Command: qvm-run -ap whonix-gateway-18 'LC_ALL=C whonixcheck --v...
  • system_tests_basic_vm_qrexec_gui

    system_tests/Fail (1/5 times with errors)
    • job 195163 Tests qubes.tests.integ.basic failed (exit code 1), details reporte...
    system_tests/Failed (1/5 times with errors)
    • job 195163 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_30_Gui_daemon/test_002_clipboard_300k (1/5 times with errors)
    • job 195163 : Clipboard copy operation failed - content...
  • system_tests_pvgrub_salt_storage

    system_tests/Failed (1/5 times with errors)
    • job 195016 # Test died: command 'curl --form upload=@nose2-junit.xml --form up...
  • system_tests_splitgpg

    system_tests/Failed (1/5 times with errors)
    • job 195018 # Test died: command 'curl --form upload=@tests-qubes.tests.extra.l...
  • system_tests_extra

    system_tests/Fail (1/5 times with errors)
    • job 194433 Tests qubes.tests.extra failed (exit code 1), details reported sepa...
    system_tests/Failed (1/5 times with errors)
    • job 195170 # Test died: command 'testfunc qubes.tests.extra' timed out...
    system_tests/Failed (1/5 times with errors)
    • job 194433 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_00_PDFConverter_debian-13-xfce/test_004_cancel_stops_conversion (1/5 times with errors)
    • job 194433 AssertionError: DispVM not cleaned up 10s after cancel: {<DispVM at...
    TC_00_PDFConverter_fedora-44-xfce/test_004_cancel_stops_conversion (1/5 times with errors)
    • job 194433 AssertionError: DispVM not cleaned up 10s after cancel: {<DispVM at...
    system_tests/wait_serial (1/5 times with errors)
    • job 195170 # Command: testfunc qubes.tests.extra...
  • system_tests_gui_interactive

    clipboard_and_web/ (1/5 times with errors)
    clipboard_and_web/Failed (1/5 times with errors)
    • job 195010 # Test died: no candidate needle with tag(s) 'personal-firefox' mat...
  • system_tests_guivm_gui_interactive

    clipboard_and_web/ (1/5 times with errors)
    clipboard_and_web/Failed (1/5 times with errors)
    • job 195012 # Test died: no candidate needle with tag(s) 'personal-firefox' mat...
  • system_tests_usbproxy

    system_tests/Fail (1/5 times with errors)
    • job 195144 Tests qubes.tests.extra failed (exit code 1), details reported sepa...
    system_tests/Failed (1/5 times with errors)
    • job 195144 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_20_USBProxy_core3_fedora-44-xfce/test_030_detach (1/5 times with errors)
    • job 195144 qubesusbproxy.core3ext.QubesUSBException: Device detach failed: 20...
  • system_tests_qrexec

    system_tests/Fail (1/5 times with errors)
    • job 195017 Tests qubes.tests.integ.qrexec failed (exit code 1), details report...
    system_tests/Failed (1/5 times with errors)
    • job 195017 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_00_Qrexec_whonix-gateway-18/test_055_qrexec_dom0_service_abort (1/5 times with errors)
    • job 195017 AssertionError: Timeout, probably stdout wasn't closed
  • system_tests_network_ipv6

    system_tests/Failed (1/5 times with errors)
    • job 195175 # Test died: command 'curl --form upload=@tests-qubes.tests.integ.n...
  • system_tests_network_updates

    system_tests/Fail (3/5 times with errors)
    • job 194439 Tests qubes.tests.integ.dom0_update failed (exit code 1), details r...
    • job 194790 Tests qubes.tests.integ.dom0_update failed (exit code 1), details r...
    • job 195176 Tests qubes.tests.integ.dom0_update failed (exit code 1), details r...
    system_tests/Fail (1/5 times with errors)
    • job 194439 Tests qubes.tests.integ.vm_update failed (exit code 1), details rep...
    system_tests/Failed (2/5 times with errors)
    • job 194790 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    • job 195176 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    system_tests/Failed (1/5 times with errors)
    • job 194439 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_00_Dom0Upgrade_whonix-gateway-18/test_000_update (2/5 times with errors)
    • job 194790 Error: Failed to download metadata for repo 'test': Cannot download...
    • job 195176 Error: Failed to download metadata for repo 'test': Cannot download...
    TC_00_Dom0Upgrade_whonix-gateway-18/test_001_update_check (1/5 times with errors)
    TC_00_Dom0Upgrade_whonix-gateway-18/test_006_update_flag_clear (1/5 times with errors)
    • job 194790 Error: Failed to download metadata for repo 'test': Cannot download...
    TC_11_QvmTemplateMgmtVM_fedora-44-xfce/test_010_template_install (1/5 times with errors)
    • job 195176 AssertionError: qvm-template failed: [Qrexec] ERROR: dnf command is...
    VmUpdates_fedora-44-xfce/test_120_updates_available_notification_qubes_vm_update (1/5 times with errors)
    • job 194439 subprocess.CalledProcessError: Command '/usr/lib/qubes/upgrades-sta...
  • system_tests_kde_gui_interactive

    clipboard_and_web/ (1/5 times with errors)
    clipboard_and_web/ (1/5 times with errors)
    clipboard_and_web/Failed (1/5 times with errors)
    • job 194988 # Test died: no candidate needle with tag(s) 'personal-firefox' mat...
    clipboard_and_web/Failed (1/5 times with errors)
    • job 195149 # Test died: no candidate needle with tag(s) 'personal-firefox' mat...
  • system_tests_guivm_vnc_gui_interactive

    guivm_manager/ (1/5 times with errors)
    simple_gui_apps/ (1/5 times with errors)
    guivm_manager/Failed (1/5 times with errors)
    • job 194416 # Test died: no candidate needle with tag(s) 'vm-settings-applicati...
    guivm_startup/Failed (1/5 times with errors)
    • job 194992 # Test died: command 'qvm-start --skip-if-running sys-gui-vnc' time...
    simple_gui_apps/Failed (1/5 times with errors)
    • job 194767 # Test died: no candidate needle with tag(s) 'work-evince, work-atr...
    guivm_manager/Stall detected (1/5 times with errors)
    • job 194416 Stall was detected during assert_screen fail...
    guivm_startup/wait_serial (1/5 times with errors)
    • job 194992 # Command: qvm-start --skip-if-running sys-gui-vnc...
    guivm_startup/wait_serial (1/5 times with errors)
    • job 194992 # Command: qvm-run --no-gui -p -u root sys-gui-vnc 'cat /home/user/...
  • system_tests_gui_interactive@hw7

    clipboard_and_web/ (1/5 times with errors)
    clipboard_and_web/Failed (1/5 times with errors)
    • job 195010 # Test died: no candidate needle with tag(s) 'personal-firefox' mat...
  • system_tests_whonix@hw1

    whonixcheck/Failed (1/5 times with errors)
    • job 195145 # Test died: command 'qvm-run -ap anon-whonix 'LC_ALL=C whonixchec...
    whonixcheck/Failed (1/5 times with errors)
    • job 194984 # Test died: command 'qvm-run -ap whonix-gateway-18 'LC_ALL=C whon...
    whonixcheck/fail (1/5 times with errors)
    • job 194984 Whonixcheck for anon-whonix failed...
    whonixcheck/wait_serial (1/5 times with errors)
    • job 195145 # Command: qvm-run -ap anon-whonix 'LC_ALL=C whonixcheck --verbose...
    whonixcheck/wait_serial (1/5 times with errors)
    • job 194984 # Command: qvm-run -ap whonix-gateway-18 'LC_ALL=C whonixcheck --v...
  • system_tests_basic_vm_qrexec_gui_ext4

    system_tests/Fail (1/5 times with errors)
    • job 195165 Tests qubes.tests.integ.vm_qrexec_gui failed (exit code 1), details...
    system_tests/Failed (1/5 times with errors)
    • job 195165 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_20_NonAudio_fedora-44-xfce-pool/test_500_gui_agent_env_sync (1/5 times with errors)
    • job 195165 qubes.exc.QubesVMError: Cannot connect to qrexec agent for 120 seco...
  • system_tests_basic_vm_qrexec_gui@hw7

    system_tests/Fail (1/5 times with errors)
    • job 195163 Tests qubes.tests.integ.basic failed (exit code 1), details reporte...
    system_tests/Failed (1/5 times with errors)
    • job 195163 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_30_Gui_daemon/test_002_clipboard_300k (1/5 times with errors)
    • job 195163 : Clipboard copy operation failed - content...
  • system_tests_dispvm

    system_tests/Fail (4/5 times with errors)
    • job 194432 Tests qubes.tests.integ.dispvm failed (exit code 1), details report...
    • job 194783 Tests qubes.tests.integ.dispvm failed (exit code 1), details report...
    • job 195008 Tests qubes.tests.integ.dispvm failed (exit code 1), details report...
    • job 195169 Tests qubes.tests.integ.dispvm failed (exit code 1), details report...
    system_tests/Failed (4/5 times with errors)
    • job 194432 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    • job 194783 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    • job 195008 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    • job 195169 # Test died: Some tests failed at qubesos/tests/system_tests.pm lin...
    TC_21_DispVM_Preload/test_012_preload_low_mem_early_startup (4/5 times with errors)
    • job 194432 ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^... AssertionError: 0 != 2
    • job 194783 ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^... AssertionError: 0 != 2
    • job 195008 ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^... AssertionError: 0 != 2
    • job 195169 ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^... AssertionError: 0 != 2

Performance Tests

Performance degradation:

No issues

Remaining performance tests:

79 tests
  • dom0_root_seq1m_q8t1_read 3:read_bandwidth_kb: 349292.00
  • dom0_root_seq1m_q8t1_write 3:write_bandwidth_kb: 222769.00
  • dom0_root_seq1m_q1t1_read 3:read_bandwidth_kb: 354728.00
  • dom0_root_seq1m_q1t1_write 3:write_bandwidth_kb: 193768.00
  • dom0_root_rnd4k_q32t1_read 3:read_bandwidth_kb: 17836.00
  • dom0_root_rnd4k_q32t1_write 3:write_bandwidth_kb: 10368.00
  • dom0_root_rnd4k_q1t1_read 3:read_bandwidth_kb: 8619.00
  • dom0_root_rnd4k_q1t1_write 3:write_bandwidth_kb: 3846.00
  • dom0_varlibqubes_seq1m_q8t1_read 3:read_bandwidth_kb: 508277.00
  • dom0_varlibqubes_seq1m_q8t1_write 3:write_bandwidth_kb: 316599.00
  • dom0_varlibqubes_seq1m_q1t1_read 3:read_bandwidth_kb: 426250.00
  • dom0_varlibqubes_seq1m_q1t1_write 3:write_bandwidth_kb: 110321.00
  • dom0_varlibqubes_rnd4k_q32t1_read 3:read_bandwidth_kb: 94850.00
  • dom0_varlibqubes_rnd4k_q32t1_write 3:write_bandwidth_kb: 9135.00
  • dom0_varlibqubes_rnd4k_q1t1_read 3:read_bandwidth_kb: 8355.00
  • dom0_varlibqubes_rnd4k_q1t1_write 3:write_bandwidth_kb: 5060.00
  • fedora-44-xfce_root_seq1m_q8t1_read 3:read_bandwidth_kb: 389370.00
  • fedora-44-xfce_root_seq1m_q8t1_write 3:write_bandwidth_kb: 132312.00
  • fedora-44-xfce_root_seq1m_q1t1_read 3:read_bandwidth_kb: 329430.00
  • fedora-44-xfce_root_seq1m_q1t1_write 3:write_bandwidth_kb: 48839.00
  • fedora-44-xfce_root_rnd4k_q32t1_read 3:read_bandwidth_kb: 88411.00
  • fedora-44-xfce_root_rnd4k_q32t1_write 3:write_bandwidth_kb: 2189.00
  • fedora-44-xfce_root_rnd4k_q1t1_read 3:read_bandwidth_kb: 8927.00
  • fedora-44-xfce_root_rnd4k_q1t1_write 3:write_bandwidth_kb: 433.00
  • fedora-44-xfce_private_seq1m_q8t1_read 3:read_bandwidth_kb: 365103.00
  • fedora-44-xfce_private_seq1m_q8t1_write 3:write_bandwidth_kb: 242613.00
  • fedora-44-xfce_private_seq1m_q1t1_read 3:read_bandwidth_kb: 352107.00
  • fedora-44-xfce_private_seq1m_q1t1_write 3:write_bandwidth_kb: 42825.00
  • fedora-44-xfce_private_rnd4k_q32t1_read 3:read_bandwidth_kb: 16411.00
  • fedora-44-xfce_private_rnd4k_q32t1_write 3:write_bandwidth_kb: 2512.00
  • fedora-44-xfce_private_rnd4k_q1t1_read 3:read_bandwidth_kb: 8209.00
  • fedora-44-xfce_private_rnd4k_q1t1_write 3:write_bandwidth_kb: 494.00
  • fedora-44-xfce_volatile_seq1m_q8t1_read 3:read_bandwidth_kb: 263262.00
  • fedora-44-xfce_volatile_seq1m_q8t1_write 3:write_bandwidth_kb: 81376.00
  • fedora-44-xfce_volatile_seq1m_q1t1_read 3:read_bandwidth_kb: 327168.00
  • fedora-44-xfce_volatile_seq1m_q1t1_write 3:write_bandwidth_kb: 61027.00
  • fedora-44-xfce_volatile_rnd4k_q32t1_read 3:read_bandwidth_kb: 79020.00
  • fedora-44-xfce_volatile_rnd4k_q32t1_write 3:write_bandwidth_kb: 3140.00
  • fedora-44-xfce_volatile_rnd4k_q1t1_read 3:read_bandwidth_kb: 8463.00
  • fedora-44-xfce_volatile_rnd4k_q1t1_write 3:write_bandwidth_kb: 665.00
  • debian-13-xfce_dom0-dispvm-api (mean:6.381): 76.57
  • debian-13-xfce_dom0-dispvm-gui-api (mean:8.738): 104.85
  • debian-13-xfce_dom0-dispvm-preload-2-api (mean:3.19): 38.28
  • debian-13-xfce_dom0-dispvm-preload-2-delay-0-api (mean:3.031): 36.37
  • debian-13-xfce_dom0-dispvm-preload-2-delay-minus-1d2-api (mean:3.31): 39.72
  • debian-13-xfce_dom0-dispvm-preload-4-api (mean:2.689): 32.27
  • debian-13-xfce_dom0-dispvm-preload-4-delay-0-api (mean:2.29): 27.48
  • debian-13-xfce_dom0-dispvm-preload-4-delay-minus-1d2-api (mean:2.388): 28.65
  • debian-13-xfce_dom0-dispvm-preload-2-gui-api (mean:4.724): 56.68
  • debian-13-xfce_dom0-dispvm-preload-4-gui-api (mean:3.69): 44.27
  • debian-13-xfce_dom0-dispvm-preload-6-gui-api (mean:3.202): 38.42
  • debian-13-xfce_dom0-vm-api (mean:0.039): 0.47
  • debian-13-xfce_dom0-vm-gui-api (mean:0.031): 0.37
  • fedora-44-xfce_dom0-dispvm-api (mean:8.319): 99.83
  • fedora-44-xfce_dom0-dispvm-gui-api (mean:10.386): 124.63
  • fedora-44-xfce_dom0-dispvm-preload-2-api (mean:3.952): 47.42
  • fedora-44-xfce_dom0-dispvm-preload-2-delay-0-api (mean:3.904): 46.85
  • fedora-44-xfce_dom0-dispvm-preload-2-delay-minus-1d2-api (mean:4.067): 48.81
  • fedora-44-xfce_dom0-dispvm-preload-4-api (mean:3.1): 37.19
  • fedora-44-xfce_dom0-dispvm-preload-4-delay-0-api (mean:2.717): 32.60
  • fedora-44-xfce_dom0-dispvm-preload-4-delay-minus-1d2-api (mean:3.094): 37.12
  • fedora-44-xfce_dom0-dispvm-preload-2-gui-api (mean:5.375): 64.50
  • fedora-44-xfce_dom0-dispvm-preload-4-gui-api (mean:4.24): 50.88
  • fedora-44-xfce_dom0-dispvm-preload-6-gui-api (mean:3.495): 41.94
  • fedora-44-xfce_dom0-vm-api (mean:0.03): 0.36
  • fedora-44-xfce_dom0-vm-gui-api (mean:0.033): 0.39
  • whonix-workstation-18_dom0-dispvm-api (mean:9.81): 117.72
  • whonix-workstation-18_dom0-dispvm-gui-api (mean:11.431): 137.18
  • whonix-workstation-18_dom0-dispvm-preload-2-api (mean:4.552): 54.63
  • whonix-workstation-18_dom0-dispvm-preload-2-delay-0-api (mean:4.522): 54.26
  • whonix-workstation-18_dom0-dispvm-preload-2-delay-minus-1d2-api (mean:4.876): 58.51
  • whonix-workstation-18_dom0-dispvm-preload-4-api (mean:3.677): 44.12
  • whonix-workstation-18_dom0-dispvm-preload-4-delay-0-api (mean:3.359): 40.30
  • whonix-workstation-18_dom0-dispvm-preload-4-delay-minus-1d2-api (mean:3.918): 47.02
  • whonix-workstation-18_dom0-dispvm-preload-2-gui-api (mean:6.079): 72.95
  • whonix-workstation-18_dom0-dispvm-preload-4-gui-api (mean:4.812): 57.74
  • whonix-workstation-18_dom0-dispvm-preload-6-gui-api (mean:3.749): 44.99
  • whonix-workstation-18_dom0-vm-api (mean:0.032): 0.38
  • whonix-workstation-18_dom0-vm-gui-api (mean:0.043): 0.52

@ben-grande

Copy link
Copy Markdown
Contributor Author

I have two ideas for fixing the libvirt issue:

  • increase timeout to be the se as shutdown timeout, which is 120s.
  • wait for libvirt event: 8b06d4e

@ben-grande

Copy link
Copy Markdown
Contributor Author

This is a timeout:

# test_016_preload_race_less
# failure: 

# timestamp 2026-08-10T17:04:21.886123
Traceback (most recent call last):
  File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 592, in cleanup_loop
    self.loop.run_until_complete(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        asyncio.wait_for(libvirt_event_impl.drain(), timeout=30)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 596, in cleanup_loop
    raise AssertionError("libvirt event impl drain timeout")
AssertionError: libvirt event impl drain timeout

# system-out: 


# failure: 

# timestamp 1970-01-01T00:00:00
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 573, in cleanup_gc
    assert not leaked
           ^^^^^^^^^^
AssertionError

And all the following ones have self._finished set to the object of asyncio.Event() of the first failure.

# test_017_preload_autostart
# failure: 

# timestamp 2026-08-10T17:06:47.005305
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 592, in cleanup_loop
    self.loop.run_until_complete(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        asyncio.wait_for(libvirt_event_impl.drain(), timeout=30)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/lib64/python3.13/site-packages/libvirtaio.py", line 345, in drain
    assert self._finished is None
           ^^^^^^^^^^^^^^^^^^^^^^
AssertionError

# system-out: 


# failure: 

# timestamp 1970-01-01T00:00:00
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 573, in cleanup_gc
    assert not leaked
           ^^^^^^^^^^
AssertionError

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch from ba8185d to 7d886ad Compare August 11, 2026 07:56
@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm TEST_TEMPLATES=fedora-44-xfce

@ben-grande

Copy link
Copy Markdown
Contributor Author

And just letting the reviewers know, this error only happens on OpenQA, not on my testbench, so testing is slow...

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch from 7d886ad to 702d4c2 Compare August 11, 2026 08:19
@ben-grande

ben-grande commented Aug 11, 2026

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm TEST_TEMPLATES=fedora-44-xfce UPDATE_TEMPLATES=fedora-44-xfce DEFAULT_TEMPLATE=fedora-44-xfce


Edit: unfortunately. especifying just a single template didn't reduce the templates that were being upgraded.

@ben-grande

Copy link
Copy Markdown
Contributor Author

system_tests_dispvm

* system_tests: [Fail](https://openqa.qubes-os.org/tests/192081#step/system_tests/35) (unknown)
  `Tests qubes.tests.integ.dispvm failed (exit code 1), details report...`

Logs failed to upload, but you can see them in the video in minute 1:52: https://openqa.qubes-os.org/tests/192081/video?filename=video.webm&t=111.92,111.96

This one I can reproduce locally:

logs

% ~/run-tests -o /dev/stdout -L INFO qubes.tests.integ.dispvm/TC_21_DispVM_Preload/test_016_preload_race_less
2026-08-11 14:04:21,427: CRITICAL: startTest: started
2026-08-11 14:04:21,427 qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_016_preload_race_less[499048]: started
qubes.tests.integ.dispvm/TC_21_DispVM_Preload/test_016_preload_race_less
  Test race requesting preloaded qube while the maximum is zeroed. ... 2026-08-11 14:04:21,428: INFO: setUp: start
2026-08-11 14:04:21,428 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:04:21,491: CRITICAL: setUp: starting
2026-08-11 14:04:21,491 qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_016_preload_race_less[499048]: starting
2026-08-11 14:04:24,320 vm.test-inst-dvm[499048]: Creating directory: /var/lib/qubes/appvms/test-inst-dvm
2026-08-11 14:04:24,518 appmenus[499048]: Updating appmenus for 'test-inst-dvm' in 'dom0'
2026-08-11 14:04:30,037 vm.test-inst-dvm-alt[499048]: Creating directory: /var/lib/qubes/appvms/test-inst-dvm-alt
2026-08-11 14:04:30,301 appmenus[499048]: Updating appmenus for 'test-inst-dvm-alt' in 'dom0'
2026-08-11 14:04:30,741 appmenus[499048]: Updating appmenus for 'test-inst-dvm-alt' in 'dom0'
2026-08-11 14:04:31,244 vm.test-inst-dvm[499048]: Starting qube test-inst-dvm
2026-08-11 14:04:31,245 vm.test-inst-dvm-alt[499048]: Starting qube test-inst-dvm-alt
2026-08-11 14:04:32,698 vm.test-inst-dvm[499048]: Setting Qubes DB info for the qube
2026-08-11 14:04:32,698 vm.test-inst-dvm[499048]: Starting Qubes DB
2026-08-11 14:04:32,740 vm.test-inst-dvm[499048]: Activating qube
2026-08-11 14:04:32,743: INFO: _test_event_handler: test-inst-dvm[domain-unpaused]
2026-08-11 14:04:32,743 qubes.tests.integ.dispvm[499048]: test-inst-dvm[domain-unpaused]
2026-08-11 14:04:34,772 vm.test-inst-dvm-alt[499048]: Setting Qubes DB info for the qube
2026-08-11 14:04:34,772 vm.test-inst-dvm-alt[499048]: Starting Qubes DB
2026-08-11 14:04:34,812 vm.test-inst-dvm-alt[499048]: Activating qube
2026-08-11 14:04:34,814: INFO: _test_event_handler: test-inst-dvm-alt[domain-unpaused]
2026-08-11 14:04:34,814 qubes.tests.integ.dispvm[499048]: test-inst-dvm-alt[domain-unpaused]
2026-08-11 14:04:47,136: INFO: _test_event_handler: test-inst-dvm[domain-shutdown]
2026-08-11 14:04:47,136 qubes.tests.integ.dispvm[499048]: test-inst-dvm[domain-shutdown]
2026-08-11 14:04:47,193: INFO: _test_event_handler: test-inst-dvm-alt[domain-shutdown]
2026-08-11 14:04:47,193 qubes.tests.integ.dispvm[499048]: test-inst-dvm-alt[domain-shutdown]
2026-08-11 14:04:47,230: INFO: cleanup_preload: start
2026-08-11 14:04:47,230 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:04:47,230: INFO: cleanup_preload: deleting global threshold feature
2026-08-11 14:04:47,230 qubes.tests.integ.dispvm[499048]: deleting global threshold feature
2026-08-11 14:04:47,231: INFO: cleanup_preload: end
2026-08-11 14:04:47,231 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:04:47,260: INFO: setup_dispvm_nodes: end
2026-08-11 14:04:47,260 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:04:47,260: INFO: setUp: end
2026-08-11 14:04:47,260 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:04:47,262: INFO: _test_016_preload_race_less: start
2026-08-11 14:04:47,262 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:04:47,264: INFO: wait_preload: start
2026-08-11 14:04:47,264 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:04:47,264: INFO: _test_event_handler: test-inst-dvm[domain-preload-dispvm-start]
2026-08-11 14:04:47,264 qubes.tests.integ.dispvm[499048]: test-inst-dvm[domain-preload-dispvm-start]
2026-08-11 14:04:47,265 vm.test-inst-dvm[499048]: Received preload event 'start' because local feature was set to '1'
2026-08-11 14:04:47,265 vm.test-inst-dvm[499048]: Preloading '1' qube(s)
2026-08-11 14:04:47,270 vm.disp9051[499048]: Marking preloaded qube
2026-08-11 14:04:47,272: INFO: _test_event_handler: disp9051[domain-feature-set:preload-dispvm-in-progress]
2026-08-11 14:04:47,272 qubes.tests.integ.dispvm[499048]: disp9051[domain-feature-set:preload-dispvm-in-progress]
2026-08-11 14:04:47,277 vm.disp9051[499048]: Creating directory: /var/lib/qubes/appvms/disp9051
2026-08-11 14:04:47,278 appmenus[499048]: Removing appmenus for 'disp9051' in 'dom0'
2026-08-11 14:04:47,282 appmenus[499048]: Updating appmenus for 'disp9051' in 'dom0'
2026-08-11 14:04:47,832 vm.disp9051[499048]: Starting qube disp9051
2026-08-11 14:04:48,266: INFO: wait_preload: end
2026-08-11 14:04:48,266 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:04:48,266: INFO: run_preload_proc: start
2026-08-11 14:04:48,266 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:04:48,269: INFO: _test_event_handler: test-inst-dvm[domain-preload-dispvm-start]
2026-08-11 14:04:48,269 qubes.tests.integ.dispvm[499048]: test-inst-dvm[domain-preload-dispvm-start]
2026-08-11 14:04:48,270 vm.test-inst-dvm[499048]: Received preload event 'start' because local feature was set to ''
2026-08-11 14:04:48,270 vm.test-inst-dvm[499048]: Removing excess qube(s) from preloaded list because there may be absent qubes: 'disp9051'
2026-08-11 14:04:48,284 appmenus[499048]: Removing appmenus for 'disp9051' in 'dom0'
2026-08-11 14:04:48,388 vm.disp3190[499048]: Creating directory: /var/lib/qubes/appvms/disp3190
2026-08-11 14:04:48,390 appmenus[499048]: Updating appmenus for 'disp3190' in 'dom0'
2026-08-11 14:04:49,430 vm.disp9051[499048]: Setting Qubes DB info for the qube
2026-08-11 14:04:49,431 vm.disp9051[499048]: Starting Qubes DB
2026-08-11 14:04:49,491 vm.disp9051[499048]: Activating qube
2026-08-11 14:04:49,494: INFO: _test_event_handler: disp9051[domain-unpaused]
2026-08-11 14:04:49,494 qubes.tests.integ.dispvm[499048]: disp9051[domain-unpaused]
2026-08-11 14:04:49,749 vm.disp3190[499048]: Starting qube disp3190
2026-08-11 14:05:04,930 asyncio[499048]: Task exception was never retrieved
future: <Task finished name='Task-3229' coro=<DispVM.cleanup() done, defined at /home/user/qubes-core-admin-clone/qubes/vm/dispvm.py:971> exception=StoragePoolException('  Logical volume qubes_dom0/vm-disp9051-root-snap in use.')>
Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 985, in cleanup
    await self.kill()
  File "/home/user/qubes-core-admin-clone/qubes/vm/qubesvm.py", line 1738, in kill
    raise qubes.exc.QubesVMNotStartedError(self)
qubes.exc.QubesVMNotStartedError: Domain is powered off: 'disp9051'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 989, in cleanup
    await self._delete_domain()
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 968, in _delete_domain
    await self.remove_from_disk()
  File "/home/user/qubes-core-admin-clone/qubes/vm/qubesvm.py", line 2299, in remove_from_disk
    await self.storage.remove()
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 784, in remove
    await self.stop()
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 861, in stop
    await qubes.utils.void_coros_maybe(
    ...<5 lines>...
    )
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 337, in void_coros_maybe
    task.result()  # re-raises exception if task failed
    ~~~~~~~~~~~^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 307, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 283, in wrapper
    return await method(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 799, in stop
    changed = await self._remove_if_exists(self._vid_snap)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 769, in _remove_if_exists
    await qubes_lvm_coro(cmd, self.log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 972, in qubes_lvm_coro
    return _process_lvm_output(p.returncode, out, err, log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 942, in _process_lvm_output
    raise qubes.exc.StoragePoolException(err)
qubes.exc.StoragePoolException:   Logical volume qubes_dom0/vm-disp9051-root-snap in use.
2026-08-11 14:05:06,227 vm.disp3190[499048]: Setting Qubes DB info for the qube
2026-08-11 14:05:06,227 vm.disp3190[499048]: Starting Qubes DB
2026-08-11 14:05:06,271 vm.disp3190[499048]: Activating qube
2026-08-11 14:05:06,274: INFO: _test_event_handler: disp3190[domain-unpaused]
2026-08-11 14:05:06,274 qubes.tests.integ.dispvm[499048]: disp3190[domain-unpaused]
2026-08-11 14:05:12,823: INFO: _test_event_handler: disp3190[domain-shutdown]
2026-08-11 14:05:12,823 qubes.tests.integ.dispvm[499048]: disp3190[domain-shutdown]
2026-08-11 14:05:12,880 appmenus[499048]: Removing appmenus for 'disp3190' in 'dom0'
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume root: qubes_dom0/vm-disp3190-root
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume private: qubes_dom0/vm-disp3190-private
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume volatile: qubes_dom0/vm-disp3190-volatile
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume kernel: 7.1.5-1.18.fc41
2026-08-11 14:05:13,329: INFO: run_preload_proc: end
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,329: INFO: _test_016_preload_race_less: end
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,329: INFO: tearDown: start
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:05:13,329: INFO: cleanup_preload: start
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:05:13,329: INFO: cleanup_preload: removing preloaded disposables configured in: 'test-inst-dvm'
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: removing preloaded disposables configured in: 'test-inst-dvm'
2026-08-11 14:05:13,330: INFO: wait_preload: start
2026-08-11 14:05:13,330 qubes.tests.integ.dispvm[499048]: start
2026-08-11 14:05:13,330: INFO: wait_preload: end
2026-08-11 14:05:13,330 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,330: INFO: cleanup_preload: deleting max preload feature
2026-08-11 14:05:13,330 qubes.tests.integ.dispvm[499048]: deleting max preload feature
2026-08-11 14:05:13,332: INFO: cleanup_preload: end
2026-08-11 14:05:13,332 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,365: INFO: tearDown: end
2026-08-11 14:05:13,365 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,375 appmenus[499048]: Removing appmenus for 'test-inst-dvm' in 'dom0'
2026-08-11 14:05:15,165 vm.test-inst-dvm[499048]: Removing volume root: qubes_dom0/vm-test-inst-dvm-root
2026-08-11 14:05:15,165 vm.test-inst-dvm[499048]: Removing volume private: qubes_dom0/vm-test-inst-dvm-private
2026-08-11 14:05:15,165 vm.test-inst-dvm[499048]: Removing volume volatile: qubes_dom0/vm-test-inst-dvm-volatile
2026-08-11 14:05:15,165 vm.test-inst-dvm[499048]: Removing volume kernel: 7.1.5-1.18.fc41
2026-08-11 14:05:15,598 appmenus[499048]: Removing appmenus for 'test-inst-dvm-alt' in 'dom0'
2026-08-11 14:05:17,305 vm.test-inst-dvm-alt[499048]: Removing volume root: qubes_dom0/vm-test-inst-dvm-alt-root
2026-08-11 14:05:17,305 vm.test-inst-dvm-alt[499048]: Removing volume private: qubes_dom0/vm-test-inst-dvm-alt-private
2026-08-11 14:05:17,305 vm.test-inst-dvm-alt[499048]: Removing volume volatile: qubes_dom0/vm-test-inst-dvm-alt-volatile
2026-08-11 14:05:17,305 vm.test-inst-dvm-alt[499048]: Removing volume kernel: 7.1.5-1.18.fc41
2026-08-11 14:05:17,806 asyncio[499048]: Task exception was never retrieved
future: <Task finished name='Task-3309' coro=<Volume.stop_encrypted() done, defined at /home/user/qubes-core-admin-clone/qubes/storage/__init__.py:260> exception=StoragePoolException('  Logical volume qubes_dom0/vm-disp9051-private-snap in use.')>
Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 307, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 283, in wrapper
    return await method(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 799, in stop
    changed = await self._remove_if_exists(self._vid_snap)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 769, in _remove_if_exists
    await qubes_lvm_coro(cmd, self.log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 972, in qubes_lvm_coro
    return _process_lvm_output(p.returncode, out, err, log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 942, in _process_lvm_output
    raise qubes.exc.StoragePoolException(err)
qubes.exc.StoragePoolException:   Logical volume qubes_dom0/vm-disp9051-private-snap in use.
2026-08-11 14:05:17,806 asyncio[499048]: Task exception was never retrieved
future: <Task finished name='Task-3310' coro=<Volume.stop_encrypted() done, defined at /home/user/qubes-core-admin-clone/qubes/storage/__init__.py:260> exception=StoragePoolException('  Logical volume qubes_dom0/vm-disp9051-volatile in use.')>
Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 307, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 283, in wrapper
    return await method(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 801, in stop
    changed = await self._remove_if_exists(self.vid)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 769, in _remove_if_exists
    await qubes_lvm_coro(cmd, self.log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 972, in qubes_lvm_coro
    return _process_lvm_output(p.returncode, out, err, log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 942, in _process_lvm_output
    raise qubes.exc.StoragePoolException(err)
qubes.exc.StoragePoolException:   Logical volume qubes_dom0/vm-disp9051-volatile in use.
2026-08-11 14:05:47,844: ERROR: addFailure: FAIL (AssertionError: AssertionError('libvirt event impl drain timeout'))
2026-08-11 14:05:47,844 qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_016_preload_race_less[499048]: FAIL (AssertionError: AssertionError('libvirt event impl drain timeout'))
FAIL
Graph written to /tmp/objgraph-lyijs2hw.dot (1034 nodes)
dot: graph is too large for cairo-renderer bitmaps. Scaling by 0.269579 to fit
Image generated as /tmp/objgraph-qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_016_preload_race_less.png
2026-08-11 14:05:55,637: ERROR: addFailure: FAIL (AssertionError: AssertionError())
2026-08-11 14:05:55,637 qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_016_preload_race_less[499048]: FAIL (AssertionError: AssertionError())
FAIL

======================================================================
FAIL: qubes.tests.integ.dispvm/TC_21_DispVM_Preload/test_016_preload_race_less
  Test race requesting preloaded qube while the maximum is zeroed.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/lib64/python3.13/site-packages/libvirtaio.py", line 347, in drain
    await self._finished.wait()
  File "/usr/lib64/python3.13/asyncio/locks.py", line 213, in wait
    await fut
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/tests/__init__.py", line 592, in cleanup_loop
    self.loop.run_until_complete(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        asyncio.wait_for(libvirt_event_impl.drain(), timeout=30)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "/usr/lib64/python3.13/asyncio/tasks.py", line 506, in wait_for
    async with timeouts.timeout(timeout):
               ~~~~~~~~~~~~~~~~^^^^^^^^^
  File "/usr/lib64/python3.13/asyncio/timeouts.py", line 116, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/tests/__init__.py", line 596, in cleanup_loop
    raise AssertionError("libvirt event impl drain timeout")
AssertionError: libvirt event impl drain timeout

======================================================================
FAIL: qubes.tests.integ.dispvm/TC_21_DispVM_Preload/test_016_preload_race_less
  Test race requesting preloaded qube while the maximum is zeroed.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/tests/__init__.py", line 573, in cleanup_gc
    assert not leaked
           ^^^^^^^^^^
AssertionError

----------------------------------------------------------------------
Ran 1 test in 94.210s

FAILED (failures=2)
zsh: exit 1     ~/run-tests -o /dev/stdout -L INFO

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch from 3f42ddd to 68af9fc Compare August 11, 2026 15:12
@ben-grande

Copy link
Copy Markdown
Contributor Author

Without the line to remove preload excess, just below the TODO marker, things doesn't break. This is weird.

@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm TEST_TEMPLATES=fedora-44-xfce UPDATE_TEMPLATES=fedora-44-xfce

@ben-grande

ben-grande commented Aug 12, 2026

Copy link
Copy Markdown
Contributor Author

Failed tests

1 failures

* system_tests_dispvm
  
  * TC_21_DispVM_Preload: [test_018_preload_global](https://openqa.qubes-os.org/tests/192101#step/TC_21_DispVM_Preload/7) (failure)
    `~~~~~~~~~^^^^^^^^^^^^^^^^^^^... AssertionError: didn't preload in time`

Ok, so removing DVMTemplateMixin.remove_preload_excess from DVMTemplateMixin.on_domain_preload_dispvm_used worked, only one unrelated failure. A bit unfortunate I fixed the DispVM.cleanup but another thing broke. Will try to find a middle ground. See error from the other run that failed (not this one):

2026-08-11 14:04:49,430 vm.disp9051[499048]: Setting Qubes DB info for the qube
2026-08-11 14:04:49,431 vm.disp9051[499048]: Starting Qubes DB
2026-08-11 14:04:49,491 vm.disp9051[499048]: Activating qube
2026-08-11 14:04:49,494: INFO: _test_event_handler: disp9051[domain-unpaused]
2026-08-11 14:04:49,494 qubes.tests.integ.dispvm[499048]: disp9051[domain-unpaused]
2026-08-11 14:04:49,749 vm.disp3190[499048]: Starting qube disp3190
2026-08-11 14:05:04,930 asyncio[499048]: Task exception was never retrieved
future: <Task finished name='Task-3229' coro=<DispVM.cleanup() done, defined at /home/user/qubes-core-admin-clone/qubes/vm/dispvm.py:971> exception=StoragePoolException('  Logical volume qubes_dom0/vm-disp9051-root-snap in use.')>
Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 985, in cleanup
    await self.kill()
  File "/home/user/qubes-core-admin-clone/qubes/vm/qubesvm.py", line 1738, in kill
    raise qubes.exc.QubesVMNotStartedError(self)
qubes.exc.QubesVMNotStartedError: Domain is powered off: 'disp9051'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 989, in cleanup
    await self._delete_domain()
  File "/home/user/qubes-core-admin-clone/qubes/vm/dispvm.py", line 968, in _delete_domain
    await self.remove_from_disk()
  File "/home/user/qubes-core-admin-clone/qubes/vm/qubesvm.py", line 2299, in remove_from_disk
    await self.storage.remove()
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 784, in remove
    await self.stop()
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 861, in stop
    await qubes.utils.void_coros_maybe(
    ...<5 lines>...
    )
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 337, in void_coros_maybe
    task.result()  # re-raises exception if task failed
    ~~~~~~~~~~~^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/home/user/qubes-core-admin-clone/qubes/utils.py", line 307, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/__init__.py", line 283, in wrapper
    return await method(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 799, in stop
    changed = await self._remove_if_exists(self._vid_snap)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 769, in _remove_if_exists
    await qubes_lvm_coro(cmd, self.log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 972, in qubes_lvm_coro
    return _process_lvm_output(p.returncode, out, err, log)
  File "/home/user/qubes-core-admin-clone/qubes/storage/lvm.py", line 942, in _process_lvm_output
    raise qubes.exc.StoragePoolException(err)
qubes.exc.StoragePoolException:   Logical volume qubes_dom0/vm-disp9051-root-snap in use.
2026-08-11 14:05:06,227 vm.disp3190[499048]: Setting Qubes DB info for the qube
2026-08-11 14:05:06,227 vm.disp3190[499048]: Starting Qubes DB
2026-08-11 14:05:06,271 vm.disp3190[499048]: Activating qube
2026-08-11 14:05:06,274: INFO: _test_event_handler: disp3190[domain-unpaused]
2026-08-11 14:05:06,274 qubes.tests.integ.dispvm[499048]: disp3190[domain-unpaused]
2026-08-11 14:05:12,823: INFO: _test_event_handler: disp3190[domain-shutdown]
2026-08-11 14:05:12,823 qubes.tests.integ.dispvm[499048]: disp3190[domain-shutdown]
2026-08-11 14:05:12,880 appmenus[499048]: Removing appmenus for 'disp3190' in 'dom0'
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume root: qubes_dom0/vm-disp3190-root
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume private: qubes_dom0/vm-disp3190-private
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume volatile: qubes_dom0/vm-disp3190-volatile
2026-08-11 14:05:13,270 vm.disp3190[499048]: Removing volume kernel: 7.1.5-1.18.fc41
2026-08-11 14:05:13,329: INFO: run_preload_proc: end
2026-08-11 14:05:13,329 qubes.tests.integ.dispvm[499048]: end
2026-08-11 14:05:13,329: INFO: _test_016_preload_race_less: end

@ben-grande

Copy link
Copy Markdown
Contributor Author

I think the error might be on the storage side, that has issues when cleanup and startup (even for different qubes) happens too close to each other.

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch 3 times, most recently from fc6c1d6 to fdbb441 Compare August 12, 2026 13:28
@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm TEST_TEMPLATES=fedora-44-xfce

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch 3 times, most recently from 8f737d3 to e6fe724 Compare August 12, 2026 14:37
@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm TEST_TEMPLATES=fedora-44-xfce

@ben-grande

Copy link
Copy Markdown
Contributor Author

PipelineRetryFailed

@ben-grande

Copy link
Copy Markdown
Contributor Author

https://openqa.qubes-os.org/tests/195058/file/system_tests-tests-qubes.tests.integ.dispvm.log

Details

qubes.tests.integ.dispvm/TC_21_DispVM_Preload/test_015_preload_race_more
Test race requesting multiple preloaded qubes ... INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
CRITICAL:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:starting
INFO:vm.AppVM.test-inst-dvm:Creating directory: /var/lib/qubes/appvms/test-inst-dvm
INFO:appmenus:Updating appmenus for 'test-inst-dvm' in 'dom0'
INFO:appmenus:Updating appmenus for 'test-inst-dvm' in 'dom0'
INFO:vm.AppVM.test-inst-dvm-alt:Creating directory: /var/lib/qubes/appvms/test-inst-dvm-alt
INFO:appmenus:Updating appmenus for 'test-inst-dvm-alt' in 'dom0'
INFO:appmenus:Updating appmenus for 'test-inst-dvm-alt' in 'dom0'
INFO:vm.AppVM.test-inst-dvm:Starting qube test-inst-dvm
INFO:vm.AppVM.test-inst-dvm-alt:Starting qube test-inst-dvm-alt
INFO:vm.AppVM.test-inst-dvm:Received qid '17' and xid '31'
INFO:vm.AppVM.test-inst-dvm:Setting Qubes DB info for the qube
INFO:vm.AppVM.test-inst-dvm:Starting Qubes DB
INFO:vm.AppVM.test-inst-dvm:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-unpaused]
INFO:vm.AppVM.test-inst-dvm-alt:Received qid '18' and xid '32'
INFO:vm.AppVM.test-inst-dvm-alt:Setting Qubes DB info for the qube
INFO:vm.AppVM.test-inst-dvm-alt:Starting Qubes DB
INFO:vm.AppVM.test-inst-dvm-alt:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm-alt[domain-unpaused]
INFO:vm.AppVM.test-inst-dvm:Begin shutting down
INFO:vm.AppVM.test-inst-dvm-alt:Begin shutting down
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm-alt[domain-shutdown]
INFO:vm.AppVM.test-inst-dvm-alt:Completed shutdown
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-shutdown]
INFO:vm.AppVM.test-inst-dvm:Completed shutdown
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:deleting global threshold feature
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-start]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'start' because local feature was set to '3'
INFO:vm.AppVM.test-inst-dvm:Preloading '3' qube(s)
INFO:vm.DispVM.disp9527:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp9527:Creating directory: /var/lib/qubes/appvms/disp9527
INFO:vm.DispVM.disp7457:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp7457:Creating directory: /var/lib/qubes/appvms/disp7457
INFO:vm.DispVM.disp1175:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp1175:Creating directory: /var/lib/qubes/appvms/disp1175
INFO:appmenus:Updating appmenus for 'disp9527' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp9527' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp7457' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp7457' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp1175' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp1175' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp9527' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp7457' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp1175' in 'dom0'
INFO:vm.DispVM.disp1175:Starting qube disp1175
INFO:vm.DispVM.disp7457:Starting qube disp7457
INFO:vm.DispVM.disp9527:Starting qube disp9527
INFO:vm.DispVM.disp1175:Received qid '21' and xid '33'
INFO:vm.DispVM.disp1175:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp1175:Starting Qubes DB
INFO:vm.DispVM.disp1175:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-unpaused]
INFO:vm.DispVM.disp7457:Received qid '20' and xid '34'
INFO:vm.DispVM.disp7457:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp7457:Starting Qubes DB
INFO:vm.DispVM.disp7457:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-unpaused]
INFO:vm.DispVM.disp9527:Received qid '19' and xid '35'
INFO:vm.DispVM.disp9527:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp9527:Starting Qubes DB
INFO:vm.DispVM.disp9527:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-unpaused]
INFO:vm.DispVM.disp1175:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp1175:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
INFO:vm.DispVM.disp1175:Preload startup completed 'qubes.WaitForRunningSystem'
INFO:vm.DispVM.disp7457:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp7457:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
INFO:vm.DispVM.disp7457:Preload startup completed 'qubes.WaitForRunningSystem'
INFO:vm.DispVM.disp9527:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp9527:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
INFO:vm.DispVM.disp1175:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp1175:Setting qube memory to pref mem
INFO:vm.DispVM.disp9527:Preload startup completed 'qubes.WaitForRunningSystem'
WARNING:vm.DispVM.disp1175:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp1175:Preloading completed
INFO:vm.DispVM.disp1175:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-paused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp1175'
INFO:vm.DispVM.disp7457:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp7457:Setting qube memory to pref mem
INFO:vm.DispVM.disp9527:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp9527:Setting qube memory to pref mem
WARNING:vm.DispVM.disp7457:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp7457:Preloading completed
INFO:vm.DispVM.disp7457:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-paused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp7457'
WARNING:vm.DispVM.disp9527:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp9527:Preloading completed
INFO:vm.DispVM.disp9527:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-paused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp9527'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:vm.DispVM.disp9527:Requesting preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.AppVM.test-inst-dvm:Removing qube(s) from preloaded list because qube was requested: 'disp9527'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-unpaused]
INFO:vm.DispVM.disp9527:Unpaused preloaded qube will be marked as used
INFO:vm.DispVM.disp9527:Using preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-delete:internal]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-feature-delete:preload-dispvm-in-progress]
INFO:appmenus:Updating appmenus for 'disp9527' in 'dom0'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-used]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'used' for dispvm 'disp9527' with a delay of 3.0 second(s)
INFO:vm.DispVM.disp7457:Requesting preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.AppVM.test-inst-dvm:Removing qube(s) from preloaded list because qube was requested: 'disp7457'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-unpaused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-start]
INFO:vm.DispVM.disp7457:Unpaused preloaded qube will be marked as used
INFO:vm.DispVM.disp7457:Using preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-delete:internal]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-feature-delete:preload-dispvm-in-progress]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'start' because there is a gap with a delay of 5.0 second(s)
INFO:appmenus:Updating appmenus for 'disp7457' in 'dom0'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-used]
INFO:vm.DispVM.disp1175:Requesting preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.AppVM.test-inst-dvm:Removing qube(s) from preloaded list because qube was requested: 'disp1175'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-unpaused]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'used' for dispvm 'disp7457' with a delay of 3.0 second(s)
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-start]
INFO:vm.DispVM.disp1175:Unpaused preloaded qube will be marked as used
INFO:vm.DispVM.disp1175:Using preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-delete:internal]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-feature-delete:preload-dispvm-in-progress]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'start' because there is a gap with a delay of 5.0 second(s)
INFO:appmenus:Updating appmenus for 'disp1175' in 'dom0'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-preload-dispvm-used]
INFO:vm.AppVM.test-inst-dvm:Received preload event 'used' for dispvm 'disp1175' with a delay of 3.0 second(s)
INFO:vm.DispVM.disp9527:Begin kill
INFO:vm.DispVM.disp7457:Begin kill
INFO:vm.DispVM.disp1175:Begin kill
INFO:vm.AppVM.test-inst-dvm:Preloading '3' qube(s)
INFO:vm.AppVM.test-inst-dvm:Preloading '3' qube(s)
INFO:vm.AppVM.test-inst-dvm:Preloading '3' qube(s)
INFO:vm.DispVM.disp6323:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp6323:Creating directory: /var/lib/qubes/appvms/disp6323
INFO:vm.DispVM.disp1713:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp1713:Creating directory: /var/lib/qubes/appvms/disp1713
INFO:vm.DispVM.disp8647:Marking preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp8647:Creating directory: /var/lib/qubes/appvms/disp8647
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
WARNING:vm.AppVM.test-inst-dvm:Can't create more preloaded disposable as limit has been met
INFO:appmenus:Updating appmenus for 'disp6323' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp6323' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp1713' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp1713' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp8647' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp8647' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp6323' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp1713' in 'dom0'
INFO:appmenus:Updating appmenus for 'disp8647' in 'dom0'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp9527[domain-remove-from-disk]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp7457[domain-remove-from-disk]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1175[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp1175' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp7457' in 'dom0'
INFO:appmenus:Removing appmenus for 'disp9527' in 'dom0'
INFO:vm.DispVM.disp1713:Starting qube disp1713
INFO:vm.DispVM.disp6323:Starting qube disp6323
INFO:vm.DispVM.disp8647:Starting qube disp8647
INFO:vm.DispVM.disp9527:Removing volume root: qubes_dom0/vm-disp9527-root
INFO:vm.DispVM.disp9527:Removing volume private: qubes_dom0/vm-disp9527-private
INFO:vm.DispVM.disp9527:Removing volume volatile: qubes_dom0/vm-disp9527-volatile
INFO:vm.DispVM.disp9527:Removing volume kernel: 6.18.46-1.20.fc41
INFO:vm.DispVM.disp9527:Complete kill
INFO:vm.DispVM.disp7457:Removing volume root: qubes_dom0/vm-disp7457-root
INFO:vm.DispVM.disp7457:Removing volume private: qubes_dom0/vm-disp7457-private
INFO:vm.DispVM.disp7457:Removing volume volatile: qubes_dom0/vm-disp7457-volatile
INFO:vm.DispVM.disp7457:Removing volume kernel: 6.18.46-1.20.fc41
INFO:vm.DispVM.disp7457:Complete kill
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:vm.DispVM.disp1175:Removing volume root: qubes_dom0/vm-disp1175-root
INFO:vm.DispVM.disp1175:Removing volume private: qubes_dom0/vm-disp1175-private
INFO:vm.DispVM.disp1175:Removing volume volatile: qubes_dom0/vm-disp1175-volatile
INFO:vm.DispVM.disp1175:Removing volume kernel: 6.18.46-1.20.fc41
INFO:vm.DispVM.disp1175:Complete kill
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:vm.DispVM.disp1713:Received qid '23' and xid '36'
INFO:vm.DispVM.disp1713:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp1713:Starting Qubes DB
INFO:vm.DispVM.disp1713:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-unpaused]
INFO:vm.DispVM.disp6323:Received qid '22' and xid '37'
INFO:vm.DispVM.disp6323:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp6323:Starting Qubes DB
INFO:vm.DispVM.disp6323:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-unpaused]
INFO:vm.DispVM.disp8647:Received qid '24' and xid '38'
INFO:vm.DispVM.disp8647:Setting Qubes DB info for the qube
INFO:vm.DispVM.disp8647:Starting Qubes DB
INFO:vm.DispVM.disp8647:Activating qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-unpaused]
INFO:vm.DispVM.disp1713:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp1713:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
INFO:vm.DispVM.disp1713:Preload startup completed 'qubes.WaitForRunningSystem'
INFO:vm.DispVM.disp6323:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp6323:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
INFO:vm.DispVM.disp6323:Preload startup completed 'qubes.WaitForRunningSystem'
INFO:vm.DispVM.disp1713:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp1713:Setting qube memory to pref mem
INFO:vm.DispVM.disp8647:Preload startup waiting 'qubes.WaitForRunningSystem' with '120' seconds timeout
INFO:vm.DispVM.disp8647:Preload startup waiting 'qubes.WaitForSession' with '120' seconds timeout
WARNING:vm.DispVM.disp1713:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp1713:Preloading completed
INFO:vm.DispVM.disp1713:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-paused]
INFO:vm.DispVM.disp8647:Preload startup completed 'qubes.WaitForRunningSystem'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp1713'
INFO:vm.DispVM.disp6323:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp6323:Setting qube memory to pref mem
INFO:vm.DispVM.disp8647:Preload startup completed 'qubes.WaitForSession'
INFO:vm.DispVM.disp8647:Setting qube memory to pref mem
WARNING:vm.DispVM.disp6323:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp6323:Preloading completed
INFO:vm.DispVM.disp6323:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-paused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp6323'
WARNING:vm.DispVM.disp8647:Failed to set memory
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-feature-set:preload-dispvm-completed]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-feature-set:preload-dispvm-in-progress]
INFO:vm.DispVM.disp8647:Preloading completed
INFO:vm.DispVM.disp8647:Paused preloaded qube
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-paused]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp8647'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:removing preloaded disposables configured in: 'test-inst-dvm'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp6323'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp1713'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:preload completed for 'disp8647'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:cleaning up preloaded disposables: test-inst-dvm:[]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:start
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:deleting max preload feature
INFO:vm.AppVM.test-inst-dvm:Removing excess qube(s) from preloaded list because local feature was deleted: 'disp6323, disp1713, disp8647'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:end
INFO:vm.DispVM.disp6323:Begin cleanup
INFO:vm.DispVM.disp6323:Begin kill
INFO:vm.DispVM.disp1713:Begin cleanup
INFO:vm.DispVM.disp1713:Begin kill
INFO:vm.DispVM.disp8647:Begin cleanup
INFO:vm.DispVM.disp8647:Begin kill
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp1713' in 'dom0'
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp6323' in 'dom0'
INFO:vm.DispVM.disp1713:Removing volume root: qubes_dom0/vm-disp1713-root
INFO:vm.DispVM.disp1713:Removing volume private: qubes_dom0/vm-disp1713-private
INFO:vm.DispVM.disp1713:Removing volume volatile: qubes_dom0/vm-disp1713-volatile
INFO:vm.DispVM.disp1713:Removing volume kernel: 6.18.46-1.20.fc41
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp1713[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-shutdown]
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp8647' in 'dom0'
INFO:vm.DispVM.disp1713:Complete kill
INFO:vm.DispVM.disp1713:Normal cleanup of disposable will delete the domain
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp6323[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp6323' in 'dom0'
INFO:vm.DispVM.disp6323:Removing volume root: qubes_dom0/vm-disp6323-root
INFO:vm.DispVM.disp6323:Removing volume private: qubes_dom0/vm-disp6323-private
INFO:vm.DispVM.disp6323:Removing volume volatile: qubes_dom0/vm-disp6323-volatile
INFO:vm.DispVM.disp6323:Removing volume kernel: 6.18.46-1.20.fc41
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:disp8647[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'disp8647' in 'dom0'
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-30706' coro=<DispVM.cleanup() done, defined at /usr/lib/python3.13/site-packages/qubes/vm/dispvm.py:973> exception=AttributeError("property 'name' have no default")>
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 2365, in remove_from_disk
    await self.storage.remove()
          ^^^^^^^^^^^^
AttributeError: 'DispVM' object has no attribute 'storage'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 245, in __get__
    return getattr(instance, self._attr_name)
AttributeError: 'DispVM' object has no attribute '_qubesprop_name'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 985, in cleanup
    await self.kill()
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1812, in kill
    await waiter
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1670, in _domain_stopped_coro
    await self.fire_event_async("domain-shutdown")
  File "/usr/lib/python3.13/site-packages/qubes/events.py", line 244, in fire_event_async
    effect = task.result()
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 706, in on_domain_shutdown
    await self._delete_domain()
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 970, in _delete_domain
    await self.remove_from_disk()
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 2369, in remove_from_disk
    shutil.rmtree(self.dir_path)
                  ^^^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1113, in dir_path
    qubes.config.qubes_base_dir, self.dir_path_prefix, self.name
                                                       ^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 248, in __get__
    return self.get_default(instance)
           ~~~~~~~~~~~~~~~~^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 252, in get_default
    raise AttributeError(
        "property {!r} have no default".format(self.__name__)
    )
AttributeError: property 'name' have no default
INFO:vm.DispVM.disp8647:Removing volume root: qubes_dom0/vm-disp8647-root
INFO:vm.DispVM.disp8647:Removing volume private: qubes_dom0/vm-disp8647-private
INFO:vm.DispVM.disp8647:Removing volume volatile: qubes_dom0/vm-disp8647-volatile
INFO:vm.DispVM.disp8647:Removing volume kernel: 6.18.46-1.20.fc41
INFO:vm.DispVM.disp8647:Complete kill
INFO:vm.DispVM.disp8647:Normal cleanup of disposable will delete the domain
INFO:vm.DispVM.disp8647:Removing volume root: qubes_dom0/vm-disp8647-root
INFO:vm.DispVM.disp8647:Removing volume private: qubes_dom0/vm-disp8647-private
INFO:vm.DispVM.disp8647:Removing volume volatile: qubes_dom0/vm-disp8647-volatile
INFO:vm.DispVM.disp8647:Removing volume kernel: 6.18.46-1.20.fc41
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'test-inst-dvm' in 'dom0'
INFO:vm.AppVM.test-inst-dvm:Removing volume root: qubes_dom0/vm-test-inst-dvm-root
INFO:vm.AppVM.test-inst-dvm:Removing volume private: qubes_dom0/vm-test-inst-dvm-private
INFO:vm.AppVM.test-inst-dvm:Removing volume volatile: qubes_dom0/vm-test-inst-dvm-volatile
INFO:vm.AppVM.test-inst-dvm:Removing volume kernel: 6.18.46-1.20.fc41
INFO:qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more:test-inst-dvm-alt[domain-remove-from-disk]
INFO:appmenus:Removing appmenus for 'test-inst-dvm-alt' in 'dom0'
INFO:vm.AppVM.test-inst-dvm-alt:Removing volume root: qubes_dom0/vm-test-inst-dvm-alt-root
INFO:vm.AppVM.test-inst-dvm-alt:Removing volume private: qubes_dom0/vm-test-inst-dvm-alt-private
INFO:vm.AppVM.test-inst-dvm-alt:Removing volume volatile: qubes_dom0/vm-test-inst-dvm-alt-volatile
INFO:vm.AppVM.test-inst-dvm-alt:Removing volume kernel: 6.18.46-1.20.fc41
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-30714' coro=<QubesVM._domain_stopped_coro() done, defined at /usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py:1655> exception=AttributeError("property 'name' have no default")>
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 2365, in remove_from_disk
    await self.storage.remove()
          ^^^^^^^^^^^^
AttributeError: 'DispVM' object has no attribute 'storage'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 245, in __get__
    return getattr(instance, self._attr_name)
AttributeError: 'DispVM' object has no attribute '_qubesprop_name'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 985, in cleanup
    await self.kill()
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1812, in kill
    await waiter
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1670, in _domain_stopped_coro
    await self.fire_event_async("domain-shutdown")
  File "/usr/lib/python3.13/site-packages/qubes/events.py", line 244, in fire_event_async
    effect = task.result()
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 706, in on_domain_shutdown
    await self._delete_domain()
  File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 970, in _delete_domain
    await self.remove_from_disk()
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 2369, in remove_from_disk
    shutil.rmtree(self.dir_path)
                  ^^^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1113, in dir_path
    qubes.config.qubes_base_dir, self.dir_path_prefix, self.name
                                                       ^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 248, in __get__
    return self.get_default(instance)
           ~~~~~~~~~~~~~~~~^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/__init__.py", line 252, in get_default
    raise AttributeError(
        "property {!r} have no default".format(self.__name__)
    )
AttributeError: property 'name' have no default
ok

https://openqa.qubes-os.org/tests/195057/file/system_tests-tests-qubes.tests.integ.basic.log

Details

qubes.tests.integ.basic/TC_00_Basic/test_204_udev_block_exclude_custom_file
Check if VM images are excluded from udev parsing - ... CRITICAL:qubes.tests.integ.basic.TC_00_Basic.test_204_udev_block_exclude_custom_file:starting
INFO:vm.AppVM.test-inst-appvm:Creating directory: /var/lib/qubes/appvms/test-inst-appvm
INFO:appmenus:Updating appmenus for 'test-inst-appvm' in 'dom0'
INFO:appmenus:Updating appmenus for 'test-inst-appvm' in 'dom0'
INFO:vm.AppVM.test-inst-appvm:Starting qube test-inst-appvm
INFO:vm.AppVM.test-inst-appvm:Received qid '17' and xid '20'
INFO:vm.AppVM.test-inst-appvm:Setting Qubes DB info for the qube
INFO:vm.AppVM.test-inst-appvm:Starting Qubes DB
INFO:vm.AppVM.test-inst-appvm:Activating qube
INFO:vm.AppVM.test-inst-appvm:Begin shutting down
INFO:vm.AppVM.test-inst-appvm:Completed shutdown
INFO:vm.AppVM.test-inst-appvm:Starting qube test-inst-appvm
INFO:vm.AppVM.test-inst-appvm:Received qid '17' and xid '21'
INFO:vm.AppVM.test-inst-appvm:Setting Qubes DB info for the qube
INFO:vm.AppVM.test-inst-appvm:Starting Qubes DB
INFO:vm.AppVM.test-inst-appvm:Activating qube
INFO:vm.AppVM.test-inst-appvm:Begin kill
INFO:appmenus:Removing appmenus for 'test-inst-appvm' in 'dom0'
ERROR:vm.AppVM.test-inst-appvm:Failed to stop some volume, continuing anyway
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 784, in remove
    await self.stop()
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 861, in stop
    await qubes.utils.void_coros_maybe(
    ...<5 lines>...
    )
  File "/usr/lib/python3.13/site-packages/qubes/utils.py", line 338, in void_coros_maybe
    task.result()  # re-raises exception if task failed
    ~~~~~~~~~~~^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/usr/lib/python3.13/site-packages/qubes/utils.py", line 308, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 526, in stop
    await self._destroy_blockdev()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 291, in _destroy_blockdev
    path = self._block_device_path()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 577, in _block_device_path
    _dev_path(self.path),
    ~~~~~~~~~^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 51, in _dev_path
    res = os.stat(file)
FileNotFoundError: [Errno 2] No such file or directory: '/var/tmp/qubes-pool-pnh0oxgl/appvms/test-inst-appvm/private.img'
INFO:vm.AppVM.test-inst-appvm:Removing volume root: qubes_dom0/vm-test-inst-appvm-root
INFO:vm.AppVM.test-inst-appvm:Removing volume private: appvms/test-inst-appvm/private
INFO:vm.AppVM.test-inst-appvm:Removing volume volatile: appvms/test-inst-appvm/volatile
INFO:vm.AppVM.test-inst-appvm:Removing volume kernel: 6.18.46-1.20.fc41
ERROR:vm.AppVM.test-inst-appvm:Failed to remove some volume
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 796, in remove
    await qubes.utils.void_coros_maybe(results)
  File "/usr/lib/python3.13/site-packages/qubes/utils.py", line 338, in void_coros_maybe
    task.result()  # re-raises exception if task failed
    ~~~~~~~~~~~^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 298, in remove
    await self.stop()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 526, in stop
    await self._destroy_blockdev()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 291, in _destroy_blockdev
    path = self._block_device_path()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 577, in _block_device_path
    _dev_path(self.path),
    ~~~~~~~~~^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 51, in _dev_path
    res = os.stat(file)
FileNotFoundError: [Errno 2] No such file or directory: '/var/tmp/qubes-pool-pnh0oxgl/appvms/test-inst-appvm/private.img'
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-10518' coro=<QubesVM._domain_stopped_coro() done, defined at /usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py:1655> exception=FileNotFoundError(2, 'No such file or directory')>
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/qubes/tests/__init__.py", line 1208, in remove_vms
    self.loop.run_until_complete(vm.kill())
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1812, in kill
    await waiter
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1669, in _domain_stopped_coro
    await self.fire_event_async("domain-stopped")
  File "/usr/lib/python3.13/site-packages/qubes/events.py", line 244, in fire_event_async
    effect = task.result()
  File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1685, in on_domain_stopped
    await self.storage.stop()
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 861, in stop
    await qubes.utils.void_coros_maybe(
    ...<5 lines>...
    )
  File "/usr/lib/python3.13/site-packages/qubes/utils.py", line 338, in void_coros_maybe
    task.result()  # re-raises exception if task failed
    ~~~~~~~~~~~^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/__init__.py", line 274, in stop_encrypted
    await qubes.utils.coro_maybe(self.stop())
  File "/usr/lib/python3.13/site-packages/qubes/utils.py", line 308, in coro_maybe
    return (await value) if asyncio.iscoroutine(value) else value
            ^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 526, in stop
    await self._destroy_blockdev()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 291, in _destroy_blockdev
    path = self._block_device_path()
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 577, in _block_device_path
    _dev_path(self.path),
    ~~~~~~~~~^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/qubes/storage/file.py", line 51, in _dev_path
    res = os.stat(file)
FileNotFoundError: [Errno 2] No such file or directory: '/var/tmp/qubes-pool-pnh0oxgl/appvms/test-inst-appvm/private.img'
ok

@ben-grande

Copy link
Copy Markdown
Contributor Author

https://openqa.qubes-os.org/tests/195058/file/system_tests-tests-qubes.tests.integ.dispvm.log

Couldn't reproduce this issue locally, but it seems that domain-remove-from-disk was called twice. Will keep trying.

https://openqa.qubes-os.org/tests/195057/file/system_tests-tests-qubes.tests.integ.basic.log

This exception seems to be on purpose and happens on main, so not related to this PR.

@ben-grande

Copy link
Copy Markdown
Contributor Author

https://openqa.qubes-os.org/tests/195058/file/system_tests-tests-qubes.tests.integ.dispvm.log

Couldn't reproduce this issue locally, but it seems that domain-remove-from-disk was called twice. Will keep trying.

Still trying to reproduce reliably. I got it to fail two or three times in thirty runs... Using both HALs available to me and another test machine.

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch from ec7442d to c46e5f1 Compare September 8, 2026 14:34
@ben-grande

Copy link
Copy Markdown
Contributor Author
2026-09-08 15:12:01,191 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: removing preloaded disposables configured in: 'test-inst-dvm'
2026-09-08 15:12:01,191 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: start
2026-09-08 15:12:21,209 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: preload completed for 'disp2053'
2026-09-08 15:12:21,209 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: preload completed for 'disp1625'
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: preload completed for 'disp215'
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: end
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: cleaning up preloaded disposables: test-inst-dvm:[]
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: start
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: end
2026-09-08 15:12:21,210 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: deleting max preload feature
2026-09-08 15:12:21,215 INFO vm.AppVM.test-inst-dvm[52260]: Removing excess qube(s) from preloaded list because local feature was deleted: 'disp2053, disp1625, disp215'
2026-09-08 15:12:21,220 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: end
2026-09-08 15:12:21,270 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: end
2026-09-08 15:12:21,270 INFO vm.DispVM.disp2053[52260]: Begin cleanup
2026-09-08 15:12:21,270 INFO vm.DispVM.disp2053[52260]: Begin kill
2026-09-08 15:12:21,454 INFO vm.DispVM.disp1625[52260]: Begin cleanup
2026-09-08 15:12:21,454 INFO vm.DispVM.disp1625[52260]: Begin kill
2026-09-08 15:12:21,650 INFO vm.DispVM.disp215[52260]: Begin cleanup
2026-09-08 15:12:21,651 INFO vm.DispVM.disp215[52260]: Begin kill
2026-09-08 15:12:21,868 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: AAA test: remove_from_disk: disp1625
2026-09-08 15:12:21,869 INFO vm.DispVM.disp1625[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/suite.py", line 122, in run
    test(result)
  File "/usr/lib64/python3.13/unittest/case.py", line 707, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:21,870 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp1625[domain-remove-from-disk]
2026-09-08 15:12:21,871 INFO appmenus[52260]: Removing appmenus for 'disp1625' in 'dom0'
2026-09-08 15:12:22,625 INFO vm.DispVM.disp1625[52260]: Removing volume root: qubes_dom0/vm-disp1625-root
2026-09-08 15:12:22,625 INFO vm.DispVM.disp1625[52260]: Removing volume private: qubes_dom0/vm-disp1625-private
2026-09-08 15:12:22,625 INFO vm.DispVM.disp1625[52260]: Removing volume volatile: qubes_dom0/vm-disp1625-volatile
2026-09-08 15:12:22,625 INFO vm.DispVM.disp1625[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:22,626 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp1625[domain-shutdown]
2026-09-08 15:12:22,637 INFO vm.DispVM.disp1625[52260]: AAA on_domain_shutdown: _delete_domain
2026-09-08 15:12:22,655 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: AAA test: remove_from_disk: disp2053
2026-09-08 15:12:22,656 INFO vm.DispVM.disp1625[52260]: Complete kill
2026-09-08 15:12:22,659 INFO vm.DispVM.disp2053[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/suite.py", line 122, in run
    test(result)
  File "/usr/lib64/python3.13/unittest/case.py", line 707, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:22,660 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp2053[domain-remove-from-disk]
2026-09-08 15:12:22,660 INFO appmenus[52260]: Removing appmenus for 'disp2053' in 'dom0'
2026-09-08 15:12:22,664 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp215[domain-shutdown]
2026-09-08 15:12:22,677 INFO vm.DispVM.disp215[52260]: AAA on_domain_shutdown: _delete_domain
2026-09-08 15:12:22,682 INFO vm.DispVM.disp215[52260]: AAA _delete_domain: remove_from_disk
2026-09-08 15:12:22,682 INFO vm.DispVM.disp215[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/dispvm.py", line 707, in on_domain_shutdown
    await self._delete_domain()
  File "/home/user/qubes-core-admin/qubes/vm/dispvm.py", line 972, in _delete_domain
    await self.remove_from_disk()
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:22,684 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp215[domain-remove-from-disk]
2026-09-08 15:12:22,684 INFO appmenus[52260]: Removing appmenus for 'disp215' in 'dom0'
2026-09-08 15:12:22,693 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp2053[domain-shutdown]
2026-09-08 15:12:22,746 INFO vm.DispVM.disp2053[52260]: AAA on_domain_shutdown: _delete_domain
2026-09-08 15:12:22,751 INFO vm.DispVM.disp2053[52260]: Complete kill
2026-09-08 15:12:22,985 INFO vm.DispVM.disp215[52260]: Removing volume root: qubes_dom0/vm-disp215-root
2026-09-08 15:12:22,986 INFO vm.DispVM.disp215[52260]: Removing volume private: qubes_dom0/vm-disp215-private
2026-09-08 15:12:22,986 INFO vm.DispVM.disp215[52260]: Removing volume volatile: qubes_dom0/vm-disp215-volatile
2026-09-08 15:12:22,986 INFO vm.DispVM.disp215[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:23,004 INFO vm.DispVM.disp215[52260]: Complete kill
2026-09-08 15:12:23,005 INFO vm.DispVM.disp2053[52260]: Removing volume root: qubes_dom0/vm-disp2053-root
2026-09-08 15:12:23,005 INFO vm.DispVM.disp2053[52260]: Removing volume private: qubes_dom0/vm-disp2053-private
2026-09-08 15:12:23,005 INFO vm.DispVM.disp2053[52260]: Removing volume volatile: qubes_dom0/vm-disp2053-volatile
2026-09-08 15:12:23,005 INFO vm.DispVM.disp2053[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:23,021 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: AAA test: remove_from_disk: disp215
2026-09-08 15:12:23,021 INFO vm.DispVM.disp215[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/suite.py", line 122, in run
    test(result)
  File "/usr/lib64/python3.13/unittest/case.py", line 707, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:23,022 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: disp215[domain-remove-from-disk]
2026-09-08 15:12:23,022 INFO appmenus[52260]: Removing appmenus for 'disp215' in 'dom0'
2026-09-08 15:12:23,251 INFO vm.DispVM.disp215[52260]: Removing volume root: qubes_dom0/vm-disp215-root
2026-09-08 15:12:23,251 INFO vm.DispVM.disp215[52260]: Removing volume private: qubes_dom0/vm-disp215-private
2026-09-08 15:12:23,251 INFO vm.DispVM.disp215[52260]: Removing volume volatile: qubes_dom0/vm-disp215-volatile
2026-09-08 15:12:23,251 INFO vm.DispVM.disp215[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:23,273 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: AAA test: remove_from_disk: test-inst-dvm
2026-09-08 15:12:23,274 INFO vm.AppVM.test-inst-dvm[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/suite.py", line 122, in run
    test(result)
  File "/usr/lib64/python3.13/unittest/case.py", line 707, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:23,274 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: test-inst-dvm[domain-remove-from-disk]
2026-09-08 15:12:23,274 INFO appmenus[52260]: Removing appmenus for 'test-inst-dvm' in 'dom0'
2026-09-08 15:12:23,689 INFO vm.AppVM.test-inst-dvm[52260]: Removing volume root: qubes_dom0/vm-test-inst-dvm-root
2026-09-08 15:12:23,689 INFO vm.AppVM.test-inst-dvm[52260]: Removing volume private: qubes_dom0/vm-test-inst-dvm-private
2026-09-08 15:12:23,690 INFO vm.AppVM.test-inst-dvm[52260]: Removing volume volatile: qubes_dom0/vm-test-inst-dvm-volatile
2026-09-08 15:12:23,690 INFO vm.AppVM.test-inst-dvm[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:23,895 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: AAA test: remove_from_disk: test-inst-dvm-alt
2026-09-08 15:12:23,895 INFO vm.AppVM.test-inst-dvm-alt[52260]: AAA remove_from_disk: start
  File "/usr/lib64/python3.13/unittest/suite.py", line 122, in run
    test(result)
  File "/usr/lib64/python3.13/unittest/case.py", line 707, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib64/python3.13/unittest/case.py", line 655, in run
    self.doCleanups()
  File "/usr/lib64/python3.13/unittest/case.py", line 688, in doCleanups
    self._callCleanup(function, *args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/never_awaited.py", line 56, in wrapper
    func(*args, **kwargs)
  File "/usr/lib64/python3.13/unittest/case.py", line 614, in _callCleanup
    function(*args, **kwargs)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 949, in cleanup_app
    self.remove_test_vms()
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1281, in remove_test_vms
    self.remove_vms(
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1252, in remove_vms
    self._remove_vm_qubes(vm)
  File "/home/user/qubes-core-admin/qubes/tests/__init__.py", line 1099, in _remove_vm_qubes
    self.loop.run_until_complete(vm.remove_from_disk())
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 712, in run_until_complete
    self.run_forever()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 683, in run_forever
    self._run_once()
  File "/usr/lib64/python3.13/asyncio/base_events.py", line 2050, in _run_once
    handle._run()
  File "/usr/lib64/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
  File "/home/user/qubes-core-admin/qubes/vm/qubesvm.py", line 2358, in remove_from_disk
    traceback.print_stack(limit=15)
2026-09-08 15:12:23,896 INFO qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: test-inst-dvm-alt[domain-remove-from-disk]
2026-09-08 15:12:23,896 INFO appmenus[52260]: Removing appmenus for 'test-inst-dvm-alt' in 'dom0'
2026-09-08 15:12:24,313 INFO vm.AppVM.test-inst-dvm-alt[52260]: Removing volume root: qubes_dom0/vm-test-inst-dvm-alt-root
2026-09-08 15:12:24,313 INFO vm.AppVM.test-inst-dvm-alt[52260]: Removing volume private: qubes_dom0/vm-test-inst-dvm-alt-private
2026-09-08 15:12:24,313 INFO vm.AppVM.test-inst-dvm-alt[52260]: Removing volume volatile: qubes_dom0/vm-test-inst-dvm-alt-volatile
2026-09-08 15:12:24,313 INFO vm.AppVM.test-inst-dvm-alt[52260]: Removing volume kernel: 7.2.2-1.1001.fc41
2026-09-08 15:12:24,669 WARNING qubes.tests.integ.dispvm.TC_21_DispVM_Preload.test_015_preload_race_more[52260]: ok
ok

@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch 2 times, most recently from 8232f5a to f81e2f5 Compare September 8, 2026 17:29
@ben-grande

Copy link
Copy Markdown
Contributor Author

openQArun TEST=system_tests_dispvm,system_tests_basic_vm_qrexec_gui

@ben-grande

ben-grande commented Sep 10, 2026

Copy link
Copy Markdown
Contributor Author

@ben-grande

Copy link
Copy Markdown
Contributor Author

Review? Especially the experimental commits. Pending openqa tests don't seem relevant, only the completed ones.

This error was uncaught because it was introduced at different commits
and different merge requests, and each one was fixing an issue important
to them, but the last one enabled "force", which should not clean up the
named disposable if it was not for the first commit.

- f1cbf21
- a82f4f2

The "force" parameter is not a good name for what it does. Remove it.
And is not needed if the methods and events are ordered correctly and
shared state runs within a lock.

Introduce tests for cases where cleanup is called implicitly or
explicitly:

- Implicit:
  - Failed startup
  - Shutdown/Kill
- Explicit:
  - Cleanup when not running
  - Cleanup when running

Fixes: QubesOS/qubes-issues#11042
Fixes: QubesOS/qubes-issues#10928
When "DispVM.cleanup()" runs, it attempts to "QubesVM.kill()" the
domain, but in the case the domain has started "QubesVM.start()", but
the power state is still not running because it hasn't reached that
stage, "QubesVM.kill" is skipped, the domain is deleted from the store,
but when attempting to "QubesVM.remove_from_disk()", it fails, because
at the same time this asynchronous task is running, the
"QubesVM.start()" continues starting up the domain.

In order to avoid this racy condition, always cancel the startup when
stopping the domain is requested, even if not attempting to
"libvirt_domain.destroy()", as the domain might indeed not be running
yet, as the purpose of "kill()" is to not have a running domain, even on
early start.

When cancelling "start()", do not cancel exception handling, it might
even be already at that stage, such as a "kill()" called from "start()".
To avoid this issue, "asyncio.shield()" is used to prevent cancellation
of select tasks.
@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch 2 times, most recently from c6934da to 1fc2c6d Compare September 14, 2026 09:33
Makes no sense to complain to clients that domain isn't running when
kill is requested and the startup cancellation was done.
Instead of having several places to edit the logging format, use a
single source of truth to define the format.

This comes with the removal of logger from disposables integration
tests, that were never needed at all, and they were
duplicating/propagating the messages twice.

Ideally, I'd just use the debug format, as that would help when
collection logs from OpenQA or users that have not changed the log
level.
With this patch, it avoids leaving domain cleanup for the test instance,
avoiding certain events from being called twice.
When an unclean shutdown of a preloaded disposable happened after the
qube was created on disk but before the startup completed, the qube was
not saved to the store, so the script "cleanup-dispvms" can't find the
disposable to delete on the next restart of "qubes-core.service".

Save the domain to the store prior to the long startup so it can be
deleted on the next reboot, in case there is an unclean shutdown.
Although "create_on_disk()" takes some time, there doesn't seem to be a
need to "app.save()" before it, as creating the domain object doesn't
leave remnants on the system, until the qube is created on disk.

Fixes: QubesOS/qubes-issues#11086
@ben-grande
ben-grande force-pushed the skip-cleaning-named-disp branch from 1fc2c6d to 7b29d64 Compare September 14, 2026 09:53
@ben-grande

Copy link
Copy Markdown
Contributor Author

PipelineRetryFailed

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

3 participants