Machine state will be reset. To keep it, pass --keep-machine-state start all VLans (finished: start all VLans, in 0.00 seconds) Test will time out and terminate in 3600.0 seconds run the VM test script additionally exposed symbols: peer1, peer2, vlan1, 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 start all VMs peer1: systemd-nspawn running (pid 52) peer2: systemd-nspawn running (pid 53) peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal... peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal... (finished: start all VMs, in 0.00 seconds) peer1: must succeed: greet-world nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(peer1): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths. nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(peer2): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths. Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file. ░ Spawning container peer2 on /build/vm-state-peer2. Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file. ░ Spawning container peer1 on /build/vm-state-peer1. peer1 # No journal boot entry found for the specified boot (+0). peer2 # No journal boot entry found for the specified boot (+0). peer1 # [6018424.935895] peer1 systemd-journald[69]: Journal started peer1 # [6018424.935956] peer1 systemd-journald[69]: Runtime Journal (/run/log/journal/35050c0f355a4c049e7e6fc3dd6f8727) is 8M, max 2.5G, 2.4G free. peer1 # [6018424.939584] peer1 systemd[1]: Starting Flush Journal to Persistent Storage... peer1 # [6018424.948235] peer1 systemd-journald[69]: Time spent on flushing to /var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727 is 1.983ms for 3 entries. peer1 # [6018424.948235] peer1 systemd-journald[69]: System Journal (/var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727) is 8M, max 4G, 3.9G free. peer1 # [6018424.957766] peer1 systemd[1]: Finished Create Static Device Nodes in /dev. peer1 # [6018424.958443] peer1 systemd[1]: Reached target Preparation for Local File Systems. peer1 # [6018424.958567] peer1 systemd[1]: Reached target Local File Systems. peer1 # [6018424.959491] peer1 systemd[1]: Listening on Boot Loader Control Service Socket. peer1 # [6018424.959542] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer1 # [6018424.960472] peer1 systemd[1]: Starting Save Transient machine-id to Disk... peer1 # [6018424.960513] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer1 # [6018425.089676] peer1 systemd[1]: Finished Firewall. peer1 # [6018425.090541] peer1 systemd[1]: Reached target Preparation for Network. peer1 # [6018425.090862] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket. peer1 # [6018425.091962] peer1 systemd[1]: Starting Network Management... peer1 # [6018425.101673] peer1 systemd[1]: Finished Flush Journal to Persistent Storage. peer1 # [6018425.102601] peer1 systemd[1]: Starting Create System Files and Directories... peer1 # [6018425.120192] peer1 systemd-tmpfiles[176]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer1 # [6018425.120372] peer1 systemd-tmpfiles[176]: fchmod() of /var/log/journal failed: Operation not permitted peer1 # [6018425.120489] peer1 systemd-tmpfiles[176]: fchmod() of /var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727 failed: Operation not permitted peer1 # [6018425.120667] peer1 systemd-tmpfiles[176]: fchmod() of /run/log/journal failed: Operation not permitted peer1 # [6018425.122078] peer1 systemd[1]: Finished Create System Files and Directories. peer1 # [6018425.123076] peer1 systemd[1]: Starting Rebuild Journal Catalog... peer1 # [6018425.123750] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer1 # [6018425.135781] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer1 # [6018425.144611] peer1 systemd[1]: Finished Rebuild Journal Catalog. peer1 # [6018425.146629] peer1 systemd[1]: Starting Update is Completed... peer1 # [6018425.157729] peer1 systemd[1]: Finished Update is Completed. peer1 # [6018425.530229] peer1 systemd-networkd[173]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer1 # [6018425.530320] peer1 systemd-networkd[173]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer1 # [6018425.537532] peer1 systemd-networkd[173]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section. peer1 # [6018425.537697] peer1 systemd-networkd[173]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section. peer1 # [6018425.537857] peer1 systemd-networkd[173]: lo: Link UP peer1 # [6018425.537860] peer1 systemd-networkd[173]: lo: Gained carrier peer1 # [6018425.538048] peer1 systemd-networkd[173]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer1 # [6018425.538568] peer1 systemd-networkd[173]: eth1: Link UP peer1 # [6018425.538676] peer1 systemd[1]: Started Network Management. peer1 # [6018425.539835] peer1 systemd-networkd[173]: eth1: Gained carrier peer1 # [6018425.540451] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer1 # [6018425.586191] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer1 # [6018425.733649] peer1 systemd-resolved[86]: Positive Trust Anchors: peer1 # [6018425.733662] peer1 systemd-resolved[86]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer1 # [6018425.733665] peer1 systemd-resolved[86]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer1 # [6018425.733700] peer1 systemd-resolved[86]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test peer1 # [6018425.756501] peer1 systemd-resolved[86]: Using system hostname 'peer1'. peer1 # [6018425.758236] peer1 systemd[1]: Started Network Name Resolution. peer1 # [6018425.758329] peer1 systemd[1]: Reached target Network. peer1 # [6018425.758391] peer1 systemd[1]: Reached target System Initialization. peer1 # [6018425.758441] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container peer1 # [6018425.758466] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories. peer1 # [6018425.758485] peer1 systemd[1]: Reached target Timer Units. peer2 # [6018424.932553] peer2 systemd-journald[69]: Journal started peer1 # [6018425.758615] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket. peer2 # [6018424.932607] peer2 systemd-journald[69]: Runtime Journal (/run/log/journal/f40a2aa2970340adb4b1956c27185a6b) is 8M, max 2.5G, 2.4G free. peer1 # [6018425.758746] peer1 systemd[1]: Listening on Nix Daemon Socket. peer2 # [6018424.939033] peer2 systemd[1]: Starting Flush Journal to Persistent Storage... peer1 # [6018425.758855] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. peer2 # [6018424.939827] peer2 systemd[1]: Starting Network Name Resolution... peer1 # [6018425.758877] peer1 systemd[1]: Reached target Socket Units. peer2 # [6018424.940722] peer2 systemd[1]: Starting Create Static Device Nodes in /dev... peer1 # [6018425.758914] peer1 systemd[1]: Reached target Basic System. peer2 # [6018424.949427] peer2 systemd-journald[69]: Time spent on flushing to /var/log/journal/f40a2aa2970340adb4b1956c27185a6b is 2.890ms for 5 entries. peer1 # [6018425.759934] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database... peer2 # [6018424.949427] peer2 systemd-journald[69]: System Journal (/var/log/journal/f40a2aa2970340adb4b1956c27185a6b) is 8M, max 4G, 3.9G free. peer1 # [6018425.761025] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)... peer2 # [6018424.958475] peer2 systemd[1]: Finished Create Static Device Nodes in /dev. peer1 # [6018425.762238] peer1 systemd[1]: Starting D-Bus System Message Bus... peer2 # [6018424.959092] peer2 systemd[1]: Reached target Preparation for Local File Systems. peer1 # [6018425.777485] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database. peer2 # [6018424.959205] peer2 systemd[1]: Reached target Local File Systems. peer1 # [6018425.864865] peer1 nsncd[188]: Aug 17 15:10:51.911 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer2 # [6018424.959973] peer2 systemd[1]: Listening on Boot Loader Control Service Socket. peer1 # [6018425.858913] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd). peer2 # [6018424.960028] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer1 # [6018425.858989] peer1 systemd[1]: Reached target Host and Network Name Lookups. peer2 # [6018424.960808] peer2 systemd[1]: Starting Save Transient machine-id to Disk... peer1 # [6018425.859061] peer1 systemd[1]: Reached target User and Group Name Lookups. peer2 # [6018424.960845] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer1 # [6018425.865620] peer1 systemd[1]: Starting User Login Management... peer2 # [6018425.087460] peer2 systemd[1]: Finished Firewall. peer1 # [6018425.866659] peer1 systemd[1]: Starting Permit User Sessions... peer2 # [6018425.087631] peer2 systemd[1]: Reached target Preparation for Network. peer1 # [6018425.939892] peer1 dbus-broker-launch[189]: Looking up NSS user entry for 'systemd-timesync'... peer2 # [6018425.087891] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket. peer1 # [6018425.940908] peer1 dbus-broker-launch[189]: NSS returned no entry for 'systemd-timesync' peer2 # [6018425.089111] peer2 systemd[1]: Starting Network Management... peer1 # [6018425.940908] peer1 dbus-broker-launch[189]: Invalid user-name in /nix/store/bzhzsi2scg9ylag825wmrcxn1qdmn538-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" peer2 # [6018425.095239] peer2 systemd[1]: Finished Flush Journal to Persistent Storage. peer1 # [6018425.941356] peer1 systemd[1]: Started D-Bus System Message Bus. peer2 # [6018425.097058] peer2 systemd[1]: Starting Create System Files and Directories... peer1 # [6018425.949205] peer1 dbus-broker-launch[189]: Ready peer2 # [6018425.113460] peer2 systemd-tmpfiles[176]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer2 # [6018425.113652] peer2 systemd-tmpfiles[176]: fchmod() of /var/log/journal failed: Operation not permitted peer2 # [6018425.113782] peer2 systemd-tmpfiles[176]: fchmod() of /var/log/journal/f40a2aa2970340adb4b1956c27185a6b failed: Operation not permitted peer2 # [6018425.113981] peer2 systemd-tmpfiles[176]: fchmod() of /run/log/journal failed: Operation not permitted peer2 # [6018425.115099] peer2 systemd[1]: Finished Create System Files and Directories. peer2 # [6018425.116957] peer2 systemd[1]: Starting Rebuild Journal Catalog... peer2 # [6018425.117811] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer2 # [6018425.132300] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer2 # [6018425.137744] peer2 systemd[1]: Finished Rebuild Journal Catalog. peer2 # [6018425.139644] peer2 systemd[1]: Starting Update is Completed... peer2 # [6018425.152164] peer2 systemd[1]: Finished Update is Completed. peer2 # [6018425.523083] peer2 systemd-networkd[172]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer2 # [6018425.523177] peer2 systemd-networkd[172]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer2 # [6018425.529918] peer2 systemd-networkd[172]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section. peer2 # [6018425.530086] peer2 systemd-networkd[172]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section. peer2 # [6018425.530261] peer2 systemd-networkd[172]: lo: Link UP peer2 # [6018425.530264] peer2 systemd-networkd[172]: lo: Gained carrier peer2 # [6018425.530470] peer2 systemd-networkd[172]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer2 # [6018425.530957] peer2 systemd-networkd[172]: eth1: Link UP peer2 # [6018425.531292] peer2 systemd[1]: Started Network Management. peer2 # [6018425.532302] peer2 systemd-networkd[172]: eth1: Gained carrier peer2 # [6018425.532364] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer2 # [6018425.582032] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer2 # [6018425.725087] peer2 systemd-resolved[93]: Positive Trust Anchors: peer2 # [6018425.725100] peer2 systemd-resolved[93]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer2 # [6018425.725104] peer2 systemd-resolved[93]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer2 # [6018425.725138] peer2 systemd-resolved[93]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test peer2 # [6018425.747545] peer2 systemd-resolved[93]: Using system hostname 'peer2'. peer2 # [6018425.748945] peer2 systemd[1]: Started Network Name Resolution. peer2 # [6018425.749026] peer2 systemd[1]: Reached target Network. peer2 # [6018425.749090] peer2 systemd[1]: Reached target System Initialization. peer2 # [6018425.749140] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container peer2 # [6018425.749172] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories. peer2 # [6018425.749189] peer2 systemd[1]: Reached target Timer Units. peer2 # [6018425.749323] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket. peer2 # [6018425.749438] peer2 systemd[1]: Listening on Nix Daemon Socket. peer2 # [6018425.749544] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. peer2 # [6018425.749564] peer2 systemd[1]: Reached target Socket Units. peer2 # [6018425.749599] peer2 systemd[1]: Reached target Basic System. peer2 # [6018425.750701] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database... peer2 # [6018425.751691] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)... peer2 # [6018425.752928] peer2 systemd[1]: Starting D-Bus System Message Bus... peer2 # [6018425.773080] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database. peer2 # [6018425.870355] peer2 nsncd[188]: Aug 17 15:10:51.923 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer2 # [6018425.870423] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd). peer2 # [6018425.870487] peer2 systemd[1]: Reached target Host and Network Name Lookups. peer2 # [6018425.870543] peer2 systemd[1]: Reached target User and Group Name Lookups. peer2 # [6018425.940221] peer2 dbus-broker-launch[189]: Looking up NSS user entry for 'systemd-timesync'... peer1 # [6018425.983617] peer1 systemd[1]: Finished Permit User Sessions. peer1 # [6018425.985082] peer1 systemd[1]: Started Console Getty. peer1 # [6018425.985184] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 peer1 # [6018425.985288] peer1 systemd[1]: Reached target Login Prompts. peer2 # [6018425.976414] peer2 systemd[1]: Starting User Login Management... peer2 # [6018425.977272] peer2 systemd[1]: Starting Permit User Sessions... peer2 # [6018425.986034] peer2 dbus-broker-launch[189]: NSS returned no entry for 'systemd-timesync' peer2 # [6018425.986034] peer2 dbus-broker-launch[189]: Invalid user-name in /nix/store/bchwmcclwa7p3k7bipbg1njw3vwghjbd-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" peer2 # [6018425.986661] peer2 systemd[1]: Started D-Bus System Message Bus. peer2 # [6018425.995946] peer2 dbus-broker-launch[189]: Ready peer2 # [6018425.997088] peer2 systemd[1]: Finished Permit User Sessions. peer2 # [6018425.999397] peer2 systemd[1]: Started Console Getty. peer2 # [6018425.999496] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 peer2 # [6018425.999611] peer2 systemd[1]: Reached target Login Prompts. peer1 # [6018426.474680] peer1 systemd-logind[204]: New seat seat0. peer1 # [6018426.474922] peer1 systemd[1]: Started User Login Management. peer1 # [6018426.476366] peer1 systemd[1]: Starting linger-users.service... peer1 # [6018426.495372] peer1 systemd[1]: linger-users.service: Deactivated successfully. peer1 # [6018426.495538] peer1 systemd[1]: Finished linger-users.service. peer1 # [6018426.495977] peer1 systemd[1]: Reached target Multi-User System. peer2 # [6018426.491915] peer2 systemd-logind[204]: New seat seat0. peer2 # [6018426.492107] peer2 systemd[1]: Started User Login Management. peer2 # [6018426.493579] peer2 systemd[1]: Starting linger-users.service... peer2 # [6018426.512087] peer2 systemd[1]: linger-users.service: Deactivated successfully. peer2 # [6018426.512173] peer2 systemd[1]: Finished linger-users.service. peer2 # [6018426.512701] peer2 systemd[1]: Reached target Multi-User System. peer1 # [6018426.880147] peer1 systemd-networkd[173]: eth1: Gained IPv6LL peer2 # [6018427.040137] peer2 systemd-networkd[172]: eth1: Gained IPv6LL peer1: (finished: must succeed: greet-world, in 4.15 seconds) peer2: must succeed: greet-world peer2: (finished: must succeed: greet-world, in 0.01 seconds) (finished: run the VM test script, in 4.16 seconds) peer1 # [6018427.781155] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. peer1 # [6018427.782258] peer1 systemd[1]: Finished Save Transient machine-id to Disk. peer1 # [6018427.782506] peer1 systemd[1]: Startup finished in 3.315s. peer2 # [6018427.788939] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. peer2 # [6018427.790924] peer2 systemd[1]: Finished Save Transient machine-id to Disk. peer2 # [6018427.791324] peer2 systemd[1]: Startup finished in 3.316s. test script finished in 4.94s cleanup kill NspawnMachine (pid 52) kill NspawnMachine (pid 53) Container peer1 terminated by signal KILL. Container peer2 terminated by signal KILL. (finished: cleanup, in 0.38 seconds)