machine # [   70.035734] systemd[1]: Starting DHCP Client...
machine # [   70.045957] dhcpcd[690]: dhcpcd-9.4.1 starting
machine # [   70.050620] dhcpcd[695]: dev: loaded udev
machine # [   70.052900] r6g4nwns9wh2kqi008c1nc100yza4syf-audit-disable[689]: No rules
machine # [   70.062432] systemd[1]: Starting Logrotate configuration check...
machine # [   70.070603] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
machine: Guest shell says: b'Spawning backdoor root shell...\n'
machine: connected to guest root shell
machine: (connecting took 71.01 seconds)
(finished: waiting for the VM to finish booting, in 71.01 seconds)
machine # [   70.082580] logrotate[698]: warning: logrotate in debug mode does nothing except printing debug messages!  Consider using verbose mode (-v) instead if this is not what you want.[   70.183035] 8021q: 802.1Q VLAN Support v1.8
machine # 
machine # [   70.101518] logrotate[698]: reading config file /nix/store/2my9cdxg2pmzj3q7vy76s1malpys36g5-logrotate.conf
machine # [   70.112784] logrotate[698]: note: 'monthly' overrides previously specified 'weekly'
machine # [   70.120568] logrotate[698]: Reading state from file: /var/lib/logrotate.status
machine # [   70.132828] logrotate[698]: state file /var/lib/logrotate.status does not exist
machine # [   70.141313] logrotate[698]: Allocating hash table for state file, size 64 entries
machine # [   70.147173] logrotate[698]: Handling 2 logs
machine # [   70.147627] logrotate[698]: rotating pattern: "/var/log/btmp"  monthly (1 rotations)
machine # [   70.156248] logrotate[698]: empty log files are not rotated, only log files >= 1048576 bytes are rotated, old logs are removed
machine # [   70.169911] logrotate[698]: considering log /var/log/btmp
machine # [   70.175452] logrotate[698]: Creating new state
machine # [   70.181466] logrotate[698]:   Now: 2023-08-13 03:05
machine # [   70.181931] logrotate[698]:   Last rotated at 2023-08-13 03:00
machine # [   70.188468] logrotate[698]:   log does not need rotating (log has already been rotated)
machine # [   70.202887] logrotate[698]: rotating pattern: "/var/log/wtmp"  monthly (1 rotations)
machine # [   70.206635] logrotate[698]: empty log files are not rotated, only log files >= 1048576 bytes are rotated, old logs are removed
machine # [   70.215697] logrotate[698]: considering log /var/log/wtmp
machine # [   70.220277] logrotate[698]: Creating new state
machine # [   70.220764] logrotate[698]:   Now: 2023-08-13 03:05
machine # [   70.228225] logrotate[698]:   Last rotated at 2023-08-13 03:00
machine # [   70.228771] logrotate[698]:   log does not need rotating (log has already been rotated)
machine # [   70.252137] systemd[1]: Started Reset console on configuration changes.
machine # [   70.258332] systemd[1]: Starting resolvconf update...
(finished: must succeed: [ $(stat -c%U /run/secrets-rendered/test_template) = 'someuser' ], in 71.17 seconds)
machine: must succeed: [ $(stat -c%G /run/secrets-rendered/test_template) = 'somegroup' ]
machine # [   70.265839] nsncd[704]: Aug 13 03:05:04.165 INFO started, handoff_timeout: 3s, worker_count: 8, path: "/var/run/nscd/socket"
machine # [   70.275944] systemd[1]: Finished Kernel Auditing.
machine # [   70.282642] systemd[1]: Finished Logrotate configuration check.
machine # [   70.297333] systemd[1]: Started Name Service Cache Daemon (nsncd).
machine # [   70.300518] dbus-daemon[724]: dbus[724]: Unknown username "systemd-timesync" in message bus configuration file
machine # [   70.309638] systemd[1]: Reached target Host and Network Name Lookups.
machine # [   70.314549] systemd[1]: Reached target User and Group Name Lookups.
machine # [   70.319303] systemd[1]: Starting User Login Management...
machine # [   70.324140] systemd-oomd[683]: No swap; memory pressure usage will be degraded
machine # [   70.327737] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
machine # [   70.331616] systemd[1]: Starting D-Bus System Message Bus...
machine # [   70.337089] systemd[1]: Started D-Bus System Message Bus.
machine # [   70.337794] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
(finished: must succeed: [ $(stat -c%G /run/secrets-rendered/test_template) = 'somegroup' ], in 0.09 seconds)
machine: must succeed: [ $(stat -c%U /run/secrets-rendered/test_default) = 'root' ]
machine # [   70.400124] systemd-logind[722]: New seat seat0.
machine # [   70.410291] systemd-logind[722]: Watching system buttons on /dev/input/event2 (Power Button)
machine # [   70.411347] systemd-logind[722]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
machine # [   70.413475] systemd-logind[722]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
machine # [   70.415757] systemd[1]: Started User Login Management.
(finished: must succeed: [ $(stat -c%U /run/secrets-rendered/test_default) = 'root' ], in 0.08 seconds)
machine: must succeed: [ $(stat -c%G /run/secrets-rendered/test_default) = 'root' ]
machine # [   70.453626] systemd[1]: Stopped target Host and Network Name Lookups.
machine # [   70.454421] systemd[1]: Stopping Host and Network Name Lookups...
machine # [   70.455312] systemd[1]: Stopped target User and Group Name Lookups.
machine # [   70.455972] systemd[1]: Stopping User and Group Name Lookups...
machine # [   70.459834] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
machine # [   70.481259] systemd[1]: nscd.service: Deactivated successfully.
machine # [   70.484456] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
machine # [   70.501591] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
(finished: must succeed: [ $(stat -c%G /run/secrets-rendered/test_default) = 'root' ], in 0.08 seconds)
machine: must succeed: cat /run/secrets-rendered/test_template
machine # [   70.513463] systemd[1]: Finished resolvconf update.
machine # [   70.515116] systemd[1]: Reached target Preparation for Network.
machine # [   70.516659] systemd[1]: Reached target All Network Interfaces (deprecated).
machine # [   70.607288] cfg80211: Loading compiled-in X.509 certificates for regulatory database
machine # [   70.523565] systemd[1]: Starting Address configuration of eth1...
machine # [   70.541277] systemd[1]: Started Name Service Cache Daemon (nsncd).
machine # [   70.543231] systemd[1]: Reached target Host and Network Name Lookups.
machine # [   70.544600] systemd[1]: Reached target User and Group Name Lookups.
machine # [   70.549436] nsncd[775]: Aug 13 03:05:04.554 INFO started, handoff_timeout: 3s, worker_count: 8, path: "/var/run/nscd/socket"
(finished: must succeed: cat /run/secrets-rendered/test_template, in 0.06 seconds)
machine: must succeed: cat /run/secrets-rendered/test_default
machine # [   70.657585] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
machine # [   70.662009] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
machine # [   70.662663] cfg80211: failed to load regulatory.db
machine # [   70.667915] 8021q: adding VLAN 0 to HW filter on device eth1
machine # [   70.591110] network-addresses-eth1-start[780]: adding address 192.168.1.1/24... done
(finished: must succeed: cat /run/secrets-rendered/test_default, in 0.04 seconds)
(finished: run the VM test script, in 82.68 seconds)
machine # [   70.612063] systemd[1]: Finished Address configuration of eth1.
machine # [   70.617090] systemd[1]: Starting Networking Setup...
machine # [   70.749469] 8021q: adding VLAN 0 to HW filter on device eth0
machine # [   70.664945] dhcpcd[695]: eth0: waiting for carrier
machine # [   70.665576] dhcpcd[695]: eth0: carrier acquired
machine # [   70.676680] dhcpcd[695]: DUID 00:01:00:01:2c:6b:04:e0:52:54:00:12:34:56
machine # [   70.677457] dhcpcd[695]: eth0: IAID 00:12:34:56
machine # [   70.678130] dhcpcd[695]: eth0: adding address fe80::5054:ff:fe12:3456
test script finished in 83.01s
cleanup
kill machine (pid 8)
machine # qemu-kvm: terminating on signal 15 from pid 6 (/nix/store/2c7sgx69p6mmp76cvmi5j6c72dj76jj8-python3-3.10.12/bin/python3.10)
(finished: cleanup, in 0.16 seconds)
kill vlan (pid 7)