Broken AppVMs After Upgrade (Presence of Snap is Common Factor)

After following the steps to upgrade Qubes, I have run into an issue where AppVMs that actively use Snap will start but not successfully load applications. The common factor seems to be the Standard Notes snap as I have one AppVM that uses Snap but not Standard Notes and it’s completely functional.

Troubleshooting steps:

  • A/B testing with different AppVMs and Template VMs (how I identified common factor)
  • Built new AppVMs using same template as failing images (new AppVMs work fine)
  • Grepped through logs in dom0 (found nothing of interest so far)

Any suggestions on further troubleshooting?

UPDATE:
Common factor is 100% Standard Notes. I can recreate the issue by the following.

  • Create new AppVM from template with Snaps enabled (steps here: How to install software | Qubes OS)
  • Installed Standard Notes app and ran it from with AppVM
  • Restarted AppVM
  • Attempted to load Terminal, Standard Notes, anything. Failed.

I have almost enough information to open an issue but would love to get more data.

1 Like

UPDATE 2:

Using the console in the Qubes Manager, I am able to interact with the AppVMs. I was able to look at dmesg. I did not find anything interesting but here it is:

[    0.000000] Linux version 6.1.62-1.qubes.fc32.x86_64 (mockbuild@262dca78fb66416b9d854a12f8202d28) (gcc (GCC) 10.3.1 20210422 (Red Hat 10.3.1-1), GNU ld version 2.34-6.fc32) #1 SMP PREEMPT_DYNAMIC Tue Nov 14 07:11:33 CET 2023
[    0.000000] Command line: root=/dev/mapper/dmroot ro nomodeset console=hvc0 rd_NO_PLYMOUTH rd.plymouth.enable=0 plymouth.enable=0 xen_scrub_pages=0 swiotlb=2048 apparmor=1 security=apparmor
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000a0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000fbffffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000fc000000-0x00000000fc00803f] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000feff8000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000203ffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] Hypervisor detected: Xen HVM
[    0.000000] Xen version 4.14.
[    0.000009] HVMOP_pagetable_dying not supported
[    0.177207] tsc: Fast TSC calibration failed
[    0.177212] tsc: Detected 1608.012 MHz processor
[    0.177233] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.177239] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.177248] last_pfn = 0x204000 max_arch_pfn = 0x400000000
[    0.177307] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.177317] last_pfn = 0xfc000 max_arch_pfn = 0x400000000
[    0.189953] Using GB pages for direct mapping
[    0.190774] RAMDISK: [mem 0x05001000-0x0616bfff]
[    0.190892] ACPI: Early table checksum verification disabled
[    0.190896] ACPI: RSDP 0x00000000FC008000 000024 (v02 Xen   )
[    0.190903] ACPI: XSDT 0x00000000FC007F60 000034 (v01 Xen    HVM      00000000 HVML 00000000)
[    0.190911] ACPI: FACP 0x00000000FC007D60 00010C (v05 Xen    HVM      00000000 HVML 00000000)
[    0.190919] ACPI: DSDT 0x00000000FC001040 006C9B (v05 Xen    HVM      00000000 INTL 20190509)
[    0.190923] ACPI: FACS 0x00000000FC001000 000040
[    0.190927] ACPI: FACS 0x00000000FC001000 000040
[    0.190931] ACPI: APIC 0x00000000FC007E70 00003C (v02 Xen    HVM      00000000 HVML 00000000)
[    0.190935] ACPI: Reserving FACP table memory at [mem 0xfc007d60-0xfc007e6b]
[    0.190937] ACPI: Reserving DSDT table memory at [mem 0xfc001040-0xfc007cda]
[    0.190938] ACPI: Reserving FACS table memory at [mem 0xfc001000-0xfc00103f]
[    0.190940] ACPI: Reserving FACS table memory at [mem 0xfc001000-0xfc00103f]
[    0.190941] ACPI: Reserving APIC table memory at [mem 0xfc007e70-0xfc007eab]
[    0.191100] No NUMA configuration found
[    0.191101] Faking a node at [mem 0x0000000000000000-0x0000000203ffffff]
[    0.191115] NODE_DATA(0) allocated [mem 0x203fd4000-0x203ffefff]
[    0.227123] Zone ranges:
[    0.227220]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.227224]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.227416]   Normal   [mem 0x0000000100000000-0x0000000203ffffff]
[    0.227418]   Device   empty
[    0.227420] Movable zone start for each node
[    0.227424] Early memory node ranges
[    0.227424]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.227523]   node   0: [mem 0x0000000000100000-0x00000000fbffffff]
[    0.227526]   node   0: [mem 0x0000000100000000-0x0000000203ffffff]
[    0.227623] Initmem setup node 0 [mem 0x0000000000001000-0x0000000203ffffff]
[    0.228041] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.228106] On node 0, zone DMA: 96 pages in unavailable ranges
[    0.261671] On node 0, zone Normal: 16384 pages in unavailable ranges
[    0.262064] On node 0, zone Normal: 16384 pages in unavailable ranges
[    0.262390] ACPI: No IOAPIC entries present
[    0.262393] ACPI: Using ACPI for processor (LAPIC) configuration information
[    0.262396] TSC deadline timer available
[    0.262528] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[    0.262771] [mem 0xfc008040-0xfeff7fff] available for PCI devices
[    0.262880] Booting kernel on Xen PVH
[    0.262882] Xen version: 4.14.6
[    0.262984] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.274263] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:2 nr_cpu_ids:2 nr_node_ids:1
[    0.276130] percpu: Embedded 62 pages/cpu s217088 r8192 d28672 u1048576
[    0.276150] pcpu-alloc: s217088 r8192 d28672 u1048576 alloc=1*2097152
[    0.276155] pcpu-alloc: [0] 0 1 
[    0.276197] xen: PV spinlocks enabled
[    0.276201] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.276226] Fallback order for Node 0: 0 
[    0.276229] Built 1 zonelists, mobility grouping on.  Total pages: 2063872
[    0.276231] Policy zone: Normal
[    0.276233] Kernel command line: root=/dev/mapper/dmroot ro nomodeset console=hvc0 rd_NO_PLYMOUTH rd.plymouth.enable=0 plymouth.enable=0 xen_scrub_pages=0 swiotlb=2048 apparmor=1 security=apparmor
[    0.276291] Booted with the nomodeset parameter. Only the system framebuffer will be available
[    0.276464] Unknown kernel command line parameters "rd_NO_PLYMOUTH", will be passed to user space.
[    0.276519] random: crng init done
[    0.277130] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[    0.277424] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.277775] mem auto-init: stack:byref_all(zero), heap alloc:on, heap free:on
[    0.277780] mem auto-init: clearing system memory may take some time...
[    0.277786] software IO TLB: area num 2.
[    3.490356] Memory: 8157692K/8388220K available (18441K kernel code, 3244K rwdata, 7608K rodata, 3576K init, 17832K bss, 230272K reserved, 0K cma-reserved)
[    3.490531] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    3.490566] ftrace: allocating 55888 entries in 219 pages
[    3.503612] ftrace: allocated 219 pages with 6 groups
[    3.504697] Dynamic Preempt: voluntary
[    3.504761] rcu: Preemptible hierarchical RCU implementation.
[    3.504767] rcu: 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=2.
[    3.504769] 	Trampoline variant of Tasks RCU enabled.
[    3.504776] 	Rude variant of Tasks RCU enabled.
[    3.504776] 	Tracing variant of Tasks RCU enabled.
[    3.504777] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[    3.504778] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    3.511813] NR_IRQS: 524544, nr_irqs: 48, preallocated irqs: 16
[    3.511855] xen:events: Using FIFO-based ABI
[    3.511880] xen:events: Xen HVM callback vector for event delivery is enabled
[    3.512062] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    3.514664] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
[    3.514717] Console: colour dummy device 80x25
[    3.516216] printk: console [hvc0] enabled
[    3.516286] ACPI: Core revision 20220331
[    3.516374] ACPI: setting ELCR to 0200 (from ffff)
[    3.516437] APIC: Switch to symmetric I/O mode setup
[    3.516482] x2apic enabled
[    3.516495] Switched APIC routing to physical x2apic.
[    3.516557] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x172db5a3588, max_idle_ns: 440795248312 ns
[    3.516593] Calibrating delay loop (skipped), value calculated using timer frequency.. 3216.02 BogoMIPS (lpj=1608012)
[    3.516834] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    3.516851] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    3.516871] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    3.516894] Spectre V2 : Mitigation: Enhanced IBRS
[    3.516907] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    3.516924] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT
[    3.516941] RETBleed: Mitigation: Enhanced IBRS
[    3.516955] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    3.516976] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[    3.517001] MMIO Stale Data: Mitigation: Clear CPU buffers
[    3.517015] SRBDS: Unknown: Dependent on hypervisor status
[    3.517045] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    3.517064] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    3.517080] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    3.517094] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
[    3.517112] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    3.517128] x86/fpu: xstate_offset[9]:  832, xstate_sizes[9]:    8
[    3.517143] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
[    3.517590] Freeing SMP alternatives memory: 48K
[    3.517590] pid_max: default: 32768 minimum: 301
[    3.517590] LSM: Security Framework initializing
[    3.517590] Yama: becoming mindful.
[    3.517590] AppArmor: AppArmor initialized
[    3.517590] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    3.517590] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    3.517590] clocksource: xen: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    3.517590] Xen: using vcpuop timer interface
[    3.517590] installing Xen timer for CPU 0
[    3.517590] smpboot: CPU0: Intel(R) Core(TM) i7-10710U CPU @ 1.10GHz (family: 0x6, model: 0xa6, stepping: 0x1)
[    3.517590] cpu 0 spinlock event irq 20
[    3.517590] cblist_init_generic: Setting adjustable number of callback queues.
[    3.517590] cblist_init_generic: Setting shift to 1 and lim to 1.
[    3.517590] cblist_init_generic: Setting adjustable number of callback queues.
[    3.517590] cblist_init_generic: Setting shift to 1 and lim to 1.
[    3.517590] cblist_init_generic: Setting adjustable number of callback queues.
[    3.517590] cblist_init_generic: Setting shift to 1 and lim to 1.
[    3.517590] Performance Events: unsupported p6 CPU model 166 no PMU driver, software events only.
[    3.517590] signal: max sigframe size: 3632
[    3.517590] rcu: Hierarchical SRCU implementation.
[    3.517590] rcu: 	Max phase no-delay instances is 400.
[    3.518841] NMI watchdog: Perf NMI watchdog permanently disabled
[    3.518987] smp: Bringing up secondary CPUs ...
[    3.519920] installing Xen timer for CPU 1
[    3.520072] x86: Booting SMP configuration:
[    3.520086] .... node  #0, CPUs:      #1
[    3.520600] cpu 1 spinlock event irq 25
[    3.520692] smp: Brought up 1 node, 2 CPUs
[    3.520712] smpboot: Max logical packages: 1
[    3.520727] smpboot: Total of 2 processors activated (6432.04 BogoMIPS)
[    3.521750] devtmpfs: initialized
[    3.521750] x86/mm: Memory block size: 128MB
[    3.523840] clipped [mem 0xfc008040-0xffdfffff] to [mem 0xfc008040-0xfeff7fff] for e820 entry [mem 0xfeff8000-0xfeffffff]
[    3.524311] memmap_init_zone_device initialised 32768 pages in 0ms
[    3.524841] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    3.524881] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[    3.525047] pinctrl core: initialized pinctrl subsystem
[    3.530590] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    3.530659] xen:grant_table: Grant tables using version 1 layout
[    3.530739] Grant table initialized
[    3.531017] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[    3.531056] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    3.531096] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    3.531162] audit: initializing netlink subsys (disabled)
[    3.531271] audit: type=2000 audit(1703006147.615:1): state=initialized audit_enabled=0 res=1
[    3.531271] thermal_sys: Registered thermal governor 'fair_share'
[    3.531271] thermal_sys: Registered thermal governor 'bang_bang'
[    3.531601] thermal_sys: Registered thermal governor 'step_wise'
[    3.531622] thermal_sys: Registered thermal governor 'user_space'
[    3.531655] cpuidle: using governor menu
[    3.531985] PCI: Fatal: No config space access function found
[    3.534912] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
[    3.555013] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[    3.555036] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
[    3.555054] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[    3.555070] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
[    3.555595] cryptd: max_cpu_qlen set to 1000
[    3.555927] raid6: skipped pq benchmark and selected avx2x4
[    3.555945] raid6: using avx2x2 recovery algorithm
[    3.556133] ACPI: Added _OSI(Module Device)
[    3.556148] ACPI: Added _OSI(Processor Device)
[    3.556163] ACPI: Added _OSI(3.0 _SCP Extensions)
[    3.556178] ACPI: Added _OSI(Processor Aggregator Device)
[    3.563137] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    3.563514] ACPI: OSL: SCI (ACPI GSI 9) not registered
[    3.585265] ACPI: Interpreter enabled
[    3.585286] ACPI: PM: (supports S0)
[    3.585298] ACPI: Using platform specific model for interrupt routing
[    3.585335] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    3.585359] PCI: Using E820 reservations for host bridge windows
[    3.585642] ACPI: Enabled 1 GPEs in block 00 to 0F
[    3.585669] ACPI Error: No handler or method for GPE 00, disabling event (20220331/evgpe-839)
[    3.585705] ACPI Error: No handler or method for GPE 01, disabling event (20220331/evgpe-839)
[    3.585749] ACPI Error: No handler or method for GPE 03, disabling event (20220331/evgpe-839)
[    3.585784] ACPI Error: No handler or method for GPE 04, disabling event (20220331/evgpe-839)
[    3.585817] ACPI Error: No handler or method for GPE 05, disabling event (20220331/evgpe-839)
[    3.586613] ACPI Error: No handler or method for GPE 06, disabling event (20220331/evgpe-839)
[    3.586653] ACPI Error: No handler or method for GPE 07, disabling event (20220331/evgpe-839)
[    3.593565] xen:balloon: Initialising balloon driver
[    3.596738] acpi LNXCPU:02: Still not present
[    3.596738] acpi LNXCPU:03: Still not present
[    3.596738] acpi LNXCPU:04: Still not present
[    3.596781] acpi LNXCPU:05: Still not present
[    3.596807] acpi LNXCPU:06: Still not present
[    3.596833] acpi LNXCPU:07: Still not present
[    3.596861] acpi LNXCPU:08: Still not present
[    3.596887] acpi LNXCPU:09: Still not present
[    3.596913] acpi LNXCPU:0a: Still not present
[    3.596939] acpi LNXCPU:0b: Still not present
[    3.596966] acpi LNXCPU:0c: Still not present
[    3.596991] acpi LNXCPU:0d: Still not present
[    3.597017] acpi LNXCPU:0e: Still not present
[    3.597043] acpi LNXCPU:0f: Still not present
[    3.597070] acpi LNXCPU:10: Still not present
[    3.597096] acpi LNXCPU:11: Still not present
[    3.597141] acpi LNXCPU:12: Still not present
[    3.597168] acpi LNXCPU:13: Still not present
[    3.597196] acpi LNXCPU:14: Still not present
[    3.597223] acpi LNXCPU:15: Still not present
[    3.597249] acpi LNXCPU:16: Still not present
[    3.597283] acpi LNXCPU:17: Still not present
[    3.597310] acpi LNXCPU:18: Still not present
[    3.597337] acpi LNXCPU:1a: Still not present
[    3.597369] acpi LNXCPU:1b: Still not present
[    3.597396] acpi LNXCPU:1c: Still not present
[    3.597423] acpi LNXCPU:1d: Still not present
[    3.597451] acpi LNXCPU:1e: Still not present
[    3.597477] acpi LNXCPU:1f: Still not present
[    3.597504] acpi LNXCPU:20: Still not present
[    3.597531] acpi LNXCPU:22: Still not present
[    3.597558] acpi LNXCPU:23: Still not present
[    3.597590] acpi LNXCPU:24: Still not present
[    3.597590] acpi LNXCPU:25: Still not present
[    3.597590] acpi LNXCPU:26: Still not present
[    3.597590] acpi LNXCPU:27: Still not present
[    3.597590] acpi LNXCPU:28: Still not present
[    3.597590] acpi LNXCPU:29: Still not present
[    3.597590] acpi LNXCPU:2a: Still not present
[    3.597590] acpi LNXCPU:2b: Still not present
[    3.597590] acpi LNXCPU:2c: Still not present
[    3.597590] acpi LNXCPU:2e: Still not present
[    3.597590] acpi LNXCPU:2f: Still not present
[    3.597590] acpi LNXCPU:31: Still not present
[    3.597590] acpi LNXCPU:32: Still not present
[    3.597590] acpi LNXCPU:33: Still not present
[    3.597590] acpi LNXCPU:34: Still not present
[    3.597590] acpi LNXCPU:35: Still not present
[    3.597590] acpi LNXCPU:36: Still not present
[    3.597590] acpi LNXCPU:37: Still not present
[    3.597590] acpi LNXCPU:38: Still not present
[    3.597590] acpi LNXCPU:39: Still not present
[    3.597590] acpi LNXCPU:3a: Still not present
[    3.597590] acpi LNXCPU:3b: Still not present
[    3.597590] acpi LNXCPU:3c: Still not present
[    3.597704] iommu: Default domain type: Translated 
[    3.597590] acpi LNXCPU:3d: Still not present
[    3.597730] iommu: DMA domain TLB invalidation policy: lazy mode 
[    3.597590] acpi LNXCPU:3e: Still not present
[    3.597590] acpi LNXCPU:3f: Still not present
[    3.597590] acpi LNXCPU:40: Still not present
[    3.597590] acpi LNXCPU:41: Still not present
[    3.597590] acpi LNXCPU:42: Still not present
[    3.597590] acpi LNXCPU:43: Still not present
[    3.597929] SCSI subsystem initialized
[    3.597590] acpi LNXCPU:44: Still not present
[    3.597590] acpi LNXCPU:45: Still not present
[    3.597590] acpi LNXCPU:46: Still not present
[    3.598031] libata version 3.00 loaded.
[    3.597590] acpi LNXCPU:47: Still not present
[    3.598076] ACPI: bus type USB registered
[    3.597590] acpi LNXCPU:48: Still not present
[    3.598110] usbcore: registered new interface driver usbfs
[    3.597590] acpi LNXCPU:49: Still not present
[    3.598143] usbcore: registered new interface driver hub
[    3.597590] acpi LNXCPU:4a: Still not present
[    3.598168] usbcore: registered new device driver usb
[    3.597590] acpi LNXCPU:4b: Still not present
[    3.597590] acpi LNXCPU:4c: Still not present
[    3.598225] pps_core: LinuxPPS API ver. 1 registered
[    3.597590] acpi LNXCPU:4d: Still not present
[    3.598253] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    3.598257] PTP clock support registered
[    3.597590] acpi LNXCPU:4e: Still not present
[    3.597590] acpi LNXCPU:4f: Still not present
[    3.598613] EDAC MC: Ver: 3.0.0
[    3.597590] acpi LNXCPU:50: Still not present
[    3.597590] acpi LNXCPU:51: Still not present
[    3.597590] acpi LNXCPU:52: Still not present
[    3.597590] acpi LNXCPU:53: Still not present
[    3.597590] acpi LNXCPU:54: Still not present
[    3.597590] acpi LNXCPU:55: Still not present
[    3.597590] acpi LNXCPU:56: Still not present
[    3.597590] acpi LNXCPU:57: Still not present
[    3.599279] NetLabel: Initializing
[    3.599625] NetLabel:  domain hash size = 128
[    3.599641] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    3.599659] acpi LNXCPU:58: Still not present
[    3.599700] acpi LNXCPU:59: Still not present
[    3.599717] NetLabel:  unlabeled traffic allowed by default
[    3.599729] acpi LNXCPU:5a: Still not present
[    3.599740] mctp: management component transport protocol core
[    3.599767] acpi LNXCPU:5b: Still not present
[    3.599784] NET: Registered PF_MCTP protocol family
[    3.599856] acpi LNXCPU:5c: Still not present
[    3.599864] PCI: Using ACPI for IRQ routing
[    3.599885] acpi LNXCPU:5d: Still not present
[    3.599886] PCI: System does not support PCI
[    3.599914] acpi LNXCPU:5e: Still not present
[    3.599946] acpi LNXCPU:5f: Still not present
[    3.599986] acpi LNXCPU:60: Still not present
[    3.600015] acpi LNXCPU:61: Still not present
[    3.600043] acpi LNXCPU:62: Still not present
[    3.600069] acpi LNXCPU:63: Still not present
[    3.600097] acpi LNXCPU:64: Still not present
[    3.600124] acpi LNXCPU:65: Still not present
[    3.600153] acpi LNXCPU:66: Still not present
[    3.600192] acpi LNXCPU:67: Still not present
[    3.600228] acpi LNXCPU:68: Still not present
[    3.600255] acpi LNXCPU:69: Still not present
[    3.600283] acpi LNXCPU:6a: Still not present
[    3.600309] acpi LNXCPU:6b: Still not present
[    3.600337] acpi LNXCPU:6c: Still not present
[    3.600365] acpi LNXCPU:6d: Still not present
[    3.600392] acpi LNXCPU:6e: Still not present
[    3.600420] acpi LNXCPU:6f: Still not present
[    3.600446] acpi LNXCPU:70: Still not present
[    3.600474] acpi LNXCPU:71: Still not present
[    3.600502] acpi LNXCPU:72: Still not present
[    3.600528] acpi LNXCPU:73: Still not present
[    3.600556] acpi LNXCPU:74: Still not present
[    3.600584] acpi LNXCPU:75: Still not present
[    3.600590] acpi LNXCPU:76: Still not present
[    3.600602] acpi LNXCPU:77: Still not present
[    3.600602] acpi LNXCPU:78: Still not present
[    3.600602] acpi LNXCPU:79: Still not present
[    3.600602] acpi LNXCPU:7a: Still not present
[    3.600602] acpi LNXCPU:7b: Still not present
[    3.600602] acpi LNXCPU:7c: Still not present
[    3.600602] acpi LNXCPU:7d: Still not present
[    3.600602] acpi LNXCPU:7e: Still not present
[    3.600602] acpi LNXCPU:7f: Still not present
[    3.600659] vgaarb: loaded
[    3.600920] clocksource: Switched to clocksource xen
[    3.636916] VFS: Disk quotas dquot_6.6.0
[    3.636952] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    3.637224] AppArmor: AppArmor Filesystem Enabled
[    3.637278] pnp: PnP ACPI init
[    3.637330] pnp: PnP ACPI: found 0 devices
[    3.643355] NET: Registered PF_INET protocol family
[    3.643423] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    3.646021] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear)
[    3.646123] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    3.646161] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    3.646292] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, linear)
[    3.646731] TCP: Hash tables configured (established 65536 bind 65536)
[    3.646907] MPTCP token hash table entries: 8192 (order: 5, 196608 bytes, linear)
[    3.646965] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    3.647025] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    3.647103] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    3.647130] NET: Registered PF_XDP protocol family
[    3.647146] PCI: CLS 0 bytes, default 64
[    3.647165] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    3.647187] software IO TLB: mapped [mem 0x00000000fbc00000-0x00000000fc000000] (4MB)
[    3.647306] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x172db5a3588, max_idle_ns: 440795248312 ns
[    3.647514] Trying to unpack rootfs image as initramfs...
[    3.664379] Freeing initrd memory: 17836K
[    3.665669] Initialise system trusted keyrings
[    3.665708] Key type blacklist registered
[    3.665855] workingset: timestamp_bits=36 max_order=21 bucket_order=0
[    3.668212] zbud: loaded
[    3.669064] integrity: Platform Keyring initialized
[    3.669081] integrity: Machine keyring initialized
[    3.680053] NET: Registered PF_ALG protocol family
[    3.680079] xor: automatically using best checksumming function   avx       
[    3.680103] Key type asymmetric registered
[    3.680116] Asymmetric key parser 'x509' registered
[    3.681460] process '/usr/bin/busybox' started with executable stack
[    3.684886] alg: self-tests for CTR-KDF (hmac(sha256)) passed
[    3.684977] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[    3.685187] io scheduler mq-deadline registered
[    3.685223] io scheduler kyber registered
[    3.685287] io scheduler bfq registered
[    3.688388] atomic64_test: passed for x86-64 platform with CX8 and with SSE
[    3.697858] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    3.700042] Non-volatile memory driver v1.3
[    3.700070] Linux agpgart interface v0.103
[    3.700163] ACPI: bus type drm_connector registered
[    3.800789] usbcore: registered new interface driver usbserial_generic
[    3.800829] usbserial: USB Serial support registered for generic
[    3.800893] i8042: PNP: No PS/2 controller found.
[    3.800968] mousedev: PS/2 mouse device common for all mice
[    3.801047] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
[    3.801122] device-mapper: uevent: version 1.0.3
[    3.801231] device-mapper: ioctl: 4.47.0-ioctl (2022-07-28) initialised: dm-devel@redhat.com
[    3.801386] intel_pstate: CPU model not supported
[    3.801462] hid: raw HID events driver (C) Jiri Kosina
[    3.801674] usbcore: registered new interface driver usbhid
[    3.801694] usbhid: USB HID core driver
[    3.801862] drop_monitor: Initializing network drop monitor service
[    3.802000] Initializing XFRM netlink socket
[    3.802208] NET: Registered PF_INET6 protocol family
[    3.806393] Segment Routing with IPv6
[    3.806414] RPL Segment Routing with IPv6
[    3.806437] In-situ OAM (IOAM) with IPv6
[    3.806508] mip6: Mobile IPv6
[    3.806547] NET: Registered PF_PACKET protocol family
[    3.934940] IPI shorthand broadcast: enabled
[    3.934975] AVX2 version of gcm_enc/dec engaged.
[    3.935246] AES CTR mode by8 optimization enabled
[    3.940029] sched_clock: Marking stable (3935030914, 4524601)->(4456198410, -516642895)
[    3.943689] registered taskstats version 1
[    3.974074] Loading compiled-in X.509 certificates
[    4.005291] Loaded X.509 cert 'Build time autogenerated kernel key: 95791ebe9f26d42b67c1f3bbbbc771eed1c07329'
[    4.009627] zswap: loaded using pool lzo/zbud
[    4.013125] page_owner is disabled
[    4.016650] Key type .fscrypt registered
[    4.016677] Key type fscrypt-provisioning registered
[    4.020585] Btrfs loaded, crc32c=crc32c-generic, zoned=yes, fsverity=yes
[    4.020651] Key type big_key registered
[    4.034038] Key type encrypted registered
[    4.034072] AppArmor: AppArmor sha1 policy hashing enabled
[    4.034113] ima: No TPM chip found, activating TPM-bypass!
[    4.034141] Loading compiled-in module X.509 certificates
[    4.035024] Loaded X.509 cert 'Build time autogenerated kernel key: 95791ebe9f26d42b67c1f3bbbbc771eed1c07329'
[    4.035125] ima: Allocated hash algorithm: sha256
[    4.035175] ima: No architecture policies found
[    4.035233] evm: Initialising EVM extended attributes:
[    4.035251] evm: security.selinux
[    4.035263] evm: security.SMACK64 (disabled)
[    4.035279] evm: security.SMACK64EXEC (disabled)
[    4.035295] evm: security.SMACK64TRANSMUTE (disabled)
[    4.035312] evm: security.SMACK64MMAP (disabled)
[    4.035327] evm: security.apparmor
[    4.035350] evm: security.ima
[    4.035364] evm: security.capability
[    4.035377] evm: HMAC attrs: 0x1
[    4.313584] alg: No test for 842 (842-scomp)
[    4.317610] alg: No test for 842 (842-generic)
[    4.613330] xenbus_probe_frontend: Device with no driver: device/vbd/51712
[    4.613368] xenbus_probe_frontend: Device with no driver: device/vbd/51728
[    4.613394] xenbus_probe_frontend: Device with no driver: device/vbd/51744
[    4.613459] xenbus_probe_frontend: Device with no driver: device/vbd/51760
[    4.613485] xenbus_probe_frontend: Device with no driver: device/vif/0
[    4.613618] RAS: Correctable Errors collector initialized.
[    4.613662] xen:balloon: Waiting for initial ballooning down having finished.
[    8.253595] xen:balloon: Initial ballooning down finished.
[    8.255481] Freeing unused decrypted memory: 2036K
[    8.256893] Freeing unused kernel image (initmem) memory: 3576K
[    8.256917] Write protecting the kernel read-only data: 28672k
[    8.257609] Freeing unused kernel image (text/rodata gap) memory: 2036K
[    8.258258] Freeing unused kernel image (rodata/data gap) memory: 584K
[    8.258281] rodata_test: all tests were successful
[    8.258300] Run /init as init process
[    8.258317]   with arguments:
[    8.258319]     /init
[    8.258321]     rd_NO_PLYMOUTH
[    8.258326]   with environment:
[    8.258327]     HOME=/
[    8.258328]     TERM=linux
[    8.263495] Invalid max_queues (4), will use default max: 2.
[    8.280203] blkfront: xvda: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled; bounce buffer: enabled
[    8.292806]  xvda: xvda1 xvda2 xvda3
[    8.297033] blkfront: xvdb: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled; bounce buffer: enabled
[    8.301255] blkfront: xvdc: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled; bounce buffer: enabled
[    8.303886] blkfront: xvdd: barrier or flush: disabled; persistent grants: enabled; indirect descriptors: enabled; bounce buffer: enabled
[    8.660726]  xvdc: xvdc1 xvdc3
[    8.680333] EXT4-fs (xvda3): mounted filesystem with ordered data mode. Quota mode: none.
[    8.684116] /dev/xvdd: Can't open blockdev
[    8.684459] EXT4-fs (xvdd): mounting ext3 file system using the ext4 subsystem
[    8.685968] EXT4-fs (xvdd): mounted filesystem with ordered data mode. Quota mode: none.
[    8.906094] systemd[1]: systemd 247.3-7+deb11u4 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[    8.906259] systemd[1]: Detected virtualization xen.
[    8.906282] systemd[1]: Detected architecture x86-64.
[    8.910437] systemd[1]: No hostname configured.
[    8.910466] systemd[1]: Set hostname to <localhost>.
[    9.076932] systemd[1]: /lib/systemd/system/qubes-gui-agent.service:15: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
[    9.163620] systemd[1]: Queued start job for default target Multi-User System.
[    9.172126] systemd[1]: Created slice system-getty.slice.
[    9.172713] systemd[1]: Created slice system-modprobe.slice.
[    9.173195] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    9.173562] systemd[1]: Created slice User and Session Slice.
[    9.173751] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    9.173923] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    9.174262] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    9.174664] systemd[1]: Reached target Local Encrypted Volumes.
[    9.174811] systemd[1]: Reached target Remote File Systems.
[    9.174908] systemd[1]: Reached target Slices.
[    9.175162] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[    9.175449] systemd[1]: Listening on LVM2 poll daemon socket.
[    9.175725] systemd[1]: Listening on Syslog Socket.
[    9.176095] systemd[1]: Listening on fsck to fsckd communication Socket.
[    9.176261] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    9.176550] systemd[1]: Listening on Journal Audit Socket.
[    9.176775] systemd[1]: Listening on Journal Socket (/dev/log).
[    9.176990] systemd[1]: Listening on Journal Socket.
[    9.177321] systemd[1]: Listening on udev Control Socket.
[    9.177490] systemd[1]: Listening on udev Kernel Socket.
[    9.179153] systemd[1]: Mounting Huge Pages File System...
[    9.180904] systemd[1]: Mounting POSIX Message Queue File System...
[    9.182280] systemd[1]: Mounting Kernel Debug File System...
[    9.183666] systemd[1]: Mounting Kernel Trace File System...
[    9.184518] systemd[1]: Finished Availability of block devices.
[    9.186274] systemd[1]: Starting Enable swap on /dev/xvdc1 early...
[    9.188668] systemd[1]: Starting Set the console keyboard layout...
[    9.190835] systemd[1]: Starting Create list of static device nodes for the current kernel...
[    9.193687] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
[    9.197862] systemd[1]: Starting Load Kernel Module configfs...
[    9.200633] Adding 1048572k swap on /dev/xvdc1.  Priority:-2 extents:1 across:1048572k SSFS
[    9.200635] systemd[1]: Starting Load Kernel Module drm...
[    9.201907] systemd[1]: Starting Load Kernel Module fuse...
[    9.209866] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[    9.220021] fuse: init (API version 7.37)
[    9.223787] systemd[1]: Starting Journal Service...
[    9.226001] systemd[1]: Starting Load Kernel Modules...
[    9.227271] systemd[1]: Starting Coldplug All udev Devices...
[    9.229443] systemd[1]: Condition check resulted in /dev/xvdc1 being skipped.
[    9.229620] systemd[1]: Unnecessary job for /dev/xvdc1 was removed.
[    9.230411] systemd[1]: Mounted Huge Pages File System.
[    9.230712] systemd[1]: Mounted POSIX Message Queue File System.
[    9.230906] systemd[1]: Mounted Kernel Debug File System.
[    9.231087] systemd[1]: Mounted Kernel Trace File System.
[    9.231436] systemd[1]: dev-xvdc1-swap.service: Succeeded.
[    9.231784] systemd[1]: Finished Enable swap on /dev/xvdc1 early.
[    9.233446] systemd[1]: Finished Create list of static device nodes for the current kernel.
[    9.366657] systemd[1]: modprobe@configfs.service: Succeeded.
[    9.366968] systemd[1]: Finished Load Kernel Module configfs.
[    9.367893] systemd[1]: modprobe@drm.service: Succeeded.
[    9.368336] systemd[1]: Finished Load Kernel Module drm.
[    9.368779] systemd[1]: modprobe@fuse.service: Succeeded.
[    9.369238] systemd[1]: Finished Load Kernel Module fuse.
[    9.369580] systemd[1]: Reached target Swap.
[    9.371669] systemd[1]: Mounting FUSE Control File System...
[    9.373518] systemd[1]: Mounting Kernel Configuration File System...
[    9.373948] systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
[    9.375370] systemd[1]: Starting Remount Root and Kernel File Systems...
[    9.386714] systemd[1]: Mounted Kernel Configuration File System.
[    9.403475] systemd[1]: Mounted FUSE Control File System.
[    9.422562] lp: driver loaded but no devices found
[    9.428501] EXT4-fs (xvda3): re-mounted. Quota mode: none.
[    9.436989] ppdev: user-space parallel port driver
[    9.442023] systemd[1]: Finished Remount Root and Kernel File Systems.
[    9.443201] systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
[    9.443280] systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
[    9.444196] xen:xen_evtchn: Event-channel device installed
[    9.449814] systemd[1]: Starting Create System Users...
[    9.471362] systemd[1]: Finished Load Kernel Modules.
[    9.476872] systemd[1]: Starting Qubes DB agent...
[    9.478470] systemd[1]: Starting Apply Kernel Variables...
[    9.478870] systemd[1]: Started Journal Service.
[    9.501811] systemd-journald[265]: Received client request to flush runtime journal.
[    9.680142] EXT4-fs (xvdb): mounted filesystem with ordered data mode. Quota mode: none.
[    9.969880] input: PC Speaker as /devices/platform/pcspkr/input/input0
[   10.055150] Error: Driver 'pcspkr' is already registered, aborting...
[   10.056560] xen_netfront: Initialising Xen virtual ethernet driver
[   10.060391] xen_netfront: backend supports XDP headroom
[   10.060422] vif vif-0: bouncing transmitted data to zeroed pages
[   10.224049] audit: type=1400 audit(1703006154.307:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-xpdfimport" pid=424 comm="apparmor_parser"
[   10.235025] audit: type=1400 audit(1703006154.318:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=425 comm="apparmor_parser"
[   10.235077] audit: type=1400 audit(1703006154.318:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=425 comm="apparmor_parser"
[   10.241140] audit: type=1400 audit(1703006154.324:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-oopslash" pid=432 comm="apparmor_parser"
[   10.253369] audit: type=1400 audit(1703006154.336:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=434 comm="apparmor_parser"
[   10.273960] audit: type=1400 audit(1703006154.357:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=444 comm="apparmor_parser"
[   10.286493] audit: type=1400 audit(1703006154.369:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=447 comm="apparmor_parser"
[   10.286565] audit: type=1400 audit(1703006154.369:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=447 comm="apparmor_parser"
[   10.295592] audit: type=1400 audit(1703006154.375:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/haveged" pid=448 comm="apparmor_parser"
[   10.359494] audit: type=1400 audit(1703006154.442:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/evince" pid=433 comm="apparmor_parser"
[   21.094767] fbcon: Taking over console
[   65.751969] loop: module loaded
[   65.754319] loop0: detected capacity change from 0 to 83672
[   65.768941] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[   67.103601] loop1: detected capacity change from 0 to 8
[   67.152646] loop2: detected capacity change from 0 to 113992
[   67.216682] loop1: detected capacity change from 0 to 151784
[   67.272341] loop3: detected capacity change from 0 to 337560
[   67.325667] loop4: detected capacity change from 0 to 187776
[   67.425860] loop5: detected capacity change from 0 to 191544
[   67.489226] loop6: detected capacity change from 0 to 256776
[   67.545359] loop7: detected capacity change from 0 to 8
[   68.630436] loop1: detected capacity change from 0 to 151784

FIX:
Removed snapd and qubes-snapd-helper from the TemplateVM and AppVM starts normally. Originally thought cloning the failed AppVM would work but it only ran successfully once.

REMAINING PROBLEM:
Reinstalled snapd and qubes-snapd-helper and AppVM exhibited same behavior. There’s the issue I was looking for. Reporting.

ISSUE LINK:

I’ll mark your workaround as a solution for folks with the same issue, of course feel free to change that if you don’t think it’s a good idea!

If you can define reproduction steps, I would encourage you to report it.