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: machine, router, 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 machine: systemd-nspawn running (pid 52) router: systemd-nspawn running (pid 53) machine: Waiting for journal at /build/vm-state-machine/var/log/journal... router: Waiting for journal at /build/vm-state-router/var/log/journal... (finished: start all VMs, in 0.00 seconds) router: waiting for unit multi-user.target nixos-nspawn(router): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(router): 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(machine): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(machine): 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. 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 router on /build/vm-state-router. ░ Spawning container machine on /build/vm-state-machine. machine # [6241325.091033] machine systemd-journald[54]: Journal started machine # [6241325.091092] machine systemd-journald[54]: Runtime Journal (/run/log/journal/c14d39e82a20423d8f70f0cac9d148b0) is 8M, max 2.5G, 2.4G free. machine # [6241325.092784] machine systemd[1]: Finished Create Static Device Nodes in /dev gracefully. machine # [6241325.102098] machine systemd[1]: Starting Flush Journal to Persistent Storage... machine # [6241325.102796] machine systemd[1]: Starting Create Static Device Nodes in /dev... machine # [6241325.113738] machine systemd-journald[54]: Time spent on flushing to /var/log/journal/c14d39e82a20423d8f70f0cac9d148b0 is 1.813ms for 5 entries. machine # [6241325.113738] machine systemd-journald[54]: System Journal (/var/log/journal/c14d39e82a20423d8f70f0cac9d148b0) is 8M, max 4G, 3.9G free. machine # [6241325.118298] machine systemd[1]: Finished Create Static Device Nodes in /dev. machine # [6241325.118542] machine systemd[1]: Reached target Preparation for Local File Systems. machine # [6241325.118623] machine systemd[1]: Reached target Local File Systems. machine # [6241325.119339] machine systemd[1]: Listening on Boot Loader Control Service Socket. machine # [6241325.119378] machine systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container machine # [6241325.120326] machine systemd[1]: Starting Save Transient machine-id to Disk... machine # [6241325.120361] machine systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys machine # [6241325.129596] machine systemd[1]: Finished Flush Journal to Persistent Storage. machine # [6241325.131201] machine systemd[1]: Starting Create System Files and Directories... machine # [6241325.149152] machine systemd-tmpfiles[97]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted machine # [6241325.149371] machine systemd-tmpfiles[97]: fchmod() of /var/log/journal failed: Operation not permitted machine # [6241325.149517] machine systemd-tmpfiles[97]: fchmod() of /var/log/journal/c14d39e82a20423d8f70f0cac9d148b0 failed: Operation not permitted machine # [6241325.149741] machine systemd-tmpfiles[97]: fchmod() of /run/log/journal failed: Operation not permitted machine # [6241325.151230] machine systemd[1]: Finished Create System Files and Directories. machine # [6241325.152278] machine systemd[1]: Starting Rebuild Journal Catalog... machine # [6241325.152921] machine systemd[1]: Starting Record System Boot/Shutdown in UTMP... router # [6241325.101198] router systemd-journald[54]: Journal started machine # [6241325.165041] machine systemd[1]: Finished Record System Boot/Shutdown in UTMP. router # [6241325.101256] router systemd-journald[54]: Runtime Journal (/run/log/journal/ee136996679243f9b40f2e8c53d3b4a5) is 8M, max 2.5G, 2.4G free. machine # [6241325.174065] machine systemd[1]: Finished Rebuild Journal Catalog. router # [6241325.104228] router systemd[1]: Starting Flush Journal to Persistent Storage... machine # [6241325.175171] machine systemd[1]: Starting Update is Completed... router # [6241325.105014] router systemd[1]: Starting Network Name Resolution... machine # [6241325.185523] machine systemd[1]: Finished Update is Completed. router # [6241325.105608] router systemd[1]: Starting Create Static Device Nodes in /dev... router # [6241325.114839] router systemd-journald[54]: Time spent on flushing to /var/log/journal/ee136996679243f9b40f2e8c53d3b4a5 is 1.992ms for 5 entries. router # [6241325.114839] router systemd-journald[54]: System Journal (/var/log/journal/ee136996679243f9b40f2e8c53d3b4a5) is 8M, max 4G, 3.9G free. router # [6241325.120627] router systemd[1]: Finished Create Static Device Nodes in /dev. router # [6241325.120851] router systemd[1]: Reached target Preparation for Local File Systems. router # [6241325.120936] router systemd[1]: Reached target Local File Systems. router # [6241325.121640] router systemd[1]: Listening on Boot Loader Control Service Socket. router # [6241325.121682] router systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container router # [6241325.122584] router systemd[1]: Starting Save Transient machine-id to Disk... router # [6241325.122618] router systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys router # [6241325.123554] router systemd[1]: Starting Network Management... router # [6241325.130990] router systemd[1]: Finished Flush Journal to Persistent Storage. router # [6241325.131913] router systemd[1]: Starting Create System Files and Directories... router # [6241325.148453] router systemd-tmpfiles[70]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted router # [6241325.148666] router systemd-tmpfiles[70]: fchmod() of /var/log/journal failed: Operation not permitted router # [6241325.148811] router systemd-tmpfiles[70]: fchmod() of /var/log/journal/ee136996679243f9b40f2e8c53d3b4a5 failed: Operation not permitted machine # [6241325.185669] machine systemd[1]: Reached target System Initialization. router # [6241325.149025] router systemd-tmpfiles[70]: fchmod() of /run/log/journal failed: Operation not permitted machine # [6241325.185740] machine systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container router # [6241325.150417] router systemd[1]: Finished Create System Files and Directories. machine # [6241325.185769] machine systemd[1]: Started Daily Cleanup of Temporary Directories. router # [6241325.151518] router systemd[1]: Starting Rebuild Journal Catalog... machine # [6241325.185786] machine systemd[1]: Reached target Timer Units. router # [6241325.152301] router systemd[1]: Starting Record System Boot/Shutdown in UTMP... machine # [6241325.185888] machine systemd[1]: Listening on D-Bus System Message Bus Socket. router # [6241325.165219] router systemd[1]: Finished Record System Boot/Shutdown in UTMP. machine # [6241325.185993] machine systemd[1]: Listening on Nix Daemon Socket. router # [6241325.174424] router systemd[1]: Finished Rebuild Journal Catalog. machine # [6241325.186077] machine systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. router # [6241325.175623] router systemd[1]: Starting Update is Completed... machine # [6241325.186101] machine systemd[1]: Reached target Socket Units. router # [6241325.186477] router systemd[1]: Finished Update is Completed. machine # [6241325.186130] machine systemd[1]: Reached target Basic System. machine # [6241325.187068] machine systemd[1]: Starting Import lastlog data into lastlog2 database... machine # [6241325.187833] machine systemd[1]: Starting Name Service Cache Daemon (nsncd)... machine # [6241325.207190] machine systemd[1]: Finished Import lastlog data into lastlog2 database. machine # [6241325.264844] machine nsncd[138]: Aug 20 05:05:51.317 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" machine # [6241325.264885] machine systemd[1]: Started Name Service Cache Daemon (nsncd). machine # [6241325.264938] machine systemd[1]: Reached target Host and Network Name Lookups. machine # [6241325.264984] machine systemd[1]: Reached target User and Group Name Lookups. machine # [6241325.266089] machine systemd[1]: Starting User Login Management... machine # [6241325.308377] machine systemd[1]: Finished Firewall. machine # [6241325.308602] machine systemd[1]: Reached target Preparation for Network. machine # [6241325.309567] machine systemd[1]: Starting Address configuration of eth1... machine # [6241325.310406] machine systemd[1]: Starting Extra networking commands.... machine # [6241325.311207] machine systemd[1]: Starting Setup wg0 dummy interface... machine # [6241325.330128] machine network-addresses-eth1-start[224]: adding address 192.168.1.1/24... done machine # [6241325.332486] machine systemd[1]: Finished Setup wg0 dummy interface. machine # [6241325.332944] machine network-addresses-eth1-start[224]: adding address 2001:db8:1::1/64... done machine # [6241325.338022] machine systemd[1]: Finished Address configuration of eth1. machine # [6241325.372790] machine systemd[1]: Stopped target Host and Network Name Lookups. machine # [6241325.372860] machine systemd[1]: Stopping Host and Network Name Lookups... machine # [6241325.372921] machine systemd[1]: Stopped target User and Group Name Lookups. machine # [6241325.372952] machine systemd[1]: Stopping User and Group Name Lookups... machine # [6241325.373156] machine systemd[1]: Stopping Name Service Cache Daemon (nsncd)... machine # [6241325.376388] machine systemd[1]: nscd.service: Deactivated successfully. machine # [6241325.376565] machine systemd[1]: Stopped Name Service Cache Daemon (nsncd). machine # [6241325.378834] machine systemd[1]: Starting Name Service Cache Daemon (nsncd)... machine # [6241325.387942] machine systemd[1]: Finished Extra networking commands.. machine # [6241325.388258] machine systemd[1]: Reached target Network. machine # [6241325.389930] machine systemd[1]: Starting Nginx Web Server... machine # [6241325.459628] machine nsncd[292]: Aug 20 05:05:51.512 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" machine # [6241325.459782] machine systemd[1]: Started Name Service Cache Daemon (nsncd). machine # [6241325.459877] machine systemd[1]: Reached target Host and Network Name Lookups. machine # [6241325.459973] machine systemd[1]: Reached target User and Group Name Lookups. machine # [6241325.461360] machine systemd[1]: Starting Permit User Sessions... machine # [6241325.507863] machine systemd[1]: Finished Permit User Sessions. machine # [6241325.509582] machine systemd[1]: Started Console Getty. machine # [6241325.509655] machine systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 machine # [6241325.509693] machine systemd[1]: Reached target Login Prompts. machine # [6241325.619023] machine systemd[1]: Finished Save Transient machine-id to Disk. router # [6241325.467272] router systemd-networkd[67]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted router # [6241325.467362] router systemd-networkd[67]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted router # [6241325.473615] router systemd-networkd[67]: lo: Link UP router # [6241325.473624] router systemd-networkd[67]: lo: Gained carrier router # [6241325.473823] router systemd-networkd[67]: eth1: Configuring with /etc/systemd/network/40-eth1.network. router # [6241325.474197] router systemd[1]: Started Network Management. router # [6241325.500381] router systemd-networkd[67]: eth1: Link UP router # [6241325.500833] router systemd-networkd[67]: eth1: Gained carrier router # [6241325.501547] router systemd[1]: Starting Enable Persistent Storage in systemd-networkd... router # [6241325.534517] router systemd[1]: Finished Enable Persistent Storage in systemd-networkd. router # [6241325.619243] router systemd[1]: Finished Save Transient machine-id to Disk. router # [6241325.691142] router systemd-resolved[61]: Positive Trust Anchors: router # [6241325.691153] router systemd-resolved[61]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d router # [6241325.691156] router systemd-resolved[61]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 router # [6241325.691191] router systemd-resolved[61]: 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 router # [6241325.713177] router systemd-resolved[61]: Using system hostname 'router'. router # [6241325.714550] router systemd[1]: Started Network Name Resolution. router # [6241325.714678] router systemd[1]: Reached target Network. router # [6241325.714799] router systemd[1]: Reached target System Initialization. router # [6241325.714889] router systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container router # [6241325.714939] router systemd[1]: Started Daily Cleanup of Temporary Directories. router # [6241325.714981] router systemd[1]: Reached target Timer Units. router # [6241325.715325] router systemd[1]: Listening on D-Bus System Message Bus Socket. router # [6241325.715543] router systemd[1]: Listening on Nix Daemon Socket. router # [6241325.715761] router systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. router # [6241325.715836] router systemd[1]: Reached target Socket Units. router # [6241325.715926] router systemd[1]: Reached target Basic System. router # [6241325.717780] router systemd[1]: Starting Import lastlog data into lastlog2 database... machine # [6241325.714095] machine systemd-logind[200]: New seat seat0. machine # [6241325.714524] machine systemd[1]: Started User Login Management. machine # [6241325.716194] machine systemd[1]: Starting D-Bus System Message Bus... machine # [6241325.717456] machine systemd[1]: Starting linger-users.service... machine # [6241325.779490] machine systemd[1]: linger-users.service: Deactivated successfully. machine # [6241325.779778] machine systemd[1]: Finished linger-users.service. machine # [6241325.850153] machine nginx-pre-start[323]: nginx: the configuration file /nix/store/f6bz7fb6kqyk1j719hra7mgz5f5dynlv-nginx.conf syntax is ok machine # [6241325.850153] machine nginx-pre-start[323]: nginx: configuration file /nix/store/f6bz7fb6kqyk1j719hra7mgz5f5dynlv-nginx.conf test is successful machine # [6241325.856402] machine systemd[1]: Started Nginx Web Server. machine # [6241325.856698] machine systemd[1]: Reached target Multi-User System. machine # [6241325.951892] machine dbus-broker-launch[319]: Looking up NSS user entry for 'systemd-timesync'... machine # [6241325.953207] machine dbus-broker-launch[319]: NSS returned no entry for 'systemd-timesync' machine # [6241325.953207] machine dbus-broker-launch[319]: Invalid user-name in /nix/store/6sxd1m5zq429m31qjhs79mw71n2yyln2-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" machine # [6241325.953658] machine systemd[1]: Started D-Bus System Message Bus. machine # [6241325.962508] machine dbus-broker-launch[319]: Ready machine # [6241325.963159] machine systemd[1]: Startup finished in 1.214s. machine # [6241326.081972] machine systemd[1]: etc-machine\x2did.mount: Deactivated successfully. router # [6241325.719256] router systemd[1]: Starting Nginx Web Server... router # [6241325.768588] router systemd[1]: Starting Name Service Cache Daemon (nsncd)... router # [6241325.770947] router systemd[1]: Starting D-Bus System Message Bus... router # [6241325.786050] router systemd[1]: Finished Import lastlog data into lastlog2 database. router # [6241325.872158] router nsncd[84]: Aug 20 05:05:51.925 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" router # [6241325.872167] router systemd[1]: Started Name Service Cache Daemon (nsncd). router # [6241325.872263] router systemd[1]: Reached target Host and Network Name Lookups. router # [6241325.872363] router systemd[1]: Reached target User and Group Name Lookups. router # [6241325.896446] router systemd[1]: Starting User Login Management... router # [6241325.897966] router systemd[1]: Starting Permit User Sessions... router # [6241325.910227] router systemd[1]: Finished Permit User Sessions. router # [6241325.911820] router systemd[1]: Started Console Getty. router # [6241325.911896] router systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 router # [6241325.911940] router systemd[1]: Reached target Login Prompts. router # [6241325.945264] router dbus-broker-launch[88]: Looking up NSS user entry for 'systemd-timesync'... router # [6241325.946498] router dbus-broker-launch[88]: NSS returned no entry for 'systemd-timesync' router # [6241325.946498] router dbus-broker-launch[88]: Invalid user-name in /nix/store/i3vwn6i16yaczblcskv1irvqmw5k0pns-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" router # [6241325.946954] router systemd[1]: Started D-Bus System Message Bus. router # [6241325.954676] router dbus-broker-launch[88]: Ready router # [6241326.091258] router systemd[1]: etc-machine\x2did.mount: Deactivated successfully. router # [6241326.298796] router nginx-pre-start[114]: nginx: the configuration file /nix/store/qrsah5s67snpprkgwckqjvb52f8z9ciz-nginx.conf syntax is ok router # [6241326.299400] router nginx-pre-start[114]: nginx: configuration file /nix/store/qrsah5s67snpprkgwckqjvb52f8z9ciz-nginx.conf test is successful router # [6241326.304114] router systemd[1]: Started Nginx Web Server. router # [6241326.313419] router systemd-logind[103]: New seat seat0. router # [6241326.313642] router systemd[1]: Started User Login Management. router: (finished: waiting for unit multi-user.target, in 2.15 seconds) router: waiting for unit nginx.service router: (finished: waiting for unit nginx.service, in 0.02 seconds) machine: waiting for unit multi-user.target machine: (finished: waiting for unit multi-user.target, in 0.02 seconds) machine: waiting for unit nginx.service machine: (finished: waiting for unit nginx.service, in 0.02 seconds) router: must succeed: ip -4 addr show eth1 | grep -oP '(?<=inet\s)\d+(\.\d+){3}' router: (finished: must succeed: ip -4 addr show eth1 | grep -oP '(?<=inet\s)\d+(\.\d+){3}', in 0.01 seconds) router: must succeed: ip -6 addr show eth1 | grep -oP '(?<=inet6\s)[0-9a-f:]+' | grep -v '^fe80' | head -1 router: (finished: must succeed: ip -6 addr show eth1 | grep -oP '(?<=inet6\s)[0-9a-f:]+' | grep -v '^fe80' | head -1, in 0.01 seconds) Router IPv4: 192.168.1.2 Router IPv6: 2001:db8:1::2 machine: must succeed: systemctl restart firewall router # [6241326.353476] router systemd[1]: Starting linger-users.service... router # [6241326.368168] router systemd[1]: linger-users.service: Deactivated successfully. router # [6241326.368491] router systemd[1]: Finished linger-users.service. router # [6241326.369296] router systemd[1]: Reached target Multi-User System. router # [6241326.369583] router systemd[1]: Startup finished in 1.623s. machine # [6241326.580533] machine systemd[1]: Stopping Firewall... machine # [6241327.025400] machine systemd[1]: firewall.service: Deactivated successfully. machine # [6241327.025653] machine systemd[1]: Stopped Firewall. machine # [6241327.027198] machine systemd[1]: Starting Firewall... router # [6241327.008211] router systemd-networkd[67]: eth1: Gained IPv6LL machine: (finished: must succeed: systemctl restart firewall, in 1.42 seconds) machine: waiting for unit firewall.service machine: (finished: waiting for unit firewall.service, in 0.01 seconds) machine: must succeed: iptables -L user-firewall-output >&2 Chain user-firewall-output (1 references) target prot opt source destination RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere RETURN all -- anywhere anywhere REJECT all -- anywhere anywhere owner UID match bob reject-with icmp-port-unreachable RETURN all -- anywhere anywhere machine: (finished: must succeed: iptables -L user-firewall-output >&2, in 0.01 seconds) machine: waiting for success: runuser -u alice -- curl -s http://127.0.0.1:8080 machine: (finished: waiting for success: runuser -u alice -- curl -s http://127.0.0.1:8080, in 0.02 seconds) machine: must succeed: runuser -u alice -- curl -s http://192.168.1.2 machine: (finished: must succeed: runuser -u alice -- curl -s http://192.168.1.2, in 0.02 seconds) machine: must succeed: runuser -u alice -- curl -s http://[2001:db8:1::2] machine: (finished: must succeed: runuser -u alice -- curl -s http://[2001:db8:1::2], in 0.02 seconds) machine: must succeed: runuser -u bob -- curl -s http://127.0.0.1:8080 machine: (finished: must succeed: runuser -u bob -- curl -s http://127.0.0.1:8080, in 0.02 seconds) machine: must succeed: runuser -u bob -- curl -s --connect-timeout 2 http://192.168.1.2 2>&1 || echo 'EXIT_CODE='$? machine: (finished: must succeed: runuser -u bob -- curl -s --connect-timeout 2 http://192.168.1.2 2>&1 || echo 'EXIT_CODE='$?, in 0.02 seconds) machine: must succeed: runuser -u bob -- curl -s --connect-timeout 2 http://[2001:db8:1::2] 2>&1 || echo 'EXIT_CODE='$? machine # [6241327.979618] machine systemd[1]: Finished Firewall. machine # [6241328.013804] machine runuser[482]: pam_unix(runuser:session): session opened for user alice(uid=1001) by (uid=0) machine # [6241328.024528] machine runuser[482]: pam_unix(runuser:session): session closed for user alice machine # [6241328.034050] machine runuser[484]: pam_unix(runuser:session): session opened for user alice(uid=1001) by (uid=0) machine # [6241328.045469] machine runuser[484]: pam_unix(runuser:session): session closed for user alice machine # [6241328.055272] machine runuser[486]: pam_unix(runuser:session): session opened for user alice(uid=1001) by (uid=0) machine # [6241328.065481] machine runuser[486]: pam_unix(runuser:session): session closed for user alice machine # [6241328.073260] machine runuser[488]: pam_unix(runuser:session): session opened for user bob(uid=1002) by (uid=0) machine # [6241328.083278] machine runuser[488]: pam_unix(runuser:session): session closed for user bob machine # [6241328.093353] machine runuser[491]: pam_unix(runuser:session): session opened for user bob(uid=1002) by (uid=0) machine # [6241328.103047] machine runuser[491]: pam_unix(runuser:session): session closed for user bob machine # [6241328.112416] machine runuser[494]: pam_unix(runuser:session): session opened for user bob(uid=1002) by (uid=0) machine: (finished: must succeed: runuser -u bob -- curl -s --connect-timeout 2 http://[2001:db8:1::2] 2>&1 || echo 'EXIT_CODE='$?, in 1.05 seconds) machine: must succeed: iptables -L user-firewall-output -n -v machine: (finished: must succeed: iptables -L user-firewall-output -n -v, in 0.01 seconds) machine: must succeed: ip6tables -L user-firewall-output -n -v machine: (finished: must succeed: ip6tables -L user-firewall-output -n -v, in 0.01 seconds) machine: waiting for unit setup-wg0-interface.service machine: (finished: waiting for unit setup-wg0-interface.service, in 0.02 seconds) machine: waiting for unit nginx.service machine: (finished: waiting for unit nginx.service, in 0.01 seconds) machine: waiting for TCP port 8081 on 10.100.0.2 Connection to 10.100.0.2 8081 port [tcp/sunproxyadmin] succeeded! machine: (finished: waiting for TCP port 8081 on 10.100.0.2, in 0.01 seconds) machine: must succeed: ip link show wg0 machine: (finished: must succeed: ip link show wg0, in 0.01 seconds) machine: must succeed: ip addr show wg0 machine: (finished: must succeed: ip addr show wg0, in 0.01 seconds) machine: must succeed: runuser -u alice -- curl -s --interface wg0 http://10.100.0.2:8081/ machine: (finished: must succeed: runuser -u alice -- curl -s --interface wg0 http://10.100.0.2:8081/, in 0.02 seconds) machine: must succeed: runuser -u alice -- curl -s --interface wg0 http://[fd00::2]:8081/ machine: (finished: must succeed: runuser -u alice -- curl -s --interface wg0 http://[fd00::2]:8081/, in 0.02 seconds) machine: must succeed: runuser -u bob -- curl -s --interface wg0 http://10.100.0.2:8081/ machine: (finished: must succeed: runuser -u bob -- curl -s --interface wg0 http://10.100.0.2:8081/, in 0.02 seconds) machine: must succeed: runuser -u bob -- curl -s --interface wg0 http://[fd00::2]:8081/ machine: (finished: must succeed: runuser -u bob -- curl -s --interface wg0 http://[fd00::2]:8081/, in 0.02 seconds) machine: must succeed: iptables -L user-firewall-output -n -v | grep -E 'wg0|wg\+' >&2 0 0 RETURN all -- * wg+ 0.0.0.0/0 0.0.0.0/0 machine: (finished: must succeed: iptables -L user-firewall-output -n -v | grep -E 'wg0|wg\+' >&2, in 0.01 seconds) (finished: run the VM test script, in 4.99 seconds) machine # [6241329.154447] machine runuser[494]: pam_unix(runuser:session): session closed for user bob machine # [6241329.237365] machine runuser[503]: pam_unix(runuser:session): session opened for user alice(uid=1001) by (uid=0) machine # [6241329.246660] machine runuser[503]: pam_unix(runuser:session): session closed for user alice machine # [6241329.256135] machine runuser[505]: pam_unix(runuser:session): session opened for user alice(uid=1001) by (uid=0) machine # [6241329.266689] machine runuser[505]: pam_unix(runuser:session): session closed for user alice machine # [6241329.276509] machine runuser[507]: pam_unix(runuser:session): session opened for user bob(uid=1002) by (uid=0) machine # [6241329.287761] machine runuser[507]: pam_unix(runuser:session): session closed for user bob machine # [6241329.296343] machine runuser[509]: pam_unix(runuser:session): session opened for user bob(uid=1002) by (uid=0) machine # [6241329.306576] machine runuser[509]: pam_unix(runuser:session): session closed for user bob test script finished in 5.16s cleanup kill NspawnMachine (pid 52) kill NspawnMachine (pid 53) Container machine terminated by signal KILL. Container router terminated by signal KILL. (finished: cleanup, in 0.38 seconds)