machine # [  102.087141] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
machine # [  102.088447] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
machine # [  102.109773] systemd[1]: Found device Virtio network device.
machine # [  102.118090] systemd[1]: Starting Address configuration of eth1...
machine # [  102.219164] AVX2 version of gcm_enc/dec engaged.
machine # [  102.221575] AES CTR mode by8 optimization enabled
machine: Spawning backdoor root shell...

machine: connected to guest root shell
machine: (connecting took 104.87 seconds)
(finished: waiting for the VM to finish booting, in 104.87 seconds)
machine # [  102.212091] dhcpcd[643]: Failed to reload-or-try-restart ntpd.service: Unit ntpd.service not found.
machine # [  102.213616] dhcpcd[643]: Failed to reload-or-try-restart openntpd.service: Unit openntpd.service not found.
machine # [  102.217991] systemd[1]: nscd.service: Deactivated successfully.
machine # [  102.222361] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
machine # [  102.225350] dhcpcd[643]: Failed to reload-or-try-restart chronyd.service: Unit chronyd.service not found.
machine # [  102.247870] dhcpcd[653]: eth0: IAID 00:12:34:56
machine # [  102.249338] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
machine # [  102.251770] systemd[1]: Started DHCP Client.
machine # [  102.297963] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
machine # [  102.404516] ppdev: user-space parallel port driver
machine # [  102.446069] mousedev: PS/2 mouse device common for all mice
(finished: must succeed: getent shadow example-user | grep -q :test_value:, in 105.18 seconds)
machine: must succeed: cat /run/secrets/nested/test/file | grep -q 'another value'
(finished: must succeed: cat /run/secrets/nested/test/file | grep -q 'another value', in 0.02 seconds)
machine: must succeed: [ $(stat -c%U /run/secrets/nested/test/file) = example-user ]
(finished: must succeed: [ $(stat -c%U /run/secrets/nested/test/file) = example-user ], in 0.04 seconds)
machine: must succeed: cat /run/secrets-for-users/test_key | grep -q 'test_value'
machine # [  102.687545] 8021q: adding VLAN 0 to HW filter on device eth1
(finished: must succeed: cat /run/secrets-for-users/test_key | grep -q 'test_value', in 0.03 seconds)
machine: must succeed: /run/current-system/bin/switch-to-configuration test
machine # [  102.733144] dhcpcd[653]: eth0: soliciting an IPv6 router
machine # [  102.735419] network-addresses-eth1-start[742]: adding address 192.168.1.1/24... done
machine # [  102.746197] nsncd[812]: Aug 06 03:07:53.808 INFO started, handoff_timeout: 3s, worker_count: 8, path: "/var/run/nscd/socket"
machine # [  102.748274] systemd[1]: Started Name Service Cache Daemon (nsncd).
machine # [  102.748887] systemd[1]: Reached target Host and Network Name Lookups.
machine # [  102.755143] systemd[1]: Reached target User and Group Name Lookups.
machine # [  102.762285] systemd[1]: Starting User Login Management...
machine # [  102.764116] systemd[1]: Finished Address configuration of eth1.
machine # [  102.766957] systemd[1]: Starting Networking Setup...
machine # [  102.847043] dbus-daemon[648]: dbus[648]: Unknown username "systemd-timesync" in message bus configuration file
machine # [  102.882348] systemd-logind[855]: New seat seat0.
machine # [  102.887536] systemd-logind[855]: Watching system buttons on /dev/input/event2 (Power Button)
machine # [  102.888900] systemd-logind[855]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
machine # [  102.889922] systemd[1]: Started User Login Management.
machine # [  102.995245] systemd[1]: Finished Networking Setup.
machine # [  102.999644] systemd[1]: Starting Extra networking commands....
machine # [  103.005416] dhcpcd[653]: eth0: Router Advertisement from fe80::2
machine # [  103.006098] dhcpcd[653]: eth0: adding address fec0::5054:ff:fe12:3456/64
machine # [  103.006800] dhcpcd[653]: eth0: adding route to fec0::/64
machine # [  103.007692] dhcpcd[653]: eth0: adding default route via fe80::2
machine # [  103.094751] systemd[1]: Finished Extra networking commands..
machine # [  103.095758] systemd[1]: Reached target Network.
machine # [  103.096438] systemd[1]: Reached target Network is Online.
machine # [  103.109292] systemd[1]: Starting Permit User Sessions...
machine # [  103.113689] systemd[1]: Started D-Bus System Message Bus.
machine # [  103.132915] dbus-daemon[648]: [system] Successfully activated service 'org.freedesktop.systemd1'
machine # [  103.138661] systemd[1]: Finished Permit User Sessions.
machine # [  103.144550] systemd[1]: Started Getty on tty1.
machine # [  103.145398] systemd[1]: Reached target Login Prompts.
machine # [  103.149119] systemd[1]: Reached target Multi-User System.
machine # [  103.250429] systemd[1]: Startup finished in 1min 22.673s (kernel) + 20.576s (userspace) = 1min 43.250s.
machine # [  103.357057] kvm: Nested Virtualization enabled
machine # [  103.357552] SVM: kvm: Nested Paging enabled
machine # [  103.376856] EDAC MC: Ver: 3.0.0
machine # [  103.321983] (udev-worker)[601]: vtcon0: Process '/nix/store/rpagyb9792jx4f2hlqz9q0ld3frlzxq5-systemd-253.6/lib/systemd/systemd-vconsole-setup' failed with exit code 1.
machine # [  103.326719] (udev-worker)[790]: vtcon1: Process '/nix/store/rpagyb9792jx4f2hlqz9q0ld3frlzxq5-systemd-253.6/lib/systemd/systemd-vconsole-setup' failed with exit code 1.
machine # [  104.022602] dhcpcd[653]: eth0: rebinding lease of 10.0.2.15
machine # [  104.025904] dhcpcd[653]: eth0: leased 10.0.2.15 for 86400 seconds
machine # [  104.079321] systemd-logind[855]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
machine # [  104.694217] nixos[841]: switching to system configuration /nix/store/ks1jh0rfp3llraqk4z73n09vfn72k72m-nixos-system-machine-23.05pre-git
machine # [  104.710710] systemd[1]: Stopped target Local File Systems.
machine # [  104.714362] systemd[1]: Stopped target All Network Interfaces (deprecated).
machine # [  104.716881] systemd[1]: Stopped target Remote File Systems.
machine # activating the configuration...
machine # [  105.628449] systemd[1]: Reloading requested from client PID 1061 (unit backdoor.service)...
machine # [  105.630123] systemd[1]: Reloading...
machine # [  112.700821] systemd[1]: Reloading finished in 7068 ms.
machine # setting up tmpfiles
machine # [  112.823883] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
machine # [  112.825856] systemd[1]: Reached target Local File Systems.
machine # [  112.830962] systemd[1]: Reached target Remote File Systems.
machine # [  112.834364] systemd[1]: Reached target All Network Interfaces (deprecated).
machine # [  112.850622] systemd[1]: Starting Load Kernel Module efi_pstore...
machine # [  112.858101] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
machine # [  112.860324] systemd[1]: Finished Load Kernel Module efi_pstore.
machine # [  112.862076] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
machine # [  112.904496] nixos[841]: finished switching to system configuration /nix/store/ks1jh0rfp3llraqk4z73n09vfn72k72m-nixos-system-machine-23.05pre-git
(finished: must succeed: /run/current-system/bin/switch-to-configuration test, in 10.30 seconds)
machine: must succeed: cat /run/secrets/nested/test/file | grep -q 'another value'
(finished: must succeed: cat /run/secrets/nested/test/file | grep -q 'another value', in 0.02 seconds)
machine: must succeed: cat /run/secrets-for-users/test_key | grep -q 'test_value'
(finished: must succeed: cat /run/secrets-for-users/test_key | grep -q 'test_value', in 0.01 seconds)
(finished: run the VM test script, in 133.79 seconds)
test script finished in 136.78s
cleanup
kill machine (pid 8)
machine # qemu-kvm: terminating on signal 15 from pid 6 (/nix/store/a5k7x5mn7i7rcji4n99mwiqhmgjdzxmk-python3-3.10.12/bin/python3.10)
(finished: cleanup, in 0.16 seconds)
kill vlan (pid 7)