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
beta: systemd-nspawn running (pid 54)
alpha: systemd-nspawn running (pid 52)
gamma: systemd-nspawn running (pid 56)
alpha: Waiting for journal at /build/vm-state-alpha/var/log/journal...
beta: Waiting for journal at /build/vm-state-beta/var/log/journal...
gamma: Waiting for journal at /build/vm-state-gamma/var/log/journal...
(finished: start all VMs, in 0.00 seconds)
alpha: waiting for unit data-mesher.service
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.
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.
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.
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 beta on /build/vm-state-beta.
░ Spawning container gamma on /build/vm-state-gamma.
beta # No journal files were found.
beta # No journal boot entry found for the specified boot (+0).
alpha # No journal files were found.
alpha # No journal boot entry found for the specified boot (+0).
gamma # No journal files were found.
gamma # No journal boot entry found for the specified boot (+0).
beta # [6396297.391412] beta systemd-journald[87]: Journal started
beta # [6396297.391467] beta systemd-journald[87]: Runtime Journal (/run/log/journal/793e9c4df0cb480ea489541517a58497) is 8M, max 2.5G, 2.4G free.
beta # [6396297.399741] beta systemd[1]: Starting Flush Journal to Persistent Storage...
beta # [6396297.400562] beta systemd[1]: Starting Network Name Resolution...
beta # [6396297.401229] beta systemd[1]: Starting Create Static Device Nodes in /dev...
beta # [6396297.410583] beta systemd-journald[87]: Time spent on flushing to /var/log/journal/793e9c4df0cb480ea489541517a58497 is 1.504ms for 5 entries.
beta # [6396297.410583] beta systemd-journald[87]: System Journal (/var/log/journal/793e9c4df0cb480ea489541517a58497) is 8M, max 4G, 3.9G free.
beta # [6396297.415639] beta systemd[1]: Finished Create Static Device Nodes in /dev.
beta # [6396297.416284] beta systemd[1]: Reached target Preparation for Local File Systems.
beta # [6396297.416647] beta systemd[1]: Reached target Local File Systems.
beta # [6396297.417456] beta systemd[1]: Listening on Boot Loader Control Service Socket.
beta # [6396297.417502] beta systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
beta # [6396297.418317] beta systemd[1]: Starting Save Transient machine-id to Disk...
alpha # [6396297.401336] alpha systemd-journald[87]: Journal started
alpha # [6396297.401393] alpha systemd-journald[87]: Runtime Journal (/run/log/journal/2690fd33eedd42ce80487cfc5bfa977e) is 8M, max 2.5G, 2.4G free.
beta # [6396297.418350] beta systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
alpha # [6396297.407221] alpha systemd[1]: Starting Flush Journal to Persistent Storage...
beta # [6396297.443194] beta systemd[1]: Finished Flush Journal to Persistent Storage.
beta # [6396297.444749] beta systemd[1]: Starting Create System Files and Directories...
beta # [6396297.461639] beta systemd-tmpfiles[140]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
beta # [6396297.461811] beta systemd-tmpfiles[140]: fchmod() of /var/log/journal failed: Operation not permitted
alpha # [6396297.407963] alpha systemd[1]: Starting Network Name Resolution...
beta # [6396297.461921] beta systemd-tmpfiles[140]: fchmod() of /var/log/journal/793e9c4df0cb480ea489541517a58497 failed: Operation not permitted
beta # [6396297.462090] beta systemd-tmpfiles[140]: fchmod() of /run/log/journal failed: Operation not permitted
beta # [6396297.463399] beta systemd[1]: Finished Create System Files and Directories.
beta # [6396297.464334] beta systemd[1]: Starting Rebuild Journal Catalog...
beta # [6396297.464976] beta systemd[1]: Starting Record System Boot/Shutdown in UTMP...
beta # [6396297.478454] beta systemd[1]: Finished Record System Boot/Shutdown in UTMP.
beta # [6396297.484446] beta systemd[1]: Finished Rebuild Journal Catalog.
beta # [6396297.485462] beta systemd[1]: Starting Update is Completed...
beta # [6396297.495091] beta systemd[1]: Finished Update is Completed.
beta # [6396297.535740] beta systemd[1]: Finished Firewall.
beta # [6396297.535880] beta systemd[1]: Reached target Preparation for Network.
beta # [6396297.536091] beta systemd[1]: Listening on Network Management Resolve Hook Socket.
beta # [6396297.537047] beta systemd[1]: Starting Network Management...
alpha # [6396297.408571] alpha systemd[1]: Starting Create Static Device Nodes in /dev...
beta # [6396297.919642] beta systemd-networkd[204]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
alpha # [6396297.418160] alpha systemd-journald[87]: Time spent on flushing to /var/log/journal/2690fd33eedd42ce80487cfc5bfa977e is 1.478ms for 5 entries.
beta # [6396297.919732] beta systemd-networkd[204]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
alpha # [6396297.418160] alpha systemd-journald[87]: System Journal (/var/log/journal/2690fd33eedd42ce80487cfc5bfa977e) is 8M, max 4G, 3.9G free.
beta # [6396297.928233] beta systemd-networkd[204]: /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 # [6396297.425285] alpha systemd[1]: Finished Create Static Device Nodes in /dev.
beta # [6396297.928397] beta systemd-networkd[204]: /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 # [6396297.425956] alpha systemd[1]: Reached target Preparation for Local File Systems.
beta # [6396297.928560] beta systemd-networkd[204]: lo: Link UP
alpha # [6396297.426077] alpha systemd[1]: Reached target Local File Systems.
beta # [6396297.928564] beta systemd-networkd[204]: lo: Gained carrier
alpha # [6396297.426890] alpha systemd[1]: Listening on Boot Loader Control Service Socket.
beta # [6396297.928752] beta systemd-networkd[204]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
alpha # [6396297.426937] alpha systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
beta # [6396297.929229] beta systemd-networkd[204]: eth1: Link UP
alpha # [6396297.427768] alpha systemd[1]: Starting Save Transient machine-id to Disk...
beta # [6396297.929452] beta systemd-networkd[204]: eth1: Gained carrier
alpha # [6396297.427805] alpha systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
beta # [6396297.930005] beta systemd[1]: Started Network Management.
alpha # [6396297.443999] alpha systemd[1]: Finished Flush Journal to Persistent Storage.
beta # [6396297.931598] beta systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
alpha # [6396297.445367] alpha systemd[1]: Starting Create System Files and Directories...
beta # [6396298.025895] beta systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
alpha # [6396297.460986] alpha systemd-tmpfiles[139]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
beta # [6396298.047516] beta systemd-resolved[109]: Positive Trust Anchors:
alpha # [6396297.461156] alpha systemd-tmpfiles[139]: fchmod() of /var/log/journal failed: Operation not permitted
beta # [6396298.047528] beta systemd-resolved[109]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
alpha # [6396297.461526] alpha systemd-tmpfiles[139]: fchmod() of /var/log/journal/2690fd33eedd42ce80487cfc5bfa977e failed: Operation not permitted
beta # [6396298.047531] beta systemd-resolved[109]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
alpha # [6396297.461708] alpha systemd-tmpfiles[139]: fchmod() of /run/log/journal failed: Operation not permitted
beta # [6396298.047567] beta 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
alpha # [6396297.463189] alpha systemd[1]: Finished Create System Files and Directories.
beta # [6396298.070021] beta systemd-resolved[109]: Using system hostname 'beta'.
alpha # [6396297.464179] alpha systemd[1]: Starting Rebuild Journal Catalog...
beta # [6396298.071429] beta systemd[1]: Started Network Name Resolution.
alpha # [6396297.464953] alpha systemd[1]: Starting Record System Boot/Shutdown in UTMP...
beta # [6396298.071494] beta systemd[1]: Reached target Network.
alpha # [6396297.477423] alpha systemd[1]: Finished Record System Boot/Shutdown in UTMP.
beta # [6396298.071559] beta systemd[1]: Reached target System Initialization.
gamma # [6396297.391924] gamma systemd-journald[87]: Journal started
beta # [6396298.071603] beta systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
gamma # [6396297.391979] gamma systemd-journald[87]: Runtime Journal (/run/log/journal/435dfc3a7c59464bbe7c9d5210205550) is 8M, max 2.5G, 2.4G free.
beta # [6396298.071625] beta systemd[1]: Started Daily Cleanup of Temporary Directories.
gamma # [6396297.400286] gamma systemd[1]: Starting Flush Journal to Persistent Storage...
alpha # [6396297.485295] alpha systemd[1]: Finished Rebuild Journal Catalog.
beta # [6396298.071641] beta systemd[1]: Reached target Timer Units.
gamma # [6396297.401284] gamma systemd[1]: Starting Network Name Resolution...
beta # [6396298.071751] beta systemd[1]: Listening on D-Bus System Message Bus Socket.
gamma # [6396297.401947] gamma systemd[1]: Starting Create Static Device Nodes in /dev...
alpha # [6396297.486624] alpha systemd[1]: Starting Update is Completed...
gamma # [6396297.408837] gamma systemd-journald[87]: Time spent on flushing to /var/log/journal/435dfc3a7c59464bbe7c9d5210205550 is 1.476ms for 5 entries.
alpha # [6396297.495513] alpha systemd[1]: Finished Update is Completed.
beta # [6396298.071863] beta systemd[1]: Listening on Nix Daemon Socket.
gamma # [6396297.408837] gamma systemd-journald[87]: System Journal (/var/log/journal/435dfc3a7c59464bbe7c9d5210205550) is 8M, max 4G, 3.9G free.
beta # [6396298.071964] beta systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
gamma # [6396297.415541] gamma systemd[1]: Finished Create Static Device Nodes in /dev.
alpha # [6396297.537807] alpha systemd[1]: Finished Firewall.
gamma # [6396297.416209] gamma systemd[1]: Reached target Preparation for Local File Systems.
beta # [6396298.071982] beta systemd[1]: Reached target Socket Units.
gamma # [6396297.416334] gamma systemd[1]: Reached target Local File Systems.
alpha # [6396297.537902] alpha systemd[1]: Reached target Preparation for Network.
gamma # [6396297.417130] gamma systemd[1]: Listening on Boot Loader Control Service Socket.
alpha # [6396297.538107] alpha systemd[1]: Listening on Network Management Resolve Hook Socket.
beta # [6396298.072030] beta systemd[1]: Reached target Basic System.
gamma # [6396297.417174] gamma systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
beta # [6396298.073228] beta systemd[1]: Starting data mesher daemon...
gamma # [6396297.418007] gamma systemd[1]: Starting Save Transient machine-id to Disk...
alpha # [6396297.539064] alpha systemd[1]: Starting Network Management...
gamma # [6396297.418042] gamma systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
alpha # [6396297.913375] alpha systemd-networkd[204]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
beta # [6396298.073959] beta systemd[1]: Starting Import lastlog data into lastlog2 database...
gamma # [6396297.431375] gamma systemd[1]: Finished Flush Journal to Persistent Storage.
beta # [6396298.074807] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)...
gamma # [6396297.432390] gamma systemd[1]: Starting Create System Files and Directories...
alpha # [6396297.913459] alpha systemd-networkd[204]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
gamma # [6396297.448565] gamma systemd-tmpfiles[137]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
alpha # [6396297.920919] alpha systemd-networkd[204]: /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 # [6396298.076039] beta systemd[1]: Starting D-Bus System Message Bus...
gamma # [6396297.448777] gamma systemd-tmpfiles[137]: fchmod() of /var/log/journal failed: Operation not permitted
alpha # [6396297.921088] alpha systemd-networkd[204]: /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 # [6396297.448917] gamma systemd-tmpfiles[137]: fchmod() of /var/log/journal/435dfc3a7c59464bbe7c9d5210205550 failed: Operation not permitted
alpha # [6396297.921229] alpha systemd-networkd[204]: lo: Link UP
gamma # [6396297.449122] gamma systemd-tmpfiles[137]: fchmod() of /run/log/journal failed: Operation not permitted
alpha # [6396297.921234] alpha systemd-networkd[204]: lo: Gained carrier
gamma # [6396297.450651] gamma systemd[1]: Finished Create System Files and Directories.
alpha # [6396297.921388] alpha systemd-networkd[204]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
gamma # [6396297.451856] gamma systemd[1]: Starting Rebuild Journal Catalog...
alpha # [6396297.922072] alpha systemd-networkd[204]: eth1: Link UP
gamma # [6396297.452616] gamma systemd[1]: Starting Record System Boot/Shutdown in UTMP...
alpha # [6396297.922352] alpha systemd-networkd[204]: eth1: Gained carrier
gamma # [6396297.464573] gamma systemd[1]: Finished Record System Boot/Shutdown in UTMP.
alpha # [6396297.922361] alpha systemd[1]: Started Network Management.
gamma # [6396297.471764] gamma systemd[1]: Finished Rebuild Journal Catalog.
alpha # [6396297.923390] alpha systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
gamma # [6396297.472860] gamma systemd[1]: Starting Update is Completed...
alpha # [6396298.005541] alpha systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
gamma # [6396297.482669] gamma systemd[1]: Finished Update is Completed.
alpha # [6396298.050840] alpha systemd-resolved[110]: Positive Trust Anchors:
gamma # [6396297.532432] gamma systemd[1]: Finished Firewall.
alpha # [6396298.050851] alpha systemd-resolved[110]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
gamma # [6396297.532582] gamma systemd[1]: Reached target Preparation for Network.
alpha # [6396298.050854] alpha systemd-resolved[110]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
gamma # [6396297.532793] gamma systemd[1]: Listening on Network Management Resolve Hook Socket.
alpha # [6396298.050888] alpha systemd-resolved[110]: 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 # [6396297.533798] gamma systemd[1]: Starting Network Management...
alpha # [6396298.072998] alpha systemd-resolved[110]: Using system hostname 'alpha'.
gamma # [6396297.911599] gamma systemd-networkd[204]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
alpha # [6396298.074381] alpha systemd[1]: Started Network Name Resolution.
gamma # [6396297.911690] gamma systemd-networkd[204]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
alpha # [6396298.074470] alpha systemd[1]: Reached target Network.
gamma # [6396297.920401] gamma systemd-networkd[204]: /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 # [6396298.074541] alpha systemd[1]: Reached target System Initialization.
gamma # [6396297.920578] gamma systemd-networkd[204]: /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 # [6396298.074594] alpha systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
gamma # [6396297.920799] gamma systemd-networkd[204]: lo: Link UP
alpha # [6396298.074623] alpha systemd[1]: Started Daily Cleanup of Temporary Directories.
gamma # [6396297.920804] gamma systemd-networkd[204]: lo: Gained carrier
alpha # [6396298.074639] alpha systemd[1]: Reached target Timer Units.
gamma # [6396297.920984] gamma systemd-networkd[204]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
alpha # [6396298.074774] alpha systemd[1]: Listening on D-Bus System Message Bus Socket.
gamma # [6396297.921536] gamma systemd[1]: Started Network Management.
alpha # [6396298.075341] alpha systemd[1]: Listening on Nix Daemon Socket.
gamma # [6396297.921648] gamma systemd-networkd[204]: eth1: Link UP
alpha # [6396298.075592] alpha systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
gamma # [6396297.922136] gamma systemd-networkd[204]: eth1: Gained carrier
alpha # [6396298.075625] alpha systemd[1]: Reached target Socket Units.
gamma # [6396297.922756] gamma systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
alpha # [6396298.075676] alpha systemd[1]: Reached target Basic System.
gamma # [6396298.009401] gamma systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
alpha # [6396298.077078] alpha systemd[1]: Starting data mesher daemon...
gamma # [6396298.054569] gamma systemd-resolved[111]: Positive Trust Anchors:
gamma # [6396298.054581] gamma systemd-resolved[111]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
gamma # [6396298.054584] gamma systemd-resolved[111]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
gamma # [6396298.054618] gamma 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
gamma # [6396298.076625] gamma systemd-resolved[111]: Using system hostname 'gamma'.
gamma # [6396298.077959] gamma systemd[1]: Started Network Name Resolution.
gamma # [6396298.078035] gamma systemd[1]: Reached target Network.
gamma # [6396298.078104] gamma systemd[1]: Reached target System Initialization.
gamma # [6396298.078151] gamma systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
gamma # [6396298.078178] gamma systemd[1]: Started Daily Cleanup of Temporary Directories.
gamma # [6396298.078195] gamma systemd[1]: Reached target Timer Units.
gamma # [6396298.078315] gamma systemd[1]: Listening on D-Bus System Message Bus Socket.
gamma # [6396298.078418] gamma systemd[1]: Listening on Nix Daemon Socket.
gamma # [6396298.078518] gamma systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
gamma # [6396298.078538] gamma systemd[1]: Reached target Socket Units.
gamma # [6396298.078572] gamma systemd[1]: Reached target Basic System.
alpha # [6396298.292455] alpha systemd[1]: Starting Import lastlog data into lastlog2 database...
alpha # [6396298.293836] alpha systemd[1]: Starting Name Service Cache Daemon (nsncd)...
alpha # [6396298.295313] alpha systemd[1]: Starting D-Bus System Message Bus...
alpha # [6396298.313711] alpha systemd[1]: Finished Import lastlog data into lastlog2 database.
alpha # [6396298.495664] alpha systemd[1]: Started Name Service Cache Daemon (nsncd).
alpha # [6396298.495736] alpha systemd[1]: Reached target Host and Network Name Lookups.
alpha # [6396298.496383] alpha nsncd[212]: Aug 22 00:08:44.549 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
alpha # [6396298.495806] alpha systemd[1]: Reached target User and Group Name Lookups.
alpha # [6396298.502136] alpha systemd[1]: Starting User Login Management...
alpha # [6396298.503156] alpha systemd[1]: Starting Permit User Sessions...
alpha # [6396298.513692] alpha systemd[1]: Finished Permit User Sessions.
alpha # [6396298.515298] alpha systemd[1]: Started Console Getty.
alpha # [6396298.515379] alpha systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
alpha # [6396298.515418] alpha systemd[1]: Reached target Login Prompts.
gamma # [6396298.292455] gamma systemd[1]: Starting data mesher daemon...
gamma # [6396298.293553] gamma systemd[1]: Starting Import lastlog data into lastlog2 database...
gamma # [6396298.294544] gamma systemd[1]: Starting Name Service Cache Daemon (nsncd)...
gamma # [6396298.295653] gamma systemd[1]: Starting D-Bus System Message Bus...
gamma # [6396298.315134] gamma systemd[1]: Finished Import lastlog data into lastlog2 database.
gamma # [6396298.494638] gamma nsncd[211]: Aug 22 00:08:44.547 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
gamma # [6396298.494647] gamma systemd[1]: Started Name Service Cache Daemon (nsncd).
gamma # [6396298.494744] gamma systemd[1]: Reached target Host and Network Name Lookups.
gamma # [6396298.494843] gamma systemd[1]: Reached target User and Group Name Lookups.
gamma # [6396298.501715] gamma systemd[1]: Starting User Login Management...
gamma # [6396298.502637] gamma systemd[1]: Starting Permit User Sessions...
gamma # [6396298.512087] gamma systemd[1]: Finished Permit User Sessions.
gamma # [6396298.513450] gamma systemd[1]: Started Console Getty.
gamma # [6396298.513502] gamma systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
gamma # [6396298.513521] gamma systemd[1]: Reached target Login Prompts.
beta # [6396298.307801] beta systemd[1]: Finished Import lastlog data into lastlog2 database.
beta # [6396298.483320] beta systemd[1]: Started Name Service Cache Daemon (nsncd).
beta # [6396298.483378] beta systemd[1]: Reached target Host and Network Name Lookups.
beta # [6396298.483752] beta nsncd[211]: Aug 22 00:08:44.536 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
beta # [6396298.483431] beta systemd[1]: Reached target User and Group Name Lookups.
beta # [6396298.501246] beta systemd[1]: Starting User Login Management...
beta # [6396298.502076] beta systemd[1]: Starting Permit User Sessions...
beta # [6396298.513805] beta systemd[1]: Finished Permit User Sessions.
beta # [6396298.515481] beta systemd[1]: Started Console Getty.
beta # [6396298.515537] beta systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
beta # [6396298.515561] beta systemd[1]: Reached target Login Prompts.
gamma # [6396298.590009] gamma dbus-broker-launch[212]: Looking up NSS user entry for 'systemd-timesync'...
gamma # [6396298.592482] gamma dbus-broker-launch[212]: NSS returned no entry for 'systemd-timesync'
gamma # [6396298.592482] gamma dbus-broker-launch[212]: Invalid user-name in /nix/store/r467fybq8imqxxx1sakqq32ay68d83ra-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
gamma # [6396298.592974] gamma systemd[1]: Started D-Bus System Message Bus.
gamma # [6396298.600129] gamma dbus-broker-launch[212]: Ready
gamma # [6396298.684371] gamma systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
gamma # [6396298.685586] gamma systemd[1]: Finished Save Transient machine-id to Disk.
beta # [6396298.607613] beta dbus-broker-launch[212]: Looking up NSS user entry for 'systemd-timesync'...
beta # [6396298.608457] beta dbus-broker-launch[212]: NSS returned no entry for 'systemd-timesync'
beta # [6396298.608457] beta dbus-broker-launch[212]: Invalid user-name in /nix/store/r467fybq8imqxxx1sakqq32ay68d83ra-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
beta # [6396298.608871] beta systemd[1]: Started D-Bus System Message Bus.
beta # [6396298.620193] beta dbus-broker-launch[212]: Ready
beta # [6396298.691584] beta systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
beta # [6396298.693541] beta systemd[1]: Finished Save Transient machine-id to Disk.
alpha # [6396298.600784] alpha dbus-broker-launch[213]: Looking up NSS user entry for 'systemd-timesync'...
alpha # [6396298.601467] alpha dbus-broker-launch[213]: NSS returned no entry for 'systemd-timesync'
alpha # [6396298.601467] alpha dbus-broker-launch[213]: Invalid user-name in /nix/store/r467fybq8imqxxx1sakqq32ay68d83ra-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
alpha # [6396298.602026] alpha systemd[1]: Started D-Bus System Message Bus.
alpha # [6396298.608899] alpha dbus-broker-launch[213]: Ready
alpha # [6396298.691923] alpha systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
alpha # [6396298.693852] alpha systemd[1]: Finished Save Transient machine-id to Disk.
beta # [6396298.921734] beta data-mesher[209]: time=2026-08-22T00:08:44.974Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
beta # [6396298.922752] beta data-mesher[209]: time=2026-08-22T00:08:44.975Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd: [/dns/alpha.clan/tcp/7946]} {12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
beta # [6396298.922752] beta data-mesher[209]: time=2026-08-22T00:08:44.975Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
beta # [6396298.924017] beta data-mesher[209]: time=2026-08-22T00:08:44.977Z level=INFO msg="checking file integrity"
beta # [6396298.924160] beta data-mesher[209]: time=2026-08-22T00:08:44.977Z level=INFO msg="file integrity check complete"
beta # [6396298.927986] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="libp2p host created" peer_id=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 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 # [6396298.928071] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="registered HTTP route" method=GET path=/files
beta # [6396298.928071] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
beta # [6396298.928071] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
beta # [6396298.928071] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="starting server"
gamma # [6396298.904465] gamma data-mesher[209]: time=2026-08-22T00:08:44.957Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
beta # [6396298.928142] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="waiting for DHT to populate" delay=10s
gamma # [6396298.908187] gamma data-mesher[209]: time=2026-08-22T00:08:44.961Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd: [/dns/alpha.clan/tcp/7946]} {12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396298.928220] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="HTTP server listening" address=[::1]:7331
gamma # [6396298.908243] gamma data-mesher[209]: time=2026-08-22T00:08:44.961Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
beta # [6396298.928250] beta data-mesher[209]: time=2026-08-22T00:08:44.981Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
gamma # [6396298.916166] gamma data-mesher[209]: time=2026-08-22T00:08:44.969Z level=INFO msg="checking file integrity"
beta # [6396298.986420] beta data-mesher[209]: time=2026-08-22T00:08:45.039Z level=INFO msg="peer connected" peer_id=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd remote_addr=/ip4/192.168.1.1/tcp/7946
gamma # [6396298.916316] gamma data-mesher[209]: time=2026-08-22T00:08:44.969Z level=INFO msg="file integrity check complete"
beta # [6396299.010886] beta systemd-logind[228]: New seat seat0.
gamma # [6396298.921734] gamma data-mesher[209]: time=2026-08-22T00:08:44.974Z level=INFO msg="libp2p host created" peer_id=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt 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]"
beta # [6396299.011086] beta systemd[1]: Started User Login Management.
gamma # [6396298.921809] gamma data-mesher[209]: time=2026-08-22T00:08:44.974Z level=INFO msg="registered HTTP route" method=GET path=/files
beta # [6396299.036878] beta systemd[1]: Starting linger-users.service...
gamma # [6396298.921809] gamma data-mesher[209]: time=2026-08-22T00:08:44.974Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
beta # [6396299.048305] beta systemd[1]: linger-users.service: Deactivated successfully.
gamma # [6396298.921809] gamma data-mesher[209]: time=2026-08-22T00:08:44.974Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
beta # [6396299.048412] beta systemd[1]: Finished linger-users.service.
gamma # [6396298.921809] gamma data-mesher[209]: time=2026-08-22T00:08:44.974Z level=INFO msg="starting server"
gamma # [6396298.921887] gamma data-mesher[209]: time=2026-08-22T00:08:44.975Z level=INFO msg="waiting for DHT to populate" delay=10s
gamma # [6396298.921974] gamma data-mesher[209]: time=2026-08-22T00:08:44.975Z level=INFO msg="HTTP server listening" address=[::1]:7331
gamma # [6396298.922012] gamma data-mesher[209]: time=2026-08-22T00:08:44.975Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
gamma # [6396299.020150] gamma systemd-logind[228]: New seat seat0.
gamma # [6396299.020351] gamma systemd[1]: Started User Login Management.
gamma # [6396299.037150] gamma systemd[1]: Starting linger-users.service...
gamma # [6396299.047996] gamma systemd[1]: linger-users.service: Deactivated successfully.
gamma # [6396299.048176] gamma systemd[1]: Finished linger-users.service.
gamma # [6396299.072224] gamma systemd-networkd[204]: eth1: Gained IPv6LL
alpha # [6396298.973152] alpha data-mesher[209]: time=2026-08-22T00:08:45.026Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
alpha # [6396298.974164] alpha data-mesher[209]: time=2026-08-22T00:08:45.027Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd: [/dns/alpha.clan/tcp/7946]} {12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
alpha # [6396298.974164] alpha data-mesher[209]: time=2026-08-22T00:08:45.027Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
alpha # [6396298.975719] alpha data-mesher[209]: time=2026-08-22T00:08:45.028Z level=INFO msg="checking file integrity"
alpha # [6396298.975828] alpha data-mesher[209]: time=2026-08-22T00:08:45.028Z level=INFO msg="file integrity check complete"
alpha # [6396298.979735] alpha data-mesher[209]: time=2026-08-22T00:08:45.032Z level=INFO msg="libp2p host created" peer_id=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd 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 # [6396298.979810] alpha data-mesher[209]: time=2026-08-22T00:08:45.032Z level=INFO msg="registered HTTP route" method=GET path=/files
alpha # [6396298.979810] alpha data-mesher[209]: time=2026-08-22T00:08:45.032Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
alpha # [6396298.979810] alpha data-mesher[209]: time=2026-08-22T00:08:45.032Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
alpha # [6396298.979810] alpha data-mesher[209]: time=2026-08-22T00:08:45.032Z level=INFO msg="starting server"
alpha # [6396298.979990] alpha data-mesher[209]: time=2026-08-22T00:08:45.033Z level=INFO msg="waiting for DHT to populate" delay=10s
alpha # [6396298.979990] alpha data-mesher[209]: time=2026-08-22T00:08:45.033Z level=INFO msg="HTTP server listening" address=[::1]:7331
alpha # [6396298.980112] alpha data-mesher[209]: time=2026-08-22T00:08:45.033Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
alpha # [6396298.985399] alpha data-mesher[209]: time=2026-08-22T00:08:45.038Z level=INFO msg="peer connected" peer_id=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 remote_addr=/ip4/192.168.1.2/tcp/7946
alpha # [6396299.013721] alpha systemd-logind[228]: New seat seat0.
alpha # [6396299.013896] alpha systemd[1]: Started User Login Management.
alpha # [6396299.036983] alpha systemd[1]: Starting linger-users.service...
alpha # [6396299.048335] alpha systemd[1]: linger-users.service: Deactivated successfully.
alpha # [6396299.048412] alpha systemd[1]: Finished linger-users.service.
alpha # [6396299.168224] alpha systemd-networkd[204]: eth1: Gained IPv6LL
beta # [6396299.616213] beta systemd-networkd[204]: eth1: Gained IPv6LL
gamma # [6396303.934180] gamma data-mesher[209]: time=2026-08-22T00:08:49.987Z level=INFO msg="peer connected" peer_id=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 remote_addr=/ip6/2001:db8:1::2/tcp/7946
gamma # [6396303.946686] gamma data-mesher[209]: time=2026-08-22T00:08:49.999Z level=INFO msg="peer connected" peer_id=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd remote_addr=/ip4/192.168.1.1/tcp/7946
beta # [6396303.935776] beta data-mesher[209]: time=2026-08-22T00:08:49.988Z level=INFO msg="peer connected" peer_id=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt remote_addr=/ip6/2001:db8:1::3/tcp/7946
alpha # [6396303.948526] alpha data-mesher[209]: time=2026-08-22T00:08:50.001Z level=INFO msg="peer connected" peer_id=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt remote_addr=/ip4/192.168.1.3/tcp/7946
alpha: still waiting for container 'alpha' to reach ready state...
gamma # [6396308.922053] gamma data-mesher[209]: time=2026-08-22T00:08:54.975Z level=INFO msg="performing state exchange with peers on join" count=1
gamma # [6396308.922053] gamma data-mesher[209]: time=2026-08-22T00:08:54.975Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396308.923170] gamma data-mesher[209]: time=2026-08-22T00:08:54.976Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396308.923170] gamma data-mesher[209]: time=2026-08-22T00:08:54.976Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396308.923170] gamma data-mesher[209]: time=2026-08-22T00:08:54.976Z level=INFO msg="server started"
gamma # [6396308.923170] gamma data-mesher[209]: time=2026-08-22T00:08:54.976Z level=INFO msg="starting expired-file sweeper" interval=1m0s
gamma # [6396308.923325] gamma systemd[1]: Started data mesher daemon.
gamma # [6396308.923669] gamma systemd[1]: Reached target Multi-User System.
gamma # [6396308.923893] gamma systemd[1]: Startup finished in 12.129s.
beta # [6396308.922746] beta data-mesher[209]: time=2026-08-22T00:08:54.975Z level=INFO msg="received state sync from peer" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396308.922746] beta data-mesher[209]: time=2026-08-22T00:08:54.975Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396308.928390] beta data-mesher[209]: time=2026-08-22T00:08:54.981Z level=INFO msg="performing state exchange with peers on join" count=1
beta # [6396308.928432] beta data-mesher[209]: time=2026-08-22T00:08:54.981Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
beta # [6396308.928944] beta data-mesher[209]: time=2026-08-22T00:08:54.982Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396308.928944] beta data-mesher[209]: time=2026-08-22T00:08:54.982Z level=INFO msg="state exchange complete" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
beta # [6396308.928986] beta data-mesher[209]: time=2026-08-22T00:08:54.982Z level=INFO msg="server started"
beta # [6396308.929091] beta data-mesher[209]: time=2026-08-22T00:08:54.982Z level=INFO msg="starting expired-file sweeper" interval=1m0s
beta # [6396308.929154] beta systemd[1]: Started data mesher daemon.
beta # [6396308.929386] beta systemd[1]: Reached target Multi-User System.
beta # [6396308.929546] beta systemd[1]: Startup finished in 12.132s.
beta # [6396308.980740] beta data-mesher[209]: time=2026-08-22T00:08:55.033Z level=INFO msg="received state sync from peer" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396308.980740] beta data-mesher[209]: time=2026-08-22T00:08:55.033Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
alpha # [6396308.928841] alpha data-mesher[209]: time=2026-08-22T00:08:54.981Z level=INFO msg="received state sync from peer" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396308.928841] alpha data-mesher[209]: time=2026-08-22T00:08:54.982Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396308.980383] alpha data-mesher[209]: time=2026-08-22T00:08:55.033Z level=INFO msg="performing state exchange with peers on join" count=1
alpha # [6396308.980383] alpha data-mesher[209]: time=2026-08-22T00:08:55.033Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
alpha # [6396308.980826] alpha data-mesher[209]: time=2026-08-22T00:08:55.033Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396308.980826] alpha data-mesher[209]: time=2026-08-22T00:08:55.033Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
alpha # [6396308.980884] alpha data-mesher[209]: time=2026-08-22T00:08:55.034Z level=INFO msg="server started"
alpha # [6396308.981056] alpha data-mesher[209]: time=2026-08-22T00:08:55.034Z level=INFO msg="starting expired-file sweeper" interval=1m0s
alpha # [6396308.981103] alpha systemd[1]: Started data mesher daemon.
alpha # [6396308.981636] alpha systemd[1]: Reached target Multi-User System.
alpha # [6396308.982491] alpha systemd[1]: Startup finished in 12.185s.
alpha: (finished: waiting for unit data-mesher.service, in 13.16 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.02 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/hk2gmkyvzjcrm2031zsfvq073pqbhw94-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/hk2gmkyvzjcrm2031zsfvq073pqbhw94-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.04 seconds)
??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/258dmf26bj4wx2idmzbn2vz4hzlmk8bh-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/258dmf26bj4wx2idmzbn2vz4hzlmk8bh-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 # [6396309.508013] alpha data-mesher[209]: time=2026-08-22T00:08:55.561Z level=INFO msg=http_request uri=/files/test_file status=204
gamma # [6396313.924147] gamma data-mesher[209]: time=2026-08-22T00:08:59.977Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6396313.925763] gamma data-mesher[209]: time=2026-08-22T00:08:59.977Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396313.925763] gamma data-mesher[209]: time=2026-08-22T00:08:59.977Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396313.925763] gamma data-mesher[209]: time=2026-08-22T00:08:59.977Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396313.925763] gamma data-mesher[209]: time=2026-08-22T00:08:59.977Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6396313.929614] gamma data-mesher[209]: time=2026-08-22T00:08:59.982Z level=INFO msg="received state sync from peer" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396313.929614] gamma data-mesher[209]: time=2026-08-22T00:08:59.982Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396313.982499] gamma data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="received state sync from peer" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396313.982499] gamma data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396313.982673] gamma data-mesher[209]: time=2026-08-22T00:09:00.035Z level=DEBUG msg="new file detected" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd name=test_file name=test_file
gamma # [6396313.982673] gamma data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="scheduling file download" name=test_file
gamma # [6396313.982673] gamma data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="downloading file" name=test_file signed_at="2026-08-22 00:08:55.544 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396313.986454] gamma data-mesher[209]: time=2026-08-22T00:09:00.039Z level=INFO msg="download complete" name=test_file signed_at="2026-08-22 00:08:55.544 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd written=true elapsed=3.784292ms
beta # [6396313.924614] beta data-mesher[209]: time=2026-08-22T00:08:59.977Z level=INFO msg="received state sync from peer" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396313.924614] beta data-mesher[209]: time=2026-08-22T00:08:59.977Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396313.929157] beta data-mesher[209]: time=2026-08-22T00:08:59.982Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [6396313.929298] beta data-mesher[209]: time=2026-08-22T00:08:59.982Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
beta # [6396313.929762] beta data-mesher[209]: time=2026-08-22T00:08:59.982Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396313.929762] beta data-mesher[209]: time=2026-08-22T00:08:59.982Z level=INFO msg="state exchange complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
beta # [6396313.929915] beta data-mesher[209]: time=2026-08-22T00:08:59.982Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6396313.981847] alpha data-mesher[209]: time=2026-08-22T00:09:00.034Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6396313.982238] alpha data-mesher[209]: time=2026-08-22T00:09:00.035Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
alpha # [6396313.982659] alpha data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
alpha # [6396313.982659] alpha data-mesher[209]: time=2026-08-22T00:09:00.035Z level=INFO msg="state exchange complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
alpha # [6396313.982722] alpha data-mesher[209]: time=2026-08-22T00:09:00.035Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6396313.982948] alpha data-mesher[209]: time=2026-08-22T00:09:00.036Z level=INFO msg="received file request" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_file
alpha # [6396313.985143] alpha data-mesher[209]: time=2026-08-22T00:09:00.038Z level=INFO msg="file transfer complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_file
gamma # [6396318.925463] gamma data-mesher[209]: time=2026-08-22T00:09:04.978Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6396318.925463] gamma data-mesher[209]: time=2026-08-22T00:09:04.978Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396318.926271] gamma data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396318.926271] gamma data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396318.926271] gamma data-mesher[209]: time=2026-08-22T00:09:04.979Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6396318.926608] gamma data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="received file request" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_file
gamma # [6396318.929187] gamma data-mesher[209]: time=2026-08-22T00:09:04.982Z level=INFO msg="file transfer complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_file
gamma # [6396318.930806] gamma data-mesher[209]: time=2026-08-22T00:09:04.983Z level=INFO msg="received state sync from peer" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396318.930806] gamma data-mesher[209]: time=2026-08-22T00:09:04.983Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
beta # [6396318.926015] beta data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="received state sync from peer" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396318.926015] beta data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396318.926502] beta data-mesher[209]: time=2026-08-22T00:09:04.979Z level=DEBUG msg="new file detected" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt name=test_file name=test_file
beta # [6396318.926502] beta data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="scheduling file download" name=test_file
beta # [6396318.926502] beta data-mesher[209]: time=2026-08-22T00:09:04.979Z level=INFO msg="downloading file" name=test_file signed_at="2026-08-22 00:08:55.544 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396318.930483] beta data-mesher[209]: time=2026-08-22T00:09:04.983Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [6396318.931292] beta data-mesher[209]: time=2026-08-22T00:09:04.983Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
beta # [6396318.931292] beta data-mesher[209]: time=2026-08-22T00:09:04.984Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396318.931292] beta data-mesher[209]: time=2026-08-22T00:09:04.984Z level=DEBUG msg="new file detected" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt name=test_file name=test_file
beta # [6396318.931292] beta data-mesher[209]: time=2026-08-22T00:09:04.984Z level=INFO msg="state exchange complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
beta # [6396318.931292] beta data-mesher[209]: time=2026-08-22T00:09:04.984Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6396318.942789] beta data-mesher[209]: time=2026-08-22T00:09:04.995Z level=INFO msg="download complete" name=test_file signed_at="2026-08-22 00:08:55.544 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt written=true elapsed=16.573308ms
beta # [6396318.984336] beta data-mesher[209]: time=2026-08-22T00:09:05.037Z level=INFO msg="received state sync from peer" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396318.984336] beta data-mesher[209]: time=2026-08-22T00:09:05.037Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
alpha # [6396318.983675] alpha data-mesher[209]: time=2026-08-22T00:09:05.036Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6396318.984076] alpha data-mesher[209]: time=2026-08-22T00:09:05.036Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
alpha # [6396318.984803] alpha data-mesher[209]: time=2026-08-22T00:09:05.037Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396318.984846] alpha data-mesher[209]: time=2026-08-22T00:09:05.038Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
alpha # [6396318.984906] alpha data-mesher[209]: time=2026-08-22T00:09:05.038Z level=DEBUG msg="push/pull successful" interval=5s
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 10.08 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/hk2gmkyvzjcrm2031zsfvq073pqbhw94-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/hk2gmkyvzjcrm2031zsfvq073pqbhw94-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 # [6396319.645991] beta data-mesher[209]: time=2026-08-22T00:09:05.699Z level=INFO msg=http_request uri=/files/test_file status=204
gamma # [6396323.927331] gamma data-mesher[209]: time=2026-08-22T00:09:09.980Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6396323.928086] gamma data-mesher[209]: time=2026-08-22T00:09:09.980Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
gamma # [6396323.928086] gamma data-mesher[209]: time=2026-08-22T00:09:09.981Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396323.928196] gamma data-mesher[209]: time=2026-08-22T00:09:09.981Z level=INFO msg="state exchange complete" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
gamma # [6396323.928196] gamma data-mesher[209]: time=2026-08-22T00:09:09.981Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6396323.985408] gamma data-mesher[209]: time=2026-08-22T00:09:10.038Z level=INFO msg="received state sync from peer" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396323.985408] gamma data-mesher[209]: time=2026-08-22T00:09:10.038Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396323.997545] gamma data-mesher[209]: time=2026-08-22T00:09:10.050Z level=DEBUG msg="imported tombstone" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd name=test_file written=true
alpha # [6396323.927894] alpha data-mesher[209]: time=2026-08-22T00:09:09.981Z level=INFO msg="received state sync from peer" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
alpha # [6396323.927894] alpha data-mesher[209]: time=2026-08-22T00:09:09.981Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
alpha # [6396323.931792] alpha data-mesher[209]: time=2026-08-22T00:09:09.984Z level=INFO msg="received state sync from peer" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
beta # [6396323.931338] beta data-mesher[209]: time=2026-08-22T00:09:09.984Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6396323.931792] alpha data-mesher[209]: time=2026-08-22T00:09:09.984Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396323.952070] alpha data-mesher[209]: time=2026-08-22T00:09:10.005Z level=DEBUG msg="imported tombstone" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 name=test_file written=true
alpha # [6396323.984954] alpha data-mesher[209]: time=2026-08-22T00:09:10.038Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6396323.985010] alpha data-mesher[209]: time=2026-08-22T00:09:10.038Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
alpha # [6396323.997766] alpha data-mesher[209]: time=2026-08-22T00:09:10.050Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
alpha # [6396323.997830] alpha data-mesher[209]: time=2026-08-22T00:09:10.050Z level=INFO msg="state exchange complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
beta # [6396323.931744] beta data-mesher[209]: time=2026-08-22T00:09:09.984Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
alpha # [6396323.997830] alpha data-mesher[209]: time=2026-08-22T00:09:10.050Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6396323.952455] beta data-mesher[209]: time=2026-08-22T00:09:10.005Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396323.952455] beta data-mesher[209]: time=2026-08-22T00:09:10.005Z level=INFO msg="state exchange complete" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
beta # [6396323.952594] beta data-mesher[209]: time=2026-08-22T00:09:10.005Z 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/7y84rgsq6a8ghl5m36l8kz67zdaicnyq-per-machine-alpha-data-mesher-node-identity_identity.pub
alpha: (finished: must succeed: cat /nix/store/7y84rgsq6a8ghl5m36l8kz67zdaicnyq-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/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/hk2gmkyvzjcrm2031zsfvq073pqbhw94-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/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/hk2gmkyvzjcrm2031zsfvq073pqbhw94-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/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14, in 0.01 seconds)
beta: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha # [6396324.739723] alpha data-mesher[209]: time=2026-08-22T00:09:10.792Z level=INFO msg=http_request uri=/files/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 status=204
gamma # [6396328.929194] gamma data-mesher[209]: time=2026-08-22T00:09:14.982Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6396328.929194] gamma data-mesher[209]: time=2026-08-22T00:09:14.982Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396328.930339] gamma data-mesher[209]: time=2026-08-22T00:09:14.983Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
gamma # [6396328.930339] gamma data-mesher[209]: time=2026-08-22T00:09:14.983Z level=INFO msg="state exchange complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 timeout=5s
gamma # [6396328.930339] gamma data-mesher[209]: time=2026-08-22T00:09:14.983Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6396328.999235] gamma data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="received state sync from peer" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396328.999235] gamma data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396328.999420] gamma data-mesher[209]: time=2026-08-22T00:09:15.052Z level=DEBUG msg="new file detected" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd name=test_file name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
gamma # [6396328.999596] gamma data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="scheduling file download" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
gamma # [6396328.999596] gamma data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="downloading file" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 signed_at="2026-08-22 00:09:10.79 +0000 UTC" signed_by="fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
gamma # [6396329.002555] gamma data-mesher[209]: time=2026-08-22T00:09:15.055Z level=INFO msg="download complete" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 signed_at="2026-08-22 00:09:10.79 +0000 UTC" signed_by="fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd written=true elapsed=2.975001ms
beta # [6396328.929784] beta data-mesher[209]: time=2026-08-22T00:09:14.982Z level=INFO msg="received state sync from peer" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396328.929784] beta data-mesher[209]: time=2026-08-22T00:09:14.982Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
beta # [6396328.953317] beta data-mesher[209]: time=2026-08-22T00:09:15.006Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [6396328.953463] beta data-mesher[209]: time=2026-08-22T00:09:15.006Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
beta # [6396328.954984] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=INFO msg="merging remote state" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396328.955611] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=DEBUG msg="new file detected" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd name=test_file name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
beta # [6396328.955655] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=INFO msg="state exchange complete" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd timeout=5s
beta # [6396328.955655] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6396328.955706] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=INFO msg="scheduling file download" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
beta # [6396328.955731] beta data-mesher[209]: time=2026-08-22T00:09:15.008Z level=INFO msg="downloading file" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 signed_at="2026-08-22 00:09:10.79 +0000 UTC" signed_by="fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd
beta # [6396328.957824] beta data-mesher[209]: time=2026-08-22T00:09:15.010Z level=INFO msg="download complete" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 signed_at="2026-08-22 00:09:10.79 +0000 UTC" signed_by="fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14=" peer=12D3KooWJCTrRc3yEBjh7s89fzskn8pryfWCS5STHX9eYCh5zhnd written=true elapsed=2.101709ms
alpha # [6396328.954289] alpha data-mesher[209]: time=2026-08-22T00:09:15.007Z level=INFO msg="received state sync from peer" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396328.954289] alpha data-mesher[209]: time=2026-08-22T00:09:15.007Z level=INFO msg="merging remote state" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3
alpha # [6396328.956166] alpha data-mesher[209]: time=2026-08-22T00:09:15.009Z level=INFO msg="received file request" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha # [6396328.957005] alpha data-mesher[209]: time=2026-08-22T00:09:15.010Z level=INFO msg="file transfer complete" peer=12D3KooWAovAHgmfbDnsxkCe22BYvAvPt3N54mFMHkKvPrWmSRs3 network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha # [6396328.998591] alpha data-mesher[209]: time=2026-08-22T00:09:15.051Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6396328.998728] alpha data-mesher[209]: time=2026-08-22T00:09:15.051Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
alpha # [6396328.999632] alpha data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="merging remote state" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt
alpha # [6396328.999811] alpha data-mesher[209]: time=2026-08-22T00:09:15.052Z level=INFO msg="state exchange complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt timeout=5s
alpha # [6396328.999850] alpha data-mesher[209]: time=2026-08-22T00:09:15.053Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6396329.000108] alpha data-mesher[209]: time=2026-08-22T00:09:15.053Z level=INFO msg="received file request" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha # [6396329.001692] alpha data-mesher[209]: time=2026-08-22T00:09:15.054Z level=INFO msg="file transfer complete" peer=12D3KooWJTrTC7bS9PFqDxm2JQ6u2b9BCthABCKotUvEgMLJHcTt network="L6Pbpa5VKy9JW7S12yJLmmVhAeL70UK5O8uUwfHqkjY=" name=test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14, in 5.04 seconds)
gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14, 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/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/hk2gmkyvzjcrm2031zsfvq073pqbhw94-shared-data-mesher-network_network.pub
Error: failed to update file: 403 Forbidden, signer fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14= is not authorized for this file test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14
alpha: (finished: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/hk2gmkyvzjcrm2031zsfvq073pqbhw94-shared-data-mesher-network_network.pub, in 0.02 seconds)
(finished: run the VM test script, in 33.58 seconds)
test script finished in 33.84s
cleanup
kill NspawnMachine (pid 52)
alpha # [6396329.825906] alpha data-mesher[209]: time=2026-08-22T00:09:15.879Z level=INFO msg=http_request uri=/files/test_ns/fIazRqpZeStJedXnojG3Ntn8c7k04foCsxob8iUMt14 status=403
kill NspawnMachine (pid 54)
Container alpha terminated by signal KILL.
kill NspawnMachine (pid 56)
Container beta terminated by signal KILL.
(finished: cleanup, in 0.44 seconds)
Container gamma terminated by signal KILL.