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: alpha, beta, gamma, 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 alpha: systemd-nspawn running (pid 53) beta: systemd-nspawn running (pid 54) gamma: systemd-nspawn running (pid 55) alpha: Waiting for journal at /build/vm-state-alpha/var/log/journal... gamma: Waiting for journal at /build/vm-state-gamma/var/log/journal... (finished: start all VMs, in 0.00 seconds) beta: Waiting for journal at /build/vm-state-beta/var/log/journal... alpha: waiting for unit data-mesher.service nixos-nspawn(gamma): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(gamma): 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(beta): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(beta): 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(alpha): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(alpha): 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 alpha on /build/vm-state-alpha. ░ Spawning container gamma on /build/vm-state-gamma. 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 beta on /build/vm-state-beta. alpha # [94550.874818] alpha systemd-journald[88]: Journal started alpha # [94550.874868] alpha systemd-journald[88]: Runtime Journal (/run/log/journal/262adbea8f414996af715d86de7cbb39) is 8M, max 2.5G, 2.4G free. alpha # [94550.879481] alpha systemd[1]: Finished Create Static Device Nodes in /dev gracefully. alpha # [94550.888237] alpha systemd[1]: Starting Flush Journal to Persistent Storage... alpha # [94550.889176] alpha systemd[1]: Starting Network Name Resolution... alpha # [94550.889897] alpha systemd[1]: Starting Create Static Device Nodes in /dev... alpha # [94550.897797] alpha systemd-journald[88]: Time spent on flushing to /var/log/journal/262adbea8f414996af715d86de7cbb39 is 1.608ms for 6 entries. alpha # [94550.897797] alpha systemd-journald[88]: System Journal (/var/log/journal/262adbea8f414996af715d86de7cbb39) is 8M, max 4G, 3.9G free. alpha # [94550.905135] alpha systemd[1]: Finished Create Static Device Nodes in /dev. alpha # [94550.905388] alpha systemd[1]: Reached target Preparation for Local File Systems. alpha # [94550.905480] alpha systemd[1]: Reached target Local File Systems. alpha # [94550.906230] alpha systemd[1]: Listening on Boot Loader Control Service Socket. alpha # [94550.906278] alpha systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container alpha # [94550.907174] alpha systemd[1]: Starting Save Transient machine-id to Disk... alpha # [94550.907210] alpha systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys alpha # [94550.923008] alpha systemd[1]: Finished Flush Journal to Persistent Storage. alpha # [94550.924537] alpha systemd[1]: Starting Create System Files and Directories... alpha # [94550.945330] alpha systemd-tmpfiles[137]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted alpha # [94550.945520] alpha systemd-tmpfiles[137]: fchmod() of /var/log/journal failed: Operation not permitted alpha # [94550.945651] alpha systemd-tmpfiles[137]: fchmod() of /var/log/journal/262adbea8f414996af715d86de7cbb39 failed: Operation not permitted alpha # [94550.945851] alpha systemd-tmpfiles[137]: fchmod() of /run/log/journal failed: Operation not permitted alpha # [94550.947276] alpha systemd[1]: Finished Create System Files and Directories. alpha # [94550.948373] alpha systemd[1]: Starting Rebuild Journal Catalog... alpha # [94550.949319] alpha systemd[1]: Starting Record System Boot/Shutdown in UTMP... alpha # [94550.960920] alpha systemd[1]: Finished Record System Boot/Shutdown in UTMP. alpha # [94550.967422] alpha systemd[1]: Finished Rebuild Journal Catalog. alpha # [94550.968525] alpha systemd[1]: Starting Update is Completed... alpha # [94550.979746] alpha systemd[1]: Finished Update is Completed. gamma # [94550.879623] gamma systemd-journald[87]: Journal started gamma # [94550.879682] gamma systemd-journald[87]: Runtime Journal (/run/log/journal/40e4e744cf314a93b264a79557460c0f) is 8M, max 2.5G, 2.4G free. gamma # [94550.887769] gamma systemd[1]: Starting Flush Journal to Persistent Storage... gamma # [94550.888629] gamma systemd[1]: Starting Network Name Resolution... gamma # [94550.889341] gamma systemd[1]: Starting Create Static Device Nodes in /dev... gamma # [94550.896907] gamma systemd-journald[87]: Time spent on flushing to /var/log/journal/40e4e744cf314a93b264a79557460c0f is 1.595ms for 5 entries. gamma # [94550.896907] gamma systemd-journald[87]: System Journal (/var/log/journal/40e4e744cf314a93b264a79557460c0f) is 8M, max 4G, 3.9G free. gamma # [94550.905148] gamma systemd[1]: Finished Create Static Device Nodes in /dev. gamma # [94550.905397] gamma systemd[1]: Reached target Preparation for Local File Systems. gamma # [94550.905487] gamma systemd[1]: Reached target Local File Systems. gamma # [94550.906233] gamma systemd[1]: Listening on Boot Loader Control Service Socket. gamma # [94550.906277] gamma systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container gamma # [94550.907175] gamma systemd[1]: Starting Save Transient machine-id to Disk... gamma # [94550.907210] gamma systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys gamma # [94550.922564] gamma systemd[1]: Finished Flush Journal to Persistent Storage. gamma # [94550.924196] gamma systemd[1]: Starting Create System Files and Directories... gamma # [94550.945606] gamma systemd-tmpfiles[134]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted gamma # [94550.945830] gamma systemd-tmpfiles[134]: fchmod() of /var/log/journal failed: Operation not permitted gamma # [94550.945984] gamma systemd-tmpfiles[134]: fchmod() of /var/log/journal/40e4e744cf314a93b264a79557460c0f failed: Operation not permitted gamma # [94550.946208] gamma systemd-tmpfiles[134]: fchmod() of /run/log/journal failed: Operation not permitted gamma # [94550.948857] gamma systemd[1]: Finished Create System Files and Directories. gamma # [94550.950299] gamma systemd[1]: Starting Rebuild Journal Catalog... gamma # [94550.951057] gamma systemd[1]: Starting Record System Boot/Shutdown in UTMP... gamma # [94550.962618] gamma systemd[1]: Finished Record System Boot/Shutdown in UTMP. gamma # [94550.970995] gamma systemd[1]: Finished Rebuild Journal Catalog. gamma # [94550.971972] gamma systemd[1]: Starting Update is Completed... beta # [94550.907395] beta systemd-journald[88]: Journal started beta # [94550.907456] beta systemd-journald[88]: Runtime Journal (/run/log/journal/ba758b4a027b4a04833bf49c45c0abfb) is 8M, max 2.5G, 2.4G free. beta # [94550.910807] beta systemd[1]: Finished Create Static Device Nodes in /dev gracefully. beta # [94550.919006] beta systemd[1]: Starting Flush Journal to Persistent Storage... beta # [94550.919953] beta systemd[1]: Starting Network Name Resolution... beta # [94550.920749] beta systemd[1]: Starting Create Static Device Nodes in /dev... beta # [94550.929172] beta systemd-journald[88]: Time spent on flushing to /var/log/journal/ba758b4a027b4a04833bf49c45c0abfb is 1.576ms for 6 entries. beta # [94550.929172] beta systemd-journald[88]: System Journal (/var/log/journal/ba758b4a027b4a04833bf49c45c0abfb) is 8M, max 4G, 3.9G free. beta # [94550.933060] beta systemd[1]: Finished Create Static Device Nodes in /dev. beta # [94550.933787] beta systemd[1]: Reached target Preparation for Local File Systems. beta # [94550.933916] beta systemd[1]: Reached target Local File Systems. beta # [94550.934787] beta systemd[1]: Listening on Boot Loader Control Service Socket. beta # [94550.934839] beta systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container beta # [94550.935806] beta systemd[1]: Starting Save Transient machine-id to Disk... beta # [94550.935840] beta systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys beta # [94550.945935] beta systemd[1]: Finished Flush Journal to Persistent Storage. beta # [94550.947170] beta systemd[1]: systemd-tmpfiles-setup.service: Failed to spawn executor: No such file or directory beta # [94550.947191] beta systemd[1]: systemd-tmpfiles-setup.service: Failed to spawn 'start' task: No such file or directory beta # [94550.947227] beta systemd[1]: systemd-tmpfiles-setup.service: Failed with result 'resources'. beta # [94550.947384] beta systemd[1]: Failed to start Create System Files and Directories. beta # [94550.948345] beta systemd[1]: Starting Rebuild Journal Catalog... beta # [94550.949323] beta systemd[1]: Starting Record System Boot/Shutdown in UTMP... beta # [94550.961256] beta systemd[1]: Finished Record System Boot/Shutdown in UTMP. beta # [94550.968332] beta systemd[1]: Finished Rebuild Journal Catalog. beta # [94550.969902] beta systemd[1]: Starting Update is Completed... alpha # [94550.994354] alpha systemd[1]: Finished Save Transient machine-id to Disk. alpha # [94551.033935] alpha systemd[1]: Finished Firewall. alpha # [94551.034119] alpha systemd[1]: Reached target Preparation for Network. alpha # [94551.034387] alpha systemd[1]: Listening on Network Management Resolve Hook Socket. alpha # [94551.035598] alpha systemd[1]: Starting Network Management... gamma # [94550.981973] gamma systemd[1]: Finished Update is Completed. gamma # [94550.994353] gamma systemd[1]: Finished Save Transient machine-id to Disk. gamma # [94551.035995] gamma systemd[1]: Finished Firewall. gamma # [94551.036169] gamma systemd[1]: Reached target Preparation for Network. gamma # [94551.036371] gamma systemd[1]: Listening on Network Management Resolve Hook Socket. gamma # [94551.037321] gamma systemd[1]: Starting Network Management... beta # [94550.981966] beta systemd[1]: Finished Update is Completed. beta # [94550.994361] beta systemd[1]: Finished Save Transient machine-id to Disk. beta # [94551.064891] beta systemd[1]: Finished Firewall. beta # [94551.065044] beta systemd[1]: Reached target Preparation for Network. beta # [94551.065258] beta systemd[1]: Listening on Network Management Resolve Hook Socket. beta # [94551.066225] beta systemd[1]: Starting Network Management... beta # [94551.391524] beta systemd-networkd[205]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted beta # [94551.391615] beta systemd-networkd[205]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted beta # [94551.398189] beta systemd-networkd[205]: /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. beta # [94551.398355] beta systemd-networkd[205]: /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. beta # [94551.398504] beta systemd-networkd[205]: lo: Link UP beta # [94551.398509] beta systemd-networkd[205]: lo: Gained carrier beta # [94551.398681] beta systemd-networkd[205]: eth1: Configuring with /etc/systemd/network/40-eth1.network. beta # [94551.399125] beta systemd[1]: Started Network Management. beta # [94551.399171] beta systemd-networkd[205]: eth1: Link UP beta # [94551.399504] beta systemd-networkd[205]: eth1: Gained carrier beta # [94551.400543] beta systemd[1]: Starting Enable Persistent Storage in systemd-networkd... gamma # [94551.404990] gamma systemd-networkd[205]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted gamma # [94551.405076] gamma systemd-networkd[205]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted beta # [94551.441724] beta systemd[1]: Finished Enable Persistent Storage in systemd-networkd. gamma # [94551.411373] gamma systemd-networkd[205]: /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. gamma # [94551.411538] gamma systemd-networkd[205]: /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. gamma # [94551.411668] gamma systemd-networkd[205]: lo: Link UP gamma # [94551.411673] gamma systemd-networkd[205]: lo: Gained carrier gamma # [94551.411846] gamma systemd-networkd[205]: eth1: Configuring with /etc/systemd/network/40-eth1.network. gamma # [94551.412228] gamma systemd[1]: Started Network Management. gamma # [94551.432555] gamma systemd[1]: Starting Enable Persistent Storage in systemd-networkd... gamma # [94551.432650] gamma systemd-networkd[205]: eth1: Link UP gamma # [94551.433237] gamma systemd-networkd[205]: eth1: Gained carrier gamma # [94551.466245] gamma systemd[1]: Finished Enable Persistent Storage in systemd-networkd. gamma # [94551.505619] gamma systemd-resolved[109]: Positive Trust Anchors: gamma # [94551.505630] gamma systemd-resolved[109]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d gamma # [94551.505633] gamma systemd-resolved[109]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 gamma # [94551.505669] gamma systemd-resolved[109]: 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 gamma # [94551.527419] gamma systemd-resolved[109]: Using system hostname 'gamma'. gamma # [94551.528814] gamma systemd[1]: Started Network Name Resolution. gamma # [94551.528946] gamma systemd[1]: Reached target Network. gamma # [94551.529075] gamma systemd[1]: Reached target System Initialization. gamma # [94551.529178] gamma systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container gamma # [94551.529230] gamma systemd[1]: Started Daily Cleanup of Temporary Directories. gamma # [94551.529269] gamma systemd[1]: Reached target Timer Units. gamma # [94551.529491] gamma systemd[1]: Listening on D-Bus System Message Bus Socket. gamma # [94551.529719] gamma systemd[1]: Listening on Nix Daemon Socket. gamma # [94551.529948] gamma systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. gamma # [94551.529995] gamma systemd[1]: Reached target Socket Units. gamma # [94551.530085] gamma systemd[1]: Reached target Basic System. gamma # [94551.564608] gamma systemd[1]: Starting data mesher daemon... gamma # [94551.565938] gamma systemd[1]: Starting Import lastlog data into lastlog2 database... gamma # [94551.567279] gamma systemd[1]: Starting Name Service Cache Daemon (nsncd)... gamma # [94551.569697] gamma systemd[1]: Starting D-Bus System Message Bus... gamma # [94551.588659] gamma systemd[1]: Finished Import lastlog data into lastlog2 database. gamma # [94551.733083] gamma nsncd[212]: Sep 05 09:42:51.718 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" gamma # [94551.733101] gamma systemd[1]: Started Name Service Cache Daemon (nsncd). gamma # [94551.733154] gamma systemd[1]: Reached target Host and Network Name Lookups. gamma # [94551.733205] gamma systemd[1]: Reached target User and Group Name Lookups. beta # [94551.505812] beta systemd-resolved[112]: Positive Trust Anchors: beta # [94551.505821] beta systemd-resolved[112]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d beta # [94551.505824] beta systemd-resolved[112]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 beta # [94551.505858] beta systemd-resolved[112]: 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 beta # [94551.527472] beta systemd-resolved[112]: Using system hostname 'beta'. beta # [94551.528789] beta systemd[1]: Started Network Name Resolution. beta # [94551.528886] beta systemd[1]: Reached target Network. beta # [94551.528966] beta systemd[1]: Reached target System Initialization. beta # [94551.529032] beta systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container beta # [94551.529068] beta systemd[1]: Started Daily Cleanup of Temporary Directories. beta # [94551.529090] beta systemd[1]: Reached target Timer Units. beta # [94551.529251] beta systemd[1]: Listening on D-Bus System Message Bus Socket. beta # [94551.529296] beta systemd[1]: Nix Daemon Socket skipped, unmet condition check ConditionPathIsReadWrite=/nix/var/nix/daemon-socket beta # [94551.529424] beta systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. beta # [94551.529454] beta systemd[1]: Reached target Socket Units. beta # [94551.529503] beta systemd[1]: Reached target Basic System. beta # [94551.529722] beta systemd[1]: System is tainted: var-run-bad beta # [94551.564528] beta systemd[1]: Starting data mesher daemon... beta # [94551.564590] beta systemd[1]: Import lastlog data into lastlog2 database skipped, unmet condition check ConditionPathExists=/var/log/lastlog beta # [94551.565743] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)... beta # [94551.567360] beta systemd[1]: Starting D-Bus System Message Bus... beta # [94551.733094] beta nsncd[211]: Sep 05 09:42:51.718 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" beta # [94551.733094] beta nsncd[211]: Error: Read-only file system (os error 30) alpha # [94551.402743] alpha systemd-networkd[206]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted alpha # [94551.402833] alpha systemd-networkd[206]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted alpha # [94551.409441] alpha systemd-networkd[206]: /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. alpha # [94551.409607] alpha systemd-networkd[206]: /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. alpha # [94551.409754] alpha systemd-networkd[206]: lo: Link UP alpha # [94551.409758] alpha systemd-networkd[206]: lo: Gained carrier alpha # [94551.409953] alpha systemd-networkd[206]: eth1: Configuring with /etc/systemd/network/40-eth1.network. alpha # [94551.410324] alpha systemd[1]: Started Network Management. alpha # [94551.432317] alpha systemd-networkd[206]: eth1: Link UP alpha # [94551.432426] alpha systemd[1]: Starting Enable Persistent Storage in systemd-networkd... alpha # [94551.432734] alpha systemd-networkd[206]: eth1: Gained carrier alpha # [94551.466154] alpha systemd[1]: Finished Enable Persistent Storage in systemd-networkd. alpha # [94551.495464] alpha systemd-resolved[111]: Positive Trust Anchors: alpha # [94551.495475] alpha systemd-resolved[111]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d alpha # [94551.495479] alpha systemd-resolved[111]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 alpha # [94551.495516] alpha systemd-resolved[111]: 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 alpha # [94551.517590] alpha systemd-resolved[111]: Using system hostname 'alpha'. alpha # [94551.518952] alpha systemd[1]: Started Network Name Resolution. alpha # [94551.519050] alpha systemd[1]: Reached target Network. alpha # [94551.519129] alpha systemd[1]: Reached target System Initialization. alpha # [94551.519189] alpha systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container alpha # [94551.519221] alpha systemd[1]: Started Daily Cleanup of Temporary Directories. alpha # [94551.519241] alpha systemd[1]: Reached target Timer Units. alpha # [94551.519378] alpha systemd[1]: Listening on D-Bus System Message Bus Socket. alpha # [94551.519522] alpha systemd[1]: Listening on Nix Daemon Socket. alpha # [94551.519651] alpha systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. alpha # [94551.519674] alpha systemd[1]: Reached target Socket Units. alpha # [94551.519716] alpha systemd[1]: Reached target Basic System. alpha # [94551.521244] alpha systemd[1]: Starting data mesher daemon... alpha # [94551.522259] alpha systemd[1]: Starting Import lastlog data into lastlog2 database... alpha # [94551.523247] alpha systemd[1]: Starting Name Service Cache Daemon (nsncd)... alpha # [94551.524730] alpha systemd[1]: Starting D-Bus System Message Bus... alpha # [94551.582511] alpha systemd[1]: Finished Import lastlog data into lastlog2 database. alpha # [94551.734633] alpha nsncd[213]: Sep 05 09:42:51.720 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" alpha # [94551.734593] alpha systemd[1]: Started Name Service Cache Daemon (nsncd). alpha # [94551.734653] alpha systemd[1]: Reached target Host and Network Name Lookups. alpha # [94551.734725] alpha systemd[1]: Reached target User and Group Name Lookups. beta # [94551.736432] beta systemd[1]: nscd.service: Main process exited, code=exited, status=1/FAILURE beta # [94551.736640] beta systemd[1]: nscd.service: Failed with result 'exit-code'. beta # [94551.736890] beta systemd[1]: Failed to start Name Service Cache Daemon (nsncd). beta # [94551.736917] beta systemd[1]: Dependency failed for User and Group Name Lookups. beta # [94551.736937] beta systemd[1]: nss-user-lookup.target: Job nss-user-lookup.target/start failed with result 'dependency'. beta # [94551.736961] beta systemd[1]: Dependency failed for Host and Network Name Lookups. beta # [94551.736979] beta systemd[1]: nss-lookup.target: Job nss-lookup.target/start failed with result 'dependency'. beta # [94551.741994] beta systemd[1]: nscd.service: Scheduled restart job immediately on client request, restart counter is at 1. beta # [94551.772928] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)... beta # [94551.834521] beta dbus-broker-launch[212]: Looking up NSS user entry for 'systemd-timesync'... beta # [94551.835122] beta dbus-broker-launch[212]: NSS returned no entry for 'systemd-timesync' beta # [94551.835122] beta dbus-broker-launch[212]: Invalid user-name in /nix/store/y1xvnyfk8grlcjwhifz48bs8cwjiagww-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" beta # [94551.835518] beta systemd[1]: Started D-Bus System Message Bus. beta # [94551.842852] beta dbus-broker-launch[212]: Ready beta # [94551.874439] beta nsncd[219]: Sep 05 09:42:51.860 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" beta # [94551.874741] beta nsncd[219]: Error: Read-only file system (os error 30) beta # [94551.877436] beta systemd[1]: nscd.service: Main process exited, code=exited, status=1/FAILURE beta # [94551.877650] beta systemd[1]: nscd.service: Failed with result 'exit-code'. beta # [94551.877823] beta systemd[1]: Failed to start Name Service Cache Daemon (nsncd). beta # [94551.877929] beta systemd[1]: Dependency failed for User and Group Name Lookups. beta # [94551.877945] beta systemd[1]: nss-user-lookup.target: Job nss-user-lookup.target/start failed with result 'dependency'. beta # [94551.877964] beta systemd[1]: Dependency failed for Host and Network Name Lookups. beta # [94551.877983] beta systemd[1]: nss-lookup.target: Job nss-lookup.target/start failed with result 'dependency'. beta # [94551.880372] beta systemd[1]: nscd.service: Scheduled restart job immediately on client request, restart counter is at 2. beta # [94551.881582] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)... beta # [94551.890497] beta systemd[1]: etc-machine\x2did.mount: Deactivated successfully. alpha # [94551.736640] alpha systemd[1]: Starting User Login Management... alpha # [94551.737560] alpha systemd[1]: Starting Permit User Sessions... alpha # [94551.780103] alpha systemd[1]: Finished Permit User Sessions. alpha # [94551.781322] alpha systemd[1]: Started Console Getty. alpha # [94551.781376] alpha systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 alpha # [94551.781401] alpha systemd[1]: Reached target Login Prompts. alpha # [94551.856151] alpha dbus-broker-launch[214]: Looking up NSS user entry for 'systemd-timesync'... alpha # [94551.857318] alpha dbus-broker-launch[214]: NSS returned no entry for 'systemd-timesync' alpha # [94551.857318] alpha dbus-broker-launch[214]: Invalid user-name in /nix/store/y1xvnyfk8grlcjwhifz48bs8cwjiagww-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" alpha # [94551.857706] alpha systemd[1]: Started D-Bus System Message Bus. alpha # [94551.866460] alpha systemd[1]: etc-machine\x2did.mount: Deactivated successfully. alpha # [94551.871081] alpha dbus-broker-launch[214]: Ready gamma # [94551.734774] gamma systemd[1]: Starting User Login Management... gamma # [94551.735767] gamma systemd[1]: Starting Permit User Sessions... gamma # [94551.780184] gamma systemd[1]: Finished Permit User Sessions. gamma # [94551.781819] gamma systemd[1]: Started Console Getty. gamma # [94551.781902] gamma systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 gamma # [94551.781946] gamma systemd[1]: Reached target Login Prompts. gamma # [94551.817014] gamma dbus-broker-launch[213]: Looking up NSS user entry for 'systemd-timesync'... gamma # [94551.818376] gamma dbus-broker-launch[213]: NSS returned no entry for 'systemd-timesync' gamma # [94551.818376] gamma dbus-broker-launch[213]: Invalid user-name in /nix/store/y1xvnyfk8grlcjwhifz48bs8cwjiagww-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" gamma # [94551.819066] gamma systemd[1]: Started D-Bus System Message Bus. gamma # [94551.826355] gamma dbus-broker-launch[213]: Ready gamma # [94551.865964] gamma systemd[1]: etc-machine\x2did.mount: Deactivated successfully. beta # [94552.024635] beta nsncd[226]: Sep 05 09:42:52.010 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" beta # [94552.024635] beta nsncd[226]: Error: Read-only file system (os error 30) beta # [94552.027338] beta systemd[1]: nscd.service: Main process exited, code=exited, status=1/FAILURE beta # [94552.027498] beta systemd[1]: nscd.service: Failed with result 'exit-code'. beta # [94552.027709] beta systemd[1]: Failed to start Name Service Cache Daemon (nsncd). beta # [94552.027889] beta systemd[1]: Dependency failed for User and Group Name Lookups. beta # [94552.027909] beta systemd[1]: nss-user-lookup.target: Job nss-user-lookup.target/start failed with result 'dependency'. beta # [94552.027929] beta systemd[1]: Dependency failed for Host and Network Name Lookups. beta # [94552.027950] beta systemd[1]: nss-lookup.target: Job nss-lookup.target/start failed with result 'dependency'. beta # [94552.030245] beta systemd[1]: nscd.service: Start request repeated too quickly. beta # [94552.030256] beta systemd[1]: nscd.service: Failed with result 'start-limit-hit'. beta # [94552.030442] beta systemd[1]: Failed to start Name Service Cache Daemon (nsncd). beta # [94552.030542] beta systemd[1]: Dependency failed for User and Group Name Lookups. beta # [94552.030559] beta systemd[1]: nss-user-lookup.target: Job nss-user-lookup.target/start failed with result 'dependency'. beta # [94552.030569] beta systemd[1]: Dependency failed for Host and Network Name Lookups. beta # [94552.030582] beta systemd[1]: nss-lookup.target: Job nss-lookup.target/start failed with result 'dependency'. beta # [94552.031985] beta systemd[1]: Starting User Login Management... beta # [94552.032895] beta systemd[1]: Starting Permit User Sessions... beta # [94552.080871] beta data-mesher[210]: time=2026-09-05T09:42:52.066Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] beta # [94552.081953] beta data-mesher[210]: time=2026-09-05T09:42:52.067Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ: [/dns/alpha.clan/tcp/7946]} {12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y beta # [94552.081985] beta data-mesher[210]: time=2026-09-05T09:42:52.067Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml beta # [94552.086923] beta systemd[1]: Finished Permit User Sessions. beta # [94552.088373] beta systemd[1]: Started Console Getty. beta # [94552.088497] beta systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 beta # [94552.088635] beta systemd[1]: Reached target Login Prompts. beta # [94552.099326] beta data-mesher[210]: time=2026-09-05T09:42:52.085Z level=INFO msg="checking file integrity" beta # [94552.099426] beta data-mesher[210]: time=2026-09-05T09:42:52.085Z level=INFO msg="file integrity check complete" beta # [94552.103351] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="libp2p host created" peer_id=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.2/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::2/tcp/7946]" beta # [94552.103384] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=GET path=/files beta # [94552.103384] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name beta # [94552.103421] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name beta # [94552.103421] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="starting server" beta # [94552.103917] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="HTTP server listening" address=[::1]:7331 beta # [94552.103972] beta data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 beta # [94552.104594] beta data-mesher[210]: time=2026-09-05T09:42:52.090Z level=INFO msg="waiting for DHT to populate" delay=10s beta # [94552.110016] beta data-mesher[210]: time=2026-09-05T09:42:52.095Z level=INFO msg="peer connected" peer_id=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe remote_addr=/ip4/192.168.1.3/tcp/7946 beta # [94552.147153] beta data-mesher[210]: time=2026-09-05T09:42:52.132Z level=INFO msg="peer connected" peer_id=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ remote_addr=/ip4/192.168.1.1/tcp/7946 alpha # [94552.135276] alpha data-mesher[211]: time=2026-09-05T09:42:52.121Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] alpha # [94552.136373] alpha data-mesher[211]: time=2026-09-05T09:42:52.122Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ: [/dns/alpha.clan/tcp/7946]} {12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ alpha # [94552.136429] alpha data-mesher[211]: time=2026-09-05T09:42:52.122Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml alpha # [94552.137722] alpha data-mesher[211]: time=2026-09-05T09:42:52.123Z level=INFO msg="checking file integrity" alpha # [94552.137838] alpha data-mesher[211]: time=2026-09-05T09:42:52.123Z level=INFO msg="file integrity check complete" alpha # [94552.141735] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="libp2p host created" peer_id=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.1/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::1/tcp/7946]" alpha # [94552.141772] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="registered HTTP route" method=GET path=/files alpha # [94552.141772] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name alpha # [94552.141772] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name alpha # [94552.141822] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="starting server" alpha # [94552.141880] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="waiting for DHT to populate" delay=10s alpha # [94552.142018] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="HTTP server listening" address=[::1]:7331 alpha # [94552.142068] alpha data-mesher[211]: time=2026-09-05T09:42:52.127Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 alpha # [94552.146474] alpha data-mesher[211]: time=2026-09-05T09:42:52.132Z level=INFO msg="peer connected" peer_id=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y remote_addr=/ip4/192.168.1.2/tcp/7946 alpha # [94552.154098] alpha data-mesher[211]: time=2026-09-05T09:42:52.139Z level=INFO msg="peer connected" peer_id=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe remote_addr=/ip4/192.168.1.3/tcp/7946 alpha # [94552.231435] alpha systemd-logind[227]: New seat seat0. alpha # [94552.231612] alpha systemd[1]: Started User Login Management. alpha # [94552.233600] alpha systemd[1]: Starting linger-users.service... alpha # [94552.246643] alpha systemd[1]: linger-users.service: Deactivated successfully. alpha # [94552.246775] alpha systemd[1]: Finished linger-users.service. gamma # [94552.084910] gamma data-mesher[210]: time=2026-09-05T09:42:52.070Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] gamma # [94552.085975] gamma data-mesher[210]: time=2026-09-05T09:42:52.071Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ: [/dns/alpha.clan/tcp/7946]} {12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe gamma # [94552.085975] gamma data-mesher[210]: time=2026-09-05T09:42:52.071Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml gamma # [94552.099545] gamma data-mesher[210]: time=2026-09-05T09:42:52.085Z level=INFO msg="checking file integrity" gamma # [94552.099664] gamma data-mesher[210]: time=2026-09-05T09:42:52.085Z level=INFO msg="file integrity check complete" gamma # [94552.103448] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="libp2p host created" peer_id=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.3/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::3/tcp/7946]" gamma # [94552.103495] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=GET path=/files gamma # [94552.103495] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name gamma # [94552.103495] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name gamma # [94552.103495] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="starting server" gamma # [94552.103600] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="waiting for DHT to populate" delay=10s gamma # [94552.103694] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="HTTP server listening" address=[::1]:7331 gamma # [94552.103741] gamma data-mesher[210]: time=2026-09-05T09:42:52.089Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 gamma # [94552.109247] gamma data-mesher[210]: time=2026-09-05T09:42:52.094Z level=INFO msg="peer connected" peer_id=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y remote_addr=/ip4/192.168.1.2/tcp/7946 gamma # [94552.156102] gamma data-mesher[210]: time=2026-09-05T09:42:52.141Z level=INFO msg="peer connected" peer_id=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ remote_addr=/ip4/192.168.1.1/tcp/7946 gamma # [94552.229715] gamma systemd-logind[228]: New seat seat0. gamma # [94552.229906] gamma systemd[1]: Started User Login Management. gamma # [94552.231996] gamma systemd[1]: Starting linger-users.service... gamma # [94552.245600] gamma systemd[1]: linger-users.service: Deactivated successfully. gamma # [94552.245921] gamma systemd[1]: Finished linger-users.service. beta # [94552.445036] beta systemd-logind[232]: New seat seat0. beta # [94552.445246] beta systemd[1]: Started User Login Management. beta # [94552.446440] beta systemd[1]: Starting linger-users.service... beta # [94552.493436] beta systemd[1]: linger-users.service: Deactivated successfully. beta # [94552.493728] beta systemd[1]: Finished linger-users.service. beta # [94552.772098] beta systemd-networkd[205]: eth1: Gained IPv6LL alpha # [94553.088222] alpha systemd-networkd[206]: eth1: Gained IPv6LL gamma # [94553.056177] gamma systemd-networkd[205]: eth1: Gained IPv6LL alpha: still waiting for container 'alpha' to reach ready state... alpha # [94562.104710] alpha data-mesher[211]: time=2026-09-05T09:43:02.090Z level=INFO msg="received state sync from peer" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94562.105535] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="performing state exchange with peers on join" count=1 alpha # [94562.104710] alpha data-mesher[211]: time=2026-09-05T09:43:02.090Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94562.105535] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94562.142376] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=INFO msg="performing state exchange with peers on join" count=1 beta # [94562.106051] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94562.106051] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="state exchange complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s beta # [94562.106105] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="server started" beta # [94562.106164] beta data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="starting expired-file sweeper" interval=1m0s alpha # [94562.142496] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s beta # [94562.106253] beta systemd[1]: Started data mesher daemon. alpha # [94562.142957] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94562.106478] beta systemd[1]: Reached target Multi-User System. alpha # [94562.142957] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=INFO msg="state exchange complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s beta # [94562.106799] beta systemd[1]: Startup finished in 11.590s. alpha # [94562.143022] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=INFO msg="server started" alpha # [94562.143569] alpha data-mesher[211]: time=2026-09-05T09:43:02.128Z level=INFO msg="starting expired-file sweeper" interval=1m0s alpha # [94562.143197] alpha systemd[1]: Started data mesher daemon. alpha # [94562.143445] alpha systemd[1]: Reached target Multi-User System. alpha # [94562.143950] alpha systemd[1]: Startup finished in 11.641s. gamma # [94562.104150] gamma data-mesher[210]: time=2026-09-05T09:43:02.089Z level=INFO msg="performing state exchange with peers on join" count=1 gamma # [94562.104505] gamma data-mesher[210]: time=2026-09-05T09:43:02.090Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s gamma # [94562.104886] gamma data-mesher[210]: time=2026-09-05T09:43:02.090Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94562.104886] gamma data-mesher[210]: time=2026-09-05T09:43:02.090Z level=INFO msg="state exchange complete" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s gamma # [94562.104940] gamma data-mesher[210]: time=2026-09-05T09:43:02.090Z level=INFO msg="server started" gamma # [94562.104996] gamma data-mesher[210]: time=2026-09-05T09:43:02.090Z level=INFO msg="starting expired-file sweeper" interval=1m0s gamma # [94562.105214] gamma systemd[1]: Started data mesher daemon. gamma # [94562.105741] gamma systemd[1]: Reached target Multi-User System. gamma # [94562.105936] gamma data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="received state sync from peer" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y gamma # [94562.105936] gamma data-mesher[210]: time=2026-09-05T09:43:02.091Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y gamma # [94562.106184] gamma systemd[1]: Startup finished in 11.602s. gamma # [94562.142846] gamma data-mesher[210]: time=2026-09-05T09:43:02.128Z level=INFO msg="received state sync from peer" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94562.142846] gamma data-mesher[210]: time=2026-09-05T09:43:02.128Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ alpha: (finished: waiting for unit data-mesher.service, in 12.67 seconds) beta: waiting for unit data-mesher.service beta: (finished: waiting for unit data-mesher.service, in 0.02 seconds) gamma: waiting for unit data-mesher.service gamma: (finished: waiting for unit data-mesher.service, in 0.01 seconds) alpha: must succeed: echo -n 'hello world' > /tmp/test_file alpha: (finished: must succeed: echo -n 'hello world' > /tmp/test_file, in 0.01 seconds) alpha: waiting for success: data-mesher file update /tmp/test_file --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key alpha: (finished: waiting for success: data-mesher file update /tmp/test_file --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.03 seconds) ??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 alpha: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file ??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 alpha: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file, in 0.01 seconds) beta: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file alpha # [94562.703922] alpha data-mesher[211]: time=2026-09-05T09:43:02.689Z level=INFO msg=http_request uri=/files/test_file status=204 alpha # [94567.107445] alpha data-mesher[211]: time=2026-09-05T09:43:07.093Z level=INFO msg="received state sync from peer" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94567.107445] alpha data-mesher[211]: time=2026-09-05T09:43:07.093Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94567.108392] alpha data-mesher[211]: time=2026-09-05T09:43:07.094Z level=INFO msg="received file request" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_file alpha # [94567.110262] alpha data-mesher[211]: time=2026-09-05T09:43:07.096Z level=INFO msg="file transfer complete" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_file alpha # [94567.143761] alpha data-mesher[211]: time=2026-09-05T09:43:07.129Z level=DEBUG msg="attempting push/pull" peer_count=2 alpha # [94567.143848] alpha data-mesher[211]: time=2026-09-05T09:43:07.129Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94567.144646] alpha data-mesher[211]: time=2026-09-05T09:43:07.130Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe alpha # [94567.144646] alpha data-mesher[211]: time=2026-09-05T09:43:07.130Z level=INFO msg="state exchange complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94567.144776] alpha data-mesher[211]: time=2026-09-05T09:43:07.130Z level=DEBUG msg="push/pull successful" interval=5s alpha # [94567.144976] alpha data-mesher[211]: time=2026-09-05T09:43:07.130Z level=INFO msg="received file request" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_file alpha # [94567.145912] alpha data-mesher[211]: time=2026-09-05T09:43:07.131Z level=INFO msg="file transfer complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_file gamma # [94567.105219] gamma data-mesher[210]: time=2026-09-05T09:43:07.091Z level=DEBUG msg="attempting push/pull" peer_count=2 gamma # [94567.105219] gamma data-mesher[210]: time=2026-09-05T09:43:07.091Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s gamma # [94567.105816] gamma data-mesher[210]: time=2026-09-05T09:43:07.091Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y gamma # [94567.105816] gamma data-mesher[210]: time=2026-09-05T09:43:07.091Z level=INFO msg="state exchange complete" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s gamma # [94567.105880] gamma data-mesher[210]: time=2026-09-05T09:43:07.091Z level=DEBUG msg="push/pull successful" interval=5s gamma # [94567.144447] gamma data-mesher[210]: time=2026-09-05T09:43:07.130Z level=INFO msg="received state sync from peer" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94567.144447] gamma data-mesher[210]: time=2026-09-05T09:43:07.130Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94567.144561] gamma data-mesher[210]: time=2026-09-05T09:43:07.130Z level=DEBUG msg="new file detected" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ name=test_file name=test_file gamma # [94567.144561] gamma data-mesher[210]: time=2026-09-05T09:43:07.130Z level=INFO msg="scheduling file download" name=test_file gamma # [94567.144605] gamma data-mesher[210]: time=2026-09-05T09:43:07.130Z level=INFO msg="downloading file" name=test_file signed_at="2026-09-05 09:43:02.686 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94567.147481] gamma data-mesher[210]: time=2026-09-05T09:43:07.133Z level=INFO msg="download complete" name=test_file signed_at="2026-09-05 09:43:02.686 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ written=true elapsed=2.898519ms beta # [94567.105675] beta data-mesher[210]: time=2026-09-05T09:43:07.091Z level=INFO msg="received state sync from peer" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94567.105675] beta data-mesher[210]: time=2026-09-05T09:43:07.091Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94567.107069] beta data-mesher[210]: time=2026-09-05T09:43:07.092Z level=DEBUG msg="attempting push/pull" peer_count=2 beta # [94567.107069] beta data-mesher[210]: time=2026-09-05T09:43:07.092Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s beta # [94567.107833] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ beta # [94567.107904] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=DEBUG msg="new file detected" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ name=test_file name=test_file beta # [94567.107904] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=INFO msg="state exchange complete" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s beta # [94567.108034] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=INFO msg="scheduling file download" name=test_file beta # [94567.108034] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=DEBUG msg="push/pull successful" interval=5s beta # [94567.108034] beta data-mesher[210]: time=2026-09-05T09:43:07.093Z level=INFO msg="downloading file" name=test_file signed_at="2026-09-05 09:43:02.686 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ beta # [94567.122644] beta data-mesher[210]: time=2026-09-05T09:43:07.108Z level=INFO msg="download complete" name=test_file signed_at="2026-09-05 09:43:02.686 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ written=true elapsed=14.656602ms beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file, in 5.04 seconds) gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file, in 0.01 seconds) beta: waiting for success: data-mesher file delete test_file --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key beta: (finished: waiting for success: data-mesher file delete test_file --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.04 seconds) alpha: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file beta # [94567.800434] beta data-mesher[210]: time=2026-09-05T09:43:07.786Z level=INFO msg=http_request uri=/files/test_file status=204 alpha # [94572.108730] alpha data-mesher[211]: time=2026-09-05T09:43:12.094Z level=INFO msg="received state sync from peer" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94572.108730] alpha data-mesher[211]: time=2026-09-05T09:43:12.094Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94572.110595] alpha data-mesher[211]: time=2026-09-05T09:43:12.096Z level=DEBUG msg="imported tombstone" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y name=test_file written=true alpha # [94572.145766] alpha data-mesher[211]: time=2026-09-05T09:43:12.131Z level=DEBUG msg="attempting push/pull" peer_count=2 alpha # [94572.145766] alpha data-mesher[211]: time=2026-09-05T09:43:12.131Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94572.146534] alpha data-mesher[211]: time=2026-09-05T09:43:12.132Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe alpha # [94572.146583] alpha data-mesher[211]: time=2026-09-05T09:43:12.132Z level=INFO msg="state exchange complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94572.146583] alpha data-mesher[211]: time=2026-09-05T09:43:12.132Z level=DEBUG msg="push/pull successful" interval=5s beta # [94572.107229] beta data-mesher[210]: time=2026-09-05T09:43:12.093Z level=INFO msg="received state sync from peer" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94572.107229] beta data-mesher[210]: time=2026-09-05T09:43:12.093Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe gamma # [94572.106510] gamma data-mesher[210]: time=2026-09-05T09:43:12.092Z level=DEBUG msg="attempting push/pull" peer_count=2 beta # [94572.108150] beta data-mesher[210]: time=2026-09-05T09:43:12.093Z level=DEBUG msg="attempting push/pull" peer_count=2 gamma # [94572.106871] gamma data-mesher[210]: time=2026-09-05T09:43:12.092Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s beta # [94572.108221] beta data-mesher[210]: time=2026-09-05T09:43:12.094Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s gamma # [94572.107562] gamma data-mesher[210]: time=2026-09-05T09:43:12.093Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y beta # [94572.110982] beta data-mesher[210]: time=2026-09-05T09:43:12.096Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94572.110406] gamma data-mesher[210]: time=2026-09-05T09:43:12.096Z level=DEBUG msg="imported tombstone" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y name=test_file written=true beta # [94572.111046] beta data-mesher[210]: time=2026-09-05T09:43:12.096Z level=INFO msg="state exchange complete" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s gamma # [94572.110406] gamma data-mesher[210]: time=2026-09-05T09:43:12.096Z level=INFO msg="state exchange complete" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s gamma # [94572.110536] gamma data-mesher[210]: time=2026-09-05T09:43:12.096Z level=DEBUG msg="push/pull successful" interval=5s gamma # [94572.146246] gamma data-mesher[210]: time=2026-09-05T09:43:12.132Z level=INFO msg="received state sync from peer" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94572.146246] gamma data-mesher[210]: time=2026-09-05T09:43:12.132Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ beta # [94572.111046] beta data-mesher[210]: time=2026-09-05T09:43:12.096Z level=DEBUG msg="push/pull successful" interval=5s alpha: (finished: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file, in 5.04 seconds) beta: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file beta: (finished: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file, in 0.01 seconds) gamma: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file gamma: (finished: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file, in 0.01 seconds) alpha: must succeed: cat /nix/store/jvpsqchyzp9dnxnslxqbfbbnb2pginry-per-machine-alpha-data-mesher-node-identity_identity.pub alpha: (finished: must succeed: cat /nix/store/jvpsqchyzp9dnxnslxqbfbbnb2pginry-per-machine-alpha-data-mesher-node-identity_identity.pub, in 0.01 seconds) alpha: must succeed: echo -n 'namespace_data' > /tmp/ns_file alpha: (finished: must succeed: echo -n 'namespace_data' > /tmp/ns_file, in 0.01 seconds) alpha: waiting for success: data-mesher file update /tmp/ns_file --name 'test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --cert /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.cert alpha: (finished: waiting for success: data-mesher file update /tmp/ns_file --name 'test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub --cert /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.cert, in 0.03 seconds) alpha: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns, in 0.01 seconds) beta: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha # [94572.904782] alpha data-mesher[211]: time=2026-09-05T09:43:12.890Z level=INFO msg=http_request uri=/files/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns status=204 alpha # [94577.112876] alpha data-mesher[211]: time=2026-09-05T09:43:17.098Z level=INFO msg="received state sync from peer" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94577.112876] alpha data-mesher[211]: time=2026-09-05T09:43:17.098Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y alpha # [94577.114301] alpha data-mesher[211]: time=2026-09-05T09:43:17.100Z level=INFO msg="received file request" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha # [94577.116568] alpha data-mesher[211]: time=2026-09-05T09:43:17.102Z level=INFO msg="file transfer complete" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha # [94577.146734] alpha data-mesher[211]: time=2026-09-05T09:43:17.132Z level=DEBUG msg="attempting push/pull" peer_count=2 alpha # [94577.146864] alpha data-mesher[211]: time=2026-09-05T09:43:17.132Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94577.148489] alpha data-mesher[211]: time=2026-09-05T09:43:17.134Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe alpha # [94577.148599] alpha data-mesher[211]: time=2026-09-05T09:43:17.134Z level=INFO msg="state exchange complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe timeout=5s alpha # [94577.148599] alpha data-mesher[211]: time=2026-09-05T09:43:17.134Z level=DEBUG msg="push/pull successful" interval=5s alpha # [94577.148978] alpha data-mesher[211]: time=2026-09-05T09:43:17.134Z level=INFO msg="received file request" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha # [94577.149767] alpha data-mesher[211]: time=2026-09-05T09:43:17.135Z level=INFO msg="file transfer complete" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe network="DyZh+TqFB/c80ScY5LOP6EyCC6x204T9h2e8K0wBn5Q=" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns gamma # [94577.111526] gamma data-mesher[210]: time=2026-09-05T09:43:17.097Z level=DEBUG msg="attempting push/pull" peer_count=2 gamma # [94577.111526] gamma data-mesher[210]: time=2026-09-05T09:43:17.097Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s gamma # [94577.112676] gamma data-mesher[210]: time=2026-09-05T09:43:17.098Z level=INFO msg="merging remote state" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y gamma # [94577.112752] gamma data-mesher[210]: time=2026-09-05T09:43:17.098Z level=INFO msg="state exchange complete" peer=12D3KooWA7Un1wjrPbF8BrZpUW6wbCJrAzRYPHM9NSLv1BDmyR2Y timeout=5s gamma # [94577.112752] gamma data-mesher[210]: time=2026-09-05T09:43:17.098Z level=DEBUG msg="push/pull successful" interval=5s gamma # [94577.147503] gamma data-mesher[210]: time=2026-09-05T09:43:17.133Z level=INFO msg="received state sync from peer" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94577.147648] gamma data-mesher[210]: time=2026-09-05T09:43:17.133Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94577.148196] gamma data-mesher[210]: time=2026-09-05T09:43:17.134Z level=DEBUG msg="new file detected" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ name=test_file name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns gamma # [94577.148355] gamma data-mesher[210]: time=2026-09-05T09:43:17.134Z level=INFO msg="scheduling file download" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns gamma # [94577.148452] gamma data-mesher[210]: time=2026-09-05T09:43:17.134Z level=INFO msg="downloading file" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns signed_at="2026-09-05 09:43:12.888 +0000 UTC" signed_by="GW8gZN1BVQLQAxGei7e/N3w0LjXJEDwiacBzkl6v6ns=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ gamma # [94577.151308] gamma data-mesher[210]: time=2026-09-05T09:43:17.137Z level=INFO msg="download complete" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns signed_at="2026-09-05 09:43:12.888 +0000 UTC" signed_by="GW8gZN1BVQLQAxGei7e/N3w0LjXJEDwiacBzkl6v6ns=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ written=true elapsed=2.9062ms beta # [94577.111739] beta data-mesher[210]: time=2026-09-05T09:43:17.097Z level=DEBUG msg="attempting push/pull" peer_count=2 beta # [94577.111739] beta data-mesher[210]: time=2026-09-05T09:43:17.097Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s beta # [94577.112582] beta data-mesher[210]: time=2026-09-05T09:43:17.098Z level=INFO msg="received state sync from peer" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94577.112582] beta data-mesher[210]: time=2026-09-05T09:43:17.098Z level=INFO msg="merging remote state" peer=12D3KooWJs4a9N4rSeHLbXCTMSZi2u2iXNAsW9GaQcJyaGhfJdhe beta # [94577.113273] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=INFO msg="merging remote state" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ beta # [94577.113651] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=DEBUG msg="new file detected" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ name=test_file name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns beta # [94577.113651] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=INFO msg="state exchange complete" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ timeout=5s beta # [94577.113778] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=DEBUG msg="push/pull successful" interval=5s beta # [94577.113778] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=INFO msg="scheduling file download" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns beta # [94577.113778] beta data-mesher[210]: time=2026-09-05T09:43:17.099Z level=INFO msg="downloading file" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns signed_at="2026-09-05 09:43:12.888 +0000 UTC" signed_by="GW8gZN1BVQLQAxGei7e/N3w0LjXJEDwiacBzkl6v6ns=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ beta # [94577.118163] beta data-mesher[210]: time=2026-09-05T09:43:17.103Z level=INFO msg="download complete" name=test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns signed_at="2026-09-05 09:43:12.888 +0000 UTC" signed_by="GW8gZN1BVQLQAxGei7e/N3w0LjXJEDwiacBzkl6v6ns=" peer=12D3KooWBXeeCNhu9XNj6uJx9oJQaDJivtfKoPAXt9wKqSEM5yiJ written=true elapsed=4.38694ms beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns, in 5.05 seconds) gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns, in 0.01 seconds) alpha: must succeed: echo -n 'no_cert' > /tmp/ns_nocert alpha: (finished: must succeed: echo -n 'no_cert' > /tmp/ns_nocert, in 0.01 seconds) alpha: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub Error: failed to update file: 403 Forbidden, signer GW8gZN1BVQLQAxGei7e/N3w0LjXJEDwiacBzkl6v6ns= is not authorized for this file test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns alpha: (finished: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/h9a92cywhmavxnqkg8mmbfpn5gkb3lgl-shared-data-mesher-network_network.pub, in 0.03 seconds) (finished: run the VM test script, in 28.04 seconds) alpha # [94578.010027] alpha data-mesher[211]: time=2026-09-05T09:43:17.995Z level=INFO msg=http_request uri=/files/test_ns/GW8gZN1BVQLQAxGei7e_N3w0LjXJEDwiacBzkl6v6ns status=403 test script finished in 30.00s cleanup kill NspawnMachine (pid 53) kill NspawnMachine (pid 54) Traceback (most recent call last): File "/nix/store/bb3iw9xkbhd3l5i277i0w599xgl72knz-run-nspawn-1.0/lib/python3.14/site-packages/run_nspawn/__init__.py", line 218, in run exit_code = cp.wait() File "/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/lib/python3.14/subprocess.py", line 1279, in wait return self._wait(timeout=timeout) ~~~~~~~~~~^^^^^^^^^^^^^^^^^ File "/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/lib/python3.14/subprocess.py", line 2084, in _wait (pid, sts) = self._try_wait(0) ~~~~~~~~~~~~~~^^^ File "/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/lib/python3.14/subprocess.py", line 2042, in _try_wait (pid, sts) = os.waitpid(self.pid, wait_flags) ~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^ File "/nix/store/bb3iw9xkbhd3l5i277i0w599xgl72knz-run-nspawn-1.0/lib/python3.14/site-packages/run_nspawn/__init__.py", line 17, in signal.signal(signal.SIGTERM, lambda _signum, _frame: sys.exit(0)) ~~~~~~~~^^^ SystemExit: 0 During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/nix/store/bb3iw9xkbhd3l5i277i0w599xgl72knz-run-nspawn-1.0/bin/.run-nspawn-wrapped", line 9, in sys.exit(main()) ~~~~^^ File "/nix/store/bb3iw9xkbhd3l5i277i0w599xgl72knz-run-nspawn-1.0/lib/python3.14/site-packages/run_nspawn/__init__.py", line 280, in main run( ~~~^ container_name=args.container_name, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ...<5 lines>... cmdline=args.cmdline, ^^^^^^^^^^^^^^^^^^^^^ ) ^ File "/nix/store/bb3iw9xkbhd3l5i277i0w599xgl72knz-run-nspawn-1.0/lib/python3.14/site-packages/run_nspawn/__init__.py", line 232, in run subprocess.run( ~~~~~~~~~~~~~~^ [ ^ ...<4 lines>... check=True, ^^^^^^^^^^^ ) ^ File "/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/lib/python3.14/subprocess.py", line 578, in run raise CalledProcessError(retcode, process.args, output=stdout, stderr=stderr) subprocess.CalledProcessError: Command '['/nix/store/g02rikjs4v596794gar5hv251p14d16q-e2fsprogs-1.47.4-bin/bin/chattr', '-i', PosixPath('/build/vm-state-beta/var/empty')]' returned non-zero exit status 1. kill NspawnMachine (pid 55) Container alpha terminated by signal KILL. Container beta terminated by signal KILL. Container gamma terminated by signal KILL. (finished: cleanup, in 0.49 seconds)