Machine state will be reset. To keep it, pass --keep-machine-state
start all VLans
(finished: start all VLans, in 0.00 seconds)

Test will time out and terminate in 3600.0 seconds
run the VM test script
additionally exposed symbols:
    alpha, beta, gamma,
    vlan1,
    start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh
start all VMs
alpha: systemd-nspawn running (pid 53)
beta: systemd-nspawn running (pid 54)
gamma: systemd-nspawn running (pid 55)
alpha: Waiting for journal at /build/vm-state-alpha/var/log/journal...
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(gamma): TAP vde-tap1 not found; container will be isolated from VDE
nixos-nspawn(gamma): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.
nixos-nspawn(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(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.
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 gamma on /build/vm-state-gamma.
░ Spawning container beta on /build/vm-state-beta.
beta # No journal files were found.
gamma # No journal files were found.
beta # No journal boot entry found for the specified boot (+0).
gamma # 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).
beta # [6727659.246954] beta systemd-journald[87]: Journal started
beta # [6727659.247009] beta systemd-journald[87]: Runtime Journal (/run/log/journal/644b3c539bc94e7db3655e8b4b608b74) is 8M, max 2.5G, 2.4G free.
beta # [6727659.265640] beta systemd[1]: Starting Flush Journal to Persistent Storage...
beta # [6727659.266498] beta systemd[1]: Starting Network Name Resolution...
beta # [6727659.267218] beta systemd[1]: Starting Create Static Device Nodes in /dev...
beta # [6727659.275384] beta systemd-journald[87]: Time spent on flushing to /var/log/journal/644b3c539bc94e7db3655e8b4b608b74 is 1.621ms for 5 entries.
beta # [6727659.275384] beta systemd-journald[87]: System Journal (/var/log/journal/644b3c539bc94e7db3655e8b4b608b74) is 8M, max 4G, 3.9G free.
beta # [6727659.292212] beta systemd[1]: Finished Create Static Device Nodes in /dev.
beta # [6727659.292538] beta systemd[1]: Reached target Preparation for Local File Systems.
beta # [6727659.292626] beta systemd[1]: Reached target Local File Systems.
beta # [6727659.293453] beta systemd[1]: Listening on Boot Loader Control Service Socket.
beta # [6727659.293500] beta systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
beta # [6727659.294472] beta systemd[1]: Starting Save Transient machine-id to Disk...
beta # [6727659.294509] beta systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
beta # [6727659.452300] beta systemd[1]: Finished Firewall.
beta # [6727659.452770] beta systemd[1]: Finished Flush Journal to Persistent Storage.
beta # [6727659.454003] beta systemd[1]: Reached target Preparation for Network.
beta # [6727659.454317] beta systemd[1]: Listening on Network Management Resolve Hook Socket.
beta # [6727659.455870] beta systemd[1]: Starting Network Management...
beta # [6727659.456719] beta systemd[1]: Starting Create System Files and Directories...
beta # [6727659.471747] beta systemd-tmpfiles[197]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
beta # [6727659.471931] beta systemd-tmpfiles[197]: fchmod() of /var/log/journal failed: Operation not permitted
beta # [6727659.472294] beta systemd-tmpfiles[197]: fchmod() of /var/log/journal/644b3c539bc94e7db3655e8b4b608b74 failed: Operation not permitted
beta # [6727659.472494] beta systemd-tmpfiles[197]: fchmod() of /run/log/journal failed: Operation not permitted
beta # [6727659.474957] beta systemd[1]: Finished Create System Files and Directories.
beta # [6727659.477603] beta systemd[1]: Starting Rebuild Journal Catalog...
beta # [6727659.478642] beta systemd[1]: Starting Record System Boot/Shutdown in UTMP...
beta # [6727659.490993] beta systemd[1]: Finished Record System Boot/Shutdown in UTMP.
beta # [6727659.498900] beta systemd[1]: Finished Rebuild Journal Catalog.
beta # [6727659.500690] beta systemd[1]: Starting Update is Completed...
beta # [6727659.514447] beta systemd[1]: Finished Update is Completed.
beta # [6727660.097756] beta systemd-networkd[196]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
beta # [6727660.097854] beta systemd-networkd[196]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
beta # [6727660.104593] beta systemd-networkd[196]: /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 # [6727660.104758] beta systemd-networkd[196]: /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 # [6727660.104919] beta systemd-networkd[196]: lo: Link UP
beta # [6727660.104923] beta systemd-networkd[196]: lo: Gained carrier
beta # [6727660.105104] beta systemd-networkd[196]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
beta # [6727660.105540] beta systemd[1]: Started Network Management.
beta # [6727660.105617] beta systemd-networkd[196]: eth1: Link UP
beta # [6727660.105833] beta systemd-networkd[196]: eth1: Gained carrier
beta # [6727660.106553] beta systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
alpha # [6727659.244490] alpha systemd-journald[87]: Journal started
alpha # [6727659.244555] alpha systemd-journald[87]: Runtime Journal (/run/log/journal/dfdae8cac650459a8378d17a14de9106) is 8M, max 2.5G, 2.4G free.
alpha # [6727659.247549] alpha systemd[1]: Starting Flush Journal to Persistent Storage...
alpha # [6727659.257112] alpha systemd[1]: Finished Create Static Device Nodes in /dev.
alpha # [6727659.257388] alpha systemd[1]: Reached target Preparation for Local File Systems.
alpha # [6727659.257487] alpha systemd[1]: Reached target Local File Systems.
alpha # [6727659.258085] alpha systemd-journald[87]: Time spent on flushing to /var/log/journal/dfdae8cac650459a8378d17a14de9106 is 2.154ms for 6 entries.
alpha # [6727659.258085] alpha systemd-journald[87]: System Journal (/var/log/journal/dfdae8cac650459a8378d17a14de9106) is 8M, max 4G, 3.9G free.
alpha # [6727659.258288] alpha systemd[1]: Listening on Boot Loader Control Service Socket.
alpha # [6727659.258336] alpha systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
alpha # [6727659.259255] alpha systemd[1]: Starting Save Transient machine-id to Disk...
alpha # [6727659.259290] alpha systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
alpha # [6727659.452739] alpha systemd[1]: Finished Firewall.
alpha # [6727659.453046] alpha systemd[1]: Finished Flush Journal to Persistent Storage.
alpha # [6727659.453875] alpha systemd[1]: Reached target Preparation for Network.
alpha # [6727659.454278] alpha systemd[1]: Listening on Network Management Resolve Hook Socket.
alpha # [6727659.455356] alpha systemd[1]: Starting Network Management...
alpha # [6727659.456049] alpha systemd[1]: Starting Create System Files and Directories...
alpha # [6727659.471806] alpha systemd-tmpfiles[197]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
alpha # [6727659.471989] alpha systemd-tmpfiles[197]: fchmod() of /var/log/journal failed: Operation not permitted
alpha # [6727659.472750] alpha systemd-tmpfiles[197]: fchmod() of /var/log/journal/dfdae8cac650459a8378d17a14de9106 failed: Operation not permitted
alpha # [6727659.472947] alpha systemd-tmpfiles[197]: fchmod() of /run/log/journal failed: Operation not permitted
alpha # [6727659.477643] alpha systemd[1]: Finished Create System Files and Directories.
alpha # [6727659.478886] alpha systemd[1]: Starting Rebuild Journal Catalog...
alpha # [6727659.479694] alpha systemd[1]: Starting Record System Boot/Shutdown in UTMP...
alpha # [6727659.491012] alpha systemd[1]: Finished Record System Boot/Shutdown in UTMP.
alpha # [6727659.499843] alpha systemd[1]: Finished Rebuild Journal Catalog.
alpha # [6727659.500885] alpha systemd[1]: Starting Update is Completed...
alpha # [6727659.512734] alpha systemd[1]: Finished Update is Completed.
alpha # [6727660.094520] alpha systemd-networkd[196]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
alpha # [6727660.094622] alpha systemd-networkd[196]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
alpha # [6727660.101572] alpha systemd-networkd[196]: /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 # [6727660.101735] alpha systemd-networkd[196]: /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 # [6727660.101920] alpha systemd-networkd[196]: lo: Link UP
alpha # [6727660.101924] alpha systemd-networkd[196]: lo: Gained carrier
alpha # [6727660.102132] alpha systemd-networkd[196]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
alpha # [6727660.102556] alpha systemd[1]: Started Network Management.
alpha # [6727660.102639] alpha systemd-networkd[196]: eth1: Link UP
alpha # [6727660.102865] alpha systemd-networkd[196]: eth1: Gained carrier
alpha # [6727660.103636] alpha systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
gamma # [6727659.246826] gamma systemd-journald[87]: Journal started
gamma # [6727659.246885] gamma systemd-journald[87]: Runtime Journal (/run/log/journal/3ff398f145b448d6a3dd0f978ccec440) is 8M, max 2.5G, 2.4G free.
gamma # [6727659.256875] gamma systemd[1]: Starting Flush Journal to Persistent Storage...
gamma # [6727659.257372] gamma systemd[1]: Finished Create Static Device Nodes in /dev.
gamma # [6727659.258122] gamma systemd[1]: Reached target Preparation for Local File Systems.
gamma # [6727659.258240] gamma systemd[1]: Reached target Local File Systems.
gamma # [6727659.259053] gamma systemd[1]: Listening on Boot Loader Control Service Socket.
gamma # [6727659.259101] gamma systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
gamma # [6727659.260270] gamma systemd[1]: Starting Save Transient machine-id to Disk...
gamma # [6727659.260315] gamma systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
gamma # [6727659.266397] gamma systemd-journald[87]: Time spent on flushing to /var/log/journal/3ff398f145b448d6a3dd0f978ccec440 is 1.742ms for 10 entries.
gamma # [6727659.266397] gamma systemd-journald[87]: System Journal (/var/log/journal/3ff398f145b448d6a3dd0f978ccec440) is 8M, max 4G, 3.9G free.
gamma # [6727659.399718] gamma systemd[1]: Finished Firewall.
gamma # [6727659.399898] gamma systemd[1]: Reached target Preparation for Network.
gamma # [6727659.400159] gamma systemd[1]: Listening on Network Management Resolve Hook Socket.
gamma # [6727659.401387] gamma systemd[1]: Starting Network Management...
gamma # [6727659.452373] gamma systemd[1]: Finished Flush Journal to Persistent Storage.
gamma # [6727659.453958] gamma systemd[1]: Starting Create System Files and Directories...
gamma # [6727659.472868] gamma systemd-tmpfiles[198]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
gamma # [6727659.473082] gamma systemd-tmpfiles[198]: fchmod() of /var/log/journal failed: Operation not permitted
gamma # [6727659.473222] gamma systemd-tmpfiles[198]: fchmod() of /var/log/journal/3ff398f145b448d6a3dd0f978ccec440 failed: Operation not permitted
gamma # [6727659.473455] gamma systemd-tmpfiles[198]: fchmod() of /run/log/journal failed: Operation not permitted
gamma # [6727659.477699] gamma systemd[1]: Finished Create System Files and Directories.
gamma # [6727659.478904] gamma systemd[1]: Starting Rebuild Journal Catalog...
gamma # [6727659.479693] gamma systemd[1]: Starting Record System Boot/Shutdown in UTMP...
gamma # [6727659.490991] gamma systemd[1]: Finished Record System Boot/Shutdown in UTMP.
gamma # [6727659.499673] gamma systemd[1]: Finished Rebuild Journal Catalog.
gamma # [6727659.500845] gamma systemd[1]: Starting Update is Completed...
gamma # [6727659.512089] gamma systemd[1]: Finished Update is Completed.
gamma # [6727660.067044] gamma systemd-networkd[194]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted
gamma # [6727660.067137] gamma systemd-networkd[194]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted
gamma # [6727660.074125] gamma systemd-networkd[194]: /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 # [6727660.074296] gamma systemd-networkd[194]: /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 # [6727660.074480] gamma systemd-networkd[194]: lo: Link UP
gamma # [6727660.074484] gamma systemd-networkd[194]: lo: Gained carrier
gamma # [6727660.074699] gamma systemd-networkd[194]: eth1: Configuring with /etc/systemd/network/40-eth1.network.
gamma # [6727660.075191] gamma systemd[1]: Started Network Management.
gamma # [6727660.075223] gamma systemd-networkd[194]: eth1: Link UP
gamma # [6727660.075481] gamma systemd-networkd[194]: eth1: Gained carrier
gamma # [6727660.076374] gamma systemd[1]: Starting Enable Persistent Storage in systemd-networkd...
gamma # [6727660.166144] gamma systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
beta # [6727660.188518] beta systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
alpha # [6727660.193100] alpha systemd[1]: Finished Enable Persistent Storage in systemd-networkd.
alpha # [6727660.308798] alpha systemd-resolved[109]: Positive Trust Anchors:
alpha # [6727660.308817] alpha systemd-resolved[109]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
alpha # [6727660.308821] alpha systemd-resolved[109]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
alpha # [6727660.308858] alpha 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 # [6727660.386737] alpha systemd-resolved[109]: Using system hostname 'alpha'.
alpha # [6727660.392281] alpha systemd[1]: Started Network Name Resolution.
alpha # [6727660.392431] alpha systemd[1]: Reached target Network.
alpha # [6727660.392535] alpha systemd[1]: Reached target System Initialization.
alpha # [6727660.392583] alpha systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
alpha # [6727660.392618] alpha systemd[1]: Started Daily Cleanup of Temporary Directories.
alpha # [6727660.392636] alpha systemd[1]: Reached target Timer Units.
alpha # [6727660.392811] alpha systemd[1]: Listening on D-Bus System Message Bus Socket.
alpha # [6727660.392967] alpha systemd[1]: Listening on Nix Daemon Socket.
alpha # [6727660.393080] alpha systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
alpha # [6727660.393105] alpha systemd[1]: Reached target Socket Units.
alpha # [6727660.393149] alpha systemd[1]: Reached target Basic System.
alpha # [6727660.395997] alpha systemd[1]: Starting data mesher daemon...
alpha # [6727660.399929] alpha systemd[1]: Starting Import lastlog data into lastlog2 database...
alpha # [6727660.403377] alpha systemd[1]: Starting Name Service Cache Daemon (nsncd)...
alpha # [6727660.440243] alpha systemd[1]: Starting D-Bus System Message Bus...
alpha # [6727660.470886] alpha systemd[1]: Finished Import lastlog data into lastlog2 database.
beta # [6727660.436530] beta systemd-resolved[118]: Positive Trust Anchors:
beta # [6727660.436555] beta systemd-resolved[118]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
beta # [6727660.436558] beta systemd-resolved[118]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
beta # [6727660.436596] beta systemd-resolved[118]: 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 # [6727660.462764] beta systemd-resolved[118]: Using system hostname 'beta'.
beta # [6727660.465340] beta systemd[1]: Started Network Name Resolution.
beta # [6727660.465474] beta systemd[1]: Reached target Network.
beta # [6727660.465566] beta systemd[1]: Reached target System Initialization.
beta # [6727660.465621] beta systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
beta # [6727660.465653] beta systemd[1]: Started Daily Cleanup of Temporary Directories.
beta # [6727660.465676] beta systemd[1]: Reached target Timer Units.
beta # [6727660.465840] beta systemd[1]: Listening on D-Bus System Message Bus Socket.
beta # [6727660.465985] beta systemd[1]: Listening on Nix Daemon Socket.
beta # [6727660.466103] beta systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
beta # [6727660.466126] beta systemd[1]: Reached target Socket Units.
beta # [6727660.466171] beta systemd[1]: Reached target Basic System.
beta # [6727660.468901] beta systemd[1]: Starting data mesher daemon...
beta # [6727660.469992] beta systemd[1]: Starting Import lastlog data into lastlog2 database...
beta # [6727660.473697] beta systemd[1]: Starting Name Service Cache Daemon (nsncd)...
beta # [6727660.476169] beta systemd[1]: Starting D-Bus System Message Bus...
beta # [6727660.520683] beta systemd[1]: Finished Import lastlog data into lastlog2 database.
gamma # [6727660.765405] gamma systemd-resolved[110]: Positive Trust Anchors:
gamma # [6727660.765425] gamma systemd-resolved[110]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
gamma # [6727660.765429] gamma systemd-resolved[110]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16
gamma # [6727660.765465] gamma 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 # [6727660.823382] gamma systemd-resolved[110]: Using system hostname 'gamma'.
gamma # [6727660.832332] gamma systemd[1]: Started Network Name Resolution.
gamma # [6727660.832479] gamma systemd[1]: Reached target Network.
gamma # [6727660.832585] gamma systemd[1]: Reached target System Initialization.
gamma # [6727660.832639] gamma systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
gamma # [6727660.832669] gamma systemd[1]: Started Daily Cleanup of Temporary Directories.
gamma # [6727660.832688] gamma systemd[1]: Reached target Timer Units.
gamma # [6727660.832869] gamma systemd[1]: Listening on D-Bus System Message Bus Socket.
gamma # [6727660.833042] gamma systemd[1]: Listening on Nix Daemon Socket.
gamma # [6727660.833177] gamma systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
gamma # [6727660.833197] gamma systemd[1]: Reached target Socket Units.
gamma # [6727660.833237] gamma systemd[1]: Reached target Basic System.
gamma # [6727660.836222] gamma systemd[1]: Starting data mesher daemon...
gamma # [6727660.842662] gamma systemd[1]: Starting Import lastlog data into lastlog2 database...
gamma # [6727660.948296] gamma systemd[1]: Starting Name Service Cache Daemon (nsncd)...
gamma # [6727660.960342] gamma systemd[1]: Starting D-Bus System Message Bus...
gamma # [6727660.966322] gamma systemd[1]: Finished Import lastlog data into lastlog2 database.
beta # [6727661.002485] beta systemd[1]: Started Name Service Cache Daemon (nsncd).
beta # [6727661.005866] beta nsncd[211]: Aug 25 20:11:27.055 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
beta # [6727661.002591] beta systemd[1]: Reached target Host and Network Name Lookups.
beta # [6727661.002665] beta systemd[1]: Reached target User and Group Name Lookups.
beta # [6727661.006971] beta systemd[1]: Starting User Login Management...
beta # [6727661.008536] beta systemd[1]: Starting Permit User Sessions...
beta # [6727661.028214] beta systemd[1]: Finished Permit User Sessions.
beta # [6727661.029649] beta systemd[1]: Started Console Getty.
beta # [6727661.029716] beta systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
beta # [6727661.029736] beta systemd[1]: Reached target Login Prompts.
alpha # [6727661.828200] alpha systemd-networkd[196]: eth1: Gained IPv6LL
alpha # [6727661.972059] alpha nsncd[211]: Aug 25 20:11:28.023 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
alpha # [6727661.970922] alpha systemd[1]: Started Name Service Cache Daemon (nsncd).
alpha # [6727661.971002] alpha systemd[1]: Reached target Host and Network Name Lookups.
alpha # [6727661.971066] alpha systemd[1]: Reached target User and Group Name Lookups.
alpha # [6727661.972577] alpha systemd[1]: Starting User Login Management...
alpha # [6727661.973658] alpha systemd[1]: Starting Permit User Sessions...
alpha # [6727662.027694] alpha systemd[1]: Finished Permit User Sessions.
alpha # [6727662.029342] alpha systemd[1]: Started Console Getty.
alpha # [6727662.029407] alpha systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
alpha # [6727662.029432] alpha systemd[1]: Reached target Login Prompts.
beta # [6727661.960189] beta systemd-networkd[196]: eth1: Gained IPv6LL
gamma # [6727662.056335] gamma systemd-networkd[194]: eth1: Gained IPv6LL
beta # [6727663.760988] beta systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
beta # [6727663.762763] beta systemd[1]: Finished Save Transient machine-id to Disk.
gamma # [6727663.870249] gamma systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
gamma # [6727663.871444] gamma systemd[1]: Finished Save Transient machine-id to Disk.
alpha # [6727663.798704] alpha systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
alpha # [6727663.799599] alpha systemd[1]: Finished Save Transient machine-id to Disk.
gamma # [6727664.227606] gamma nsncd[211]: Aug 25 20:11:30.280 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
gamma # [6727664.227637] gamma systemd[1]: Started Name Service Cache Daemon (nsncd).
gamma # [6727664.227725] gamma systemd[1]: Reached target Host and Network Name Lookups.
gamma # [6727664.227796] gamma systemd[1]: Reached target User and Group Name Lookups.
gamma # [6727664.229940] gamma systemd[1]: Starting User Login Management...
gamma # [6727664.231352] gamma systemd[1]: Starting Permit User Sessions...
gamma # [6727664.243033] gamma systemd[1]: Finished Permit User Sessions.
gamma # [6727664.248319] gamma systemd[1]: Started Console Getty.
gamma # [6727664.248426] gamma systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
gamma # [6727664.248458] gamma systemd[1]: Reached target Login Prompts.
alpha # [6727664.987155] alpha dbus-broker-launch[213]: Looking up NSS user entry for 'systemd-timesync'...
alpha # [6727664.988626] alpha dbus-broker-launch[213]: NSS returned no entry for 'systemd-timesync'
alpha # [6727664.988626] alpha dbus-broker-launch[213]: Invalid user-name in /nix/store/vvx1gcbxnhn7b09rflvf7fsv8czxw7hw-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
alpha # [6727664.988936] alpha systemd[1]: Started D-Bus System Message Bus.
alpha # [6727664.995986] alpha dbus-broker-launch[213]: Ready
beta # [6727664.969158] beta dbus-broker-launch[212]: Looking up NSS user entry for 'systemd-timesync'...
beta # [6727664.970048] beta dbus-broker-launch[212]: NSS returned no entry for 'systemd-timesync'
beta # [6727664.970048] beta dbus-broker-launch[212]: Invalid user-name in /nix/store/vvx1gcbxnhn7b09rflvf7fsv8czxw7hw-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
beta # [6727664.970473] beta systemd[1]: Started D-Bus System Message Bus.
beta # [6727664.977921] beta dbus-broker-launch[212]: Ready
gamma # [6727665.112778] gamma dbus-broker-launch[216]: Looking up NSS user entry for 'systemd-timesync'...
gamma # [6727665.116686] gamma dbus-broker-launch[216]: NSS returned no entry for 'systemd-timesync'
gamma # [6727665.116686] gamma dbus-broker-launch[216]: Invalid user-name in /nix/store/vvx1gcbxnhn7b09rflvf7fsv8czxw7hw-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
gamma # [6727665.117539] gamma systemd[1]: Started D-Bus System Message Bus.
gamma # [6727665.124824] gamma dbus-broker-launch[216]: Ready
alpha # [6727665.464068] alpha data-mesher[209]: time=2026-08-25T20:11:31.517Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
alpha # [6727665.465201] alpha data-mesher[209]: time=2026-08-25T20:11:31.518Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6: [/dns/alpha.clan/tcp/7946]} {12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
alpha # [6727665.465237] alpha data-mesher[209]: time=2026-08-25T20:11:31.518Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
alpha # [6727665.489443] alpha systemd-logind[223]: New seat seat0.
alpha # [6727665.489588] alpha systemd[1]: Started User Login Management.
alpha # [6727665.490967] alpha systemd[1]: Starting linger-users.service...
alpha # [6727665.501435] alpha systemd[1]: linger-users.service: Deactivated successfully.
alpha # [6727665.501576] alpha systemd[1]: Finished linger-users.service.
alpha # [6727665.501911] alpha data-mesher[209]: time=2026-08-25T20:11:31.555Z level=INFO msg="checking file integrity"
alpha # [6727665.502069] alpha data-mesher[209]: time=2026-08-25T20:11:31.555Z level=INFO msg="file integrity check complete"
alpha # [6727665.506363] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="libp2p host created" peer_id=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 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 # [6727665.506409] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="registered HTTP route" method=GET path=/files
alpha # [6727665.506409] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
alpha # [6727665.506409] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
alpha # [6727665.506409] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="starting server"
alpha # [6727665.506832] alpha data-mesher[209]: time=2026-08-25T20:11:31.559Z level=INFO msg="HTTP server listening" address=[::1]:7331
alpha # [6727665.507061] alpha data-mesher[209]: time=2026-08-25T20:11:31.560Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
alpha # [6727665.507308] alpha data-mesher[209]: time=2026-08-25T20:11:31.560Z level=INFO msg="waiting for DHT to populate" delay=10s
alpha # [6727665.513343] alpha data-mesher[209]: time=2026-08-25T20:11:31.566Z level=INFO msg="peer connected" peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq remote_addr=/ip4/192.168.1.3/tcp/7946
alpha # [6727665.514563] alpha data-mesher[209]: time=2026-08-25T20:11:31.567Z level=INFO msg="peer connected" peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 remote_addr=/ip6/2001:db8:1::2/tcp/7946
beta # [6727665.461370] beta data-mesher[209]: time=2026-08-25T20:11:31.514Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
beta # [6727665.462900] beta data-mesher[209]: time=2026-08-25T20:11:31.515Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6: [/dns/alpha.clan/tcp/7946]} {12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
beta # [6727665.462900] beta data-mesher[209]: time=2026-08-25T20:11:31.515Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
beta # [6727665.486067] beta systemd-logind[228]: New seat seat0.
beta # [6727665.486907] beta systemd[1]: Started User Login Management.
beta # [6727665.489285] beta systemd[1]: Starting linger-users.service...
beta # [6727665.499592] beta data-mesher[209]: time=2026-08-25T20:11:31.552Z level=INFO msg="checking file integrity"
beta # [6727665.499727] beta data-mesher[209]: time=2026-08-25T20:11:31.552Z level=INFO msg="file integrity check complete"
beta # [6727665.502386] beta systemd[1]: linger-users.service: Deactivated successfully.
beta # [6727665.502537] beta systemd[1]: Finished linger-users.service.
beta # [6727665.504302] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="libp2p host created" peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 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 # [6727665.504408] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
beta # [6727665.504408] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=GET path=/files
beta # [6727665.504408] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
beta # [6727665.504408] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="starting server"
beta # [6727665.504603] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="waiting for DHT to populate" delay=10s
beta # [6727665.504603] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="HTTP server listening" address=[::1]:7331
beta # [6727665.504603] beta data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
beta # [6727665.515947] beta data-mesher[209]: time=2026-08-25T20:11:31.568Z level=INFO msg="peer connected" peer_id=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 remote_addr=/ip6/2001:db8:1::1/tcp/7946
beta # [6727665.520196] beta data-mesher[209]: time=2026-08-25T20:11:31.573Z level=INFO msg="peer connected" peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq remote_addr=/ip4/192.168.1.3/tcp/7946
beta # [6727665.522664] beta data-mesher[209]: time=2026-08-25T20:11:31.575Z level=INFO msg="peer connected" peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq remote_addr=/ip4/192.168.1.3/tcp/7946
beta # [6727665.522664] beta data-mesher[209]: time=2026-08-25T20:11:31.575Z level=INFO msg="peer connected" peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq remote_addr=/ip6/2001:db8:1::3/tcp/7946
gamma # [6727665.465164] gamma data-mesher[209]: time=2026-08-25T20:11:31.518Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]
gamma # [6727665.466262] gamma data-mesher[209]: time=2026-08-25T20:11:31.519Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6: [/dns/alpha.clan/tcp/7946]} {12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3: [/dns/beta.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
gamma # [6727665.466262] gamma data-mesher[209]: time=2026-08-25T20:11:31.519Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml
gamma # [6727665.499509] gamma data-mesher[209]: time=2026-08-25T20:11:31.552Z level=INFO msg="checking file integrity"
gamma # [6727665.499632] gamma data-mesher[209]: time=2026-08-25T20:11:31.552Z level=INFO msg="file integrity check complete"
gamma # [6727665.504310] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="libp2p host created" peer_id=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq 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 # [6727665.504365] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name
gamma # [6727665.504365] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name
gamma # [6727665.504365] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="registered HTTP route" method=GET path=/files
gamma # [6727665.504365] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="starting server"
gamma # [6727665.504482] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="waiting for DHT to populate" delay=10s
gamma # [6727665.504546] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="HTTP server listening" address=[::1]:7331
gamma # [6727665.504578] gamma data-mesher[209]: time=2026-08-25T20:11:31.557Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331
gamma # [6727665.512686] gamma data-mesher[209]: time=2026-08-25T20:11:31.565Z level=INFO msg="peer connected" peer_id=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 remote_addr=/ip4/192.168.1.1/tcp/7946
gamma # [6727665.519283] gamma data-mesher[209]: time=2026-08-25T20:11:31.572Z level=INFO msg="peer connected" peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 remote_addr=/ip4/192.168.1.2/tcp/7946
gamma # [6727665.523425] gamma data-mesher[209]: time=2026-08-25T20:11:31.576Z level=INFO msg="peer connected" peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 remote_addr=/ip6/2001:db8:1::2/tcp/7946
gamma # [6727665.523547] gamma data-mesher[209]: time=2026-08-25T20:11:31.576Z level=INFO msg="peer connected" peer_id=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 remote_addr=/ip4/192.168.1.2/tcp/50592
gamma # [6727665.555237] gamma systemd-logind[229]: New seat seat0.
gamma # [6727665.555435] gamma systemd[1]: Started User Login Management.
gamma # [6727665.557172] gamma systemd[1]: Starting linger-users.service...
gamma # [6727665.569980] gamma systemd[1]: linger-users.service: Deactivated successfully.
gamma # [6727665.570147] gamma systemd[1]: Finished linger-users.service.
alpha: still waiting for container 'alpha' to reach ready state...
alpha # [6727675.512182] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="performing state exchange with peers on join" count=1
alpha # [6727675.512182] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="received state sync from peer" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="received state sync from peer" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="state exchange complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="server started"
alpha # [6727675.513476] alpha data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="starting expired-file sweeper" interval=1m0s
alpha # [6727675.513177] alpha systemd[1]: Started data mesher daemon.
alpha # [6727675.513398] alpha systemd[1]: Reached target Multi-User System.
alpha # [6727675.513553] alpha systemd[1]: Startup finished in 16.848s.
gamma # [6727675.506247] gamma data-mesher[209]: time=2026-08-25T20:11:41.559Z level=INFO msg="performing state exchange with peers on join" count=1
gamma # [6727675.506247] gamma data-mesher[209]: time=2026-08-25T20:11:41.559Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
gamma # [6727675.512627] gamma data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727675.512627] gamma data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
gamma # [6727675.512627] gamma data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="server started"
gamma # [6727675.513049] gamma data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="starting expired-file sweeper" interval=1m0s
gamma # [6727675.516163] gamma systemd[1]: Started data mesher daemon.
gamma # [6727675.516418] gamma systemd[1]: Reached target Multi-User System.
gamma # [6727675.516565] gamma systemd[1]: Startup finished in 16.835s.
beta # [6727675.505311] beta data-mesher[209]: time=2026-08-25T20:11:41.558Z level=INFO msg="performing state exchange with peers on join" count=1
beta # [6727675.505311] beta data-mesher[209]: time=2026-08-25T20:11:41.558Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727675.512745] beta data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="received state sync from peer" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727675.512745] beta data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727675.512868] beta data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727675.512868] beta data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727675.512868] beta data-mesher[209]: time=2026-08-25T20:11:41.565Z level=INFO msg="server started"
beta # [6727675.512951] beta data-mesher[209]: time=2026-08-25T20:11:41.566Z level=INFO msg="starting expired-file sweeper" interval=1m0s
beta # [6727675.513014] beta systemd[1]: Started data mesher daemon.
beta # [6727675.513269] beta systemd[1]: Reached target Multi-User System.
beta # [6727675.513440] beta systemd[1]: Startup finished in 16.849s.
alpha: (finished: waiting for unit data-mesher.service, in 17.67 seconds)
beta: waiting for unit data-mesher.service
beta: (finished: waiting for unit data-mesher.service, in 0.01 seconds)
gamma: waiting for unit data-mesher.service
gamma: (finished: waiting for unit data-mesher.service, in 0.01 seconds)
alpha: must succeed: echo -n 'hello world' > /tmp/test_file
alpha: (finished: must succeed: echo -n 'hello world' > /tmp/test_file, in 0.01 seconds)
alpha: waiting for success: data-mesher file update /tmp/test_file --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-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/i662g5nc00nm69g46rz14s8lpx978m49-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.13 seconds)
??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/8xlk88ia8b5yg9kfrg3skndwzgphipvr-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/8xlk88ia8b5yg9kfrg3skndwzgphipvr-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 # [6727676.003555] alpha data-mesher[209]: time=2026-08-25T20:11:42.056Z level=INFO msg=http_request uri=/files/test_file status=204
alpha # [6727680.513327] alpha data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6727680.513327] alpha data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
alpha # [6727680.513825] alpha data-mesher[209]: time=2026-08-25T20:11:46.566Z level=INFO msg="received state sync from peer" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727680.513825] alpha data-mesher[209]: time=2026-08-25T20:11:46.566Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727680.513960] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="received state sync from peer" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727680.513960] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727680.514298] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727680.514298] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="state exchange complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
alpha # [6727680.514372] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="received file request" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_file
alpha # [6727680.514473] alpha data-mesher[209]: time=2026-08-25T20:11:46.567Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6727680.522774] alpha data-mesher[209]: time=2026-08-25T20:11:46.575Z level=INFO msg="file transfer complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_file
alpha # [6727680.524319] alpha data-mesher[209]: time=2026-08-25T20:11:46.577Z level=INFO msg="received file request" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_file
alpha # [6727680.547146] alpha data-mesher[209]: time=2026-08-25T20:11:46.577Z level=INFO msg="file transfer complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_file
gamma # [6727680.513456] gamma data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727680.513456] gamma data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
gamma # [6727680.523386] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727680.523386] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=DEBUG msg="new file detected" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 name=test_file name=test_file
gamma # [6727680.523541] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
gamma # [6727680.523541] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6727680.523541] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=INFO msg="scheduling file download" name=test_file
gamma # [6727680.523603] gamma data-mesher[209]: time=2026-08-25T20:11:46.576Z level=INFO msg="downloading file" name=test_file signed_at="2026-08-25 20:11:41.957 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727680.751216] gamma data-mesher[209]: time=2026-08-25T20:11:46.804Z level=INFO msg="download complete" name=test_file signed_at="2026-08-25 20:11:41.957 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 written=true elapsed=227.638898ms
beta # [6727680.513327] beta data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [6727680.513327] beta data-mesher[209]: time=2026-08-25T20:11:46.566Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727680.513906] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="received state sync from peer" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727680.513906] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727680.513985] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=DEBUG msg="new file detected" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 name=test_file name=test_file
beta # [6727680.513985] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="scheduling file download" name=test_file
beta # [6727680.514021] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="downloading file" name=test_file signed_at="2026-08-25 20:11:41.957 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727680.514303] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727680.514303] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=DEBUG msg="new file detected" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 name=test_file name=test_file
beta # [6727680.514303] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727680.514303] beta data-mesher[209]: time=2026-08-25T20:11:46.567Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6727680.734114] beta data-mesher[209]: time=2026-08-25T20:11:46.787Z level=INFO msg="download complete" name=test_file signed_at="2026-08-25 20:11:41.957 +0000 UTC" signed_by="azwT+VhTxA+BF73Hwq0uqdXHG8XvHU2BknoVXgmEjww=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 written=true elapsed=220.065632ms
beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file, in 5.04 seconds)
gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file
gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_file && grep -q 'hello world' /var/lib/data-mesher/files/home/test_file, in 0.01 seconds)
beta: waiting for success: data-mesher file delete test_file --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-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/i662g5nc00nm69g46rz14s8lpx978m49-shared-data-mesher-network_network.pub --url http://[::1]:7331 --key /nix/store/xysmjnpbvgzv55l8s8ixr5y3ih9fz7qc-admin.key, in 0.10 seconds)
alpha: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file
beta # [6727681.166400] beta data-mesher[209]: time=2026-08-25T20:11:47.219Z level=INFO msg=http_request uri=/files/test_file status=204
alpha # [6727685.514632] alpha data-mesher[209]: time=2026-08-25T20:11:51.567Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6727685.514632] alpha data-mesher[209]: time=2026-08-25T20:11:51.567Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727685.515419] alpha data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727685.515506] alpha data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="state exchange complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727685.515506] alpha data-mesher[209]: time=2026-08-25T20:11:51.568Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6727685.514615] beta data-mesher[209]: time=2026-08-25T20:11:51.567Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727685.515232] gamma data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="received state sync from peer" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727685.515084] beta data-mesher[209]: time=2026-08-25T20:11:51.567Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
gamma # [6727685.515232] gamma data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727685.524200] beta data-mesher[209]: time=2026-08-25T20:11:51.577Z level=INFO msg="received state sync from peer" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
gamma # [6727685.515232] gamma data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="received state sync from peer" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
beta # [6727685.524200] beta data-mesher[209]: time=2026-08-25T20:11:51.577Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
gamma # [6727685.515232] gamma data-mesher[209]: time=2026-08-25T20:11:51.568Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
gamma # [6727685.523759] gamma data-mesher[209]: time=2026-08-25T20:11:51.576Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727685.523876] gamma data-mesher[209]: time=2026-08-25T20:11:51.576Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
gamma # [6727685.524382] gamma data-mesher[209]: time=2026-08-25T20:11:51.577Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
gamma # [6727685.577158] gamma data-mesher[209]: time=2026-08-25T20:11:51.630Z level=DEBUG msg="imported tombstone" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 name=test_file written=true
gamma # [6727685.577298] gamma data-mesher[209]: time=2026-08-25T20:11:51.630Z level=DEBUG msg="imported tombstone" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 name=test_file written=false
gamma # [6727685.577298] gamma data-mesher[209]: time=2026-08-25T20:11:51.630Z level=INFO msg="state exchange complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
gamma # [6727685.577298] gamma data-mesher[209]: time=2026-08-25T20:11:51.630Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6727685.577509] beta data-mesher[209]: time=2026-08-25T20:11:51.630Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
beta # [6727685.577509] beta data-mesher[209]: time=2026-08-25T20:11:51.630Z level=INFO msg="state exchange complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
beta # [6727685.577668] beta data-mesher[209]: time=2026-08-25T20:11:51.630Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6727690.516670] alpha data-mesher[209]: time=2026-08-25T20:11:56.569Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6727690.516670] alpha data-mesher[209]: time=2026-08-25T20:11:56.569Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727690.517250] alpha data-mesher[209]: time=2026-08-25T20:11:56.570Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727690.579170] alpha data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="received state sync from peer" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727690.579170] alpha data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727690.604991] alpha data-mesher[209]: time=2026-08-25T20:11:56.658Z level=DEBUG msg="imported tombstone" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq name=test_file written=true
alpha # [6727690.604991] alpha data-mesher[209]: time=2026-08-25T20:11:56.658Z level=INFO msg="state exchange complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727690.605198] alpha data-mesher[209]: time=2026-08-25T20:11:56.658Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6727690.605198] alpha data-mesher[209]: time=2026-08-25T20:11:56.658Z level=DEBUG msg="imported tombstone" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 name=test_file written=false
gamma # [6727690.516953] gamma data-mesher[209]: time=2026-08-25T20:11:56.570Z level=INFO msg="received state sync from peer" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727690.578425] beta data-mesher[209]: time=2026-08-25T20:11:56.631Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727690.516953] gamma data-mesher[209]: time=2026-08-25T20:11:56.570Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727690.578425] beta data-mesher[209]: time=2026-08-25T20:11:56.631Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
gamma # [6727690.578388] gamma data-mesher[209]: time=2026-08-25T20:11:56.631Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727690.578528] gamma data-mesher[209]: time=2026-08-25T20:11:56.631Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
gamma # [6727690.579383] gamma data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
gamma # [6727690.579421] gamma data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="state exchange complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
gamma # [6727690.579479] gamma data-mesher[209]: time=2026-08-25T20:11:56.632Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6727690.579236] beta data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="received state sync from peer" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
beta # [6727690.579236] beta data-mesher[209]: time=2026-08-25T20:11:56.632Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
beta # [6727690.605296] beta data-mesher[209]: time=2026-08-25T20:11:56.658Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727690.605396] beta data-mesher[209]: time=2026-08-25T20:11:56.658Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727690.605396] beta data-mesher[209]: time=2026-08-25T20:11:56.658Z level=DEBUG msg="push/pull successful" interval=5s
alpha: (finished: waiting for success: test ! -f /var/lib/data-mesher/files/home/test_file, in 10.06 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/hw6512jcgmq95kz2zrg7yi21w3zia2rx-per-machine-alpha-data-mesher-node-identity_identity.pub
alpha: (finished: must succeed: cat /nix/store/hw6512jcgmq95kz2zrg7yi21w3zia2rx-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/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-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/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-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/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
alpha: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU, in 0.01 seconds)
beta: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
alpha # [6727691.282155] alpha data-mesher[209]: time=2026-08-25T20:11:57.335Z level=INFO msg=http_request uri=/files/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU status=204
beta # [6727695.581741] beta data-mesher[209]: time=2026-08-25T20:12:01.634Z level=INFO msg="received state sync from peer" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
beta # [6727695.581741] beta data-mesher[209]: time=2026-08-25T20:12:01.634Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
beta # [6727695.606879] beta data-mesher[209]: time=2026-08-25T20:12:01.660Z level=DEBUG msg="attempting push/pull" peer_count=2
beta # [6727695.606967] beta data-mesher[209]: time=2026-08-25T20:12:01.660Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727695.608495] beta data-mesher[209]: time=2026-08-25T20:12:01.661Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727695.608729] beta data-mesher[209]: time=2026-08-25T20:12:01.661Z level=DEBUG msg="new file detected" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 name=test_file name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
beta # [6727695.608729] beta data-mesher[209]: time=2026-08-25T20:12:01.661Z level=INFO msg="state exchange complete" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 timeout=5s
beta # [6727695.608776] beta data-mesher[209]: time=2026-08-25T20:12:01.661Z level=DEBUG msg="push/pull successful" interval=5s
beta # [6727695.608825] beta data-mesher[209]: time=2026-08-25T20:12:01.661Z level=INFO msg="scheduling file download" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
beta # [6727695.608870] beta data-mesher[209]: time=2026-08-25T20:12:01.662Z level=INFO msg="downloading file" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU signed_at="2026-08-25 20:11:57.333 +0000 UTC" signed_by="EAfDrMsAyzx/O0X2tXut83PVizS9uNVow8YCtvPrhdU=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
beta # [6727695.610946] beta data-mesher[209]: time=2026-08-25T20:12:01.664Z level=INFO msg="download complete" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU signed_at="2026-08-25 20:11:57.333 +0000 UTC" signed_by="EAfDrMsAyzx/O0X2tXut83PVizS9uNVow8YCtvPrhdU=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 written=true elapsed=2.097189ms
alpha # [6727695.605673] alpha data-mesher[209]: time=2026-08-25T20:12:01.658Z level=DEBUG msg="attempting push/pull" peer_count=2
alpha # [6727695.606065] alpha data-mesher[209]: time=2026-08-25T20:12:01.658Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727695.606741] alpha data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="merging remote state" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq
alpha # [6727695.606741] alpha data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="state exchange complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq timeout=5s
alpha # [6727695.606741] alpha data-mesher[209]: time=2026-08-25T20:12:01.659Z level=DEBUG msg="push/pull successful" interval=5s
alpha # [6727695.607701] alpha data-mesher[209]: time=2026-08-25T20:12:01.660Z level=INFO msg="received file request" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
alpha # [6727695.607701] alpha data-mesher[209]: time=2026-08-25T20:12:01.660Z level=INFO msg="received state sync from peer" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727695.607701] alpha data-mesher[209]: time=2026-08-25T20:12:01.660Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
gamma # [6727695.580984] gamma data-mesher[209]: time=2026-08-25T20:12:01.633Z level=DEBUG msg="attempting push/pull" peer_count=2
gamma # [6727695.580984] gamma data-mesher[209]: time=2026-08-25T20:12:01.633Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
alpha # [6727695.608617] alpha data-mesher[209]: time=2026-08-25T20:12:01.661Z level=INFO msg="file transfer complete" peer=12D3KooWRrumLUuiZwycnutKcspiGc3NWRktjwnEZWYnvwDSk7pq network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
gamma # [6727695.581918] gamma data-mesher[209]: time=2026-08-25T20:12:01.634Z level=INFO msg="merging remote state" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3
alpha # [6727695.609143] alpha data-mesher[209]: time=2026-08-25T20:12:01.662Z level=INFO msg="received file request" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
alpha # [6727695.609560] alpha data-mesher[209]: time=2026-08-25T20:12:01.662Z level=INFO msg="file transfer complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 network="3D8IZ5fqdOCRn13tTxYeG8VBr7r6G1tsF9xP49h42d0=" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
gamma # [6727695.581918] gamma data-mesher[209]: time=2026-08-25T20:12:01.634Z level=INFO msg="state exchange complete" peer=12D3KooW9rnrisfUBm9WMbM8psXNrXVpcVpbJeAg2ecpktWsxxL3 timeout=5s
gamma # [6727695.581918] gamma data-mesher[209]: time=2026-08-25T20:12:01.635Z level=DEBUG msg="push/pull successful" interval=5s
gamma # [6727695.606611] gamma data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="received state sync from peer" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727695.606611] gamma data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="merging remote state" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727695.606611] gamma data-mesher[209]: time=2026-08-25T20:12:01.659Z level=DEBUG msg="new file detected" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 name=test_file name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
gamma # [6727695.606611] gamma data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="scheduling file download" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
gamma # [6727695.606782] gamma data-mesher[209]: time=2026-08-25T20:12:01.659Z level=INFO msg="downloading file" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU signed_at="2026-08-25 20:11:57.333 +0000 UTC" signed_by="EAfDrMsAyzx/O0X2tXut83PVizS9uNVow8YCtvPrhdU=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6
gamma # [6727695.610709] gamma data-mesher[209]: time=2026-08-25T20:12:01.663Z level=INFO msg="download complete" name=test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU signed_at="2026-08-25 20:11:57.333 +0000 UTC" signed_by="EAfDrMsAyzx/O0X2tXut83PVizS9uNVow8YCtvPrhdU=" peer=12D3KooWAtwZN69cWy5PMjZwgpqSwiNEJ1N1RU3oxFthKvH8yeF6 written=true elapsed=4.042457ms
beta: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU, in 5.07 seconds)
gamma: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
gamma: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU && grep -q 'namespace_data' /var/lib/data-mesher/files/home/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU, 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.00 seconds)
alpha: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-shared-data-mesher-network_network.pub
Error: failed to update file: 403 Forbidden, signer EAfDrMsAyzx/O0X2tXut83PVizS9uNVow8YCtvPrhdU= is not authorized for this file test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU
alpha: (finished: must fail: data-mesher file update /tmp/ns_nocert --name 'test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU' --url http://[::1]:7331 --key /run/secrets/per-machine/alpha/data-mesher-node-identity/identity.key --network-id /nix/store/i662g5nc00nm69g46rz14s8lpx978m49-shared-data-mesher-network_network.pub, in 0.03 seconds)
(finished: run the VM test script, in 38.23 seconds)
alpha # [6727696.397152] alpha data-mesher[209]: time=2026-08-25T20:12:02.450Z level=INFO msg=http_request uri=/files/test_ns/EAfDrMsAyzx_O0X2tXut83PVizS9uNVow8YCtvPrhdU status=403
test script finished in 39.25s
cleanup
kill NspawnMachine (pid 53)
kill NspawnMachine (pid 54)
kill NspawnMachine (pid 55)
Container alpha terminated by signal KILL.
beta # [6727697.536879] beta systemd-networkd[196]: eth1: Link DOWN
gamma # [6727697.699899] gamma systemd-networkd[194]: eth1: Link DOWN
gamma # [6727697.699916] gamma systemd-networkd[194]: eth1: Lost carrier
gamma # [6727697.836830] gamma systemd-networkd[194]: eth1: Lost IPv6LL address fe80::b014:c2ff:fec2:f403.
Container beta terminated by signal KILL.
Container gamma terminated by signal KILL.
(finished: cleanup, in 0.85 seconds)