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 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.
░ Spawning container beta on /build/vm-state-beta.
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.
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 gamma on /build/vm-state-gamma.
alpha # No journal files were found.
alpha # No journal boot entry found for the specified boot (+0).
gamma # No journal files were found.
beta # No journal files were found.
gamma # No journal boot entry found for the specified boot (+0).
beta # No journal boot entry found for the specified boot (+0).
gamma # [1547441.761873] gamma systemd-journald[90]: Journal started
gamma # [1547441.761934] gamma systemd-journald[90]: Runtime Journal (/run/log/journal/08da0c7546b24da783694f6a53f819b1) is 8M, max 2.5G, 2.4G free.
gamma # [1547441.777598] gamma systemd[1]: Finished Apply Kernel Variables.
gamma # [1547441.792551] gamma systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
gamma # [1547441.840560] gamma systemd[1]: Starting Flush Journal to Persistent Storage...
gamma # [1547441.841631] gamma systemd[1]: Starting Network Name Resolution...
gamma # [1547441.842396] gamma systemd[1]: Starting Create Static Device Nodes in /dev...
gamma # [1547441.850625] gamma systemd-journald[90]: Time spent on flushing to /var/log/journal/08da0c7546b24da783694f6a53f819b1 is 3.029ms for 7 entries.
gamma # [1547441.850625] gamma systemd-journald[90]: System Journal (/var/log/journal/08da0c7546b24da783694f6a53f819b1) is 8M, max 4G, 3.9G free.
gamma # [1547441.880972] gamma systemd[1]: Finished Create Static Device Nodes in /dev.
beta # [1547441.770819] beta systemd-journald[90]: Journal started
beta # [1547441.770877] beta systemd-journald[90]: Runtime Journal (/run/log/journal/f79bee09cc7847be85358f029a6bc847) is 8M, max 2.5G, 2.4G free.
beta # [1547441.774111] beta systemd[1]: Finished Apply Kernel Variables.
beta # [1547441.786264] beta systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
gamma # [1547441.881831] gamma systemd[1]: Reached target Preparation for Local File Systems.
gamma # [1547441.882004] gamma systemd[1]: Reached target Local File Systems.
gamma # [1547441.883266] gamma systemd[1]: Listening on Boot Loader Control Service Socket.
gamma # [1547441.883334] gamma systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
gamma # [1547441.884529] gamma systemd[1]: Starting Save Transient machine-id to Disk...
gamma # [1547441.884584] gamma systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
gamma # [1547441.937086] gamma systemd[1]: Finished Firewall.
gamma # [1547441.938050] gamma systemd[1]: Reached target Preparation for Network.
gamma # [1547441.938610] gamma systemd[1]: Listening on Network Management Resolve Hook Socket.
gamma # [1547441.940714] gamma systemd[1]: Starting Network Management...
gamma # [1547441.969721] gamma systemd[1]: Finished Flush Journal to Persistent Storage.
gamma # [1547441.972248] gamma systemd[1]: Starting Create System Files and Directories...
gamma # [1547441.988031] gamma systemd-tmpfiles[201]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
gamma # [1547441.988290] gamma systemd-tmpfiles[201]: fchmod() of /var/log/journal failed: Operation not permitted
gamma # [1547441.988473] gamma systemd-tmpfiles[201]: fchmod() of /var/log/journal/08da0c7546b24da783694f6a53f819b1 failed: Operation not permitted
gamma # [1547441.988722] gamma systemd-tmpfiles[201]: fchmod() of /run/log/journal failed: Operation not permitted
gamma # [1547441.990364] gamma systemd[1]: Finished Create System Files and Directories.
gamma # [1547441.991699] gamma systemd[1]: Starting Rebuild Journal Catalog...
gamma # [1547441.992564] gamma systemd[1]: Starting Record System Boot/Shutdown in UTMP...
gamma # [1547442.007714] gamma systemd[1]: Finished Record System Boot/Shutdown in UTMP.
gamma # [1547442.017161] gamma systemd[1]: Finished Rebuild Journal Catalog.
gamma # [1547442.018330] gamma systemd[1]: Starting Update is Completed...
gamma # [1547442.029742] gamma systemd[1]: Finished Update is Completed.
gamma # [1547442.640549] gamma systemd[1]: Finished Save Transient machine-id to Disk.
gamma # [1547442.723206] gamma systemd-networkd[197]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
gamma # [1547442.723307] gamma systemd-networkd[197]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
beta # [1547441.800397] beta systemd[1]: Starting Flush Journal to Persistent Storage...
beta # [1547441.801272] beta systemd[1]: Starting Network Name Resolution...
beta # [1547441.801976] beta systemd[1]: Starting Create Static Device Nodes in /dev...
beta # [1547441.847117] beta systemd-journald[90]: Time spent on flushing to /var/log/journal/f79bee09cc7847be85358f029a6bc847 is 2.909ms for 7 entries.
beta # [1547441.847117] beta systemd-journald[90]: System Journal (/var/log/journal/f79bee09cc7847be85358f029a6bc847) is 8M, max 4G, 3.9G free.
beta # [1547441.871389] beta systemd[1]: Finished Create Static Device Nodes in /dev.
beta # [1547441.872123] beta systemd[1]: Reached target Preparation for Local File Systems.
beta # [1547441.872243] beta systemd[1]: Reached target Local File Systems.
beta # [1547441.873106] beta systemd[1]: Listening on Boot Loader Control Service Socket.
beta # [1547441.873158] beta systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
beta # [1547441.874040] beta systemd[1]: Starting Save Transient machine-id to Disk...
beta # [1547441.874079] beta systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
beta # [1547441.949856] beta systemd[1]: Finished Firewall.
beta # [1547441.950033] beta systemd[1]: Reached target Preparation for Network.
beta # [1547441.950272] beta systemd[1]: Listening on Network Management Resolve Hook Socket.
beta # [1547441.951344] beta systemd[1]: Starting Network Management...
beta # [1547441.968986] beta systemd[1]: Finished Flush Journal to Persistent Storage.
beta # [1547441.971199] beta systemd[1]: Starting Create System Files and Directories...
beta # [1547441.988726] beta systemd-tmpfiles[201]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
beta # [1547441.988946] beta systemd-tmpfiles[201]: fchmod() of /var/log/journal failed: Operation not permitted
beta # [1547441.989088] beta systemd-tmpfiles[201]: fchmod() of /var/log/journal/f79bee09cc7847be85358f029a6bc847 failed: Operation not permitted
beta # [1547441.989315] beta systemd-tmpfiles[201]: fchmod() of /run/log/journal failed: Operation not permitted
beta # [1547441.990964] beta systemd[1]: Finished Create System Files and Directories.
beta # [1547441.992196] beta systemd[1]: Starting Rebuild Journal Catalog...
beta # [1547441.993180] beta systemd[1]: Starting Record System Boot/Shutdown in UTMP...
beta # [1547442.009483] beta systemd[1]: Finished Record System Boot/Shutdown in UTMP.
beta # [1547442.013999] beta systemd[1]: Finished Rebuild Journal Catalog.
beta # [1547442.015066] beta systemd[1]: Starting Update is Completed...
beta # [1547442.026686] beta systemd[1]: Finished Update is Completed.
beta # [1547442.643813] beta systemd[1]: Finished Save Transient machine-id to Disk.
alpha # [1547441.762348] alpha systemd-journald[90]: Journal started
alpha # [1547441.762404] alpha systemd-journald[90]: Runtime Journal (/run/log/journal/163b92cb665c47c98d5f22c0d894fd30) is 8M, max 2.5G, 2.4G free.
alpha # [1547441.774116] alpha systemd[1]: Finished Apply Kernel Variables.
alpha # [1547441.787800] alpha systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
alpha # [1547441.802850] alpha systemd[1]: Starting Flush Journal to Persistent Storage...
alpha # [1547441.803641] alpha systemd[1]: Starting Network Name Resolution...
alpha # [1547441.804540] alpha systemd[1]: Starting Create Static Device Nodes in /dev...
alpha # [1547441.847147] alpha systemd-journald[90]: Time spent on flushing to /var/log/journal/163b92cb665c47c98d5f22c0d894fd30 is 1.533ms for 7 entries.
alpha # [1547441.847147] alpha systemd-journald[90]: System Journal (/var/log/journal/163b92cb665c47c98d5f22c0d894fd30) is 8M, max 4G, 3.9G free.
alpha # [1547441.871359] alpha systemd[1]: Finished Create Static Device Nodes in /dev.
alpha # [1547441.872090] alpha systemd[1]: Reached target Preparation for Local File Systems.
alpha # [1547441.872207] alpha systemd[1]: Reached target Local File Systems.
alpha # [1547441.873069] alpha systemd[1]: Listening on Boot Loader Control Service Socket.
alpha # [1547441.873120] alpha systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
alpha # [1547441.874016] alpha systemd[1]: Starting Save Transient machine-id to Disk...
alpha # [1547441.874058] alpha systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
alpha # [1547441.940742] alpha systemd[1]: Finished Firewall.
alpha # [1547441.941503] alpha systemd[1]: Reached target Preparation for Network.
alpha # [1547441.941905] alpha systemd[1]: Listening on Network Management Resolve Hook Socket.
alpha # [1547441.943286] alpha systemd[1]: Starting Network Management...
alpha # [1547441.969366] alpha systemd[1]: Finished Flush Journal to Persistent Storage.
alpha # [1547441.970409] alpha systemd[1]: Starting Create System Files and Directories...
alpha # [1547441.987207] alpha systemd-tmpfiles[201]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
alpha # [1547441.987495] alpha systemd-tmpfiles[201]: fchmod() of /var/log/journal failed: Operation not permitted
alpha # [1547441.987683] alpha systemd-tmpfiles[201]: fchmod() of /var/log/journal/163b92cb665c47c98d5f22c0d894fd30 failed: Operation not permitted
alpha # [1547441.987934] alpha systemd-tmpfiles[201]: fchmod() of /run/log/journal failed: Operation not permitted
alpha # [1547441.989419] alpha systemd[1]: Finished Create System Files and Directories.
alpha # [1547441.990661] alpha systemd[1]: Starting Rebuild Journal Catalog...
alpha # [1547441.991432] alpha systemd[1]: Starting Record System Boot/Shutdown in UTMP...
alpha # [1547442.007198] alpha systemd[1]: Finished Record System Boot/Shutdown in UTMP.
alpha # [1547442.011731] alpha systemd[1]: Finished Rebuild Journal Catalog.
alpha # [1547442.013156] alpha systemd[1]: Starting Update is Completed...
alpha # [1547442.025002] alpha systemd[1]: Finished Update is Completed.
alpha # [1547442.643646] alpha systemd[1]: Finished Save Transient machine-id to Disk.
alpha # [1547442.732223] alpha systemd-networkd[197]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
alpha # [1547442.732319] alpha systemd-networkd[197]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
alpha # [1547442.741916] alpha systemd-networkd[197]: /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 # [1547442.742086] alpha systemd-networkd[197]: /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 # [1547442.742251] alpha systemd-networkd[197]: lo: Link UP
alpha # [1547442.742257] alpha systemd-networkd[197]: lo: Gained carrier
alpha # [1547442.742430] alpha systemd-networkd[197]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
alpha # [1547442.748794] alpha systemd-networkd[197]: eth1: Link UP
alpha # [1547442.749139] alpha systemd-networkd[197]: eth1: Gained carrier
alpha # [1547442.753068] alpha systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
alpha # [1547442.753784] alpha systemd[1]: Started Network Management.
alpha # [1547442.754889] alpha systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
alpha # [1547442.794004] alpha systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
gamma # [1547442.735551] gamma systemd-networkd[197]: /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 # [1547442.735724] gamma systemd-networkd[197]: /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 # [1547442.735887] gamma systemd-networkd[197]: lo: Link UP
gamma # [1547442.735891] gamma systemd-networkd[197]: lo: Gained carrier
gamma # [1547442.736110] gamma systemd-networkd[197]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
gamma # [1547442.736476] gamma systemd[1]: Started Network Management.
gamma # [1547442.748393] gamma systemd-networkd[197]: eth1: Link UP
gamma # [1547442.748833] gamma systemd-networkd[197]: eth1: Gained carrier
gamma # [1547442.748866] gamma systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
gamma # [1547442.762311] gamma systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
gamma # [1547442.798187] gamma systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
beta # [1547442.745046] beta systemd-networkd[197]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
beta # [1547442.745143] beta systemd-networkd[197]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
beta # [1547442.754866] beta systemd-networkd[197]: /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 # [1547442.755043] beta systemd-networkd[197]: /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 # [1547442.755215] beta systemd-networkd[197]: lo: Link UP
beta # [1547442.755218] beta systemd-networkd[197]: lo: Gained carrier
beta # [1547442.755423] beta systemd-networkd[197]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
beta # [1547442.755917] beta systemd-networkd[197]: eth1: Link UP
beta # [1547442.756269] beta systemd-networkd[197]: eth1: Gained carrier
beta # [1547442.760762] beta systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
beta # [1547442.761470] beta systemd[1]: Started Network Management.
beta # [1547442.762817] beta systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
beta # [1547442.790180] beta systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
gamma # [1547443.200706] gamma systemd-resolved[144]: Positive Trust Anchors:
gamma # [1547443.200717] gamma systemd-resolved[144]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
gamma # [1547443.200722] gamma systemd-resolved[144]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
gamma # [1547443.200756] gamma systemd-resolved[144]: 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 # [1547443.223097] gamma systemd-resolved[144]: Using system hostname 'gamma'.
gamma # [1547443.224547] gamma systemd[1]: Started Network Name Resolution.
gamma # [1547443.224620] gamma systemd[1]: Reached target Network.
gamma # [1547443.224675] gamma systemd[1]: Reached target System Initialization.
gamma # [1547443.224727] gamma systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
gamma # [1547443.224753] gamma systemd[1]: Started Daily Cleanup of Temporary Directories.
gamma # [1547443.224769] gamma systemd[1]: Reached target Timer Units.
gamma # [1547443.224887] gamma systemd[1]: Listening on D-Bus System Message Bus Socket.
gamma # [1547443.225018] gamma systemd[1]: Listening on Nix Daemon Socket.
gamma # [1547443.225123] gamma systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
gamma # [1547443.225143] gamma systemd[1]: Reached target Socket Units.
gamma # [1547443.225177] gamma systemd[1]: Reached target Basic System.
gamma # [1547443.269806] gamma systemd[1]: Starting data mesher daemon...
gamma # [1547443.270598] gamma systemd[1]: Starting Import lastlog data into lastlog2 database...
gamma # [1547443.271384] gamma systemd[1]: Starting Name Service Cache Daemon (nsncd)...
gamma # [1547443.272680] gamma systemd[1]: Starting D-Bus System Message Bus...
gamma # [1547443.290636] gamma systemd[1]: Finished Import lastlog data into lastlog2 database.
beta # [1547443.213958] beta systemd-resolved[120]: Positive Trust Anchors:
beta # [1547443.213968] beta systemd-resolved[120]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
beta # [1547443.213973] beta systemd-resolved[120]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
beta # [1547443.214007] beta systemd-resolved[120]: 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 # [1547443.235939] beta systemd-resolved[120]: Using system hostname 'beta'.
beta # [1547443.237333] beta systemd[1]: Started Network Name Resolution.
beta # [1547443.237480] beta systemd[1]: Reached target Network.
beta # [1547443.237599] beta systemd[1]: Reached target System Initialization.
beta # [1547443.237699] beta systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
beta # [1547443.237760] beta systemd[1]: Started Daily Cleanup of Temporary Directories.
beta # [1547443.237798] beta systemd[1]: Reached target Timer Units.
beta # [1547443.238036] beta systemd[1]: Listening on D-Bus System Message Bus Socket.
beta # [1547443.238255] beta systemd[1]: Listening on Nix Daemon Socket.
beta # [1547443.238473] beta systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
beta # [1547443.238522] beta systemd[1]: Reached target Socket Units.
beta # [1547443.238599] beta systemd[1]: Reached target Basic System.
beta # [1547443.270136] beta systemd[1]: Starting data mesher daemon...
beta # [1547443.271434] beta systemd[1]: Starting Import lastlog data into lastlog2 database...
beta # [1547443.273049] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)...
beta # [1547443.275166] beta systemd[1]: Starting D-Bus System Message Bus...
beta # [1547443.291498] beta systemd[1]: Finished Import lastlog data into lastlog2 database.
alpha # [1547443.209918] alpha systemd-resolved[125]: Positive Trust Anchors:
alpha # [1547443.209929] alpha systemd-resolved[125]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
alpha # [1547443.209933] alpha systemd-resolved[125]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
alpha # [1547443.209968] alpha systemd-resolved[125]: 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 # [1547443.232966] alpha systemd-resolved[125]: Using system hostname 'alpha'.
alpha # [1547443.234396] alpha systemd[1]: Started Network Name Resolution.
alpha # [1547443.234541] alpha systemd[1]: Reached target Network.
alpha # [1547443.234661] alpha systemd[1]: Reached target System Initialization.
alpha # [1547443.234763] alpha systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
alpha # [1547443.234817] alpha systemd[1]: Started Daily Cleanup of Temporary Directories.
alpha # [1547443.234858] alpha systemd[1]: Reached target Timer Units.
alpha # [1547443.235100] alpha systemd[1]: Listening on D-Bus System Message Bus Socket.
alpha # [1547443.235318] alpha systemd[1]: Listening on Nix Daemon Socket.
alpha # [1547443.235542] alpha systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
alpha # [1547443.235590] alpha systemd[1]: Reached target Socket Units.
alpha # [1547443.235673] alpha systemd[1]: Reached target Basic System.
alpha # [1547443.270097] alpha systemd[1]: Starting data mesher daemon...
alpha # [1547443.271355] alpha systemd[1]: Starting Import lastlog data into lastlog2 database...
alpha # [1547443.272729] alpha systemd[1]: Starting Name Service Cache Daemon (nsncd)...
alpha # [1547443.274879] alpha systemd[1]: Starting D-Bus System Message Bus...
alpha # [1547443.293172] alpha systemd[1]: Finished Import lastlog data into lastlog2 database.
alpha # [1547443.562745] alpha nsncd[215]: Sep 22 05:17:43.547 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
alpha # [1547443.562228] alpha systemd[1]: Started Name Service Cache Daemon (nsncd).
alpha # [1547443.562287] alpha systemd[1]: Reached target Host and Network Name Lookups.
alpha # [1547443.562351] alpha systemd[1]: Reached target User and Group Name Lookups.
alpha # [1547443.563671] alpha systemd[1]: Starting User Login Management...
alpha # [1547443.565455] alpha systemd[1]: Starting Permit User Sessions...
alpha # [1547443.607518] alpha systemd[1]: Finished Permit User Sessions.
alpha # [1547443.609268] alpha systemd[1]: Started Console Getty.
alpha # [1547443.609351] alpha systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
alpha # [1547443.609398] alpha systemd[1]: Reached target Login Prompts.
alpha # [1547443.763118] alpha dbus-broker-launch[216]: Looking up NSS user entry for 'systemd-timesync'...
alpha # [1547443.764114] alpha dbus-broker-launch[216]: NSS returned no entry for 'systemd-timesync'
alpha # [1547443.764114] alpha dbus-broker-launch[216]: Invalid user-name in /nix/store/m8v4mzkv0041ab7vjwmmixfphibk9bym-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
alpha # [1547443.764584] alpha systemd[1]: Started D-Bus System Message Bus.
alpha # [1547443.772317] alpha dbus-broker-launch[216]: Ready
beta # [1547443.583205] beta nsncd[215]: Sep 22 05:17:43.568 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
beta # [1547443.583189] beta systemd[1]: Started Name Service Cache Daemon (nsncd).
beta # [1547443.583292] beta systemd[1]: Reached target Host and Network Name Lookups.
beta # [1547443.583405] beta systemd[1]: Reached target User and Group Name Lookups.
beta # [1547443.600413] beta systemd[1]: Starting User Login Management...
beta # [1547443.601320] beta systemd[1]: Starting Permit User Sessions...
beta # [1547443.612807] beta systemd[1]: Finished Permit User Sessions.
beta # [1547443.614138] beta systemd[1]: Started Console Getty.
beta # [1547443.614192] beta systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
beta # [1547443.614217] beta systemd[1]: Reached target Login Prompts.
beta # [1547443.763120] beta dbus-broker-launch[216]: Looking up NSS user entry for 'systemd-timesync'...
beta # [1547443.765369] beta dbus-broker-launch[216]: NSS returned no entry for 'systemd-timesync'
beta # [1547443.765369] beta dbus-broker-launch[216]: Invalid user-name in /nix/store/m8v4mzkv0041ab7vjwmmixfphibk9bym-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
beta # [1547443.765789] beta systemd[1]: Started D-Bus System Message Bus.
beta # [1547443.774922] beta dbus-broker-launch[216]: Ready
gamma # [1547443.574450] gamma nsncd[215]: Sep 22 05:17:43.560 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
gamma # [1547443.574477] gamma systemd[1]: Started Name Service Cache Daemon (nsncd).
gamma # [1547443.574535] gamma systemd[1]: Reached target Host and Network Name Lookups.
gamma # [1547443.574596] gamma systemd[1]: Reached target User and Group Name Lookups.
gamma # [1547443.600413] gamma systemd[1]: Starting User Login Management...
gamma # [1547443.601268] gamma systemd[1]: Starting Permit User Sessions...
gamma # [1547443.611244] gamma systemd[1]: Finished Permit User Sessions.
gamma # [1547443.612251] gamma systemd[1]: Started Console Getty.
gamma # [1547443.612292] gamma systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
gamma # [1547443.612310] gamma systemd[1]: Reached target Login Prompts.
gamma # [1547443.779413] gamma dbus-broker-launch[216]: Looking up NSS user entry for 'systemd-timesync'...
gamma # [1547443.780582] gamma dbus-broker-launch[216]: NSS returned no entry for 'systemd-timesync'
gamma # [1547443.780620] gamma dbus-broker-launch[216]: Invalid user-name in /nix/store/m8v4mzkv0041ab7vjwmmixfphibk9bym-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
gamma # [1547443.781102] gamma systemd[1]: Started D-Bus System Message Bus.
gamma # [1547443.788078] gamma dbus-broker-launch[216]: Ready
alpha # [1547444.290527] alpha systemd-networkd[197]: eth1: Gained IPv6LL
alpha # [1547444.317112] alpha data-mesher[213]: time=2026-09-22T05:17:44.302Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
alpha # [1547444.318203] alpha data-mesher[213]: time=2026-09-22T05:17:44.303Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg: [/dns/alpha.clan/tcp/7946]} {12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
alpha # [1547444.318203] alpha data-mesher[213]: time=2026-09-22T05:17:44.304Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
alpha # [1547444.319357] alpha data-mesher[213]: time=2026-09-22T05:17:44.305Z level=INFO msg="checking file integrity"
alpha # [1547444.319475] alpha data-mesher[213]: time=2026-09-22T05:17:44.305Z level=INFO msg="file integrity check complete"
alpha # [1547444.323334] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="libp2p host created" peer_id=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg 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 # [1547444.323334] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="registered HTTP route" method=GET path=/files
alpha # [1547444.323467] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
alpha # [1547444.323467] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
alpha # [1547444.323467] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="starting server"
alpha # [1547444.323467] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="waiting for DHT to populate" delay=10s
alpha # [1547444.323654] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="HTTP server listening" address=[::1]:7331
alpha # [1547444.323654] alpha data-mesher[213]: time=2026-09-22T05:17:44.309Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
alpha # [1547444.328095] alpha data-mesher[213]: time=2026-09-22T05:17:44.313Z level=INFO msg="peer connected" peer_id=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC remote_addr=/ip4/192.168.1.2/tcp/7946
alpha # [1547444.361686] alpha data-mesher[213]: time=2026-09-22T05:17:44.347Z level=INFO msg="peer connected" peer_id=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC remote_addr=/ip4/192.168.1.3/tcp/7946
beta # [1547444.308523] beta data-mesher[213]: time=2026-09-22T05:17:44.294Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
beta # [1547444.309608] beta data-mesher[213]: time=2026-09-22T05:17:44.295Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg: [/dns/alpha.clan/tcp/7946]} {12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
beta # [1547444.309608] beta data-mesher[213]: time=2026-09-22T05:17:44.295Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
beta # [1547444.310894] beta data-mesher[213]: time=2026-09-22T05:17:44.296Z level=INFO msg="checking file integrity"
beta # [1547444.311031] beta data-mesher[213]: time=2026-09-22T05:17:44.296Z level=INFO msg="file integrity check complete"
beta # [1547444.315285] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="libp2p host created" peer_id=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC 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 # [1547444.315346] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="registered HTTP route" method=GET path=/files
beta # [1547444.315346] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
beta # [1547444.315346] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
beta # [1547444.315346] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="starting server"
beta # [1547444.315459] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="waiting for DHT to populate" delay=10s
beta # [1547444.315523] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="HTTP server listening" address=[::1]:7331
beta # [1547444.315579] beta data-mesher[213]: time=2026-09-22T05:17:44.301Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
beta # [1547444.328758] beta data-mesher[213]: time=2026-09-22T05:17:44.314Z level=INFO msg="peer connected" peer_id=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg remote_addr=/ip4/192.168.1.1/tcp/7946
beta # [1547444.352223] beta systemd-networkd[197]: eth1: Gained IPv6LL
beta # [1547444.369249] beta data-mesher[213]: time=2026-09-22T05:17:44.355Z level=INFO msg="peer connected" peer_id=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC remote_addr=/ip4/192.168.1.3/tcp/7946
gamma # [1547444.347970] gamma data-mesher[213]: time=2026-09-22T05:17:44.333Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
gamma # [1547444.349111] gamma data-mesher[213]: time=2026-09-22T05:17:44.334Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg: [/dns/alpha.clan/tcp/7946]} {12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
gamma # [1547444.349111] gamma data-mesher[213]: time=2026-09-22T05:17:44.334Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
gamma # [1547444.351241] gamma data-mesher[213]: time=2026-09-22T05:17:44.337Z level=INFO msg="checking file integrity"
gamma # [1547444.351592] gamma data-mesher[213]: time=2026-09-22T05:17:44.337Z level=INFO msg="file integrity check complete"
gamma # [1547444.355598] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="libp2p host created" peer_id=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC 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 # [1547444.355633] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
gamma # [1547444.355633] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
gamma # [1547444.355633] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="registered HTTP route" method=GET path=/files
gamma # [1547444.355693] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="starting server"
gamma # [1547444.355738] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="waiting for DHT to populate" delay=10s
gamma # [1547444.355881] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="HTTP server listening" address=[::1]:7331
gamma # [1547444.355944] gamma data-mesher[213]: time=2026-09-22T05:17:44.341Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
gamma # [1547444.360718] gamma data-mesher[213]: time=2026-09-22T05:17:44.346Z level=INFO msg="peer connected" peer_id=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg remote_addr=/ip4/192.168.1.1/tcp/7946
gamma # [1547444.368037] gamma data-mesher[213]: time=2026-09-22T05:17:44.353Z level=INFO msg="peer connected" peer_id=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC remote_addr=/ip4/192.168.1.2/tcp/7946
gamma # [1547444.416173] gamma systemd-networkd[197]: eth1: Gained IPv6LL
gamma # [1547444.566243] gamma systemd-logind[232]: New seat seat0.
gamma # [1547444.566482] gamma systemd[1]: Started User Login Management.
gamma # [1547444.568668] gamma systemd[1]: Starting linger-users.service...
alpha # [1547444.575225] alpha systemd-logind[232]: New seat seat0.
alpha # [1547444.576274] alpha systemd[1]: Started User Login Management.
alpha # [1547444.600812] alpha systemd[1]: Starting linger-users.service...
alpha # [1547444.616211] alpha systemd[1]: linger-users.service: Deactivated successfully.
alpha # [1547444.616319] alpha systemd[1]: Finished linger-users.service.
gamma # [1547444.610365] gamma systemd[1]: linger-users.service: Deactivated successfully.
gamma # [1547444.610626] gamma systemd[1]: Finished linger-users.service.
beta # [1547444.575828] beta systemd-logind[232]: New seat seat0.
beta # [1547444.576023] beta systemd[1]: Started User Login Management.
beta # [1547444.600660] beta systemd[1]: Starting linger-users.service...
beta # [1547444.612361] beta systemd[1]: linger-users.service: Deactivated successfully.
beta # [1547444.612571] beta systemd[1]: Finished linger-users.service.
alpha: still waiting for container 'alpha' to reach ready state...
alpha: (finished: waiting for unit data-mesher.service, in 13.68 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/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-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/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.05 seconds)
??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/z312acj8n2ggn1w3agk97mbvdsm371iw-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/z312acj8n2ggn1w3agk97mbvdsm371iw-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 # [1547454.316160] alpha data-mesher[213]: time=2026-09-22T05:17:54.301Z level=INFO msg="received state sync from peer" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547454.316160] alpha data-mesher[213]: time=2026-09-22T05:17:54.301Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547454.323893] alpha data-mesher[213]: time=2026-09-22T05:17:54.309Z level=INFO msg="performing state exchange with peers on join" count=1
alpha # [1547454.323993] alpha data-mesher[213]: time=2026-09-22T05:17:54.309Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547454.324801] alpha data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547454.324801] alpha data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547454.324863] alpha data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="server started"
alpha # [1547454.325098] alpha data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="starting expired-file sweeper" interval=1m0s
alpha # [1547454.325663] alpha systemd[1]: Started data mesher daemon.
alpha # [1547454.326176] alpha systemd[1]: Reached target Multi-User System.
alpha # [1547454.326510] alpha systemd[1]: Startup finished in 13.060s.
alpha # [1547454.489072] alpha data-mesher[213]: time=2026-09-22T05:17:54.474Z level=INFO msg=http_request uri=/files/test_file status=204
gamma # [1547454.356382] gamma data-mesher[213]: time=2026-09-22T05:17:54.342Z level=INFO msg="performing state exchange with peers on join" count=1
gamma # [1547454.356812] gamma data-mesher[213]: time=2026-09-22T05:17:54.342Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547454.357354] gamma data-mesher[213]: time=2026-09-22T05:17:54.343Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547454.357354] gamma data-mesher[213]: time=2026-09-22T05:17:54.343Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547454.357452] gamma data-mesher[213]: time=2026-09-22T05:17:54.343Z level=INFO msg="server started"
gamma # [1547454.357517] gamma data-mesher[213]: time=2026-09-22T05:17:54.343Z level=INFO msg="starting expired-file sweeper" interval=1m0s
gamma # [1547454.357690] gamma systemd[1]: Started data mesher daemon.
gamma # [1547454.357991] gamma systemd[1]: Reached target Multi-User System.
gamma # [1547454.358202] gamma systemd[1]: Startup finished in 13.089s.
beta # [1547454.315575] beta data-mesher[213]: time=2026-09-22T05:17:54.301Z level=INFO msg="performing state exchange with peers on join" count=1
beta # [1547454.316332] beta data-mesher[213]: time=2026-09-22T05:17:54.301Z level=DEBUG msg="initiating state exchange" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547454.316332] beta data-mesher[213]: time=2026-09-22T05:17:54.302Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547454.316454] beta data-mesher[213]: time=2026-09-22T05:17:54.302Z level=INFO msg="state exchange complete" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547454.316454] beta data-mesher[213]: time=2026-09-22T05:17:54.302Z level=INFO msg="server started"
beta # [1547454.316566] beta data-mesher[213]: time=2026-09-22T05:17:54.302Z level=INFO msg="starting expired-file sweeper" interval=1m0s
beta # [1547454.316682] beta systemd[1]: Started data mesher daemon.
beta # [1547454.316981] beta systemd[1]: Reached target Multi-User System.
beta # [1547454.317264] beta systemd[1]: Startup finished in 13.044s.
beta # [1547454.324644] beta data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="received state sync from peer" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547454.324644] beta data-mesher[213]: time=2026-09-22T05:17:54.310Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547454.357047] beta data-mesher[213]: time=2026-09-22T05:17:54.342Z level=INFO msg="received state sync from peer" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
beta # [1547454.357098] beta data-mesher[213]: time=2026-09-22T05:17:54.342Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
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.05 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/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key
beta # [1547459.317393] beta data-mesher[213]: time=2026-09-22T05:17:59.303Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [1547459.318068] beta data-mesher[213]: time=2026-09-22T05:17:59.303Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC timeout=5s
beta # [1547459.318223] beta data-mesher[213]: time=2026-09-22T05:17:59.304Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
beta # [1547459.318223] beta data-mesher[213]: time=2026-09-22T05:17:59.304Z level=INFO msg="state exchange complete" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC timeout=5s
beta # [1547459.318335] beta data-mesher[213]: time=2026-09-22T05:17:59.304Z level=DEBUG msg="push/pull successful" interval=5s
beta # [1547459.326056] beta data-mesher[213]: time=2026-09-22T05:17:59.311Z level=INFO msg="received state sync from peer" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547459.326056] beta data-mesher[213]: time=2026-09-22T05:17:59.311Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547459.326231] beta data-mesher[213]: time=2026-09-22T05:17:59.311Z level=DEBUG msg="new file detected" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg name=test_file name=test_file
beta # [1547459.326231] beta data-mesher[213]: time=2026-09-22T05:17:59.312Z level=INFO msg="scheduling file download" name=test_file
beta # [1547459.326336] beta data-mesher[213]: time=2026-09-22T05:17:59.312Z level=INFO msg="downloading file" name=test_file signed_at="2026-09-22 05:17:54.453 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547459.381231] beta data-mesher[213]: time=2026-09-22T05:17:59.367Z level=INFO msg="download complete" name=test_file signed_at="2026-09-22 05:17:54.453 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg written=true elapsed=54.964947ms
beta # [1547459.588135] beta data-mesher[213]: time=2026-09-22T05:17:59.573Z level=INFO msg=http_request uri=/files/test_file status=204
beta: (finished: waiting for success: data-mesher file delete test_file --network-id /nix/store/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.03 seconds)
alpha: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file
alpha # [1547459.325376] alpha data-mesher[213]: time=2026-09-22T05:17:59.311Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [1547459.325376] alpha data-mesher[213]: time=2026-09-22T05:17:59.311Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547459.326277] alpha data-mesher[213]: time=2026-09-22T05:17:59.312Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547459.326277] alpha data-mesher[213]: time=2026-09-22T05:17:59.312Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547459.326405] alpha data-mesher[213]: time=2026-09-22T05:17:59.312Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [1547459.326798] alpha data-mesher[213]: time=2026-09-22T05:17:59.312Z level=INFO msg="received file request" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_file
alpha # [1547459.328885] alpha data-mesher[213]: time=2026-09-22T05:17:59.314Z level=INFO msg="file transfer complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_file
alpha # [1547459.358301] alpha data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="received state sync from peer" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
alpha # [1547459.358301] alpha data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
alpha # [1547459.359087] alpha data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="received file request" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_file
alpha # [1547459.361028] alpha data-mesher[213]: time=2026-09-22T05:17:59.346Z level=INFO msg="file transfer complete" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_file
gamma # [1547459.318044] gamma data-mesher[213]: time=2026-09-22T05:17:59.303Z level=INFO msg="received state sync from peer" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547459.318044] gamma data-mesher[213]: time=2026-09-22T05:17:59.303Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547459.357753] gamma data-mesher[213]: time=2026-09-22T05:17:59.343Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [1547459.357886] gamma data-mesher[213]: time=2026-09-22T05:17:59.343Z level=DEBUG msg="initiating state exchange" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
gamma # [1547459.358560] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
gamma # [1547459.358612] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=DEBUG msg="new file detected" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg name=test_file name=test_file
gamma # [1547459.358612] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="state exchange complete" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
gamma # [1547459.358671] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [1547459.358701] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="scheduling file download" name=test_file
gamma # [1547459.358738] gamma data-mesher[213]: time=2026-09-22T05:17:59.344Z level=INFO msg="downloading file" name=test_file signed_at="2026-09-22 05:17:54.453 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
gamma # [1547459.381771] gamma data-mesher[213]: time=2026-09-22T05:17:59.367Z level=INFO msg="download complete" name=test_file signed_at="2026-09-22 05:17:54.453 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg written=true elapsed=23.027592ms
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/l8fy3mprqpbmza707a3jv7rn5cg55cqq-per-machine-alpha-data-mesher-node-identity_identity.pub
alpha # [1547464.319441] alpha data-mesher[213]: time=2026-09-22T05:18:04.305Z level=INFO msg="received state sync from peer" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547464.319441] alpha data-mesher[213]: time=2026-09-22T05:18:04.305Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547464.326838] alpha data-mesher[213]: time=2026-09-22T05:18:04.312Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [1547464.326838] alpha data-mesher[213]: time=2026-09-22T05:18:04.312Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC timeout=5s
alpha # [1547464.327645] alpha data-mesher[213]: time=2026-09-22T05:18:04.313Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
alpha # [1547464.327740] alpha data-mesher[213]: time=2026-09-22T05:18:04.313Z level=INFO msg="state exchange complete" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC timeout=5s
alpha # [1547464.327740] alpha data-mesher[213]: time=2026-09-22T05:18:04.313Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [1547464.336784] alpha data-mesher[213]: time=2026-09-22T05:18:04.322Z level=DEBUG msg="imported tombstone" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC name=test_file written=true
alpha: (finished: must succeed: cat /nix/store/l8fy3mprqpbmza707a3jv7rn5cg55cqq-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/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-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/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-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/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
alpha: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE, in 0.01 seconds)
beta: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
gamma # [1547464.327391] gamma data-mesher[213]: time=2026-09-22T05:18:04.313Z level=INFO msg="received state sync from peer" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
gamma # [1547464.327391] gamma data-mesher[213]: time=2026-09-22T05:18:04.313Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
gamma # [1547464.359514] gamma data-mesher[213]: time=2026-09-22T05:18:04.345Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [1547464.359613] gamma data-mesher[213]: time=2026-09-22T05:18:04.345Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547464.360257] gamma data-mesher[213]: time=2026-09-22T05:18:04.346Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547464.366527] gamma data-mesher[213]: time=2026-09-22T05:18:04.352Z level=DEBUG msg="imported tombstone" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC name=test_file written=true
gamma # [1547464.366527] gamma data-mesher[213]: time=2026-09-22T05:18:04.352Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547464.366664] gamma data-mesher[213]: time=2026-09-22T05:18:04.352Z level=DEBUG msg="push/pull successful" interval=5s
beta # [1547464.318668] beta data-mesher[213]: time=2026-09-22T05:18:04.304Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [1547464.318668] beta data-mesher[213]: time=2026-09-22T05:18:04.304Z level=DEBUG msg="initiating state exchange" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547464.337204] beta data-mesher[213]: time=2026-09-22T05:18:04.323Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547464.337292] beta data-mesher[213]: time=2026-09-22T05:18:04.323Z level=INFO msg="state exchange complete" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547464.337292] beta data-mesher[213]: time=2026-09-22T05:18:04.323Z level=DEBUG msg="push/pull successful" interval=5s
beta # [1547464.359999] beta data-mesher[213]: time=2026-09-22T05:18:04.345Z level=INFO msg="received state sync from peer" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
beta # [1547464.360068] beta data-mesher[213]: time=2026-09-22T05:18:04.345Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
alpha # [1547464.688274] alpha data-mesher[213]: time=2026-09-22T05:18:04.674Z level=INFO msg=http_request uri=/files/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE status=204
alpha # [1547469.328778] alpha data-mesher[213]: time=2026-09-22T05:18:09.314Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [1547469.329164] alpha data-mesher[213]: time=2026-09-22T05:18:09.314Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547469.330635] alpha data-mesher[213]: time=2026-09-22T05:18:09.316Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
alpha # [1547469.330674] alpha data-mesher[213]: time=2026-09-22T05:18:09.316Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
alpha # [1547469.330737] alpha data-mesher[213]: time=2026-09-22T05:18:09.316Z level=INFO msg="received file request" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
alpha # [1547469.330765] alpha data-mesher[213]: time=2026-09-22T05:18:09.316Z level=DEBUG msg="push/pull successful" interval=5s
beta # [1547469.329621] beta data-mesher[213]: time=2026-09-22T05:18:09.315Z level=INFO msg="received state sync from peer" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
alpha # [1547469.332499] alpha data-mesher[213]: time=2026-09-22T05:18:09.318Z level=INFO msg="file transfer complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
beta # [1547469.329621] beta data-mesher[213]: time=2026-09-22T05:18:09.315Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
alpha # [1547469.338580] alpha data-mesher[213]: time=2026-09-22T05:18:09.324Z level=INFO msg="received state sync from peer" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
beta # [1547469.330374] beta data-mesher[213]: time=2026-09-22T05:18:09.316Z level=DEBUG msg="new file detected" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg name=test_file name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
alpha # [1547469.338614] alpha data-mesher[213]: time=2026-09-22T05:18:09.324Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
beta # [1547469.330374] beta data-mesher[213]: time=2026-09-22T05:18:09.316Z level=INFO msg="scheduling file download" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
beta # [1547469.330489] beta data-mesher[213]: time=2026-09-22T05:18:09.316Z level=INFO msg="downloading file" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE signed_at="2026-09-22 05:18:04.672 +0000 UTC" signed_by="Wt7BT+SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547469.334559] beta data-mesher[213]: time=2026-09-22T05:18:09.320Z level=INFO msg="download complete" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE signed_at="2026-09-22 05:18:04.672 +0000 UTC" signed_by="Wt7BT+SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE=" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg written=true elapsed=4.044735ms
beta # [1547469.337928] beta data-mesher[213]: time=2026-09-22T05:18:09.323Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [1547469.337928] beta data-mesher[213]: time=2026-09-22T05:18:09.323Z level=DEBUG msg="initiating state exchange" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547469.339617] beta data-mesher[213]: time=2026-09-22T05:18:09.325Z level=INFO msg="merging remote state" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg
beta # [1547469.340270] beta data-mesher[213]: time=2026-09-22T05:18:09.326Z level=INFO msg="state exchange complete" peer=12D3KooWFw5sG68cV874W7eqjFt4bbrJNdMi2U9BtPgDF3TEJsSg timeout=5s
beta # [1547469.340344] beta data-mesher[213]: time=2026-09-22T05:18:09.326Z level=DEBUG msg="push/pull successful" interval=5s
beta # [1547469.368244] beta data-mesher[213]: time=2026-09-22T05:18:09.354Z level=INFO msg="received state sync from peer" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
beta # [1547469.368244] beta data-mesher[213]: time=2026-09-22T05:18:09.354Z level=INFO msg="merging remote state" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC
beta # [1547469.370154] beta data-mesher[213]: time=2026-09-22T05:18:09.355Z level=INFO msg="received file request" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
beta # [1547469.371807] beta data-mesher[213]: time=2026-09-22T05:18:09.357Z level=INFO msg="file transfer complete" peer=12D3KooW9tB8rn6Yes5AtcaEnE2K4SU1GavQEktzYyi8P861CfVC network="1g0qqEtcVQyNd9Qjx2U4g++P354YSDGL9EQql7tnxpQ=" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
gamma # [1547469.367626] gamma data-mesher[213]: time=2026-09-22T05:18:09.353Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [1547469.368028] gamma data-mesher[213]: time=2026-09-22T05:18:09.353Z level=DEBUG msg="initiating state exchange" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547469.368784] gamma data-mesher[213]: time=2026-09-22T05:18:09.354Z level=INFO msg="merging remote state" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547469.369372] gamma data-mesher[213]: time=2026-09-22T05:18:09.355Z level=DEBUG msg="new file detected" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC name=test_file name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
gamma # [1547469.369401] gamma data-mesher[213]: time=2026-09-22T05:18:09.355Z level=INFO msg="state exchange complete" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC timeout=5s
gamma # [1547469.369453] gamma data-mesher[213]: time=2026-09-22T05:18:09.355Z level=INFO msg="scheduling file download" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
gamma # [1547469.369518] gamma data-mesher[213]: time=2026-09-22T05:18:09.355Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [1547469.369545] gamma data-mesher[213]: time=2026-09-22T05:18:09.355Z level=INFO msg="downloading file" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE signed_at="2026-09-22 05:18:04.672 +0000 UTC" signed_by="Wt7BT+SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE=" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC
gamma # [1547469.373305] gamma data-mesher[213]: time=2026-09-22T05:18:09.359Z level=INFO msg="download complete" name=test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE signed_at="2026-09-22 05:18:04.672 +0000 UTC" signed_by="Wt7BT+SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE=" peer=12D3KooWR13z5XBtBndH4BqE5sFAS1jT9S36EK5FaiX3VMJLsSUC written=true elapsed=3.804172ms
beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE, in 5.05 seconds)
gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE, 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/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-shared-data-mesher-network_network.pub
Error: failed to update file: 403 Forbidden, signer Wt7BT+SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE= is not authorized for this file test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE
alpha: (finished: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/70h8fdn9fkz8b7ypbc28gw5nsjd8ymdf-shared-data-mesher-network_network.pub, in 0.03 seconds)
(finished: run the VM test script, in 29.08 seconds)
test script finished in 29.33s
cleanup
kill NspawnMachine (pid 53)
alpha # [1547469.796477] alpha data-mesher[213]: time=2026-09-22T05:18:09.782Z level=INFO msg=http_request uri=/files/test_ns/Wt7BT-SAeJ4rzEQztWnNCCLovQNBJzSh0W9fg8WWIRE status=403
kill NspawnMachine (pid 54)
Container alpha terminated by signal KILL.
kill NspawnMachine (pid 56)
Container beta terminated by signal KILL.
Container gamma terminated by signal KILL.
(finished: cleanup, in 0.49 seconds)