container-test-run-hello-service
default.checks.aarch64-linux.hello-service
· build #393
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.00 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 peer1, peer2,9 vlan1,10 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_ssh11start all VMs12peer1: systemd-nspawn running (pid 52)13peer2: systemd-nspawn running (pid 53)14peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...15peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...16(finished: start all VMs, in 0.00 seconds)17peer1: must succeed: greet-world18nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE19nixos-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.20nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE21nixos-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.22Note: 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.23░ Spawning container peer2 on /build/vm-state-peer2.24Note: 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.25░ Spawning container peer1 on /build/vm-state-peer1.26peer1 # No journal boot entry found for the specified boot (+0).27peer2 # No journal boot entry found for the specified boot (+0).28peer1 # [6018424.935895] peer1 systemd-journald[69]: Journal started29peer1 # [6018424.935956] peer1 systemd-journald[69]: Runtime Journal (/run/log/journal/35050c0f355a4c049e7e6fc3dd6f8727) is 8M, max 2.5G, 2.4G free.30peer1 # [6018424.939584] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...31peer1 # [6018424.948235] peer1 systemd-journald[69]: Time spent on flushing to /var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727 is 1.983ms for 3 entries.32peer1 # [6018424.948235] peer1 systemd-journald[69]: System Journal (/var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727) is 8M, max 4G, 3.9G free.33peer1 # [6018424.957766] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.34peer1 # [6018424.958443] peer1 systemd[1]: Reached target Preparation for Local File Systems.35peer1 # [6018424.958567] peer1 systemd[1]: Reached target Local File Systems.36peer1 # [6018424.959491] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.37peer1 # [6018424.959542] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container38peer1 # [6018424.960472] peer1 systemd[1]: Starting Save Transient machine-id to Disk...39peer1 # [6018424.960513] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys40peer1 # [6018425.089676] peer1 systemd[1]: Finished Firewall.41peer1 # [6018425.090541] peer1 systemd[1]: Reached target Preparation for Network.42peer1 # [6018425.090862] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.43peer1 # [6018425.091962] peer1 systemd[1]: Starting Network Management...44peer1 # [6018425.101673] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.45peer1 # [6018425.102601] peer1 systemd[1]: Starting Create System Files and Directories...46peer1 # [6018425.120192] peer1 systemd-tmpfiles[176]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted47peer1 # [6018425.120372] peer1 systemd-tmpfiles[176]: fchmod() of /var/log/journal failed: Operation not permitted48peer1 # [6018425.120489] peer1 systemd-tmpfiles[176]: fchmod() of /var/log/journal/35050c0f355a4c049e7e6fc3dd6f8727 failed: Operation not permitted49peer1 # [6018425.120667] peer1 systemd-tmpfiles[176]: fchmod() of /run/log/journal failed: Operation not permitted50peer1 # [6018425.122078] peer1 systemd[1]: Finished Create System Files and Directories.51peer1 # [6018425.123076] peer1 systemd[1]: Starting Rebuild Journal Catalog...52peer1 # [6018425.123750] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...53peer1 # [6018425.135781] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.54peer1 # [6018425.144611] peer1 systemd[1]: Finished Rebuild Journal Catalog.55peer1 # [6018425.146629] peer1 systemd[1]: Starting Update is Completed...56peer1 # [6018425.157729] peer1 systemd[1]: Finished Update is Completed.57peer1 # [6018425.530229] peer1 systemd-networkd[173]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted58peer1 # [6018425.530320] peer1 systemd-networkd[173]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted59peer1 # [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.60peer1 # [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.61peer1 # [6018425.537857] peer1 systemd-networkd[173]: lo: Link UP62peer1 # [6018425.537860] peer1 systemd-networkd[173]: lo: Gained carrier63peer1 # [6018425.538048] peer1 systemd-networkd[173]: eth1: Configuring with /etc/systemd/network/40-eth1.network.64peer1 # [6018425.538568] peer1 systemd-networkd[173]: eth1: Link UP65peer1 # [6018425.538676] peer1 systemd[1]: Started Network Management.66peer1 # [6018425.539835] peer1 systemd-networkd[173]: eth1: Gained carrier67peer1 # [6018425.540451] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...68peer1 # [6018425.586191] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.69peer1 # [6018425.733649] peer1 systemd-resolved[86]: Positive Trust Anchors:70peer1 # [6018425.733662] peer1 systemd-resolved[86]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d71peer1 # [6018425.733665] peer1 systemd-resolved[86]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1672peer1 # [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 test73peer1 # [6018425.756501] peer1 systemd-resolved[86]: Using system hostname 'peer1'.74peer1 # [6018425.758236] peer1 systemd[1]: Started Network Name Resolution.75peer1 # [6018425.758329] peer1 systemd[1]: Reached target Network.76peer1 # [6018425.758391] peer1 systemd[1]: Reached target System Initialization.77peer1 # [6018425.758441] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container78peer1 # [6018425.758466] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.79peer1 # [6018425.758485] peer1 systemd[1]: Reached target Timer Units.80peer2 # [6018424.932553] peer2 systemd-journald[69]: Journal started81peer1 # [6018425.758615] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.82peer2 # [6018424.932607] peer2 systemd-journald[69]: Runtime Journal (/run/log/journal/f40a2aa2970340adb4b1956c27185a6b) is 8M, max 2.5G, 2.4G free.83peer1 # [6018425.758746] peer1 systemd[1]: Listening on Nix Daemon Socket.84peer2 # [6018424.939033] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...85peer1 # [6018425.758855] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.86peer2 # [6018424.939827] peer2 systemd[1]: Starting Network Name Resolution...87peer1 # [6018425.758877] peer1 systemd[1]: Reached target Socket Units.88peer2 # [6018424.940722] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...89peer1 # [6018425.758914] peer1 systemd[1]: Reached target Basic System.90peer2 # [6018424.949427] peer2 systemd-journald[69]: Time spent on flushing to /var/log/journal/f40a2aa2970340adb4b1956c27185a6b is 2.890ms for 5 entries.91peer1 # [6018425.759934] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...92peer2 # [6018424.949427] peer2 systemd-journald[69]: System Journal (/var/log/journal/f40a2aa2970340adb4b1956c27185a6b) is 8M, max 4G, 3.9G free.93peer1 # [6018425.761025] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...94peer2 # [6018424.958475] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.95peer1 # [6018425.762238] peer1 systemd[1]: Starting D-Bus System Message Bus...96peer2 # [6018424.959092] peer2 systemd[1]: Reached target Preparation for Local File Systems.97peer1 # [6018425.777485] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.98peer2 # [6018424.959205] peer2 systemd[1]: Reached target Local File Systems.99peer1 # [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"100peer2 # [6018424.959973] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.101peer1 # [6018425.858913] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).102peer2 # [6018424.960028] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container103peer1 # [6018425.858989] peer1 systemd[1]: Reached target Host and Network Name Lookups.104peer2 # [6018424.960808] peer2 systemd[1]: Starting Save Transient machine-id to Disk...105peer1 # [6018425.859061] peer1 systemd[1]: Reached target User and Group Name Lookups.106peer2 # [6018424.960845] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys107peer1 # [6018425.865620] peer1 systemd[1]: Starting User Login Management...108peer2 # [6018425.087460] peer2 systemd[1]: Finished Firewall.109peer1 # [6018425.866659] peer1 systemd[1]: Starting Permit User Sessions...110peer2 # [6018425.087631] peer2 systemd[1]: Reached target Preparation for Network.111peer1 # [6018425.939892] peer1 dbus-broker-launch[189]: Looking up NSS user entry for 'systemd-timesync'...112peer2 # [6018425.087891] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.113peer1 # [6018425.940908] peer1 dbus-broker-launch[189]: NSS returned no entry for 'systemd-timesync'114peer2 # [6018425.089111] peer2 systemd[1]: Starting Network Management...115peer1 # [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"116peer2 # [6018425.095239] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.117peer1 # [6018425.941356] peer1 systemd[1]: Started D-Bus System Message Bus.118peer2 # [6018425.097058] peer2 systemd[1]: Starting Create System Files and Directories...119peer1 # [6018425.949205] peer1 dbus-broker-launch[189]: Ready120peer2 # [6018425.113460] peer2 systemd-tmpfiles[176]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted121peer2 # [6018425.113652] peer2 systemd-tmpfiles[176]: fchmod() of /var/log/journal failed: Operation not permitted122peer2 # [6018425.113782] peer2 systemd-tmpfiles[176]: fchmod() of /var/log/journal/f40a2aa2970340adb4b1956c27185a6b failed: Operation not permitted123peer2 # [6018425.113981] peer2 systemd-tmpfiles[176]: fchmod() of /run/log/journal failed: Operation not permitted124peer2 # [6018425.115099] peer2 systemd[1]: Finished Create System Files and Directories.125peer2 # [6018425.116957] peer2 systemd[1]: Starting Rebuild Journal Catalog...126peer2 # [6018425.117811] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...127peer2 # [6018425.132300] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.128peer2 # [6018425.137744] peer2 systemd[1]: Finished Rebuild Journal Catalog.129peer2 # [6018425.139644] peer2 systemd[1]: Starting Update is Completed...130peer2 # [6018425.152164] peer2 systemd[1]: Finished Update is Completed.131peer2 # [6018425.523083] peer2 systemd-networkd[172]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted132peer2 # [6018425.523177] peer2 systemd-networkd[172]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted133peer2 # [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.134peer2 # [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.135peer2 # [6018425.530261] peer2 systemd-networkd[172]: lo: Link UP136peer2 # [6018425.530264] peer2 systemd-networkd[172]: lo: Gained carrier137peer2 # [6018425.530470] peer2 systemd-networkd[172]: eth1: Configuring with /etc/systemd/network/40-eth1.network.138peer2 # [6018425.530957] peer2 systemd-networkd[172]: eth1: Link UP139peer2 # [6018425.531292] peer2 systemd[1]: Started Network Management.140peer2 # [6018425.532302] peer2 systemd-networkd[172]: eth1: Gained carrier141peer2 # [6018425.532364] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...142peer2 # [6018425.582032] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.143peer2 # [6018425.725087] peer2 systemd-resolved[93]: Positive Trust Anchors:144peer2 # [6018425.725100] peer2 systemd-resolved[93]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d145peer2 # [6018425.725104] peer2 systemd-resolved[93]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16146peer2 # [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 test147peer2 # [6018425.747545] peer2 systemd-resolved[93]: Using system hostname 'peer2'.148peer2 # [6018425.748945] peer2 systemd[1]: Started Network Name Resolution.149peer2 # [6018425.749026] peer2 systemd[1]: Reached target Network.150peer2 # [6018425.749090] peer2 systemd[1]: Reached target System Initialization.151peer2 # [6018425.749140] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container152peer2 # [6018425.749172] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.153peer2 # [6018425.749189] peer2 systemd[1]: Reached target Timer Units.154peer2 # [6018425.749323] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.155peer2 # [6018425.749438] peer2 systemd[1]: Listening on Nix Daemon Socket.156peer2 # [6018425.749544] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.157peer2 # [6018425.749564] peer2 systemd[1]: Reached target Socket Units.158peer2 # [6018425.749599] peer2 systemd[1]: Reached target Basic System.159peer2 # [6018425.750701] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...160peer2 # [6018425.751691] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...161peer2 # [6018425.752928] peer2 systemd[1]: Starting D-Bus System Message Bus...162peer2 # [6018425.773080] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.163peer2 # [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"164peer2 # [6018425.870423] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).165peer2 # [6018425.870487] peer2 systemd[1]: Reached target Host and Network Name Lookups.166peer2 # [6018425.870543] peer2 systemd[1]: Reached target User and Group Name Lookups.167peer2 # [6018425.940221] peer2 dbus-broker-launch[189]: Looking up NSS user entry for 'systemd-timesync'...168peer1 # [6018425.983617] peer1 systemd[1]: Finished Permit User Sessions.169peer1 # [6018425.985082] peer1 systemd[1]: Started Console Getty.170peer1 # [6018425.985184] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0171peer1 # [6018425.985288] peer1 systemd[1]: Reached target Login Prompts.172peer2 # [6018425.976414] peer2 systemd[1]: Starting User Login Management...173peer2 # [6018425.977272] peer2 systemd[1]: Starting Permit User Sessions...174peer2 # [6018425.986034] peer2 dbus-broker-launch[189]: NSS returned no entry for 'systemd-timesync'175peer2 # [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"176peer2 # [6018425.986661] peer2 systemd[1]: Started D-Bus System Message Bus.177peer2 # [6018425.995946] peer2 dbus-broker-launch[189]: Ready178peer2 # [6018425.997088] peer2 systemd[1]: Finished Permit User Sessions.179peer2 # [6018425.999397] peer2 systemd[1]: Started Console Getty.180peer2 # [6018425.999496] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0181peer2 # [6018425.999611] peer2 systemd[1]: Reached target Login Prompts.182peer1 # [6018426.474680] peer1 systemd-logind[204]: New seat seat0.183peer1 # [6018426.474922] peer1 systemd[1]: Started User Login Management.184peer1 # [6018426.476366] peer1 systemd[1]: Starting linger-users.service...185peer1 # [6018426.495372] peer1 systemd[1]: linger-users.service: Deactivated successfully.186peer1 # [6018426.495538] peer1 systemd[1]: Finished linger-users.service.187peer1 # [6018426.495977] peer1 systemd[1]: Reached target Multi-User System.188peer2 # [6018426.491915] peer2 systemd-logind[204]: New seat seat0.189peer2 # [6018426.492107] peer2 systemd[1]: Started User Login Management.190peer2 # [6018426.493579] peer2 systemd[1]: Starting linger-users.service...191peer2 # [6018426.512087] peer2 systemd[1]: linger-users.service: Deactivated successfully.192peer2 # [6018426.512173] peer2 systemd[1]: Finished linger-users.service.193peer2 # [6018426.512701] peer2 systemd[1]: Reached target Multi-User System.194peer1 # [6018426.880147] peer1 systemd-networkd[173]: eth1: Gained IPv6LL195peer2 # [6018427.040137] peer2 systemd-networkd[172]: eth1: Gained IPv6LL196peer1: (finished: must succeed: greet-world, in 4.15 seconds)197peer2: must succeed: greet-world198peer2: (finished: must succeed: greet-world, in 0.01 seconds)199(finished: run the VM test script, in 4.16 seconds)200peer1 # [6018427.781155] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.201peer1 # [6018427.782258] peer1 systemd[1]: Finished Save Transient machine-id to Disk.202peer1 # [6018427.782506] peer1 systemd[1]: Startup finished in 3.315s.203peer2 # [6018427.788939] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.204peer2 # [6018427.790924] peer2 systemd[1]: Finished Save Transient machine-id to Disk.205peer2 # [6018427.791324] peer2 systemd[1]: Startup finished in 3.316s.206test script finished in 4.94s207cleanup208kill NspawnMachine (pid 52)209kill NspawnMachine (pid 53)210Container peer1 terminated by signal KILL.211Container peer2 terminated by signal KILL.212(finished: cleanup, in 0.38 seconds)