build checks.x86_64-linux.nixos-module-test

Reproduce this run
  1. 0.10 s $ /nix/store/vzx1mi9c0xfadmsm9dhd83d005cb1qs9-coreutils-9.8/bin/timeout --kill-after=15s 7200s /nix/store/86n4l5yri6hys3zk2mwy2azcv9prqb8j-nix-2.31.4/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes --log-format internal-json build --no-link git+https://github.com/NorfairKing/upcheck?ref=master&rev=4e9e7c2d39e732129e5f6703c659ebe5578e6a84#checks.x86_64-linux.nixos-module-test --print-build-logs
  2. 0.12 s warning: ignoring untrusted flake configuration setting 'extra-substituters'.
  3. 0.12 s Pass '--accept-flake-config' to trust it
  4. 0.12 s warning: ignoring untrusted flake configuration setting 'extra-trusted-public-keys'.
  5. 0.12 s Pass '--accept-flake-config' to trust it
  6. 0.12 s
  7. 1.11 s Downloading cached test-script from https://cache.staging.nix-ci.com
  8. 1.13 s Downloading cached initrd-linux from https://cache.staging.nix-ci.com
  9. 1.14 s Downloading cached etc-hostname from https://cache.staging.nix-ci.com
  10. 1.14 s Downloading cached hosts from https://cache.staging.nix-ci.com
  11. 1.14 s Downloading cached unit-upcheck.timer from https://cache.staging.nix-ci.com
  12. 1.14 s Downloading cached upcheck-settings-check from https://cache.staging.nix-ci.com
  13. 1.14 s Downloading cached system-path from https://cache.staging.nix-ci.com
  14. 1.14 s Progress: 0 of 2 built, 1 of 23 downloaded from cache (7 downloading)
  15. 1.16 s Progress: 0 of 2 built, 2 of 23 downloaded from cache (6 downloading)
  16. 1.18 s Downloading cached upcheck-config.yaml from https://cache.staging.nix-ci.com
  17. 1.20 s Progress: 0 of 2 built, 3 of 23 downloaded from cache (5 downloading)
  18. 1.20 s Downloading cached unit-script-upcheck-start from https://cache.staging.nix-ci.com
  19. 1.20 s Progress: 0 of 2 built, 4 of 23 downloaded from cache (5 downloading)
  20. 1.24 s Progress: 0 of 2 built, 5 of 23 downloaded from cache (4 downloading)
  21. 1.25 s Downloading cached unit-upcheck.service from https://cache.staging.nix-ci.com
  22. 1.27 s Progress: 0 of 2 built, 6 of 23 downloaded from cache (4 downloading)
  23. 1.43 s Progress: 0 of 2 built, 7 of 23 downloaded from cache (3 downloading)
  24. 1.43 s Progress: 0 of 2 built, 8 of 23 downloaded from cache (2 downloading)
  25. 1.56 s Progress: 0 of 2 built, 9 of 23 downloaded from cache (1 downloading)
  26. 1.56 s Downloading cached dbus from https://cache.staging.nix-ci.com
  27. 1.58 s Progress: 0 of 2 built, 10 of 23 downloaded from cache (1 downloading)
  28. 1.58 s Downloading cached X-Restart-Triggers-dbus-broker from https://cache.staging.nix-ci.com
  29. 1.59 s Progress: 0 of 2 built, 11 of 23 downloaded from cache (1 downloading)
  30. 1.59 s Downloading cached unit-dbus-broker.service from https://cache.staging.nix-ci.com
  31. 1.59 s Downloading cached unit-dbus-broker.service from https://cache.staging.nix-ci.com
  32. 1.63 s Progress: 0 of 2 built, 12 of 23 downloaded from cache (2 downloading)
  33. 1.63 s Progress: 0 of 2 built, 13 of 23 downloaded from cache (2 downloading)
  34. 1.63 s Downloading cached user-units from https://cache.staging.nix-ci.com
  35. 1.64 s Progress: 0 of 2 built, 14 of 23 downloaded from cache (2 downloading)
  36. 1.65 s Downloading cached system-units from https://cache.staging.nix-ci.com
  37. 1.70 s Progress: 0 of 2 built, 15 of 23 downloaded from cache (1 downloading)
  38. 1.70 s Downloading cached etc from https://cache.staging.nix-ci.com
  39. 1.72 s Progress: 0 of 2 built, 16 of 23 downloaded from cache (1 downloading)
  40. 8.57 s Progress: 0 of 2 built, 17 of 23 downloaded from cache
  41. 8.60 s Downloading cached nixos-system-machine-test from https://cache.staging.nix-ci.com
  42. 8.60 s Progress: 0 of 2 built, 18 of 23 downloaded from cache
  43. 8.60 s Downloading cached closure-info from https://cache.staging.nix-ci.com
  44. 8.63 s Progress: 0 of 2 built, 19 of 23 downloaded from cache
  45. 8.63 s Downloading cached run-nixos-vm from https://cache.staging.nix-ci.com
  46. 8.66 s Progress: 0 of 2 built, 20 of 23 downloaded from cache
  47. 8.66 s Downloading cached nixos-vm from https://cache.staging.nix-ci.com
  48. 8.75 s Progress: 0 of 2 built, 21 of 23 downloaded from cache
  49. 8.75 s Downloading cached driverConfiguration.json from https://cache.staging.nix-ci.com
  50. 8.76 s Progress: 0 of 2 built, 22 of 23 downloaded from cache
  51. 8.76 s Downloading cached nixos-test-driver-upcheck-module-test from https://cache.staging.nix-ci.com
  52. 8.80 s Progress: 0 of 2 built, 23 of 23 downloaded from cache
  53. 9.04 s Building vm-test-run-upcheck-module-test
  54. 9.66 s [vm-test-run-upcheck-module-test] Machine state will be reset. To keep it, pass --keep-machine-state
  55. 9.66 s [vm-test-run-upcheck-module-test] start all VLans
  56. 9.68 s [vm-test-run-upcheck-module-test] (finished: start all VLans, in 0.01 seconds)
  57. 9.68 s [vm-test-run-upcheck-module-test] Test will time out and terminate in 3600 seconds
  58. 9.68 s [vm-test-run-upcheck-module-test] run the VM test script
  59. 9.68 s [vm-test-run-upcheck-module-test] additionally exposed symbols:
  60. 9.68 s [vm-test-run-upcheck-module-test] machine,
  61. 9.68 s [vm-test-run-upcheck-module-test] vlan1,
  62. 9.68 s [vm-test-run-upcheck-module-test] start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh
  63. 9.68 s [vm-test-run-upcheck-module-test] machine: starting vm
  64. 9.88 s [vm-test-run-upcheck-module-test] machine # Disk image does not exist, creating the virtualisation disk image...
  65. 9.88 s [vm-test-run-upcheck-module-test] machine: QEMU running (pid 12)
  66. 9.88 s [vm-test-run-upcheck-module-test] machine # Formatting '/build/vm-state-machine/tmp.yKSVamwtN0', fmt=raw size=1073741824
  67. 9.88 s [vm-test-run-upcheck-module-test] machine # mke2fs 1.47.3 (8-Jul-2025)
  68. 9.88 s [vm-test-run-upcheck-module-test] machine: waiting for unit multi-user.target
  69. 9.88 s [vm-test-run-upcheck-module-test] machine # Discarding device blocks: 0/262144 done
  70. 9.88 s [vm-test-run-upcheck-module-test] machine: waiting for the VM to finish booting
  71. 9.88 s [vm-test-run-upcheck-module-test] machine # Creating filesystem with 262144 4k blocks and 65536 inodes
  72. 9.88 s [vm-test-run-upcheck-module-test] machine # Filesystem UUID: 7c098184-24d1-4688-99d5-007bcf7e364c
  73. 9.88 s [vm-test-run-upcheck-module-test] machine # Superblock backups stored on blocks:
  74. 9.88 s [vm-test-run-upcheck-module-test] machine # 32768, 98304, 163840, 229376
  75. 9.88 s [vm-test-run-upcheck-module-test] machine #
  76. 9.88 s [vm-test-run-upcheck-module-test] machine # Allocating group tables: 0/8 done
  77. 9.88 s [vm-test-run-upcheck-module-test] machine # Writing inode tables: 0/8 done
  78. 9.88 s [vm-test-run-upcheck-module-test] machine # Creating journal (8192 blocks): done
  79. 9.88 s [vm-test-run-upcheck-module-test] machine # Writing superblocks and filesystem accounting information: 0/8 done
  80. 9.88 s [vm-test-run-upcheck-module-test] machine #
  81. 9.88 s [vm-test-run-upcheck-module-test] machine # Virtualisation disk image created.
  82. 9.98 s [vm-test-run-upcheck-module-test] machine # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  83. 10.09 s [vm-test-run-upcheck-module-test] machine #
  84. 10.09 s [vm-test-run-upcheck-module-test] machine #
  85. 10.10 s [vm-test-run-upcheck-module-test] machine # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  86. 10.11 s [vm-test-run-upcheck-module-test] machine # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  87. 10.11 s [vm-test-run-upcheck-module-test] machine #
  88. 10.11 s [vm-test-run-upcheck-module-test] machine #
  89. 10.11 s [vm-test-run-upcheck-module-test] machine #
  90. 10.11 s [vm-test-run-upcheck-module-test] machine #
  91. 10.12 s [vm-test-run-upcheck-module-test] machine # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  92. 10.14 s [vm-test-run-upcheck-module-test] machine # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  93. 10.14 s [vm-test-run-upcheck-module-test] machine #
  94. 10.14 s [vm-test-run-upcheck-module-test] machine #
  95. 10.17 s [vm-test-run-upcheck-module-test] machine # Booting from ROM...
  96. 10.20 s [vm-test-run-upcheck-module-test] machine # Probing EDD (edd=off to disable)... ok
  97. 11.50 s [vm-test-run-upcheck-module-test] machine # c[?7l[ 0.000000] Linux version 6.18.33 (nixbld@localhost) (gcc (GCC) 15.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT_DYNAMIC Sat May 23 11:07:21 UTC 2026
  98. 11.51 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/nmv8am6szbfmxbm7v9ji5r9rx3wwy9k3-nixos-system-machine-test/init regInfo=/nix/store/r5yq0r5zr950lkj92p4zyi9l0r2adzd3-closure-info/registration console=ttyS0,115200n8 console=tty0
  99. 11.51 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-provided physical RAM map:
  100. 11.51 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  101. 11.52 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  102. 11.52 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  103. 11.52 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  104. 11.52 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  105. 11.53 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  106. 11.53 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  107. 11.53 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  108. 11.53 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] NX (Execute Disable) protection: active
  109. 11.54 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] APIC: Static calls initialized
  110. 11.54 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] SMBIOS 2.8 present.
  111. 11.54 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
  112. 11.54 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] DMI: Memory slots populated: 1/1
  113. 11.54 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] Hypervisor detected: KVM
  114. 11.55 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  115. 11.55 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  116. 11.55 s [vm-test-run-upcheck-module-test] machine # [ 0.000000] kvm-clock: using sched offset of 1230753533 cycles
  117. 11.55 s [vm-test-run-upcheck-module-test] machine # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  118. 11.55 s [vm-test-run-upcheck-module-test] machine # [ 0.000005] tsc: Detected 3399.998 MHz processor
  119. 11.56 s [vm-test-run-upcheck-module-test] machine # [ 0.000700] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  120. 11.56 s [vm-test-run-upcheck-module-test] machine # [ 0.000917] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  121. 11.56 s [vm-test-run-upcheck-module-test] machine # [ 0.000925] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  122. 11.56 s [vm-test-run-upcheck-module-test] machine # [ 0.002771] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  123. 11.57 s [vm-test-run-upcheck-module-test] machine # [ 0.002785] Using GB pages for direct mapping
  124. 11.57 s [vm-test-run-upcheck-module-test] machine # [ 0.002870] RAMDISK: [mem 0x3e4ef000-0x3ffcffff]
  125. 11.57 s [vm-test-run-upcheck-module-test] machine # [ 0.002903] ACPI: Early table checksum verification disabled
  126. 11.57 s [vm-test-run-upcheck-module-test] machine # [ 0.002906] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  127. 11.57 s [vm-test-run-upcheck-module-test] machine # [ 0.002909] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  128. 11.58 s [vm-test-run-upcheck-module-test] machine # [ 0.002913] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  129. 11.58 s [vm-test-run-upcheck-module-test] machine # [ 0.002937] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  130. 11.58 s [vm-test-run-upcheck-module-test] machine # [ 0.002940] ACPI: FACS 0x000000003FFE0000 000040
  131. 11.58 s [vm-test-run-upcheck-module-test] machine # [ 0.002941] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  132. 11.59 s [vm-test-run-upcheck-module-test] machine # [ 0.002942] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  133. 11.59 s [vm-test-run-upcheck-module-test] machine # [ 0.002944] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  134. 11.59 s [vm-test-run-upcheck-module-test] machine # [ 0.002945] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  135. 11.60 s [vm-test-run-upcheck-module-test] machine # [ 0.002946] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  136. 11.60 s [vm-test-run-upcheck-module-test] machine # [ 0.002946] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  137. 11.60 s [vm-test-run-upcheck-module-test] machine # [ 0.002947] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  138. 11.60 s [vm-test-run-upcheck-module-test] machine # [ 0.002947] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  139. 11.60 s [vm-test-run-upcheck-module-test] machine # [ 0.002948] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  140. 11.61 s [vm-test-run-upcheck-module-test] machine # [ 0.003809] No NUMA configuration found
  141. 11.61 s [vm-test-run-upcheck-module-test] machine # [ 0.003810] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  142. 11.61 s [vm-test-run-upcheck-module-test] machine # [ 0.003813] NODE_DATA(0) allocated [mem 0x3ffd5780-0x3ffdacff]
  143. 11.61 s [vm-test-run-upcheck-module-test] machine # [ 0.004134] Zone ranges:
  144. 11.61 s [vm-test-run-upcheck-module-test] machine # [ 0.004135] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  145. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004137] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  146. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004138] Normal empty
  147. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004138] Device empty
  148. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004139] Movable zone start for each node
  149. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004139] Early memory node ranges
  150. 11.62 s [vm-test-run-upcheck-module-test] machine # [ 0.004140] node 0: [mem 0x0000000000001000-0x000000000009efff]
  151. 11.63 s [vm-test-run-upcheck-module-test] machine # [ 0.004140] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  152. 11.63 s [vm-test-run-upcheck-module-test] machine # [ 0.004141] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  153. 11.63 s [vm-test-run-upcheck-module-test] machine # [ 0.004231] On node 0, zone DMA: 1 pages in unavailable ranges
  154. 11.63 s [vm-test-run-upcheck-module-test] machine # [ 0.005518] On node 0, zone DMA: 97 pages in unavailable ranges
  155. 11.63 s [vm-test-run-upcheck-module-test] machine # [ 0.148928] On node 0, zone DMA32: 37 pages in unavailable ranges
  156. 11.64 s [vm-test-run-upcheck-module-test] machine # [ 0.150737] ACPI: PM-Timer IO Port: 0x608
  157. 11.64 s [vm-test-run-upcheck-module-test] machine # [ 0.150770] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  158. 11.64 s [vm-test-run-upcheck-module-test] machine # [ 0.150873] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  159. 11.64 s [vm-test-run-upcheck-module-test] machine # [ 0.150875] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  160. 11.64 s [vm-test-run-upcheck-module-test] machine # [ 0.150877] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  161. 11.65 s [vm-test-run-upcheck-module-test] machine # [ 0.150878] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  162. 11.65 s [vm-test-run-upcheck-module-test] machine # [ 0.150879] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  163. 11.65 s [vm-test-run-upcheck-module-test] machine # [ 0.150879] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  164. 11.65 s [vm-test-run-upcheck-module-test] machine # [ 0.150882] ACPI: Using ACPI (MADT) for SMP configuration information
  165. 11.66 s [vm-test-run-upcheck-module-test] machine # [ 0.150882] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  166. 11.66 s [vm-test-run-upcheck-module-test] machine # [ 0.150888] TSC deadline timer available
  167. 11.66 s [vm-test-run-upcheck-module-test] machine # [ 0.150893] CPU topo: Max. logical packages: 1
  168. 11.66 s [vm-test-run-upcheck-module-test] machine # [ 0.150894] CPU topo: Max. logical dies: 1
  169. 11.66 s [vm-test-run-upcheck-module-test] machine # [ 0.150894] CPU topo: Max. dies per package: 1
  170. 11.67 s [vm-test-run-upcheck-module-test] machine # [ 0.150897] CPU topo: Max. threads per core: 1
  171. 11.67 s [vm-test-run-upcheck-module-test] machine # [ 0.150898] CPU topo: Num. cores per package: 1
  172. 11.67 s [vm-test-run-upcheck-module-test] machine # [ 0.150898] CPU topo: Num. threads per package: 1
  173. 11.67 s [vm-test-run-upcheck-module-test] machine # [ 0.150898] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  174. 11.67 s [vm-test-run-upcheck-module-test] machine # [ 0.150937] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  175. 11.68 s [vm-test-run-upcheck-module-test] machine # [ 0.151036] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  176. 11.68 s [vm-test-run-upcheck-module-test] machine # [ 0.151037] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  177. 11.68 s [vm-test-run-upcheck-module-test] machine # [ 0.151038] [mem 0x40000000-0xfeffbfff] available for PCI devices
  178. 11.68 s [vm-test-run-upcheck-module-test] machine # [ 0.151040] Booting paravirtualized kernel on KVM
  179. 11.69 s [vm-test-run-upcheck-module-test] machine # [ 0.151043] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  180. 11.69 s [vm-test-run-upcheck-module-test] machine # [ 0.154988] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  181. 11.70 s [vm-test-run-upcheck-module-test] machine # [ 0.173862] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152
  182. 11.70 s [vm-test-run-upcheck-module-test] machine # [ 0.174005] kvm-guest: PV spinlocks disabled, single CPU
  183. 11.71 s [vm-test-run-upcheck-module-test] machine # [ 0.174007] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/nmv8am6szbfmxbm7v9ji5r9rx3wwy9k3-nixos-system-machine-test/init regInfo=/nix/store/r5yq0r5zr950lkj92p4zyi9l0r2adzd3-closure-info/registration console=ttyS0,115200n8 console=tty0
  184. 11.72 s [vm-test-run-upcheck-module-test] machine # [ 0.174088] Unknown kernel command line parameters "regInfo=/nix/store/r5yq0r5zr950lkj92p4zyi9l0r2adzd3-closure-info/registration", will be passed to user space.
  185. 11.72 s [vm-test-run-upcheck-module-test] machine # [ 0.174104] random: crng init done
  186. 11.72 s [vm-test-run-upcheck-module-test] machine # [ 0.174104] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes
  187. 11.72 s [vm-test-run-upcheck-module-test] machine # [ 0.174178] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  188. 11.72 s [vm-test-run-upcheck-module-test] machine # [ 0.177252] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  189. 11.73 s [vm-test-run-upcheck-module-test] machine # [ 0.177377] Fallback order for Node 0: 0
  190. 11.73 s [vm-test-run-upcheck-module-test] machine # [ 0.177380] Built 1 zonelists, mobility grouping on. Total pages: 262009
  191. 11.73 s [vm-test-run-upcheck-module-test] machine # [ 0.177382] Policy zone: DMA32
  192. 11.73 s [vm-test-run-upcheck-module-test] machine # [ 0.198031] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  193. 11.73 s [vm-test-run-upcheck-module-test] machine # [ 0.204164] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  194. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.223638] allocated 2097152 bytes of page_ext
  195. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.243737] ftrace: allocating 48552 entries in 192 pages
  196. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.243741] ftrace: allocated 192 pages with 2 groups
  197. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.248410] Dynamic Preempt: lazy
  198. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.250103] rcu: Preemptible hierarchical RCU implementation.
  199. 11.74 s [vm-test-run-upcheck-module-test] machine # [ 0.250104] rcu: RCU event tracing is enabled.
  200. 11.75 s [vm-test-run-upcheck-module-test] machine # [ 0.250105] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  201. 11.75 s [vm-test-run-upcheck-module-test] machine # [ 0.250106] Trampoline variant of Tasks RCU enabled.
  202. 11.75 s [vm-test-run-upcheck-module-test] machine # [ 0.250107] Rude variant of Tasks RCU enabled.
  203. 11.75 s [vm-test-run-upcheck-module-test] machine # [ 0.250107] Tracing variant of Tasks RCU enabled.
  204. 11.75 s [vm-test-run-upcheck-module-test] machine # [ 0.250108] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  205. 11.76 s [vm-test-run-upcheck-module-test] machine # [ 0.250109] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  206. 11.76 s [vm-test-run-upcheck-module-test] machine # [ 0.250268] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  207. 11.76 s [vm-test-run-upcheck-module-test] machine # [ 0.250270] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  208. 11.77 s [vm-test-run-upcheck-module-test] machine # [ 0.250272] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  209. 11.77 s [vm-test-run-upcheck-module-test] machine # [ 0.259112] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  210. 11.77 s [vm-test-run-upcheck-module-test] machine # [ 0.259891] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  211. 11.77 s [vm-test-run-upcheck-module-test] machine # [ 0.260026] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  212. 11.77 s [vm-test-run-upcheck-module-test] machine # [ 0.275019] Console: colour VGA+ 80x25
  213. 11.78 s [vm-test-run-upcheck-module-test] machine # [ 0.275026] printk: legacy console [tty0] enabled
  214. 11.78 s [vm-test-run-upcheck-module-test] machine # [ 0.397990] printk: legacy console [ttyS0] enabled
  215. 11.78 s [vm-test-run-upcheck-module-test] machine # [ 0.682509] ACPI: Core revision 20250807
  216. 11.79 s [vm-test-run-upcheck-module-test] machine # [ 0.685138] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  217. 11.79 s [vm-test-run-upcheck-module-test] machine # [ 0.689973] APIC: Switch to symmetric I/O mode setup
  218. 11.79 s [vm-test-run-upcheck-module-test] machine # [ 0.693536] x2apic enabled
  219. 11.79 s [vm-test-run-upcheck-module-test] machine # [ 0.696102] APIC: Switched APIC routing to: physical x2apic
  220. 12.23 s [vm-test-run-upcheck-module-test] machine # [ 1.135766] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  221. 12.24 s [vm-test-run-upcheck-module-test] machine # [ 1.139150] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  222. 12.24 s [vm-test-run-upcheck-module-test] machine # [ 1.144373] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  223. 12.25 s [vm-test-run-upcheck-module-test] machine # [ 1.147753] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  224. 12.25 s [vm-test-run-upcheck-module-test] machine # [ 1.150955] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  225. 12.26 s [vm-test-run-upcheck-module-test] machine # [ 1.152335] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  226. 12.26 s [vm-test-run-upcheck-module-test] machine # [ 1.154352] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto
  227. 12.27 s [vm-test-run-upcheck-module-test] machine # [ 1.156337] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  228. 12.27 s [vm-test-run-upcheck-module-test] machine # [ 1.158336] Transient Scheduler Attacks: Vulnerable: No microcode
  229. 12.27 s [vm-test-run-upcheck-module-test] machine # [ 1.160336] Spectre V2 : Mitigation: Retpolines
  230. 12.27 s [vm-test-run-upcheck-module-test] machine # [ 1.161335] Speculative Return Stack Overflow: Mitigation: Safe RET
  231. 12.28 s [vm-test-run-upcheck-module-test] machine # [ 1.163335] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  232. 12.28 s [vm-test-run-upcheck-module-test] machine # [ 1.165335] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  233. 12.29 s [vm-test-run-upcheck-module-test] machine # [ 1.167335] Spectre V2 : Enabling Restricted Speculation for firmware calls
  234. 12.29 s [vm-test-run-upcheck-module-test] machine # [ 1.169340] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  235. 12.29 s [vm-test-run-upcheck-module-test] machine # [ 1.171338] active return thunk: srso_alias_return_thunk
  236. 12.31 s [vm-test-run-upcheck-module-test] machine # [ 1.173428] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  237. 12.31 s [vm-test-run-upcheck-module-test] machine # [ 1.175340] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  238. 12.31 s [vm-test-run-upcheck-module-test] machine # [ 1.177336] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  239. 12.32 s [vm-test-run-upcheck-module-test] machine # [ 1.179335] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  240. 12.32 s [vm-test-run-upcheck-module-test] machine # [ 1.181336] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  241. 12.32 s [vm-test-run-upcheck-module-test] machine # [ 1.183335] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  242. 12.33 s [vm-test-run-upcheck-module-test] machine # [ 1.185335] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  243. 12.36 s [vm-test-run-upcheck-module-test] machine # [ 1.219837] Freeing SMP alternatives memory: 44K
  244. 12.36 s [vm-test-run-upcheck-module-test] machine # [ 1.221342] pid_max: default: 32768 minimum: 301
  245. 12.37 s [vm-test-run-upcheck-module-test] machine # [ 1.222541] LSM: initializing lsm=capability,landlock,yama,bpf,ima
  246. 12.37 s [vm-test-run-upcheck-module-test] machine # [ 1.225385] landlock: Up and running.
  247. 12.37 s [vm-test-run-upcheck-module-test] machine # [ 1.226335] Yama: becoming mindful.
  248. 12.38 s [vm-test-run-upcheck-module-test] machine # [ 1.227592] LSM support for eBPF active
  249. 12.38 s [vm-test-run-upcheck-module-test] machine # [ 1.229619] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  250. 12.38 s [vm-test-run-upcheck-module-test] machine # [ 1.232406] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  251. 12.39 s [vm-test-run-upcheck-module-test] machine # [ 1.239250] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  252. 12.40 s [vm-test-run-upcheck-module-test] machine # [ 1.243460] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  253. 12.40 s [vm-test-run-upcheck-module-test] machine # [ 1.245605] ... version: 0
  254. 12.41 s [vm-test-run-upcheck-module-test] machine # [ 1.247344] ... bit width: 48
  255. 12.41 s [vm-test-run-upcheck-module-test] machine # [ 1.248344] ... generic counters: 6
  256. 12.41 s [vm-test-run-upcheck-module-test] machine # [ 1.249344] ... generic bitmap: 000000000000003f
  257. 12.41 s [vm-test-run-upcheck-module-test] machine # [ 1.250344] ... fixed-purpose counters: 0
  258. 12.42 s [vm-test-run-upcheck-module-test] machine # [ 1.251344] ... fixed-purpose bitmap: 0000000000000000
  259. 12.42 s [vm-test-run-upcheck-module-test] machine # [ 1.252346] ... value mask: 0000ffffffffffff
  260. 12.42 s [vm-test-run-upcheck-module-test] machine # [ 1.253344] ... max period: 00007fffffffffff
  261. 12.42 s [vm-test-run-upcheck-module-test] machine # [ 1.254344] ... global_ctrl mask: 000000000000003f
  262. 12.43 s [vm-test-run-upcheck-module-test] machine # [ 1.255472] signal: max sigframe size: 3376
  263. 12.43 s [vm-test-run-upcheck-module-test] machine # [ 1.256862] rcu: Hierarchical SRCU implementation.
  264. 12.43 s [vm-test-run-upcheck-module-test] machine # [ 1.258349] rcu: Max phase no-delay instances is 400.
  265. 12.44 s [vm-test-run-upcheck-module-test] machine # [ 1.265799] smp: Bringing up secondary CPUs ...
  266. 12.44 s [vm-test-run-upcheck-module-test] machine # [ 1.267362] smp: Brought up 1 node, 1 CPU
  267. 12.45 s [vm-test-run-upcheck-module-test] machine # [ 1.268347] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  268. 12.46 s [vm-test-run-upcheck-module-test] machine # [ 1.271767] Memory: 944804K/1048036K available (17094K kernel code, 2721K rwdata, 13512K rodata, 3644K init, 3008K bss, 96028K reserved, 0K cma-reserved)
  269. 12.46 s [vm-test-run-upcheck-module-test] machine # [ 1.274310] devtmpfs: initialized
  270. 12.46 s [vm-test-run-upcheck-module-test] machine # [ 1.276461] x86/mm: Memory block size: 128MB
  271. 12.47 s [vm-test-run-upcheck-module-test] machine # [ 1.281872] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  272. 12.48 s [vm-test-run-upcheck-module-test] machine # [ 1.283500] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
  273. 12.48 s [vm-test-run-upcheck-module-test] machine # [ 1.285603] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
  274. 12.48 s [vm-test-run-upcheck-module-test] machine # [ 1.287596] pinctrl core: initialized pinctrl subsystem
  275. 12.49 s [vm-test-run-upcheck-module-test] machine # [ 1.290688] PM: RTC time: 20:25:03, date: 2026-06-01
  276. 12.51 s [vm-test-run-upcheck-module-test] machine # [ 1.313251] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  277. 12.52 s [vm-test-run-upcheck-module-test] machine # [ 1.315996] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  278. 12.52 s [vm-test-run-upcheck-module-test] machine # [ 1.317414] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  279. 12.53 s [vm-test-run-upcheck-module-test] machine # [ 1.320579] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  280. 12.53 s [vm-test-run-upcheck-module-test] machine # [ 1.322405] audit: initializing netlink subsys (disabled)
  281. 12.54 s [vm-test-run-upcheck-module-test] machine # [ 1.325493] thermal_sys: Registered thermal governor 'fair_share'
  282. 12.54 s [vm-test-run-upcheck-module-test] machine # [ 1.325495] thermal_sys: Registered thermal governor 'bang_bang'
  283. 12.54 s [vm-test-run-upcheck-module-test] machine # [ 1.327348] audit: type=2000 audit(1780345502.715:1): state=initialized audit_enabled=0 res=1
  284. 12.55 s [vm-test-run-upcheck-module-test] machine # [ 1.330351] thermal_sys: Registered thermal governor 'step_wise'
  285. 12.55 s [vm-test-run-upcheck-module-test] machine # [ 1.330353] thermal_sys: Registered thermal governor 'user_space'
  286. 12.55 s [vm-test-run-upcheck-module-test] machine # [ 1.331344] thermal_sys: Registered thermal governor 'power_allocator'
  287. 12.55 s [vm-test-run-upcheck-module-test] machine # [ 1.332384] cpuidle: using governor menu
  288. 12.56 s [vm-test-run-upcheck-module-test] machine # [ 1.337517] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  289. 12.56 s [vm-test-run-upcheck-module-test] machine # [ 1.340609] PCI: Using configuration type 1 for base access
  290. 12.57 s [vm-test-run-upcheck-module-test] machine # [ 1.342345] PCI: Using configuration type 1 for extended access
  291. 12.57 s [vm-test-run-upcheck-module-test] machine # [ 1.344154] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  292. 12.59 s [vm-test-run-upcheck-module-test] machine # [ 1.357444] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  293. 12.59 s [vm-test-run-upcheck-module-test] machine # [ 1.363345] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  294. 12.60 s [vm-test-run-upcheck-module-test] machine # [ 1.364345] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  295. 12.61 s [vm-test-run-upcheck-module-test] machine # [ 1.369158] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  296. 12.62 s [vm-test-run-upcheck-module-test] machine # [ 1.378587] ACPI: Added _OSI(Module Device)
  297. 12.62 s [vm-test-run-upcheck-module-test] machine # [ 1.379345] ACPI: Added _OSI(Processor Device)
  298. 12.62 s [vm-test-run-upcheck-module-test] machine # [ 1.382349] ACPI: Added _OSI(Processor Aggregator Device)
  299. 12.63 s [vm-test-run-upcheck-module-test] machine # [ 1.388252] ACPI: 1 ACPI AML tables successfully acquired and loaded
  300. 12.64 s [vm-test-run-upcheck-module-test] machine # [ 1.392641] ACPI: Interpreter enabled
  301. 12.64 s [vm-test-run-upcheck-module-test] machine # [ 1.394377] ACPI: PM: (supports S0 S3 S4 S5)
  302. 12.64 s [vm-test-run-upcheck-module-test] machine # [ 1.395348] ACPI: Using IOAPIC for interrupt routing
  303. 12.65 s [vm-test-run-upcheck-module-test] machine # [ 1.396584] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  304. 12.65 s [vm-test-run-upcheck-module-test] machine # [ 1.398347] PCI: Using E820 reservations for host bridge windows
  305. 12.66 s [vm-test-run-upcheck-module-test] machine # [ 1.400639] ACPI: Enabled 2 GPEs in block 00 to 0F
  306. 12.67 s [vm-test-run-upcheck-module-test] machine # [ 1.410528] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  307. 12.67 s [vm-test-run-upcheck-module-test] machine # [ 1.412356] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  308. 12.67 s [vm-test-run-upcheck-module-test] machine # [ 1.415140] acpiphp: Slot [3] registered
  309. 12.68 s [vm-test-run-upcheck-module-test] machine # [ 1.416489] acpiphp: Slot [4] registered
  310. 12.68 s [vm-test-run-upcheck-module-test] machine # [ 1.417438] acpiphp: Slot [5] registered
  311. 12.68 s [vm-test-run-upcheck-module-test] machine # [ 1.418414] acpiphp: Slot [6] registered
  312. 12.68 s [vm-test-run-upcheck-module-test] machine # [ 1.419402] acpiphp: Slot [7] registered
  313. 12.69 s [vm-test-run-upcheck-module-test] machine # [ 1.420504] acpiphp: Slot [8] registered
  314. 12.69 s [vm-test-run-upcheck-module-test] machine # [ 1.421390] acpiphp: Slot [9] registered
  315. 12.69 s [vm-test-run-upcheck-module-test] machine # [ 1.422388] acpiphp: Slot [10] registered
  316. 12.69 s [vm-test-run-upcheck-module-test] machine # [ 1.423390] acpiphp: Slot [11] registered
  317. 12.70 s [vm-test-run-upcheck-module-test] machine # [ 1.424470] acpiphp: Slot [12] registered
  318. 12.70 s [vm-test-run-upcheck-module-test] machine # [ 1.425424] acpiphp: Slot [13] registered
  319. 12.70 s [vm-test-run-upcheck-module-test] machine # [ 1.426401] acpiphp: Slot [14] registered
  320. 12.70 s [vm-test-run-upcheck-module-test] machine # [ 1.427392] acpiphp: Slot [15] registered
  321. 12.71 s [vm-test-run-upcheck-module-test] machine # [ 1.428474] acpiphp: Slot [16] registered
  322. 12.71 s [vm-test-run-upcheck-module-test] machine # [ 1.429388] acpiphp: Slot [17] registered
  323. 12.71 s [vm-test-run-upcheck-module-test] machine # [ 1.430386] acpiphp: Slot [18] registered
  324. 12.71 s [vm-test-run-upcheck-module-test] machine # [ 1.431470] acpiphp: Slot [19] registered
  325. 12.71 s [vm-test-run-upcheck-module-test] machine # [ 1.432387] acpiphp: Slot [20] registered
  326. 12.72 s [vm-test-run-upcheck-module-test] machine # [ 1.433393] acpiphp: Slot [21] registered
  327. 12.72 s [vm-test-run-upcheck-module-test] machine # [ 1.434387] acpiphp: Slot [22] registered
  328. 12.72 s [vm-test-run-upcheck-module-test] machine # [ 1.435461] acpiphp: Slot [23] registered
  329. 12.72 s [vm-test-run-upcheck-module-test] machine # [ 1.436452] acpiphp: Slot [24] registered
  330. 12.73 s [vm-test-run-upcheck-module-test] machine # [ 1.437387] acpiphp: Slot [25] registered
  331. 12.73 s [vm-test-run-upcheck-module-test] machine # [ 1.438387] acpiphp: Slot [26] registered
  332. 12.73 s [vm-test-run-upcheck-module-test] machine # [ 1.439486] acpiphp: Slot [27] registered
  333. 12.73 s [vm-test-run-upcheck-module-test] machine # [ 1.440389] acpiphp: Slot [28] registered
  334. 12.73 s [vm-test-run-upcheck-module-test] machine # [ 1.441389] acpiphp: Slot [29] registered
  335. 12.74 s [vm-test-run-upcheck-module-test] machine # [ 1.442388] acpiphp: Slot [30] registered
  336. 12.74 s [vm-test-run-upcheck-module-test] machine # [ 1.443556] acpiphp: Slot [31] registered
  337. 12.74 s [vm-test-run-upcheck-module-test] machine # [ 1.444382] PCI host bridge to bus 0000:00
  338. 12.75 s [vm-test-run-upcheck-module-test] machine # [ 1.445352] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  339. 12.75 s [vm-test-run-upcheck-module-test] machine # [ 1.447358] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  340. 12.75 s [vm-test-run-upcheck-module-test] machine # [ 1.449350] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  341. 12.76 s [vm-test-run-upcheck-module-test] machine # [ 1.451350] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  342. 12.76 s [vm-test-run-upcheck-module-test] machine # [ 1.453356] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  343. 12.76 s [vm-test-run-upcheck-module-test] machine # [ 1.455348] pci_bus 0000:00: root bus resource [bus 00-ff]
  344. 12.77 s [vm-test-run-upcheck-module-test] machine # [ 1.457069] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  345. 12.78 s [vm-test-run-upcheck-module-test] machine # [ 1.460468] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  346. 12.78 s [vm-test-run-upcheck-module-test] machine # [ 1.463952] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  347. 12.79 s [vm-test-run-upcheck-module-test] machine # [ 1.467099] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  348. 12.79 s [vm-test-run-upcheck-module-test] machine # [ 1.468456] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  349. 12.79 s [vm-test-run-upcheck-module-test] machine # [ 1.470344] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  350. 12.80 s [vm-test-run-upcheck-module-test] machine # [ 1.471344] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  351. 12.80 s [vm-test-run-upcheck-module-test] machine # [ 1.472344] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  352. 12.80 s [vm-test-run-upcheck-module-test] machine # [ 1.474006] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  353. 12.81 s [vm-test-run-upcheck-module-test] machine # [ 1.476827] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  354. 12.81 s [vm-test-run-upcheck-module-test] machine # [ 1.479761] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  355. 12.82 s [vm-test-run-upcheck-module-test] machine # [ 1.482467] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  356. 12.82 s [vm-test-run-upcheck-module-test] machine # [ 1.484369] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  357. 12.83 s [vm-test-run-upcheck-module-test] machine # [ 1.487203] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  358. 12.85 s [vm-test-run-upcheck-module-test] machine # [ 1.491016] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  359. 12.85 s [vm-test-run-upcheck-module-test] machine # [ 1.493411] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  360. 12.85 s [vm-test-run-upcheck-module-test] machine # [ 1.494433] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  361. 12.86 s [vm-test-run-upcheck-module-test] machine # [ 1.498090] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  362. 12.87 s [vm-test-run-upcheck-module-test] machine # [ 1.506431] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  363. 12.88 s [vm-test-run-upcheck-module-test] machine # [ 1.510387] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  364. 12.88 s [vm-test-run-upcheck-module-test] machine # [ 1.511373] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  365. 12.88 s [vm-test-run-upcheck-module-test] machine # [ 1.512446] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  366. 12.89 s [vm-test-run-upcheck-module-test] machine # [ 1.514370] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  367. 12.90 s [vm-test-run-upcheck-module-test] machine # [ 1.520772] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  368. 12.90 s [vm-test-run-upcheck-module-test] machine # [ 1.524373] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  369. 12.90 s [vm-test-run-upcheck-module-test] machine # [ 1.525374] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  370. 12.91 s [vm-test-run-upcheck-module-test] machine # [ 1.526437] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  371. 12.92 s [vm-test-run-upcheck-module-test] machine # [ 1.531551] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  372. 12.92 s [vm-test-run-upcheck-module-test] machine # [ 1.535372] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  373. 12.92 s [vm-test-run-upcheck-module-test] machine # [ 1.536379] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  374. 12.93 s [vm-test-run-upcheck-module-test] machine # [ 1.537448] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  375. 12.93 s [vm-test-run-upcheck-module-test] machine # [ 1.542388] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  376. 12.94 s [vm-test-run-upcheck-module-test] machine # [ 1.546448] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  377. 12.94 s [vm-test-run-upcheck-module-test] machine # [ 1.548398] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  378. 12.95 s [vm-test-run-upcheck-module-test] machine # [ 1.549442] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  379. 12.95 s [vm-test-run-upcheck-module-test] machine # [ 1.554527] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  380. 12.96 s [vm-test-run-upcheck-module-test] machine # [ 1.558371] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  381. 12.96 s [vm-test-run-upcheck-module-test] machine # [ 1.559370] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  382. 12.97 s [vm-test-run-upcheck-module-test] machine # [ 1.560439] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  383. 12.98 s [vm-test-run-upcheck-module-test] machine # [ 1.565392] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  384. 12.99 s [vm-test-run-upcheck-module-test] machine # [ 1.570387] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  385. 13.00 s [vm-test-run-upcheck-module-test] machine # [ 1.571372] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  386. 13.00 s [vm-test-run-upcheck-module-test] machine # [ 1.572460] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  387. 13.01 s [vm-test-run-upcheck-module-test] machine # [ 1.579369] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  388. 13.02 s [vm-test-run-upcheck-module-test] machine # [ 1.583371] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  389. 13.02 s [vm-test-run-upcheck-module-test] machine # [ 1.584371] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  390. 13.02 s [vm-test-run-upcheck-module-test] machine # [ 1.585441] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  391. 13.03 s [vm-test-run-upcheck-module-test] machine # [ 1.587391] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  392. 13.03 s [vm-test-run-upcheck-module-test] machine # [ 1.592369] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  393. 13.04 s [vm-test-run-upcheck-module-test] machine # [ 1.596392] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  394. 13.04 s [vm-test-run-upcheck-module-test] machine # [ 1.597438] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  395. 13.05 s [vm-test-run-upcheck-module-test] machine # [ 1.602776] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  396. 13.06 s [vm-test-run-upcheck-module-test] machine # [ 1.606388] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  397. 13.06 s [vm-test-run-upcheck-module-test] machine # [ 1.607385] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  398. 13.06 s [vm-test-run-upcheck-module-test] machine # [ 1.609465] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  399. 13.07 s [vm-test-run-upcheck-module-test] machine # [ 1.614898] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  400. 13.08 s [vm-test-run-upcheck-module-test] machine # [ 1.618382] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  401. 13.08 s [vm-test-run-upcheck-module-test] machine # [ 1.619376] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  402. 13.09 s [vm-test-run-upcheck-module-test] machine # [ 1.620493] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  403. 13.10 s [vm-test-run-upcheck-module-test] machine # [ 1.637143] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  404. 13.11 s [vm-test-run-upcheck-module-test] machine # [ 1.638604] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  405. 13.11 s [vm-test-run-upcheck-module-test] machine # [ 1.640638] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  406. 13.11 s [vm-test-run-upcheck-module-test] machine # [ 1.642552] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  407. 13.12 s [vm-test-run-upcheck-module-test] machine # [ 1.644454] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  408. 13.13 s [vm-test-run-upcheck-module-test] machine # [ 1.652981] iommu: Default domain type: Translated
  409. 13.13 s [vm-test-run-upcheck-module-test] machine # [ 1.654344] iommu: DMA domain TLB invalidation policy: lazy mode
  410. 13.14 s [vm-test-run-upcheck-module-test] machine # [ 1.657946] ACPI: bus type USB registered
  411. 13.14 s [vm-test-run-upcheck-module-test] machine # [ 1.659777] usbcore: registered new interface driver usbfs
  412. 13.14 s [vm-test-run-upcheck-module-test] machine # [ 1.661466] usbcore: registered new interface driver hub
  413. 13.14 s [vm-test-run-upcheck-module-test] machine # [ 1.662393] usbcore: registered new device driver usb
  414. 13.15 s [vm-test-run-upcheck-module-test] machine # [ 1.668647] NetLabel: Initializing
  415. 13.15 s [vm-test-run-upcheck-module-test] machine # [ 1.669344] NetLabel: domain hash size = 128
  416. 13.16 s [vm-test-run-upcheck-module-test] machine # [ 1.670343] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  417. 13.16 s [vm-test-run-upcheck-module-test] machine # [ 1.671594] NetLabel: unlabeled traffic allowed by default
  418. 13.16 s [vm-test-run-upcheck-module-test] machine # [ 1.673678] PCI: Using ACPI for IRQ routing
  419. 13.17 s [vm-test-run-upcheck-module-test] machine # [ 1.677812] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  420. 13.17 s [vm-test-run-upcheck-module-test] machine # [ 1.678332] pci 0000:00:02.0: vgaarb: bridge control possible
  421. 13.17 s [vm-test-run-upcheck-module-test] machine # [ 1.678332] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  422. 13.18 s [vm-test-run-upcheck-module-test] machine # [ 1.678348] vgaarb: loaded
  423. 13.18 s [vm-test-run-upcheck-module-test] machine # [ 1.681246] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  424. 13.18 s [vm-test-run-upcheck-module-test] machine # [ 1.682343] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  425. 13.19 s [vm-test-run-upcheck-module-test] machine # [ 1.686902] clocksource: Switched to clocksource kvm-clock
  426. 13.21 s [vm-test-run-upcheck-module-test] machine # [ 1.706794] VFS: Disk quotas dquot_6.6.0
  427. 13.21 s [vm-test-run-upcheck-module-test] machine # [ 1.709256] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  428. 13.22 s [vm-test-run-upcheck-module-test] machine # [ 1.713811] pnp: PnP ACPI init
  429. 13.22 s [vm-test-run-upcheck-module-test] machine # [ 1.717400] pnp: PnP ACPI: found 6 devices
  430. 13.24 s [vm-test-run-upcheck-module-test] machine # [ 1.735404] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  431. 13.24 s [vm-test-run-upcheck-module-test] machine # [ 1.740298] clocksource: Switched to clocksource acpi_pm
  432. 13.25 s [vm-test-run-upcheck-module-test] machine # [ 1.744086] NET: Registered PF_INET protocol family
  433. 13.25 s [vm-test-run-upcheck-module-test] machine # [ 1.748403] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  434. 13.34 s [vm-test-run-upcheck-module-test] machine # [ 1.835139] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  435. 13.35 s [vm-test-run-upcheck-module-test] machine # [ 1.840732] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  436. 13.35 s [vm-test-run-upcheck-module-test] machine # [ 1.845078] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  437. 13.35 s [vm-test-run-upcheck-module-test] machine # [ 1.849979] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  438. 13.36 s [vm-test-run-upcheck-module-test] machine # [ 1.854005] TCP: Hash tables configured (established 8192 bind 8192)
  439. 13.36 s [vm-test-run-upcheck-module-test] machine # [ 1.857959] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  440. 13.37 s [vm-test-run-upcheck-module-test] machine # [ 1.862130] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
  441. 13.37 s [vm-test-run-upcheck-module-test] machine # [ 1.865888] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
  442. 13.37 s [vm-test-run-upcheck-module-test] machine # [ 1.870223] NET: Registered PF_UNIX/PF_LOCAL protocol family
  443. 13.38 s [vm-test-run-upcheck-module-test] machine # [ 1.873721] NET: Registered PF_XDP protocol family
  444. 13.38 s [vm-test-run-upcheck-module-test] machine # [ 1.876713] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  445. 13.38 s [vm-test-run-upcheck-module-test] machine # [ 1.880163] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  446. 13.39 s [vm-test-run-upcheck-module-test] machine # [ 1.883583] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  447. 13.39 s [vm-test-run-upcheck-module-test] machine # [ 1.887353] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  448. 13.40 s [vm-test-run-upcheck-module-test] machine # [ 1.891089] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  449. 13.40 s [vm-test-run-upcheck-module-test] machine # [ 1.895625] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  450. 13.40 s [vm-test-run-upcheck-module-test] machine # [ 1.898922] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  451. 13.41 s [vm-test-run-upcheck-module-test] machine # [ 1.905385] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  452. 13.41 s [vm-test-run-upcheck-module-test] machine # [ 1.910596] PCI: CLS 0 bytes, default 64
  453. 13.42 s [vm-test-run-upcheck-module-test] machine # [ 1.914265] Trying to unpack rootfs image as initramfs...
  454. 13.43 s [vm-test-run-upcheck-module-test] machine # [ 1.924980] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  455. 13.48 s [vm-test-run-upcheck-module-test] machine # [ 1.975337] Initialise system trusted keyrings
  456. 13.49 s [vm-test-run-upcheck-module-test] machine # [ 1.982765] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  457. 13.52 s [vm-test-run-upcheck-module-test] machine # [ 2.017192] Key type asymmetric registered
  458. 13.53 s [vm-test-run-upcheck-module-test] machine # [ 2.022563] Asymmetric key parser 'x509' registered
  459. 13.53 s [vm-test-run-upcheck-module-test] machine # [ 2.029574] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
  460. 13.54 s [vm-test-run-upcheck-module-test] machine # [ 2.040034] io scheduler mq-deadline registered
  461. 13.55 s [vm-test-run-upcheck-module-test] machine # [ 2.045570] io scheduler kyber registered
  462. 13.56 s [vm-test-run-upcheck-module-test] machine # [ 2.055939] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  463. 13.57 s [vm-test-run-upcheck-module-test] machine # [ 2.065781] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  464. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.079908] Linux agpgart interface v0.103
  465. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.085866] ACPI: bus type drm_connector registered
  466. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.095667] usbcore: registered new interface driver usbserial_generic
  467. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.105641] usbserial: USB Serial support registered for generic
  468. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.113519] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  469. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.124410] drop_monitor: Initializing network drop monitor service
  470. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.135302] NET: Registered PF_INET6 protocol family
  471. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.148808] Segment Routing with IPv6
  472. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.155565] In-situ OAM (IOAM) with IPv6
  473. 13.66 s [vm-test-run-upcheck-module-test] machine # [ 2.161787] IPI shorthand broadcast: enabled
  474. 13.69 s [vm-test-run-upcheck-module-test] machine # [ 2.182859] registered taskstats version 1
  475. 13.69 s [vm-test-run-upcheck-module-test] machine # [ 2.189671] Loading compiled-in X.509 certificates
  476. 13.75 s [vm-test-run-upcheck-module-test] machine # [ 2.248595] Demotion targets for Node 0: null
  477. 13.76 s [vm-test-run-upcheck-module-test] machine # [ 2.254664] Key type .fscrypt registered
  478. 13.76 s [vm-test-run-upcheck-module-test] machine # [ 2.259529] Key type fscrypt-provisioning registered
  479. 13.77 s [vm-test-run-upcheck-module-test] machine # [ 2.267709] ima: No TPM chip found, activating TPM-bypass!
  480. 13.78 s [vm-test-run-upcheck-module-test] machine # [ 2.274511] ima: Allocated hash algorithm: sha1
  481. 13.78 s [vm-test-run-upcheck-module-test] machine # [ 2.277139] ima: No architecture policies found
  482. 13.79 s [vm-test-run-upcheck-module-test] machine # [ 2.285389] PM: Magic number: 14:570:446
  483. 13.79 s [vm-test-run-upcheck-module-test] machine # [ 2.290921] RAS: Correctable Errors collector initialized.
  484. 13.81 s [vm-test-run-upcheck-module-test] machine # [ 2.308298] Unstable clock detected, switching default tracing clock to "global"
  485. 13.82 s [vm-test-run-upcheck-module-test] machine # [ 2.308298] If you want to keep using the local clock, then add:
  486. 13.82 s [vm-test-run-upcheck-module-test] machine # [ 2.308298] "trace_clock=local"
  487. 13.82 s [vm-test-run-upcheck-module-test] machine # [ 2.308298] on the kernel command line
  488. 13.84 s [vm-test-run-upcheck-module-test] machine # [ 2.333836] clk: Disabling unused clocks
  489. 13.84 s [vm-test-run-upcheck-module-test] machine # [ 2.338717] PM: genpd: Disabling unused power domains
  490. 14.92 s [vm-test-run-upcheck-module-test] machine # [ 3.421237] Freeing initrd memory: 27524K
  491. 14.95 s [vm-test-run-upcheck-module-test] machine # [ 3.444516] Freeing unused decrypted memory: 2028K
  492. 14.98 s [vm-test-run-upcheck-module-test] machine # [ 3.474673] Freeing unused kernel image (initmem) memory: 3644K
  493. 14.98 s [vm-test-run-upcheck-module-test] machine # [ 3.479399] Write protecting the kernel read-only data: 32768k
  494. 15.00 s [vm-test-run-upcheck-module-test] machine # [ 3.494952] Freeing unused kernel image (text/rodata gap) memory: 1336K
  495. 15.01 s [vm-test-run-upcheck-module-test] machine # [ 3.509091] Freeing unused kernel image (rodata/data gap) memory: 824K
  496. 15.06 s [vm-test-run-upcheck-module-test] machine # [ 3.557239] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  497. 15.06 s [vm-test-run-upcheck-module-test] machine # [ 3.560812] Run /init as init process
  498. 15.11 s [vm-test-run-upcheck-module-test] machine # [ 3.602535] systemd[1]: Inserted module 'autofs4'
  499. 15.13 s [vm-test-run-upcheck-module-test] machine # [ 3.625862] fuse: init (API version 7.45)
  500. 15.14 s [vm-test-run-upcheck-module-test] machine # [ 3.635871] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  501. 15.15 s [vm-test-run-upcheck-module-test] machine # [ 3.649620] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  502. 15.16 s [vm-test-run-upcheck-module-test] machine # [ 3.656603] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  503. 15.23 s [vm-test-run-upcheck-module-test] machine # [ 3.727380] systemd[1]: Successfully made /usr/ read-only.
  504. 15.59 s [vm-test-run-upcheck-module-test] machine # [ 4.069082] systemd[1]: systemd 260.1 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
  505. 15.59 s [vm-test-run-upcheck-module-test] machine # [ 4.085020] systemd[1]: Detected virtualization kvm.
  506. 15.59 s [vm-test-run-upcheck-module-test] machine # [ 4.088028] systemd[1]: Detected architecture x86-64.
  507. 15.59 s [vm-test-run-upcheck-module-test] machine # [ 4.090892] systemd[1]: Running in initrd.
  508. 15.60 s [vm-test-run-upcheck-module-test] machine # [ 4.094047] systemd[1]: Initializing machine ID from random generator.
  509. 15.60 s [vm-test-run-upcheck-module-test] machine # [ 4.097828] systemd[1]: Hostname set to <machine>.
  510. 15.67 s [vm-test-run-upcheck-module-test] machine # [ 4.169575] systemd[1]: Queued start job for default target Initrd Default Target.
  511. 15.76 s [vm-test-run-upcheck-module-test] machine # [ 4.253635] systemd[1]: Created slice Slice /system/modprobe.
  512. 15.76 s [vm-test-run-upcheck-module-test] machine # [ 4.257369] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  513. 15.77 s [vm-test-run-upcheck-module-test] machine # [ 4.261828] systemd[1]: Expecting device /dev/disk/by-label/nixos...
  514. 15.77 s [vm-test-run-upcheck-module-test] machine # [ 4.265590] systemd[1]: Reached target Path Units.
  515. 15.77 s [vm-test-run-upcheck-module-test] machine # [ 4.268373] systemd[1]: Reached target Slice Units.
  516. 15.77 s [vm-test-run-upcheck-module-test] machine # [ 4.271286] systemd[1]: Reached target Swaps.
  517. 15.78 s [vm-test-run-upcheck-module-test] machine # [ 4.274624] systemd[1]: Reached target Timer Units.
  518. 15.78 s [vm-test-run-upcheck-module-test] machine # [ 4.277847] systemd[1]: Listening on D-Bus System Message Bus Socket.
  519. 15.79 s [vm-test-run-upcheck-module-test] machine # [ 4.281761] systemd[1]: Listening on Journal Socket (/dev/log).
  520. 15.79 s [vm-test-run-upcheck-module-test] machine # [ 4.285545] systemd[1]: Listening on Journal Sockets.
  521. 15.79 s [vm-test-run-upcheck-module-test] machine # [ 4.288810] systemd[1]: Listening on udev Control Socket.
  522. 15.80 s [vm-test-run-upcheck-module-test] machine # [ 4.292061] systemd[1]: Listening on udev Kernel Socket.
  523. 15.80 s [vm-test-run-upcheck-module-test] machine # [ 4.295542] systemd[1]: Reached target Socket Units.
  524. 15.81 s [vm-test-run-upcheck-module-test] machine # [ 4.302135] systemd[1]: Starting Create List of Static Device Nodes...
  525. 15.82 s [vm-test-run-upcheck-module-test] machine # [ 4.318754] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
  526. 15.84 s [vm-test-run-upcheck-module-test] machine # [ 4.334856] systemd[1]: Starting Load Kernel Module configfs...
  527. 15.87 s [vm-test-run-upcheck-module-test] machine # [ 4.369791] systemd[1]: Starting Journal Service...
  528. 15.88 s [vm-test-run-upcheck-module-test] machine # [ 4.373321] netfs: FS-Cache loaded
  529. 15.89 s [vm-test-run-upcheck-module-test] machine # [ 4.388933] 9pnet: Installing 9P2000 support
  530. 15.90 s [vm-test-run-upcheck-module-test] machine # [ 4.396663] systemd[1]: Starting Load Kernel Modules...
  531. 15.92 s [vm-test-run-upcheck-module-test] machine # [ 4.417683] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
  532. 15.93 s [vm-test-run-upcheck-module-test] machine # [ 4.426284] systemd-journald[126]: Collecting audit messages is disabled.
  533. 15.95 s [vm-test-run-upcheck-module-test] machine # [ 4.445829] systemd[1]: Starting Coldplug All udev Devices...
  534. 16.00 s [vm-test-run-upcheck-module-test] machine # [ 4.499850] systemd[1]: Finished Create List of Static Device Nodes.
  535. 16.02 s [vm-test-run-upcheck-module-test] machine # [ 4.508981] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
  536. 16.04 s [vm-test-run-upcheck-module-test] machine # [ 4.530670] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
  537. 16.07 s [vm-test-run-upcheck-module-test] machine # [ 4.548600] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
  538. 16.09 s [vm-test-run-upcheck-module-test] machine # [ 4.585288] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
  539. 16.11 s [vm-test-run-upcheck-module-test] machine # [ 4.608316] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  540. 16.13 s [vm-test-run-upcheck-module-test] machine # [ 4.627373] systemd[1]: Finished Load Kernel Module configfs.
  541. 16.16 s [vm-test-run-upcheck-module-test] machine # [ 4.653667] systemd[1]: Finished Load Kernel Modules.
  542. 16.18 s [vm-test-run-upcheck-module-test] machine # [ 4.669710] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config
  543. 16.19 s [vm-test-run-upcheck-module-test] machine # [ 3.806332] systemd-modules-load[129]: Inserted module 'dm_mod'
  544. 16.19 s [vm-test-run-upcheck-module-test] machine # [ 3.813626] systemd-modules-load[129]: Inserted module 'virtio_balloon'
  545. 16.20 s [vm-test-run-upcheck-module-test] machine # [ 4.696073] systemd[1]: Starting Apply Kernel Variables...
  546. 16.20 s [vm-test-run-upcheck-module-test] machine # [ 3.825154] systemd-modules-load[129]: Inserted module 'virtio_gpu'
  547. 16.23 s [vm-test-run-upcheck-module-test] machine # [ 4.723938] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  548. 16.24 s [vm-test-run-upcheck-module-test] machine # [ 4.738239] systemd[1]: Started Journal Service.
  549. 16.26 s [vm-test-run-upcheck-module-test] machine # [ 3.883545] systemd[1]: Finished Apply Kernel Variables.
  550. 16.27 s [vm-test-run-upcheck-module-test] machine # [ 3.892240] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  551. 16.29 s [vm-test-run-upcheck-module-test] machine # [ 3.906836] systemd[1]: Starting Create Static Device Nodes in /dev...
  552. 16.32 s [vm-test-run-upcheck-module-test] machine # [ 3.937245] systemd[1]: Finished Create Static Device Nodes in /dev.
  553. 16.32 s [vm-test-run-upcheck-module-test] machine # [ 3.942668] systemd[1]: Reached target Preparation for Local File Systems.
  554. 16.33 s [vm-test-run-upcheck-module-test] machine # [ 3.950356] systemd[1]: Reached target Local File Systems.
  555. 16.34 s [vm-test-run-upcheck-module-test] machine # [ 3.956512] systemd[1]: Starting Create System Files and Directories...
  556. 16.35 s [vm-test-run-upcheck-module-test] machine # [ 3.968957] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  557. 16.37 s [vm-test-run-upcheck-module-test] machine # [ 3.991437] systemd[1]: Finished Create System Files and Directories.
  558. 16.40 s [vm-test-run-upcheck-module-test] machine # [ 4.023490] systemd-udevd[161]: Using default interface naming scheme 'v260'.
  559. 16.43 s [vm-test-run-upcheck-module-test] machine # [ 4.049531] systemd[1]: Finished Coldplug All udev Devices.
  560. 16.44 s [vm-test-run-upcheck-module-test] machine # [ 4.063578] systemd[1]: Started Rule-based Manager for Device Events and Files.
  561. 16.45 s [vm-test-run-upcheck-module-test] machine # [ 4.069446] systemd[1]: Reached target System Initialization.
  562. 16.46 s [vm-test-run-upcheck-module-test] machine # [ 4.073587] systemd[1]: Reached target Basic System.
  563. 16.82 s [vm-test-run-upcheck-module-test] machine # [ 5.319737] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  564. 16.85 s [vm-test-run-upcheck-module-test] machine # [ 5.351322] uhci_hcd 0000:00:01.2: UHCI Host Controller
  565. 16.87 s [vm-test-run-upcheck-module-test] machine # [ 5.365608] serio: i8042 KBD port at 0x60,0x64 irq 1
  566. 16.87 s [vm-test-run-upcheck-module-test] machine # [ 5.368666] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  567. 16.88 s [vm-test-run-upcheck-module-test] machine # [ 5.378990] virtio_blk virtio5: 1/0/0 default/read/poll queues
  568. 16.89 s [vm-test-run-upcheck-module-test] machine # [ 5.388771] serio: i8042 AUX port at 0x60,0x64 irq 12
  569. 16.90 s [vm-test-run-upcheck-module-test] machine # [ 5.397584] uhci_hcd 0000:00:01.2: detected 2 ports
  570. 16.92 s [vm-test-run-upcheck-module-test] machine # [ 5.419165] SCSI subsystem initialized
  571. 16.93 s [vm-test-run-upcheck-module-test] machine # [ 5.424766] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  572. 16.95 s [vm-test-run-upcheck-module-test] machine # [ 5.445240] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  573. 16.96 s [vm-test-run-upcheck-module-test] machine # [ 5.456184] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18
  574. 16.98 s [vm-test-run-upcheck-module-test] machine # [ 5.479524] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  575. 17.00 s [vm-test-run-upcheck-module-test] machine # [ 5.502019] usb usb1: Product: UHCI Host Controller
  576. 17.01 s [vm-test-run-upcheck-module-test] machine # [ 5.509034] usb usb1: Manufacturer: Linux 6.18.33 uhci_hcd
  577. 17.03 s [vm-test-run-upcheck-module-test] machine # [ 5.527577] usb usb1: SerialNumber: 0000:00:01.2
  578. 17.04 s [vm-test-run-upcheck-module-test] machine # [ 4.656400] (udev-worker)[173]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  579. 17.06 s [vm-test-run-upcheck-module-test] machine # [ 4.676623] systemd[1]: Starting Virtual Console Setup...
  580. 17.07 s [vm-test-run-upcheck-module-test] machine # [ 4.687522] (udev-worker)[171]: Network interface NamePolicy= disabled on kernel command line.
  581. 17.07 s [vm-test-run-upcheck-module-test] machine # [ 5.570647] hub 1-0:1.0: USB hub found
  582. 17.08 s [vm-test-run-upcheck-module-test] machine # [ 4.696837] (udev-worker)[173]: Network interface NamePolicy= disabled on kernel command line.
  583. 17.10 s [vm-test-run-upcheck-module-test] machine # [ 5.597076] hub 1-0:1.0: 2 ports detected
  584. 17.13 s [vm-test-run-upcheck-module-test] machine # [ 4.744378] systemd-vconsole-setup[180]: Configuration of first virtual console was skipped, ignoring remaining ones.
  585. 17.13 s [vm-test-run-upcheck-module-test] machine # [ 5.627857] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  586. 17.14 s [vm-test-run-upcheck-module-test] machine # [ 4.762371] systemd[1]: Finished Virtual Console Setup.
  587. 17.17 s [vm-test-run-upcheck-module-test] machine # [ 4.795270] systemd[1]: Found device /dev/disk/by-label/nixos.
  588. 17.18 s [vm-test-run-upcheck-module-test] machine # [ 4.801415] systemd[1]: Reached target Initrd Root Device.
  589. 17.19 s [vm-test-run-upcheck-module-test] machine # [ 4.806331] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
  590. 17.22 s [vm-test-run-upcheck-module-test] machine # [ 5.716660] scsi host0: ata_piix
  591. 17.22 s [vm-test-run-upcheck-module-test] machine # [ 4.843296] systemd-fsck[191]: nixos: clean, 12/65536 files, 13019/262144 blocks
  592. 17.23 s [vm-test-run-upcheck-module-test] machine # [ 5.726409] scsi host1: ata_piix
  593. 17.23 s [vm-test-run-upcheck-module-test] machine # [ 5.729074] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  594. 17.24 s [vm-test-run-upcheck-module-test] machine # [ 5.733543] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  595. 17.25 s [vm-test-run-upcheck-module-test] machine # [ 4.867533] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
  596. 17.34 s [vm-test-run-upcheck-module-test] machine # [ 5.833701] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  597. 17.41 s [vm-test-run-upcheck-module-test] machine # [ 5.905057] ata2: found unknown device (class 0)
  598. 17.41 s [vm-test-run-upcheck-module-test] machine # [ 5.909193] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  599. 17.42 s [vm-test-run-upcheck-module-test] machine # [ 5.915008] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  600. 17.46 s [vm-test-run-upcheck-module-test] machine # [ 5.952012] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  601. 17.47 s [vm-test-run-upcheck-module-test] machine # [ 5.965314] cdrom: Uniform CD-ROM driver Revision: 3.20
  602. 17.51 s [vm-test-run-upcheck-module-test] machine # [ 6.005076] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  603. 17.51 s [vm-test-run-upcheck-module-test] machine # [ 6.008666] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  604. 17.52 s [vm-test-run-upcheck-module-test] machine # [ 6.014377] usb 1-1: Product: QEMU USB Tablet
  605. 17.52 s [vm-test-run-upcheck-module-test] machine # [ 6.018811] usb 1-1: Manufacturer: QEMU
  606. 17.52 s [vm-test-run-upcheck-module-test] machine # [ 6.021381] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  607. 17.56 s [vm-test-run-upcheck-module-test] machine # [ 6.060615] hid: raw HID events driver (C) Jiri Kosina
  608. 17.59 s [vm-test-run-upcheck-module-test] machine # [ 6.086649] usbcore: registered new interface driver usbhid
  609. 17.60 s [vm-test-run-upcheck-module-test] machine # [ 6.094693] usbhid: USB HID core driver
  610. 17.61 s [vm-test-run-upcheck-module-test] machine # [ 6.106096] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
  611. 17.62 s [vm-test-run-upcheck-module-test] machine # [ 6.114047] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
  612. 18.01 s [vm-test-run-upcheck-module-test] machine # [ 5.626136] systemd[1]: Mounting /sysroot...
  613. 18.14 s [vm-test-run-upcheck-module-test] machine # [ 6.629838] EXT4-fs (vda): mounted filesystem 7c098184-24d1-4688-99d5-007bcf7e364c r/w with ordered data mode. Quota mode: none.
  614. 18.14 s [vm-test-run-upcheck-module-test] machine # [ 5.762658] systemd[1]: Mounted /sysroot.
  615. 18.15 s [vm-test-run-upcheck-module-test] machine # [ 5.766431] systemd[1]: Reached target Initrd Root File System.
  616. 18.15 s [vm-test-run-upcheck-module-test] machine # [ 5.770424] systemd[1]: Starting Mountpoints Configured in the Real Root...
  617. 18.17 s [vm-test-run-upcheck-module-test] machine # [ 5.786306] systemd-sysroot-fstab-check[212]: /sysroot should be mounted in the initrd, will request daemon-reload.
  618. 18.17 s [vm-test-run-upcheck-module-test] machine # [ 5.793407] systemd[1]: Reload requested from client PID 212 ('systemd-sysroot') (unit initrd-parse-etc.service)...
  619. 18.18 s [vm-test-run-upcheck-module-test] machine # [ 5.803151] systemd[1]: Reloading...
  620. 18.39 s [vm-test-run-upcheck-module-test] machine # [ 6.012270] systemd[1]: Reloading finished in 221 ms.
  621. 18.41 s [vm-test-run-upcheck-module-test] machine # [ 6.033189] systemd-sysroot-fstab-check[212]: Requesting initrd-fs.target/start/replace...
  622. 18.48 s [vm-test-run-upcheck-module-test] machine # [ 6.102189] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  623. 18.49 s [vm-test-run-upcheck-module-test] machine # [ 6.110419] systemd-sysroot-fstab-check[212]: Requesting swap.target/start/replace...
  624. 18.50 s [vm-test-run-upcheck-module-test] machine # [ 6.116436] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
  625. 18.50 s [vm-test-run-upcheck-module-test] machine # [ 6.120513] systemd[1]: Finished Mountpoints Configured in the Real Root.
  626. 18.50 s [vm-test-run-upcheck-module-test] machine # [ 6.122899] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
  627. 18.99 s [vm-test-run-upcheck-module-test] machine # [ 6.611856] systemd[1]: Mounting /sysroot/nix/.ro-store...
  628. 19.04 s [vm-test-run-upcheck-module-test] machine # [ 6.617647] systemd[1]: Mounting /sysroot/nix/.rw-store...
  629. 19.04 s [vm-test-run-upcheck-module-test] machine # [ 6.624643] systemd[1]: Mounting /sysroot/run...
  630. 19.04 s [vm-test-run-upcheck-module-test] machine # [ 6.632743] systemd[1]: Mounting /sysroot/tmp/shared...
  631. 19.04 s [vm-test-run-upcheck-module-test] machine # [ 6.648291] systemd[1]: Mounting /sysroot/tmp/xchg...
  632. 19.04 s [vm-test-run-upcheck-module-test] machine # [ 7.536679] 9p: Installing v9fs 9p2000 file system support
  633. 19.05 s [vm-test-run-upcheck-module-test] machine # [ 6.674993] systemd[1]: Mounted /sysroot/nix/.rw-store.
  634. 19.07 s [vm-test-run-upcheck-module-test] machine # [ 6.689821] systemd[1]: Mounted /sysroot/nix/.ro-store.
  635. 19.07 s [vm-test-run-upcheck-module-test] machine # [ 6.694378] systemd[1]: Mounted /sysroot/run.
  636. 19.08 s [vm-test-run-upcheck-module-test] machine # [ 6.697418] systemd[1]: Mounted /sysroot/tmp/shared.
  637. 19.08 s [vm-test-run-upcheck-module-test] machine # [ 6.701541] systemd[1]: Mounted /sysroot/tmp/xchg.
  638. 19.09 s [vm-test-run-upcheck-module-test] machine # [ 6.708282] systemd[1]: Starting rw-sysroot-nix-store.service...
  639. 19.10 s [vm-test-run-upcheck-module-test] machine # [ 6.719153] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  640. 19.10 s [vm-test-run-upcheck-module-test] machine # [ 6.724172] systemd[1]: Finished rw-sysroot-nix-store.service.
  641. 19.99 s [vm-test-run-upcheck-module-test] machine # [ 7.611590] systemd[1]: Mounting /sysroot/nix/store...
  642. 20.02 s [vm-test-run-upcheck-module-test] machine # [ 7.637507] systemd[1]: Mounted /sysroot/nix/store.
  643. 20.03 s [vm-test-run-upcheck-module-test] machine # [ 7.642435] systemd[1]: Reached target Initrd File Systems.
  644. 20.03 s [vm-test-run-upcheck-module-test] machine # [ 7.652170] systemd[1]: Starting Find NixOS closure...
  645. 20.04 s [vm-test-run-upcheck-module-test] machine # [ 7.658183] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
  646. 20.07 s [vm-test-run-upcheck-module-test] machine # [ 7.692926] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
  647. 20.08 s [vm-test-run-upcheck-module-test] machine # [ 7.699375] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.
  648. 20.09 s [vm-test-run-upcheck-module-test] machine # [ 7.710350] systemd[1]: Finished Find NixOS closure.
  649. 20.10 s [vm-test-run-upcheck-module-test] machine # [ 7.716629] systemd[1]: Reached target Initrd Default Target.
  650. 20.10 s [vm-test-run-upcheck-module-test] machine # [ 7.722635] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
  651. 20.13 s [vm-test-run-upcheck-module-test] machine # [ 7.751952] systemd[1]: Stopped target Initrd Default Target.
  652. 20.14 s [vm-test-run-upcheck-module-test] machine # [ 7.756447] systemd[1]: Stopped target Basic System.
  653. 20.14 s [vm-test-run-upcheck-module-test] machine # [ 7.761389] systemd[1]: Stopped target Initrd Root Device.
  654. 20.14 s [vm-test-run-upcheck-module-test] machine # [ 7.765413] systemd[1]: Stopped target Path Units.
  655. 20.15 s [vm-test-run-upcheck-module-test] machine # [ 7.769283] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
  656. 20.16 s [vm-test-run-upcheck-module-test] machine # [ 7.775417] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
  657. 20.16 s [vm-test-run-upcheck-module-test] machine # [ 7.781912] systemd[1]: Stopped target Slice Units.
  658. 20.17 s [vm-test-run-upcheck-module-test] machine # [ 7.786470] systemd[1]: Stopped target Socket Units.
  659. 20.17 s [vm-test-run-upcheck-module-test] machine # [ 7.794251] systemd[1]: Stopped target System Initialization.
  660. 20.18 s [vm-test-run-upcheck-module-test] machine # [ 7.800353] systemd[1]: Stopped target Swaps.
  661. 20.18 s [vm-test-run-upcheck-module-test] machine # [ 7.805374] systemd[1]: Stopped target Timer Units.
  662. 20.19 s [vm-test-run-upcheck-module-test] machine # [ 7.809283] systemd[1]: dbus.socket: Deactivated successfully.
  663. 20.19 s [vm-test-run-upcheck-module-test] machine # [ 7.813510] systemd[1]: Closed D-Bus System Message Bus Socket.
  664. 20.20 s [vm-test-run-upcheck-module-test] machine # [ 7.817992] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
  665. 20.20 s [vm-test-run-upcheck-module-test] machine # [ 7.825912] systemd[1]: Stopped Find NixOS closure.
  666. 20.21 s [vm-test-run-upcheck-module-test] machine # [ 7.830500] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  667. 20.22 s [vm-test-run-upcheck-module-test] machine # [ 7.840400] systemd[1]: Starting rw-sysroot-nix-store.service...
  668. 20.22 s [vm-test-run-upcheck-module-test] machine # [ 7.844920] systemd[1]: systemd-sysctl.service: Deactivated successfully.
  669. 20.23 s [vm-test-run-upcheck-module-test] machine # [ 7.849837] systemd[1]: Stopped Apply Kernel Variables.
  670. 20.23 s [vm-test-run-upcheck-module-test] machine # [ 7.854325] systemd[1]: systemd-modules-load.service: Deactivated successfully.
  671. 20.24 s [vm-test-run-upcheck-module-test] machine # [ 7.860772] systemd[1]: Stopped Load Kernel Modules.
  672. 20.25 s [vm-test-run-upcheck-module-test] machine # [ 7.866659] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
  673. 20.25 s [vm-test-run-upcheck-module-test] machine # [ 7.872363] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
  674. 20.26 s [vm-test-run-upcheck-module-test] machine # [ 7.877804] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
  675. 20.26 s [vm-test-run-upcheck-module-test] machine # [ 7.885191] systemd[1]: Stopped Create System Files and Directories.
  676. 20.27 s [vm-test-run-upcheck-module-test] machine # [ 7.889348] systemd[1]: Stopped target Local File Systems.
  677. 20.27 s [vm-test-run-upcheck-module-test] machine # [ 7.894792] systemd[1]: Stopped target Preparation for Local File Systems.
  678. 20.28 s [vm-test-run-upcheck-module-test] machine # [ 7.901702] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
  679. 20.29 s [vm-test-run-upcheck-module-test] machine # [ 7.908434] systemd[1]: Stopped Coldplug All udev Devices.
  680. 20.29 s [vm-test-run-upcheck-module-test] machine # [ 7.914361] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
  681. 20.30 s [vm-test-run-upcheck-module-test] machine # [ 7.921472] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  682. 20.31 s [vm-test-run-upcheck-module-test] machine # [ 7.928589] systemd[1]: Stopped Virtual Console Setup.
  683. 20.31 s [vm-test-run-upcheck-module-test] machine # [ 7.933142] systemd[1]: systemd-udevd.service: Deactivated successfully.
  684. 20.32 s [vm-test-run-upcheck-module-test] machine # [ 7.937357] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
  685. 20.32 s [vm-test-run-upcheck-module-test] machine # [ 7.942635] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  686. 20.33 s [vm-test-run-upcheck-module-test] machine # [ 7.948325] systemd[1]: Finished rw-sysroot-nix-store.service.
  687. 20.33 s [vm-test-run-upcheck-module-test] machine # [ 7.952370] systemd[1]: initrd-cleanup.service: Deactivated successfully.
  688. 20.34 s [vm-test-run-upcheck-module-test] machine # [ 7.957247] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
  689. 20.34 s [vm-test-run-upcheck-module-test] machine # [ 7.959808] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
  690. 20.34 s [vm-test-run-upcheck-module-test] machine # [ 7.962652] systemd[1]: Closed udev Control Socket.
  691. 20.34 s [vm-test-run-upcheck-module-test] machine # [ 7.965281] systemd[1]: Starting Cleanup udev Database...
  692. 20.35 s [vm-test-run-upcheck-module-test] machine # [ 7.967581] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
  693. 20.35 s [vm-test-run-upcheck-module-test] machine # [ 7.970931] systemd[1]: Stopped Create Static Device Nodes in /dev.
  694. 20.35 s [vm-test-run-upcheck-module-test] machine # [ 7.974474] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
  695. 20.36 s [vm-test-run-upcheck-module-test] machine # [ 7.977958] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
  696. 20.36 s [vm-test-run-upcheck-module-test] machine # [ 7.981136] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
  697. 20.36 s [vm-test-run-upcheck-module-test] machine # [ 7.983920] systemd[1]: Stopped Create List of Static Device Nodes.
  698. 20.37 s [vm-test-run-upcheck-module-test] machine # [ 7.986637] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
  699. 20.37 s [vm-test-run-upcheck-module-test] machine # [ 7.989842] systemd[1]: Finished Cleanup udev Database.
  700. 20.37 s [vm-test-run-upcheck-module-test] machine # [ 7.992198] systemd[1]: Reached target Switch Root.
  701. 20.37 s [vm-test-run-upcheck-module-test] machine # [ 7.994847] systemd[1]: Starting NixOS Activation...
  702. 20.52 s [vm-test-run-upcheck-module-test] machine # [ 8.138763] initrd-nixos-activation-start[504]: booting system configuration /nix/store/nmv8am6szbfmxbm7v9ji5r9rx3wwy9k3-nixos-system-machine-test
  703. 20.58 s [vm-test-run-upcheck-module-test] machine # [ 8.203438] initrd-nixos-activation-start[504]: running activation script...
  704. 21.02 s [vm-test-run-upcheck-module-test] machine # [ 8.641384] initrd-nixos-activation-start[527]: setting up /etc...
  705. 21.29 s [vm-test-run-upcheck-module-test] machine # [ 8.910765] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
  706. 21.30 s [vm-test-run-upcheck-module-test] machine # [ 8.918357] systemd[1]: Finished NixOS Activation.
  707. 21.30 s [vm-test-run-upcheck-module-test] machine # [ 8.922993] systemd[1]: Starting Switch Root...
  708. 21.32 s [vm-test-run-upcheck-module-test] machine # [ 8.939387] systemd[1]: Switching root.
  709. 21.49 s [vm-test-run-upcheck-module-test] machine # [ 9.991215] systemd-journald[126]: Received SIGTERM from PID 1 (systemd).
  710. 21.91 s [vm-test-run-upcheck-module-test] machine # [ 10.408644] NET: Registered PF_VSOCK protocol family
  711. 22.32 s [vm-test-run-upcheck-module-test] machine # [ 10.812124] systemd[1]: systemd 260.1 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
  712. 22.33 s [vm-test-run-upcheck-module-test] machine # [ 10.823732] systemd[1]: Detected virtualization kvm.
  713. 22.33 s [vm-test-run-upcheck-module-test] machine # [ 10.825957] systemd[1]: Detected architecture x86-64.
  714. 22.33 s [vm-test-run-upcheck-module-test] machine # [ 10.828322] systemd[1]: Detected first boot.
  715. 22.37 s [vm-test-run-upcheck-module-test] machine # [ 10.870208] systemd[1]: Initializing machine ID from random generator.
  716. 22.66 s [vm-test-run-upcheck-module-test] machine # [ 11.155417] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  717. 22.80 s [vm-test-run-upcheck-module-test] machine # [ 11.301289] systemd[1]: Applying preset policy.
  718. 23.30 s [vm-test-run-upcheck-module-test] machine # [ 11.800915] systemd[1]: Populated /etc with preset unit settings.
  719. 23.54 s [vm-test-run-upcheck-module-test] machine # [ 12.030569] systemd[1]: /etc/systemd/system/upcheck.service:3: Invalid URL, ignoring: /nix/store/hpxj1401b263sdra7f40a6280jlp9v7x-upcheck-settings-check
  720. 23.83 s [vm-test-run-upcheck-module-test] machine # [ 12.321758] systemd[1]: initrd-switch-root.service: Deactivated successfully.
  721. 23.83 s [vm-test-run-upcheck-module-test] machine # [ 12.325620] systemd[1]: Stopped initrd-switch-root.service.
  722. 23.84 s [vm-test-run-upcheck-module-test] machine # [ 12.337069] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
  723. 23.84 s [vm-test-run-upcheck-module-test] machine # [ 12.341778] systemd[1]: Created slice Slice /system/getty.
  724. 23.85 s [vm-test-run-upcheck-module-test] machine # [ 12.344847] systemd[1]: Created slice User and Session Slice.
  725. 23.85 s [vm-test-run-upcheck-module-test] machine # [ 12.347418] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  726. 23.85 s [vm-test-run-upcheck-module-test] machine # [ 12.350704] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  727. 23.86 s [vm-test-run-upcheck-module-test] machine # [ 12.353902] systemd[1]: Expecting device /dev/hvc0...
  728. 23.86 s [vm-test-run-upcheck-module-test] machine # [ 12.356065] systemd[1]: Expecting device /dev/ttyS0...
  729. 23.86 s [vm-test-run-upcheck-module-test] machine # [ 12.358319] systemd[1]: Reached target Local Encrypted Volumes.
  730. 23.86 s [vm-test-run-upcheck-module-test] machine # [ 12.360757] systemd[1]: Stopped target initrd-fs.target.
  731. 23.87 s [vm-test-run-upcheck-module-test] machine # [ 12.362968] systemd[1]: Stopped target initrd-root-fs.target.
  732. 23.87 s [vm-test-run-upcheck-module-test] machine # [ 12.365523] systemd[1]: Stopped target initrd-switch-root.target.
  733. 23.87 s [vm-test-run-upcheck-module-test] machine # [ 12.368218] systemd[1]: Reached target Virtual Machines and Containers.
  734. 23.87 s [vm-test-run-upcheck-module-test] machine # [ 12.371092] systemd[1]: Reached target Path Units.
  735. 23.88 s [vm-test-run-upcheck-module-test] machine # [ 12.373365] systemd[1]: Reached target Remote File Systems.
  736. 23.88 s [vm-test-run-upcheck-module-test] machine # [ 12.375876] systemd[1]: Reached target Slice Units.
  737. 23.88 s [vm-test-run-upcheck-module-test] machine # [ 12.378204] systemd[1]: Reached target Swaps.
  738. 23.95 s [vm-test-run-upcheck-module-test] machine # [ 12.442637] systemd[1]: Listening on Process Core Dump Socket.
  739. 23.96 s [vm-test-run-upcheck-module-test] machine # [ 12.453357] systemd[1]: Listening on Credential Encryption/Decryption.
  740. 23.97 s [vm-test-run-upcheck-module-test] machine # [ 12.470139] systemd[1]: Starting Journal Log Access Socket...
  741. 23.98 s [vm-test-run-upcheck-module-test] machine # [ 12.474127] systemd[1]: Listening on Journal Audit Socket.
  742. 23.98 s [vm-test-run-upcheck-module-test] machine # [ 12.477144] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  743. 23.98 s [vm-test-run-upcheck-module-test] machine # [ 12.480329] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
  744. 23.99 s [vm-test-run-upcheck-module-test] machine # [ 12.484238] systemd[1]: Listening on udev Control Socket.
  745. 23.99 s [vm-test-run-upcheck-module-test] machine # [ 12.490249] systemd[1]: Mounting Huge Pages File System...
  746. 24.05 s [vm-test-run-upcheck-module-test] machine # [ 12.496223] systemd[1]: Mounting POSIX Message Queue File System...
  747. 24.05 s [vm-test-run-upcheck-module-test] machine # [ 12.509323] systemd[1]: Mounting Kernel Debug File System...
  748. 24.05 s [vm-test-run-upcheck-module-test] machine # [ 12.518939] systemd[1]: Mounting Kernel Trace File System...
  749. 24.05 s [vm-test-run-upcheck-module-test] machine # [ 12.532095] systemd[1]: Starting Create List of Static Device Nodes...
  750. 24.05 s [vm-test-run-upcheck-module-test] machine # [ 12.542342] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  751. 24.07 s [vm-test-run-upcheck-module-test] machine # [ 12.568285] systemd[1]: Starting Load Kernel Module configfs...
  752. 24.08 s [vm-test-run-upcheck-module-test] machine # [ 12.573919] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
  753. 24.10 s [vm-test-run-upcheck-module-test] machine # [ 12.591773] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
  754. 24.12 s [vm-test-run-upcheck-module-test] machine # [ 12.613894] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  755. 24.13 s [vm-test-run-upcheck-module-test] machine # [ 12.624402] systemd[1]: Mounting FUSE Control File System...
  756. 24.13 s [vm-test-run-upcheck-module-test] machine # [ 12.626876] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
  757. 24.15 s [vm-test-run-upcheck-module-test] machine # [ 12.646178] systemd[1]: Starting Journal Service...
  758. 24.16 s [vm-test-run-upcheck-module-test] machine # [ 12.661857] systemd[1]: Starting Load Kernel Modules...
  759. 24.18 s [vm-test-run-upcheck-module-test] machine # [ 12.680395] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  760. 24.20 s [vm-test-run-upcheck-module-test] machine # [ 12.697648] systemd[1]: Starting Remount Root and Kernel File Systems...
  761. 24.22 s [vm-test-run-upcheck-module-test] machine # [ 12.710768] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
  762. 24.24 s [vm-test-run-upcheck-module-test] machine # [ 12.734782] systemd[1]: Starting Coldplug All udev Devices...
  763. 24.24 s [vm-test-run-upcheck-module-test] machine # [ 12.737383] systemd-journald[737]: Collecting audit messages is enabled.
  764. 24.28 s [vm-test-run-upcheck-module-test] machine # [ 12.775048] loop: module loaded
  765. 24.28 s [vm-test-run-upcheck-module-test] machine # [ 12.779754] systemd[1]: Listening on Journal Log Access Socket.
  766. 24.30 s [vm-test-run-upcheck-module-test] machine # [ 12.797643] systemd[1]: Mounted Huge Pages File System.
  767. 24.31 s [vm-test-run-upcheck-module-test] machine # [ 12.807608] EXT4-fs (vda): re-mounted 7c098184-24d1-4688-99d5-007bcf7e364c.
  768. 24.32 s [vm-test-run-upcheck-module-test] machine # [ 12.812670] systemd[1]: Mounted POSIX Message Queue File System.
  769. 24.32 s [vm-test-run-upcheck-module-test] machine # [ 11.939213] systemd[1]: Queued start job for default target Multi-User System.
  770. 24.33 s [vm-test-run-upcheck-module-test] machine # [ 11.949137] systemd[1]: systemd-journald.service: Deactivated successfully.
  771. 24.33 s [vm-test-run-upcheck-module-test] machine # [ 12.831410] systemd[1]: Started Journal Service.
  772. 24.34 s [vm-test-run-upcheck-module-test] machine # [ 11.958164] systemd-modules-load[738]: Inserted module 'loop'
  773. 24.35 s [vm-test-run-upcheck-module-test] machine # [ 11.967915] systemd[1]: Mounted Kernel Debug File System.
  774. 24.35 s [vm-test-run-upcheck-module-test] machine # [ 11.974871] systemd[1]: Mounted Kernel Trace File System.
  775. 24.36 s [vm-test-run-upcheck-module-test] machine # [ 11.980917] systemd[1]: Finished Create List of Static Device Nodes.
  776. 24.37 s [vm-test-run-upcheck-module-test] machine # [ 11.985951] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  777. 24.37 s [vm-test-run-upcheck-module-test] machine # [ 11.991100] systemd[1]: Finished Load Kernel Module configfs.
  778. 24.38 s [vm-test-run-upcheck-module-test] machine # [ 11.996154] systemd[1]: Mounted FUSE Control File System.
  779. 24.38 s [vm-test-run-upcheck-module-test] machine # [ 12.000620] systemd[1]: Finished Load Kernel Modules.
  780. 24.38 s [vm-test-run-upcheck-module-test] machine # [ 12.004203] systemd[1]: Finished Remount Root and Kernel File Systems.
  781. 24.40 s [vm-test-run-upcheck-module-test] machine # [ 12.024415] systemd-oomd[740]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  782. 24.42 s [vm-test-run-upcheck-module-test] machine # [ 12.036526] systemd[1]: Mounting Kernel Configuration File System...
  783. 24.42 s [vm-test-run-upcheck-module-test] machine # [ 12.045292] systemd[1]: Starting Firewall...
  784. 24.43 s [vm-test-run-upcheck-module-test] machine # [ 12.051713] systemd[1]: Starting Flush Journal to Persistent Storage...
  785. 24.44 s [vm-test-run-upcheck-module-test] machine # [ 12.059359] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
  786. 24.45 s [vm-test-run-upcheck-module-test] machine # [ 12.071498] systemd[1]: Starting Load/Save OS Random Seed...
  787. 24.46 s [vm-test-run-upcheck-module-test] machine # [ 12.077406] systemd[1]: Starting Apply Kernel Variables...
  788. 24.48 s [vm-test-run-upcheck-module-test] machine # [ 12.105189] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  789. 24.49 s [vm-test-run-upcheck-module-test] machine # [ 12.111473] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
  790. 24.50 s [vm-test-run-upcheck-module-test] machine # [ 12.124424] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  791. 24.64 s [vm-test-run-upcheck-module-test] machine # [ 12.256889] systemd[1]: Mounted Kernel Configuration File System.
  792. 24.69 s [vm-test-run-upcheck-module-test] machine # [ 13.188358] systemd-journald[737]: Received client request to flush runtime journal.
  793. 25.12 s [vm-test-run-upcheck-module-test] machine # [ 12.736627] systemd[1]: Finished Apply Kernel Variables.
  794. 25.13 s [vm-test-run-upcheck-module-test] machine # [ 12.749174] systemd[1]: Finished Load/Save OS Random Seed.
  795. 25.14 s [vm-test-run-upcheck-module-test] machine # [ 12.756538] systemd[1]: Reached target First Boot Complete.
  796. 25.15 s [vm-test-run-upcheck-module-test] machine # [ 12.765922] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  797. 25.16 s [vm-test-run-upcheck-module-test] machine # [ 12.776460] systemd[1]: Starting Create Static Device Nodes in /dev...
  798. 25.16 s [vm-test-run-upcheck-module-test] machine # [ 12.784932] systemd[1]: Finished Coldplug All udev Devices.
  799. 25.18 s [vm-test-run-upcheck-module-test] machine # [ 12.792906] systemd[1]: Finished Create Static Device Nodes in /dev.
  800. 25.18 s [vm-test-run-upcheck-module-test] machine # [ 12.802912] systemd[1]: Reached target Preparation for Local File Systems.
  801. 25.19 s [vm-test-run-upcheck-module-test] machine # [ 12.810919] systemd[1]: Mounting /run/wrappers...
  802. 25.20 s [vm-test-run-upcheck-module-test] machine # [ 12.821970] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  803. 25.21 s [vm-test-run-upcheck-module-test] machine # [ 12.828100] systemd[1]: Mounted /run/wrappers.
  804. 25.22 s [vm-test-run-upcheck-module-test] machine # [ 12.837227] systemd[1]: Reached target Local File Systems.
  805. 25.22 s [vm-test-run-upcheck-module-test] machine # [ 12.845307] systemd[1]: Listening on Boot Loader Control Service Socket.
  806. 25.23 s [vm-test-run-upcheck-module-test] machine # [ 12.854476] systemd[1]: Starting register-nix-paths.service...
  807. 25.24 s [vm-test-run-upcheck-module-test] machine # [ 12.862800] systemd[1]: Starting Create SUID/SGID Wrappers...
  808. 25.26 s [vm-test-run-upcheck-module-test] machine # [ 12.875608] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
  809. 25.28 s [vm-test-run-upcheck-module-test] machine # [ 12.896713] systemd[1]: Starting Save Transient machine-id to Disk...
  810. 25.29 s [vm-test-run-upcheck-module-test] machine # [ 12.907560] systemd-udevd[781]: Using default interface naming scheme 'v260'.
  811. 25.30 s [vm-test-run-upcheck-module-test] machine # [ 12.919882] systemd[1]: Finished Flush Journal to Persistent Storage.
  812. 25.31 s [vm-test-run-upcheck-module-test] machine # [ 12.932776] systemd[1]: Starting Create System Files and Directories...
  813. 25.36 s [vm-test-run-upcheck-module-test] machine # [ 12.980379] systemd[1]: Finished Save Transient machine-id to Disk.
  814. 25.44 s [vm-test-run-upcheck-module-test] machine # [ 13.057617] systemd[1]: Finished Create System Files and Directories.
  815. 25.45 s [vm-test-run-upcheck-module-test] machine # [ 13.074754] systemd[1]: Starting Rebuild Journal Catalog...
  816. 25.47 s [vm-test-run-upcheck-module-test] machine # [ 13.086600] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  817. 25.50 s [vm-test-run-upcheck-module-test] machine # [ 13.123364] systemd[1]: Started Rule-based Manager for Device Events and Files.
  818. 25.61 s [vm-test-run-upcheck-module-test] machine # [ 13.227597] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  819. 25.67 s [vm-test-run-upcheck-module-test] machine # [ 13.290863] systemd[1]: Finished Rebuild Journal Catalog.
  820. 25.69 s [vm-test-run-upcheck-module-test] machine # [ 13.309288] systemd[1]: Starting Update is Completed...
  821. 25.81 s [vm-test-run-upcheck-module-test] machine # [ 13.432379] systemd[1]: Finished Update is Completed.
  822. 25.83 s [vm-test-run-upcheck-module-test] machine # [ 13.447624] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  823. 26.38 s [vm-test-run-upcheck-module-test] machine # [ 13.995317] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  824. 26.41 s [vm-test-run-upcheck-module-test] machine # [ 14.029477] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  825. 26.42 s [vm-test-run-upcheck-module-test] machine # [ 14.040399] systemd[1]: Finished Create SUID/SGID Wrappers.
  826. 26.62 s [vm-test-run-upcheck-module-test] machine # [ 14.238231] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
  827. 26.67 s [vm-test-run-upcheck-module-test] machine # [ 14.294380] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.
  828. 26.76 s [vm-test-run-upcheck-module-test] machine # [ 14.382623] (udev-worker)[887]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  829. 26.78 s [vm-test-run-upcheck-module-test] machine # [ 14.402437] (udev-worker)[887]: Network interface NamePolicy= disabled on kernel command line.
  830. 26.79 s [vm-test-run-upcheck-module-test] machine # [ 14.413790] (udev-worker)[882]: Network interface NamePolicy= disabled on kernel command line.
  831. 26.93 s [vm-test-run-upcheck-module-test] machine # [ 14.547332] systemd[1]: Finished Firewall.
  832. 26.94 s [vm-test-run-upcheck-module-test] machine # [ 14.562132] systemd[1]: Finished register-nix-paths.service.
  833. 26.95 s [vm-test-run-upcheck-module-test] machine # [ 14.567011] systemd[1]: Reached target System Initialization.
  834. 26.95 s [vm-test-run-upcheck-module-test] machine # [ 14.573671] systemd[1]: Started Discard unused filesystem blocks once a week.
  835. 26.96 s [vm-test-run-upcheck-module-test] machine # [ 14.582929] systemd[1]: Started Daily Cleanup of Temporary Directories.
  836. 26.97 s [vm-test-run-upcheck-module-test] machine # [ 14.587517] systemd[1]: Started upcheck.timer.
  837. 26.97 s [vm-test-run-upcheck-module-test] machine # [ 14.592919] systemd[1]: Reached target Timer Units.
  838. 26.98 s [vm-test-run-upcheck-module-test] machine # [ 14.596874] systemd[1]: Listening on D-Bus System Message Bus Socket.
  839. 26.99 s [vm-test-run-upcheck-module-test] machine # [ 14.606377] systemd[1]: Listening on Nix Daemon Socket.
  840. 27.00 s [vm-test-run-upcheck-module-test] machine # [ 14.611397] systemd[1]: Listening on Hostname Service Socket.
  841. 27.00 s [vm-test-run-upcheck-module-test] machine # [ 14.618447] systemd[1]: Reached target Socket Units.
  842. 27.00 s [vm-test-run-upcheck-module-test] machine # [ 14.623466] systemd[1]: Reached target Basic System.
  843. 27.01 s [vm-test-run-upcheck-module-test] machine # [ 14.630397] systemd[1]: Started backdoor.service.
  844. 27.01 s [vm-test-run-upcheck-module-test] machine # [ 14.635468] systemd[1]: Starting Import lastlog data into lastlog2 database...
  845. 27.02 s [vm-test-run-upcheck-module-test] machine # [ 14.643486] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  846. 27.03 s [vm-test-run-upcheck-module-test] machine # [ 14.652813] systemd[1]: Starting Post-Boot Actions...
  847. 27.07 s [vm-test-run-upcheck-module-test] machine # [ 14.686674] systemd[1]: Started Reset console on configuration changes.
  848. 27.08 s [vm-test-run-upcheck-module-test] machine # [ 14.698590] systemd[1]: Starting resolvconf update...
  849. 27.12 s [vm-test-run-upcheck-module-test] machine # connecting to host...
  850. 27.17 s [vm-test-run-upcheck-module-test] machine # [ 14.791396] systemd[1]: Condition check resulted in Virtio network device being skipped.
  851. 27.20 s [vm-test-run-upcheck-module-test] machine: Guest shell says: b'Spawning backdoor root shell...\n'
  852. 27.21 s [vm-test-run-upcheck-module-test] machine: connected to guest root shell
  853. 27.21 s [vm-test-run-upcheck-module-test] machine: (connecting took 17.33 seconds)
  854. 27.21 s [vm-test-run-upcheck-module-test] machine: (finished: waiting for the VM to finish booting, in 17.33 seconds)
  855. 27.23 s [vm-test-run-upcheck-module-test] machine # [ 14.846429] systemd[1]: Starting D-Bus System Message Bus...
  856. 27.24 s [vm-test-run-upcheck-module-test] machine # [ 14.862879] systemd[1]: Finished Post-Boot Actions.
  857. 27.28 s [vm-test-run-upcheck-module-test] machine # [ 14.893924] nsncd[965]: Jun 01 20:25:17.155 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  858. 27.29 s [vm-test-run-upcheck-module-test] machine # [ 14.915425] systemd[1]: Finished Import lastlog data into lastlog2 database.
  859. 27.31 s [vm-test-run-upcheck-module-test] machine # [ 14.929709] systemd[1]: Started Name Service Cache Daemon (nsncd).
  860. 27.32 s [vm-test-run-upcheck-module-test] machine # [ 14.945384] systemd[1]: Reached target Host and Network Name Lookups.
  861. 27.34 s [vm-test-run-upcheck-module-test] machine # [ 14.956223] systemd[1]: Reached target User and Group Name Lookups.
  862. 27.34 s [vm-test-run-upcheck-module-test] machine # [ 14.964696] systemd[1]: Starting User Login Management...
  863. 27.53 s [vm-test-run-upcheck-module-test] machine # [ 15.148885] dbus-broker-launch[977]: Looking up NSS user entry for 'systemd-timesync'...
  864. 27.58 s [vm-test-run-upcheck-module-test] machine # [ 15.199366] dbus-broker-launch[977]: NSS returned no entry for 'systemd-timesync'
  865. 27.59 s [vm-test-run-upcheck-module-test] machine # [ 15.212375] dbus-broker-launch[977]: Invalid user-name in /nix/store/9b5c3qrf26a6k1qb76ddv50ayzyhjw2r-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
  866. 27.62 s [vm-test-run-upcheck-module-test] machine # [ 15.241114] systemd-logind[996]: New seat seat0.
  867. 27.63 s [vm-test-run-upcheck-module-test] machine # [ 16.128785] mousedev: PS/2 mouse device common for all mice
  868. 27.63 s [vm-test-run-upcheck-module-test] machine # [ 15.255256] systemd[1]: Started User Login Management.
  869. 27.65 s [vm-test-run-upcheck-module-test] machine # [ 15.259524] systemd[1]: Starting linger-users.service...
  870. 27.67 s [vm-test-run-upcheck-module-test] machine # [ 15.292222] systemd[1]: Started D-Bus System Message Bus.
  871. 27.74 s [vm-test-run-upcheck-module-test] machine # [ 15.361967] dbus-broker-launch[977]: Ready
  872. 27.75 s [vm-test-run-upcheck-module-test] machine # [ 16.246296] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  873. 27.76 s [vm-test-run-upcheck-module-test] machine # [ 15.380927] systemd[1]: linger-users.service: Deactivated successfully.
  874. 27.77 s [vm-test-run-upcheck-module-test] machine # [ 15.390489] systemd[1]: Finished linger-users.service.
  875. 27.80 s [vm-test-run-upcheck-module-test] machine # [ 15.423391] systemd[1]: Stopped target Host and Network Name Lookups.
  876. 27.81 s [vm-test-run-upcheck-module-test] machine # [ 15.432488] systemd[1]: Stopping Host and Network Name Lookups...
  877. 27.82 s [vm-test-run-upcheck-module-test] machine # [ 15.439779] systemd[1]: Stopped target User and Group Name Lookups.
  878. 27.83 s [vm-test-run-upcheck-module-test] machine # [ 15.449324] systemd[1]: Stopping User and Group Name Lookups...
  879. 27.84 s [vm-test-run-upcheck-module-test] machine # [ 15.456819] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  880. 27.84 s [vm-test-run-upcheck-module-test] machine # [ 16.339622] ACPI: button: Power Button [PWRF]
  881. 27.84 s [vm-test-run-upcheck-module-test] machine # [ 15.465825] systemd[1]: nscd.service: Deactivated successfully.
  882. 27.85 s [vm-test-run-upcheck-module-test] machine # [ 15.471750] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  883. 27.86 s [vm-test-run-upcheck-module-test] machine # [ 15.479447] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  884. 27.89 s [vm-test-run-upcheck-module-test] machine # [ 16.388046] rtc_cmos 00:05: RTC can wake from S4
  885. 27.91 s [vm-test-run-upcheck-module-test] machine # [ 15.525266] systemd[1]: Started Name Service Cache Daemon (nsncd).
  886. 27.91 s [vm-test-run-upcheck-module-test] machine # [ 15.530864] nsncd[1049]: Jun 01 20:25:17.788 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  887. 27.93 s [vm-test-run-upcheck-module-test] machine # [ 15.549375] systemd[1]: Reached target Host and Network Name Lookups.
  888. 27.93 s [vm-test-run-upcheck-module-test] machine # [ 15.555711] systemd[1]: Reached target User and Group Name Lookups.
  889. 27.94 s [vm-test-run-upcheck-module-test] machine # [ 15.562578] systemd[1]: Finished resolvconf update.
  890. 27.95 s [vm-test-run-upcheck-module-test] machine # [ 15.568533] systemd[1]: Reached target Preparation for Network.
  891. 27.95 s [vm-test-run-upcheck-module-test] machine # [ 16.451769] parport_pc 00:03: reported by Plug and Play ACPI
  892. 27.96 s [vm-test-run-upcheck-module-test] machine # [ 15.579708] systemd[1]: Starting DHCP Client...
  893. 27.97 s [vm-test-run-upcheck-module-test] machine # [ 15.584374] systemd[1]: Starting Address configuration of eth1...
  894. 27.97 s [vm-test-run-upcheck-module-test] machine # [ 15.594802] systemd[1]: Starting Extra networking commands....
  895. 27.98 s [vm-test-run-upcheck-module-test] machine # [ 16.478767] Floppy drive(s): fd0 is 2.88M AMI BIOS
  896. 27.99 s [vm-test-run-upcheck-module-test] machine # [ 16.485645] rtc_cmos 00:05: registered as rtc0
  897. 28.03 s [vm-test-run-upcheck-module-test] machine # [ 16.530907] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  898. 28.04 s [vm-test-run-upcheck-module-test] machine # [ 16.536914] rtc_cmos 00:05: setting system clock to 2026-06-01T20:25:19 UTC (1780345519)
  899. 28.05 s [vm-test-run-upcheck-module-test] machine # [ 16.549216] FDC 0 is a S82078B
  900. 28.11 s [vm-test-run-upcheck-module-test] machine # [ 16.607262] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  901. 28.16 s [vm-test-run-upcheck-module-test] machine # [ 15.776542] network-addresses-eth1-start[1070]: adding address 192.168.1.1/24... done
  902. 28.18 s [vm-test-run-upcheck-module-test] machine # [ 15.805196] network-addresses-eth1-start[1070]: adding address 2001:db8:1::1/64... done
  903. 28.23 s [vm-test-run-upcheck-module-test] machine # [ 15.847372] systemd[1]: Finished Address configuration of eth1.
  904. 28.28 s [vm-test-run-upcheck-module-test] machine # [ 15.903880] dhcpcd[1078]: dhcpcd-10.3.1 starting
  905. 28.30 s [vm-test-run-upcheck-module-test] machine # [ 15.919884] dhcpcd[1126]: dev: loaded udev
  906. 28.31 s [vm-test-run-upcheck-module-test] machine # [ 15.931414] systemd[1]: Finished Extra networking commands..
  907. 28.32 s [vm-test-run-upcheck-module-test] machine # [ 15.941555] systemd[1]: Reached target Network.
  908. 28.33 s [vm-test-run-upcheck-module-test] machine # [ 15.947770] systemd[1]: Starting Permit User Sessions...
  909. 28.33 s [vm-test-run-upcheck-module-test] machine # [ 16.830851] 8021q: 802.1Q VLAN Support v1.8
  910. 28.34 s [vm-test-run-upcheck-module-test] machine # [ 16.836020] 8021q: adding VLAN 0 to HW filter on device eth1
  911. 28.37 s [vm-test-run-upcheck-module-test] machine # [ 16.868162] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  912. 28.39 s [vm-test-run-upcheck-module-test] machine # [ 16.010869] systemd[1]: Finished Permit User Sessions.
  913. 28.40 s [vm-test-run-upcheck-module-test] machine # [ 16.020419] systemd[1]: Started Getty on tty1.
  914. 28.40 s [vm-test-run-upcheck-module-test] machine # [ 16.025515] systemd[1]: Reached target Login Prompts.
  915. 28.58 s [vm-test-run-upcheck-module-test] machine # [ 16.953033] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  916. 28.62 s [vm-test-run-upcheck-module-test] machine # [ 16.953265] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  917. 28.62 s [vm-test-run-upcheck-module-test] machine # [ 17.066799] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  918. 28.65 s [vm-test-run-upcheck-module-test] machine # [ 17.076066] Console: switching to colour dummy device 80x25
  919. 28.65 s [vm-test-run-upcheck-module-test] machine # [ 17.118292] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  920. 28.67 s [vm-test-run-upcheck-module-test] machine # [ 17.139695] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  921. 28.67 s [vm-test-run-upcheck-module-test] machine # [ 17.140293] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  922. 28.70 s [vm-test-run-upcheck-module-test] machine # [ 17.154400] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  923. 28.70 s [vm-test-run-upcheck-module-test] machine # [ 17.154767] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  924. 28.74 s [vm-test-run-upcheck-module-test] machine # [ 17.156786] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
  925. 28.74 s [vm-test-run-upcheck-module-test] machine # [ 17.156854] cfg80211: failed to load regulatory.db
  926. 28.77 s [vm-test-run-upcheck-module-test] machine # [ 17.239839] 8021q: adding VLAN 0 to HW filter on device eth0
  927. 28.77 s [vm-test-run-upcheck-module-test] machine # [ 16.363786] dhcpcd[1126]: eth0: waiting for carrier
  928. 28.77 s [vm-test-run-upcheck-module-test] machine # [ 16.391222] dhcpcd[1126]: eth0: carrier acquired
  929. 28.77 s [vm-test-run-upcheck-module-test] machine # [ 16.393263] dhcpcd[1126]: DUID 00:01:00:01:31:b0:a7:30:52:54:00:12:34:56
  930. 28.77 s [vm-test-run-upcheck-module-test] machine # [ 16.396200] dhcpcd[1126]: eth0: IAID 00:12:34:56
  931. 28.78 s [vm-test-run-upcheck-module-test] machine # [ 16.399478] dhcpcd[1126]: eth0: adding address fe80::5054:ff:fe12:3456
  932. 28.80 s [vm-test-run-upcheck-module-test] machine # [ 16.418700] systemd[1]: Starting Virtual Console Setup...
  933. 28.80 s [vm-test-run-upcheck-module-test] machine # [ 17.299181] [drm] Found bochs VGA, ID 0xb0c5.
  934. 28.84 s [vm-test-run-upcheck-module-test] machine # [ 17.341582] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  935. 28.86 s [vm-test-run-upcheck-module-test] machine # [ 16.475943] systemd-logind[996]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  936. 28.92 s [vm-test-run-upcheck-module-test] machine # [ 17.421804] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic
  937. 28.96 s [vm-test-run-upcheck-module-test] machine # [ 17.461816] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  938. 28.99 s [vm-test-run-upcheck-module-test] machine # [ 16.613128] systemd-logind[996]: Watching system buttons on /dev/input/event2 (Power Button)
  939. 29.06 s [vm-test-run-upcheck-module-test] machine # [ 17.557222] ppdev: user-space parallel port driver
  940. 29.11 s [vm-test-run-upcheck-module-test] machine # [ 16.714765] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  941. 29.19 s [vm-test-run-upcheck-module-test] machine # [ 16.814314] systemd-logind[996]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  942. 29.31 s [vm-test-run-upcheck-module-test] machine # [ 17.614718] fbcon: bochs-drmdrmfb (fb0) is primary device
  943. 29.31 s [vm-test-run-upcheck-module-test] machine # [ 17.804073] Console: switching to colour frame buffer device 160x50
  944. 29.32 s [vm-test-run-upcheck-module-test] machine # [ 17.813353] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  945. 29.33 s [vm-test-run-upcheck-module-test] machine # [ 16.946614] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  946. 29.33 s [vm-test-run-upcheck-module-test] machine # [ 16.951924] systemd[1]: Stopped Virtual Console Setup.
  947. 29.34 s [vm-test-run-upcheck-module-test] machine # [ 16.958465] systemd[1]: Starting Virtual Console Setup...
  948. 29.37 s [vm-test-run-upcheck-module-test] machine # [ 17.867660] kvm_amd: TSC scaling supported
  949. 29.37 s [vm-test-run-upcheck-module-test] machine # [ 17.868970] kvm_amd: Nested Virtualization enabled
  950. 29.37 s [vm-test-run-upcheck-module-test] machine # [ 17.871012] kvm_amd: Nested Paging enabled
  951. 29.38 s [vm-test-run-upcheck-module-test] machine # [ 17.873166] kvm_amd: LBR virtualization supported
  952. 29.38 s [vm-test-run-upcheck-module-test] machine # [ 17.875200] kvm_amd: Virtual VMLOAD VMSAVE supported
  953. 29.38 s [vm-test-run-upcheck-module-test] machine # [ 17.876854] kvm_amd: Virtual GIF supported
  954. 29.47 s [vm-test-run-upcheck-module-test] machine # [ 17.970838] EDAC MC: Ver: 3.0.0
  955. 29.68 s [vm-test-run-upcheck-module-test] machine # [ 17.296623] dhcpcd[1126]: eth0: soliciting a DHCP lease
  956. 29.70 s [vm-test-run-upcheck-module-test] machine # [ 18.193337] NET: Registered PF_PACKET protocol family
  957. 29.70 s [vm-test-run-upcheck-module-test] machine # [ 17.324514] dhcpcd[1126]: eth0: offered 10.0.2.15 from 10.0.2.2
  958. 29.71 s [vm-test-run-upcheck-module-test] machine # [ 17.327347] dhcpcd[1126]: eth0: probing address 10.0.2.15/24
  959. 29.77 s [vm-test-run-upcheck-module-test] machine # [ 17.390542] systemd-vconsole-setup[1172]: Configuration of first virtual console was skipped, ignoring remaining ones.
  960. 29.78 s [vm-test-run-upcheck-module-test] machine # [ 17.397987] systemd[1]: Finished Virtual Console Setup.
  961. 31.39 s [vm-test-run-upcheck-module-test] machine # [ 19.005968] dhcpcd[1126]: eth0: soliciting an IPv6 router
  962. 31.39 s [vm-test-run-upcheck-module-test] machine # [ 19.008609] dhcpcd[1126]: eth0: Router Advertisement from fe80::2
  963. 31.39 s [vm-test-run-upcheck-module-test] machine # [ 19.010724] dhcpcd[1126]: eth0: adding address fec0::5054:ff:fe12:3456/64
  964. 31.39 s [vm-test-run-upcheck-module-test] machine # [ 19.013134] dhcpcd[1126]: eth0: adding route to fec0::/64
  965. 31.39 s [vm-test-run-upcheck-module-test] machine # [ 19.015252] dhcpcd[1126]: eth0: adding default route via fe80::2
  966. 35.63 s [vm-test-run-upcheck-module-test] machine # [ 23.249265] dhcpcd[1126]: eth0: leased 10.0.2.15 for 86400 seconds
  967. 35.66 s [vm-test-run-upcheck-module-test] machine # [ 23.252777] dhcpcd[1126]: eth0: adding route to 10.0.2.0/24
  968. 35.66 s [vm-test-run-upcheck-module-test] machine # [ 23.255296] dhcpcd[1126]: eth0: adding default route via 10.0.2.2
  969. 35.73 s [vm-test-run-upcheck-module-test] machine # [ 23.351314] systemd[1]: Started DHCP Client.
  970. 35.73 s [vm-test-run-upcheck-module-test] machine # [ 23.355667] systemd[1]: Reached target Multi-User System.
  971. 35.74 s [vm-test-run-upcheck-module-test] machine # [ 23.358251] systemd[1]: Startup finished in 2.692s (kernel) + 6.777s (initrd) + 13.886s (userspace) = 23.357s.
  972. 36.56 s [vm-test-run-upcheck-module-test] machine: (finished: waiting for unit multi-user.target, in 26.68 seconds)
  973. 36.66 s [vm-test-run-upcheck-module-test] machine # [ 24.280845] systemd[1]: Started Website Up Checker.
  974. 36.69 s [vm-test-run-upcheck-module-test] machine # [ 24.312630] upcheck-start[1293]: + tmpfile=/root/.upcheck
  975. 36.70 s [vm-test-run-upcheck-module-test] machine # [ 24.314906] upcheck-start[1293]: + /nix/store/mhfapwl5smcdq68g4d60h2j5wpwx0ia6-upcheck-0.0.0.0/bin/upcheck /nix/store/5a471mmavcrq0a9ca9wwdxfrx49d9nsj-upcheck-config.yaml
  976. 36.79 s [vm-test-run-upcheck-module-test] machine # [ 24.409165] upcheck-start[1293]: + exitcode=0
  977. 36.79 s [vm-test-run-upcheck-module-test] machine # [ 24.411959] upcheck-start[1293]: + [[ 0 != 0 ]]
  978. 36.80 s [vm-test-run-upcheck-module-test] machine # [ 24.415850] systemd[1]: upcheck.service: Deactivated successfully.
  979. 36.80 s [vm-test-run-upcheck-module-test] (finished: run the VM test script, in 27.13 seconds)
  980. 36.89 s [vm-test-run-upcheck-module-test] test script finished in 27.22s
  981. 36.89 s [vm-test-run-upcheck-module-test] cleanup
  982. 36.89 s [vm-test-run-upcheck-module-test] kill QemuMachine (pid 12)
  983. 36.89 s [vm-test-run-upcheck-module-test] machine # qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/60m4rxhg2fldqaak400c0lry96ijrzqn-python3-3.13.13/bin/python3.13)
  984. 37.33 s [vm-test-run-upcheck-module-test] (finished: cleanup, in 0.44 seconds)
  985. 37.42 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/v75xdd219zn1lqn809z8s7fmjvhw68x7-vm-test-run-upcheck-module-test
  986. 37.48 s [post-build-hook] copying 1 paths...
  987. 37.48 s [post-build-hook] copying path '/nix/store/v75xdd219zn1lqn809z8s7fmjvhw68x7-vm-test-run-upcheck-module-test' to 'https://cache.staging.nix-ci.com'...
  988. 38.36 s [post-build-hook] copying 0 paths...
  989. 38.42 s Progress: 1 of 2 built, 23 of 23 downloaded from cache
More Logs Raw Logs

Agent Instructions

Wait for completion, without logs:

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/wait

Latest logs, with timestamps (streams while running):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/tail

All logs, with timestamps (available after completion):

curl --netrc https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/logs

Raw logs, from the start (no timestamps):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/raw-logs

Content types available for /logs and /tail (use Accept header):

Example:

curl --netrc -H "Accept: text/csv" https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/logs

Reproduce locally: https://staging.nix-ci.com/gh:NorfairKing:upcheck/master/4e9e7c2d39e732129e5f6703c659ebe5578e6a84/8437539b-b319-4d93-819d-627cccf1ff45/repro

For more instructions, fetch https://staging.nix-ci.com/instructions .