build01: building bfpp4691j3ldjczl330gnlklpz0fsw51-container-test-run-dm-wireguard-star.drv 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: controller, peer1, peer2, 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 controller: systemd-nspawn running (pid 50) controller: Waiting for journal at /build/vm-state-controller/var/log/journal... peer1: systemd-nspawn running (pid 53) peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal... controller: waiting for unit data-mesher.service nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(controller): 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(peer1): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(peer1): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths. 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 controller on /build/vm-state-controller. ░ Spawning container peer1 on /build/vm-state-peer1. controller # No journal files were found. controller # No journal boot entry found for the specified boot (+0). peer1 # No journal files were found. peer1 # No journal boot entry found for the specified boot (+0). controller # [2274080.827251] controller systemd-journald[107]: Journal started controller # [2274080.827314] controller systemd-journald[107]: Runtime Journal (/run/log/journal/52b3f62625d84cd892ded5858e941ea8) is 8M, max 2.5G, 2.4G free. controller # [2274080.898147] controller systemd[1]: Finished Apply Kernel Variables. controller # [2274080.911979] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully. controller # [2274080.943915] controller systemd[1]: Starting Flush Journal to Persistent Storage... controller # [2274080.944967] controller systemd[1]: Starting Network Name Resolution... controller # [2274080.945617] controller systemd[1]: Starting Create Static Device Nodes in /dev... controller # [2274080.953860] controller systemd-journald[107]: Time spent on flushing to /var/log/journal/52b3f62625d84cd892ded5858e941ea8 is 1.586ms for 7 entries. controller # [2274080.953860] controller systemd-journald[107]: System Journal (/var/log/journal/52b3f62625d84cd892ded5858e941ea8) is 8M, max 4G, 3.9G free. controller # [2274080.970774] controller systemd[1]: Finished Flush Journal to Persistent Storage. controller # [2274080.971268] controller systemd[1]: Finished Create Static Device Nodes in /dev. controller # [2274080.972434] controller systemd[1]: Reached target Preparation for Local File Systems. controller # [2274080.972539] controller systemd[1]: Reached target Local File Systems. controller # [2274080.973381] controller systemd[1]: Listening on Boot Loader Control Service Socket. controller # [2274080.973431] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container controller # [2274080.974232] controller systemd[1]: Starting Save Transient machine-id to Disk... controller # [2274080.975002] controller systemd[1]: Starting Create System Files and Directories... controller # [2274080.975036] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys controller # [2274080.991260] controller systemd-tmpfiles[202]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted controller # [2274080.991464] controller systemd-tmpfiles[202]: fchmod() of /var/log/journal failed: Operation not permitted controller # [2274080.991599] controller systemd-tmpfiles[202]: fchmod() of /var/log/journal/52b3f62625d84cd892ded5858e941ea8 failed: Operation not permitted controller # [2274080.991810] controller systemd-tmpfiles[202]: fchmod() of /run/log/journal failed: Operation not permitted controller # [2274080.993283] controller systemd[1]: Finished Create System Files and Directories. controller # [2274080.994360] controller systemd[1]: Starting Rebuild Journal Catalog... controller # [2274080.995155] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP... controller # [2274081.009651] controller systemd[1]: Finished Firewall. controller # [2274081.010326] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP. controller # [2274081.013280] controller systemd[1]: Reached target Preparation for Network. controller # [2274081.013596] controller systemd[1]: Listening on Network Management Resolve Hook Socket. controller # [2274081.014764] controller systemd[1]: Starting Network Management... controller # [2274081.015116] controller systemd[1]: Finished Rebuild Journal Catalog. controller # [2274081.016802] controller systemd[1]: Starting Update is Completed... controller # [2274081.021069] controller systemd[1]: Finished Save Transient machine-id to Disk. controller # [2274081.027864] controller systemd[1]: Finished Update is Completed. peer1 # [2274080.815742] peer1 systemd-journald[98]: Journal started peer1 # [2274080.815804] peer1 systemd-journald[98]: Runtime Journal (/run/log/journal/a02720fe6cf644789cb252c4f5e25874) is 8M, max 2.5G, 2.4G free. peer1 # [2274080.840668] peer1 systemd[1]: Finished Apply Kernel Variables. peer1 # [2274080.891874] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully. peer1 # [2274080.906402] peer1 systemd[1]: Starting Flush Journal to Persistent Storage... peer1 # [2274080.908193] peer1 systemd[1]: Starting Network Name Resolution... peer1 # [2274080.909023] peer1 systemd[1]: Starting Create Static Device Nodes in /dev... peer1 # [2274080.918377] peer1 systemd-journald[98]: Time spent on flushing to /var/log/journal/a02720fe6cf644789cb252c4f5e25874 is 1.903ms for 7 entries. peer1 # [2274080.918377] peer1 systemd-journald[98]: System Journal (/var/log/journal/a02720fe6cf644789cb252c4f5e25874) is 8M, max 4G, 3.9G free. peer1 # [2274080.949820] peer1 systemd[1]: Finished Flush Journal to Persistent Storage. peer1 # [2274080.950214] peer1 systemd[1]: Finished Create Static Device Nodes in /dev. peer1 # [2274080.951359] peer1 systemd[1]: Reached target Preparation for Local File Systems. peer1 # [2274080.951467] peer1 systemd[1]: Reached target Local File Systems. peer1 # [2274080.952347] peer1 systemd[1]: Listening on Boot Loader Control Service Socket. peer1 # [2274080.952410] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer1 # [2274080.953339] peer1 systemd[1]: Starting Save Transient machine-id to Disk... peer1 # [2274080.954235] peer1 systemd[1]: Starting Create System Files and Directories... peer1 # [2274080.954276] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer1 # [2274080.974458] peer1 systemd-tmpfiles[187]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer1 # [2274080.974683] peer1 systemd-tmpfiles[187]: fchmod() of /var/log/journal failed: Operation not permitted peer1 # [2274080.974833] peer1 systemd-tmpfiles[187]: fchmod() of /var/log/journal/a02720fe6cf644789cb252c4f5e25874 failed: Operation not permitted peer1 # [2274080.975058] peer1 systemd-tmpfiles[187]: fchmod() of /run/log/journal failed: Operation not permitted peer1 # [2274080.976647] peer1 systemd[1]: Finished Create System Files and Directories. peer1 # [2274080.977803] peer1 systemd[1]: Starting Rebuild Journal Catalog... peer1 # [2274080.978555] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer1 # [2274080.991599] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer1 # [2274080.995106] peer1 systemd[1]: Finished Firewall. peer1 # [2274080.995295] peer1 systemd[1]: Reached target Preparation for Network. peer1 # [2274080.995575] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket. peer1 # [2274080.996879] peer1 systemd[1]: Starting Network Management... peer1 # [2274081.001413] peer1 systemd[1]: Finished Rebuild Journal Catalog. peer1 # [2274081.002774] peer1 systemd[1]: Starting Update is Completed... peer1 # [2274081.013509] peer1 systemd[1]: Finished Update is Completed. peer1 # [2274081.021086] peer1 systemd[1]: Finished Save Transient machine-id to Disk. controller # [2274081.755735] controller systemd-networkd[223]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted controller # [2274081.755826] controller systemd-networkd[223]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted controller # [2274081.767289] controller systemd-networkd[223]: /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. controller # [2274081.767519] controller systemd-networkd[223]: /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. controller # [2274081.767683] controller systemd-networkd[223]: lo: Link UP controller # [2274081.767689] controller systemd-networkd[223]: lo: Gained carrier controller # [2274081.767873] controller systemd-networkd[223]: eth1: Configuring with /etc/systemd/network/40-eth1.network. controller # [2274081.768597] controller systemd[1]: Started Network Management. controller # [2274081.769375] controller systemd-networkd[223]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. controller # [2274081.769696] controller systemd-networkd[223]: wg-star: netdev ready controller # [2274081.770315] controller systemd-networkd[223]: eth1: Link UP controller # [2274081.770549] controller systemd-networkd[223]: eth1: Gained carrier controller # [2274081.770674] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd... controller # [2274081.808599] controller systemd-networkd[223]: wg-star: Link UP controller # [2274081.808605] controller systemd-networkd[223]: wg-star: Gained carrier controller # [2274081.840201] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully. controller # [2274081.842073] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer1 # [2274081.782113] peer1 systemd-networkd[212]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer1 # [2274081.782207] peer1 systemd-networkd[212]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer1 # [2274081.792544] peer1 systemd-networkd[212]: /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. peer1 # [2274081.792715] peer1 systemd-networkd[212]: /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. peer1 # [2274081.792860] peer1 systemd-networkd[212]: lo: Link UP peer1 # [2274081.792866] peer1 systemd-networkd[212]: lo: Gained carrier peer1 # [2274081.793045] peer1 systemd-networkd[212]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer1 # [2274081.806279] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. peer1 # [2274081.806989] peer1 systemd[1]: Started Network Management. peer1 # [2274081.809196] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer1 # [2274081.809479] peer1 systemd-networkd[212]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. peer1 # [2274081.809803] peer1 systemd-networkd[212]: wg-star: netdev ready peer1 # [2274081.810212] peer1 systemd-networkd[212]: eth1: Link UP peer1 # [2274081.810430] peer1 systemd-networkd[212]: eth1: Gained carrier peer1 # [2274081.840994] peer1 systemd-networkd[212]: wg-star: Link UP peer1 # [2274081.841004] peer1 systemd-networkd[212]: wg-star: Gained carrier peer1 # [2274081.842810] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. controller # [2274082.194151] controller systemd-resolved[181]: Positive Trust Anchors: controller # [2274082.194163] controller systemd-resolved[181]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d controller # [2274082.194165] controller systemd-resolved[181]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 controller # [2274082.194199] controller systemd-resolved[181]: 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 controller # [2274082.214223] controller systemd-resolved[181]: Using system hostname 'controller'. controller # [2274082.215804] controller systemd[1]: Started Network Name Resolution. controller # [2274082.215947] controller systemd[1]: Reached target Network. controller # [2274082.216095] controller systemd[1]: Reached target System Initialization. controller # [2274082.216265] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher. controller # [2274082.216321] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container controller # [2274082.216371] controller systemd[1]: Started Daily Cleanup of Temporary Directories. controller # [2274082.216414] controller systemd[1]: Reached target Path Units. controller # [2274082.216491] controller systemd[1]: Reached target Timer Units. controller # [2274082.216725] controller systemd[1]: Listening on D-Bus System Message Bus Socket. controller # [2274082.216973] controller systemd[1]: Listening on Nix Daemon Socket. controller # [2274082.217214] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. controller # [2274082.217273] controller systemd[1]: Reached target Socket Units. controller # [2274082.217358] controller systemd[1]: Reached target Basic System. controller # [2274082.219829] controller systemd[1]: Starting data mesher daemon... controller # [2274082.221098] controller systemd[1]: Starting Import lastlog data into lastlog2 database... controller # [2274082.222618] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)... controller # [2274082.224696] controller systemd[1]: Starting D-Bus System Message Bus... controller # [2274082.287205] controller systemd[1]: Finished Import lastlog data into lastlog2 database. peer1 # [2274082.193901] peer1 systemd-resolved[158]: Positive Trust Anchors: peer1 # [2274082.193916] peer1 systemd-resolved[158]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer1 # [2274082.193918] peer1 systemd-resolved[158]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer1 # [2274082.193953] peer1 systemd-resolved[158]: 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 peer1 # [2274082.214112] peer1 systemd-resolved[158]: Using system hostname 'peer1'. peer1 # [2274082.215711] peer1 systemd[1]: Started Network Name Resolution. peer1 # [2274082.215851] peer1 systemd[1]: Reached target Network. peer1 # [2274082.215966] peer1 systemd[1]: Reached target System Initialization. peer1 # [2274082.216170] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher. peer1 # [2274082.216241] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer. peer1 # [2274082.216285] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container peer1 # [2274082.216326] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories. peer1 # [2274082.216380] peer1 systemd[1]: Reached target Path Units. peer1 # [2274082.216464] peer1 systemd[1]: Reached target Timer Units. peer1 # [2274082.216698] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket. peer1 # [2274082.216959] peer1 systemd[1]: Listening on Nix Daemon Socket. peer1 # [2274082.217191] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. peer1 # [2274082.217235] peer1 systemd[1]: Reached target Socket Units. peer1 # [2274082.217315] peer1 systemd[1]: Reached target Basic System. peer1 # [2274082.219664] peer1 systemd[1]: Starting data mesher daemon... peer1 # [2274082.220937] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database... peer1 # [2274082.222409] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)... peer1 # [2274082.224887] peer1 systemd[1]: Starting D-Bus System Message Bus... peer1 # [2274082.287062] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database. peer1 # [2274082.478651] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd). peer1 # [2274082.478836] peer1 nsncd[223]: Sep 30 15:08:22.464 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer1 # [2274082.478768] peer1 systemd[1]: Reached target Host and Network Name Lookups. peer1 # [2274082.478878] peer1 systemd[1]: Reached target User and Group Name Lookups. peer1 # [2274082.480921] peer1 systemd[1]: Starting User Login Management... peer1 # [2274082.482275] peer1 systemd[1]: Starting Permit User Sessions... controller # [2274082.477978] controller nsncd[234]: Sep 30 15:08:22.463 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer1 # [2274082.540046] peer1 systemd[1]: Finished Permit User Sessions. controller # [2274082.477986] controller systemd[1]: Started Name Service Cache Daemon (nsncd). peer1 # [2274082.541813] peer1 systemd[1]: Started Console Getty. controller # [2274082.478095] controller systemd[1]: Reached target Host and Network Name Lookups. peer1 # [2274082.541884] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 controller # [2274082.478203] controller systemd[1]: Reached target User and Group Name Lookups. peer1 # [2274082.541923] peer1 systemd[1]: Reached target Login Prompts. controller # [2274082.480670] controller systemd[1]: Starting User Login Management... peer1 # [2274082.602455] peer1 dbus-broker-launch[224]: Looking up NSS user entry for 'systemd-timesync'... controller # [2274082.482041] controller systemd[1]: Starting Permit User Sessions... peer1 # [2274082.603670] peer1 dbus-broker-launch[224]: NSS returned no entry for 'systemd-timesync' controller # [2274082.540397] controller systemd[1]: Finished Permit User Sessions. peer1 # [2274082.603670] peer1 dbus-broker-launch[224]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" controller # [2274082.541950] controller systemd[1]: Started Console Getty. peer1 # [2274082.604283] peer1 systemd[1]: Started D-Bus System Message Bus. controller # [2274082.542032] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 peer1 # [2274082.613270] peer1 dbus-broker-launch[224]: Ready controller # [2274082.542072] controller systemd[1]: Reached target Login Prompts. controller # [2274082.610763] controller dbus-broker-launch[235]: Looking up NSS user entry for 'systemd-timesync'... controller # [2274082.611979] controller dbus-broker-launch[235]: NSS returned no entry for 'systemd-timesync' controller # [2274082.611979] controller dbus-broker-launch[235]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" controller # [2274082.612437] controller systemd[1]: Started D-Bus System Message Bus. controller # [2274082.621246] controller dbus-broker-launch[235]: Ready peer1 # [2274083.029468] peer1 data-mesher[221]: time=2026-09-30T15:08:23.015Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] peer1 # [2274083.030902] peer1 data-mesher[221]: time=2026-09-30T15:08:23.016Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf peer1 # [2274083.030902] peer1 data-mesher[221]: time=2026-09-30T15:08:23.016Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml peer1 # [2274083.032279] peer1 data-mesher[221]: time=2026-09-30T15:08:23.018Z level=INFO msg="checking file integrity" peer1 # [2274083.034085] peer1 data-mesher[221]: time=2026-09-30T15:08:23.018Z level=INFO msg="file integrity check complete" peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="libp2p host created" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf 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 /ip6/fda1:5c8::23fd:a719:7f48:87f1/tcp/7946]" peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=GET path=/files peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="starting server" peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="waiting for DHT to populate" delay=10s peer1 # [2274083.036742] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="HTTP server listening" address=[::1]:7331 peer1 # [2274083.036742] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 peer1 # [2274083.048454] peer1 data-mesher[221]: time=2026-09-30T15:08:23.034Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946 controller # [2274083.036676] controller data-mesher[232]: time=2026-09-30T15:08:23.022Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] controller # [2274083.037759] controller data-mesher[232]: time=2026-09-30T15:08:23.023Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ controller # [2274083.037759] controller data-mesher[232]: time=2026-09-30T15:08:23.023Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml controller # [2274083.039005] controller data-mesher[232]: time=2026-09-30T15:08:23.024Z level=INFO msg="checking file integrity" controller # [2274083.040021] controller data-mesher[232]: time=2026-09-30T15:08:23.024Z level=INFO msg="file integrity check complete" controller # [2274083.042997] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="libp2p host created" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ 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 /ip6/fda1:5c8::28bc:6cf0:1e15:8c64/tcp/7946]" controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=GET path=/files controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="starting server" controller # [2274083.043119] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="waiting for DHT to populate" delay=10s controller # [2274083.043243] controller data-mesher[232]: time=2026-09-30T15:08:23.029Z level=INFO msg="HTTP server listening" address=[::1]:7331 controller # [2274083.043243] controller data-mesher[232]: time=2026-09-30T15:08:23.029Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 controller # [2274083.047896] controller data-mesher[232]: time=2026-09-30T15:08:23.033Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946 controller # [2274083.076262] controller systemd-networkd[223]: eth1: Gained IPv6LL controller # [2274083.324922] controller systemd-logind[252]: New seat seat0. controller # [2274083.325103] controller systemd[1]: Started User Login Management. controller # [2274083.332671] controller systemd[1]: Starting linger-users.service... controller # [2274083.346470] controller systemd[1]: linger-users.service: Deactivated successfully. controller # [2274083.346596] controller systemd[1]: Finished linger-users.service. peer1 # [2274083.291856] peer1 systemd-logind[241]: New seat seat0. peer1 # [2274083.292111] peer1 systemd[1]: Started User Login Management. peer1 # [2274083.293474] peer1 systemd[1]: Starting linger-users.service... peer1 # [2274083.343645] peer1 systemd[1]: linger-users.service: Deactivated successfully. peer1 # [2274083.343903] peer1 systemd[1]: Finished linger-users.service. peer1 # [2274083.648121] peer1 systemd-networkd[212]: eth1: Gained IPv6LL controller: still waiting for container 'controller' to reach ready state... peer1 # [2274093.036971] peer1 data-mesher[221]: time=2026-09-30T15:08:33.022Z level=INFO msg="performing state exchange with peers on join" count=1 peer1 # [2274093.037508] peer1 data-mesher[221]: time=2026-09-30T15:08:33.022Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274093.037911] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274093.037911] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274093.038003] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="server started" peer1 # [2274093.038210] peer1 systemd[1]: Started data mesher daemon. peer1 # [2274093.038788] peer1 data-mesher[221]: time=2026-09-30T15:08:33.024Z level=INFO msg="starting expired-file sweeper" interval=1m0s peer1 # [2274093.039744] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher... peer1 # [2274093.044298] peer1 data-mesher[221]: time=2026-09-30T15:08:33.030Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274093.044364] peer1 data-mesher[221]: time=2026-09-30T15:08:33.030Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274093.205198] peer1 data-mesher[221]: time=2026-09-30T15:08:33.190Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 status=204 peer1 # [2274093.205685] peer1 dm-wg-star-publish[286]: Status: 204 No Content peer1 # [2274093.207721] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer1 # [2274093.209365] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully. peer1 # [2274093.209665] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher. peer1 # [2274093.210654] peer1 systemd[1]: Reached target Multi-User System. peer1 # [2274093.302905] peer1 dm-wg-star-reconfig[312]: No controller data available yet, skipping controller # [2274093.037689] controller data-mesher[232]: time=2026-09-30T15:08:33.023Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274093.037689] controller data-mesher[232]: time=2026-09-30T15:08:33.023Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274093.043593] controller data-mesher[232]: time=2026-09-30T15:08:33.029Z level=INFO msg="performing state exchange with peers on join" count=1 controller # [2274093.043593] controller data-mesher[232]: time=2026-09-30T15:08:33.029Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274093.044460] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274093.044460] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274093.044581] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="server started" controller # [2274093.044653] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="starting expired-file sweeper" interval=1m0s controller # [2274093.044741] controller systemd[1]: Started data mesher daemon. controller # [2274093.088753] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher... controller # [2274093.132901] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [2274093.141736] controller data-mesher[232]: time=2026-09-30T15:08:33.127Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204 controller # [2274093.142021] controller dm-wg-star-publish[297]: Status: 204 No Content controller # [2274093.145747] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher. controller # [2274093.146569] controller systemd[1]: Reached target Multi-User System. controller # [2274093.230665] controller dm-wg-star-reconfig[323]: No peer data available yet, skipping controller # [2274093.232017] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [2274093.232285] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. controller # [2274093.232846] controller systemd[1]: Startup finished in 12.872s. controller: (finished: waiting for unit data-mesher.service, in 13.68 seconds) peer1: waiting for unit data-mesher.service peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds) ??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller ??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds) peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller peer1 # [2274093.304119] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer1 # [2274093.304280] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer1 # [2274093.304800] peer1 systemd[1]: Startup finished in 12.962s. controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.028Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.028Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274098.044094] controller data-mesher[232]: time=2026-09-30T15:08:38.029Z level=INFO msg="received file request" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller controller # [2274098.044856] controller data-mesher[232]: time=2026-09-30T15:08:38.030Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [2274098.044992] controller data-mesher[232]: time=2026-09-30T15:08:38.030Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274098.046411] controller data-mesher[232]: time=2026-09-30T15:08:38.032Z level=INFO msg="file transfer complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller controller # [2274098.047232] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274098.047839] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 controller # [2274098.047923] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274098.047923] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=DEBUG msg="push/pull successful" interval=5s controller # [2274098.048372] controller data-mesher[232]: time=2026-09-30T15:08:38.034Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf written=true elapsed=6.071683ms controller # [2274098.050222] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [2274098.192375] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [2274098.192525] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. peer1 # [2274098.040292] peer1 data-mesher[221]: time=2026-09-30T15:08:38.026Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [2274098.041029] peer1 data-mesher[221]: time=2026-09-30T15:08:38.026Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274098.042279] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274098.042279] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274098.043148] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 peer1 # [2274098.044311] peer1 data-mesher[221]: time=2026-09-30T15:08:38.030Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 peer1 # [2274098.046787] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274098.046834] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274098.046834] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer1 # [2274098.049432] peer1 data-mesher[221]: time=2026-09-30T15:08:38.035Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=6.949896ms peer1 # [2274098.052164] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer1 # [2274098.168465] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer1 # [2274098.192422] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.05 seconds) controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q . controller: (finished: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q ., in 0.01 seconds) controller: waiting for success: wg show wg-star peers | grep -q . controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds) peer1: waiting for success: wg show wg-star peers | grep -q . peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds) peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64 peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds) controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1 controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds) controller: must succeed: wg show wg-star peers | wc -l controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds) peer2: systemd-nspawn running (pid 782) peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal... peer2: waiting for unit data-mesher.service nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE nixos-nspawn(peer2): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths. 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 peer2 on /build/vm-state-peer2. peer2 # No journal files were found. peer2 # No journal boot entry found for the specified boot (+0). peer2 # [2274099.575779] peer2 systemd-journald[99]: Journal started peer2 # [2274099.575831] peer2 systemd-journald[99]: Runtime Journal (/run/log/journal/9c8783ffa30f405ea91870b02260e851) is 8M, max 2.5G, 2.4G free. peer2 # [2274099.584385] peer2 systemd[1]: Finished Apply Kernel Variables. peer2 # [2274099.596409] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully. peer2 # [2274099.610214] peer2 systemd[1]: Starting Flush Journal to Persistent Storage... peer2 # [2274099.611008] peer2 systemd[1]: Starting Network Name Resolution... peer2 # [2274099.611855] peer2 systemd[1]: Starting Create Static Device Nodes in /dev... peer2 # [2274099.646935] peer2 systemd-journald[99]: Time spent on flushing to /var/log/journal/9c8783ffa30f405ea91870b02260e851 is 2.198ms for 7 entries. peer2 # [2274099.646935] peer2 systemd-journald[99]: System Journal (/var/log/journal/9c8783ffa30f405ea91870b02260e851) is 8M, max 4G, 3.9G free. peer2 # [2274099.662251] peer2 systemd[1]: Finished Flush Journal to Persistent Storage. peer2 # [2274099.662920] peer2 systemd[1]: Finished Create Static Device Nodes in /dev. peer2 # [2274099.663882] peer2 systemd[1]: Reached target Preparation for Local File Systems. peer2 # [2274099.663994] peer2 systemd[1]: Reached target Local File Systems. peer2 # [2274099.664936] peer2 systemd[1]: Listening on Boot Loader Control Service Socket. peer2 # [2274099.665000] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer2 # [2274099.665910] peer2 systemd[1]: Starting Save Transient machine-id to Disk... peer2 # [2274099.666675] peer2 systemd[1]: Starting Create System Files and Directories... peer2 # [2274099.666711] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer2 # [2274099.685599] peer2 systemd-tmpfiles[165]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer2 # [2274099.686425] peer2 systemd-tmpfiles[165]: fchmod() of /var/log/journal failed: Operation not permitted peer2 # [2274099.686551] peer2 systemd-tmpfiles[165]: fchmod() of /var/log/journal/9c8783ffa30f405ea91870b02260e851 failed: Operation not permitted peer2 # [2274099.686735] peer2 systemd-tmpfiles[165]: fchmod() of /run/log/journal failed: Operation not permitted peer2 # [2274099.689329] peer2 systemd[1]: Finished Create System Files and Directories. peer2 # [2274099.690719] peer2 systemd[1]: Starting Rebuild Journal Catalog... peer2 # [2274099.691749] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer2 # [2274099.695890] peer2 systemd[1]: Finished Save Transient machine-id to Disk. peer2 # [2274099.705519] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer2 # [2274099.715229] peer2 systemd[1]: Finished Rebuild Journal Catalog. peer2 # [2274099.716274] peer2 systemd[1]: Starting Update is Completed... peer2 # [2274099.727473] peer2 systemd[1]: Finished Update is Completed. peer2 # [2274099.754696] peer2 systemd[1]: Finished Firewall. peer2 # [2274099.754855] peer2 systemd[1]: Reached target Preparation for Network. peer2 # [2274099.755061] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket. peer2 # [2274099.756008] peer2 systemd[1]: Starting Network Management... peer2 # [2274100.403884] peer2 systemd-networkd[217]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer2 # [2274100.403979] peer2 systemd-networkd[217]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer2 # [2274100.413703] peer2 systemd-networkd[217]: /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. peer2 # [2274100.413868] peer2 systemd-networkd[217]: /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. peer2 # [2274100.414002] peer2 systemd-networkd[217]: lo: Link UP peer2 # [2274100.414006] peer2 systemd-networkd[217]: lo: Gained carrier peer2 # [2274100.414185] peer2 systemd-networkd[217]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer2 # [2274100.414732] peer2 systemd[1]: Started Network Management. peer2 # [2274100.416120] peer2 systemd-networkd[217]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. peer2 # [2274100.416208] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer2 # [2274100.416417] peer2 systemd-networkd[217]: wg-star: netdev ready peer2 # [2274100.416789] peer2 systemd-networkd[217]: eth1: Link UP peer2 # [2274100.416994] peer2 systemd-networkd[217]: eth1: Gained carrier peer2 # [2274100.460621] peer2 systemd-networkd[217]: wg-star: Link UP peer2 # [2274100.460628] peer2 systemd-networkd[217]: wg-star: Gained carrier peer2 # [2274100.469563] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer2 # [2274100.590495] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. peer2 # [2274100.752188] peer2 systemd-resolved[130]: Positive Trust Anchors: peer2 # [2274100.752201] peer2 systemd-resolved[130]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer2 # [2274100.752205] peer2 systemd-resolved[130]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer2 # [2274100.752240] peer2 systemd-resolved[130]: 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 peer2 # [2274100.772297] peer2 systemd-resolved[130]: Using system hostname 'peer2'. peer2 # [2274100.773881] peer2 systemd[1]: Started Network Name Resolution. peer2 # [2274100.774015] peer2 systemd[1]: Reached target Network. peer2 # [2274100.774133] peer2 systemd[1]: Reached target System Initialization. peer2 # [2274100.774295] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher. peer2 # [2274100.774348] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer. peer2 # [2274100.774388] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container peer2 # [2274100.774425] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories. peer2 # [2274100.774467] peer2 systemd[1]: Reached target Path Units. peer2 # [2274100.774544] peer2 systemd[1]: Reached target Timer Units. peer2 # [2274100.774761] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket. peer2 # [2274100.774978] peer2 systemd[1]: Listening on Nix Daemon Socket. peer2 # [2274100.775193] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. peer2 # [2274100.775234] peer2 systemd[1]: Reached target Socket Units. peer2 # [2274100.775308] peer2 systemd[1]: Reached target Basic System. peer2 # [2274100.777937] peer2 systemd[1]: Starting data mesher daemon... peer2 # [2274100.779302] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database... peer2 # [2274100.780700] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)... peer2 # [2274100.782961] peer2 systemd[1]: Starting D-Bus System Message Bus... peer2 # [2274100.846657] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database. peer2 # [2274101.007655] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd). peer2 # [2274101.007766] peer2 systemd[1]: Reached target Host and Network Name Lookups. peer2 # [2274101.007872] peer2 systemd[1]: Reached target User and Group Name Lookups. peer2 # [2274101.008437] peer2 nsncd[224]: Sep 30 15:08:40.994 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer2 # [2274101.010003] peer2 systemd[1]: Starting User Login Management... peer2 # [2274101.011332] peer2 systemd[1]: Starting Permit User Sessions... peer2 # [2274101.048286] peer2 systemd[1]: Finished Permit User Sessions. peer2 # [2274101.049883] peer2 systemd[1]: Started Console Getty. peer2 # [2274101.049971] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 peer2 # [2274101.050006] peer2 systemd[1]: Reached target Login Prompts. peer2 # [2274101.145891] peer2 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'... peer2 # [2274101.147394] peer2 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync' peer2 # [2274101.147394] peer2 dbus-broker-launch[225]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" peer2 # [2274101.147879] peer2 systemd[1]: Started D-Bus System Message Bus. peer2 # [2274101.155315] peer2 dbus-broker-launch[225]: Ready peer2 # [2274101.578053] peer2 data-mesher[222]: time=2026-09-30T15:08:41.563Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] peer2 # [2274101.579140] peer2 data-mesher[222]: time=2026-09-30T15:08:41.564Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK peer2 # [2274101.579140] peer2 data-mesher[222]: time=2026-09-30T15:08:41.564Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml peer2 # [2274101.582694] peer2 data-mesher[222]: time=2026-09-30T15:08:41.568Z level=INFO msg="checking file integrity" peer2 # [2274101.582841] peer2 data-mesher[222]: time=2026-09-30T15:08:41.568Z level=INFO msg="file integrity check complete" peer2 # [2274101.588573] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="libp2p host created" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK 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 /ip6/fda1:5c8::c289:fe9d:a6bc:e45b/tcp/7946]" peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=GET path=/files peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="starting server" peer2 # [2274101.588863] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="waiting for DHT to populate" delay=10s peer2 # [2274101.588863] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="HTTP server listening" address=[::1]:7331 peer2 # [2274101.588961] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 peer2 # [2274101.594114] peer2 data-mesher[222]: time=2026-09-30T15:08:41.579Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946 peer2 # [2274101.600177] peer2 systemd-networkd[217]: eth1: Gained IPv6LL peer2 # [2274101.601979] peer2 data-mesher[222]: time=2026-09-30T15:08:41.587Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946 peer2 # [2274101.805576] peer2 systemd-logind[242]: New seat seat0. peer2 # [2274101.805795] peer2 systemd[1]: Started User Login Management. peer2 # [2274101.806895] peer2 systemd[1]: Starting linger-users.service... controller # [2274101.595582] controller data-mesher[232]: time=2026-09-30T15:08:41.581Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946 peer1 # [2274101.603132] peer1 data-mesher[221]: time=2026-09-30T15:08:41.588Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946 peer2 # [2274101.862009] peer2 systemd[1]: linger-users.service: Deactivated successfully. peer2 # [2274101.862163] peer2 systemd[1]: Finished linger-users.service. controller # [2274103.043780] controller data-mesher[232]: time=2026-09-30T15:08:43.029Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274103.043780] controller data-mesher[232]: time=2026-09-30T15:08:43.029Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274103.048609] controller data-mesher[232]: time=2026-09-30T15:08:43.034Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [2274103.048609] controller data-mesher[232]: time=2026-09-30T15:08:43.034Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274103.049784] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274103.049994] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s controller # [2274103.050044] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [2274103.043224] peer1 data-mesher[221]: time=2026-09-30T15:08:43.028Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [2274103.043224] peer1 data-mesher[221]: time=2026-09-30T15:08:43.029Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274103.044559] peer1 data-mesher[221]: time=2026-09-30T15:08:43.030Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274103.045136] peer1 data-mesher[221]: time=2026-09-30T15:08:43.030Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274103.045207] peer1 data-mesher[221]: time=2026-09-30T15:08:43.031Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [2274103.048905] peer1 data-mesher[221]: time=2026-09-30T15:08:43.034Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274103.048983] peer1 data-mesher[221]: time=2026-09-30T15:08:43.034Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ controller # [2274108.046536] controller data-mesher[232]: time=2026-09-30T15:08:48.032Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274108.046536] controller data-mesher[232]: time=2026-09-30T15:08:48.032Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf controller # [2274108.050678] controller data-mesher[232]: time=2026-09-30T15:08:48.036Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [2274108.050678] controller data-mesher[232]: time=2026-09-30T15:08:48.036Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s controller # [2274108.052640] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK controller # [2274108.052640] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s controller # [2274108.052781] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="push/pull successful" interval=5s controller # [2274108.053217] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller controller # [2274108.053391] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 controller # [2274108.053761] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller controller # [2274108.056102] controller data-mesher[232]: time=2026-09-30T15:08:48.041Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 peer2 # [2274108.051687] peer2 data-mesher[222]: time=2026-09-30T15:08:48.037Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274108.051687] peer2 data-mesher[222]: time=2026-09-30T15:08:48.037Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274108.052894] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274108.058575] peer2 data-mesher[222]: time=2026-09-30T15:08:48.044Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=5.952361ms peer2 # [2274108.059892] peer2 data-mesher[222]: time=2026-09-30T15:08:48.045Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=7.070576ms peer2 # [2274108.060811] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer2 # [2274108.234922] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer2 # [2274108.235252] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer1 # [2274108.045807] peer1 data-mesher[221]: time=2026-09-30T15:08:48.031Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [2274108.045807] peer1 data-mesher[221]: time=2026-09-30T15:08:48.031Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274108.047627] peer1 data-mesher[221]: time=2026-09-30T15:08:48.033Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer1 # [2274108.048274] peer1 data-mesher[221]: time=2026-09-30T15:08:48.034Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s peer1 # [2274108.048355] peer1 data-mesher[221]: time=2026-09-30T15:08:48.034Z level=DEBUG msg="push/pull successful" interval=5s peer2: still waiting for container 'peer2' to reach ready state... peer2 # [2274111.589512] peer2 data-mesher[222]: time=2026-09-30T15:08:51.575Z level=INFO msg="performing state exchange with peers on join" count=1 peer2 # [2274111.589512] peer2 data-mesher[222]: time=2026-09-30T15:08:51.575Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s peer2 # [2274111.591549] peer2 data-mesher[222]: time=2026-09-30T15:08:51.577Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf peer2 # [2274111.592373] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s peer2 # [2274111.592453] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="server started" peer2 # [2274111.592587] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="starting expired-file sweeper" interval=1m0s peer2 # [2274111.592774] peer2 systemd[1]: Started data mesher daemon. peer2 # [2274111.595061] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher... peer2 # [2274111.757370] peer2 data-mesher[222]: time=2026-09-30T15:08:51.743Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY status=204 peer2 # [2274111.757821] peer2 dm-wg-star-publish[298]: Status: 204 No Content peer2 # [2274111.759579] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer2 # [2274111.762010] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully. peer2 # [2274111.762335] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher. peer2 # [2274111.763324] peer2 systemd[1]: Reached target Multi-User System. peer1 # [2274111.590304] peer1 data-mesher[221]: time=2026-09-30T15:08:51.576Z level=INFO msg="received state sync from peer" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK peer1 # [2274111.590304] peer1 data-mesher[221]: time=2026-09-30T15:08:51.576Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK peer2: (finished: waiting for unit data-mesher.service, in 13.68 seconds) ??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1 ??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 peer2 # [2274111.919023] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer2 # [2274111.919340] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer2 # [2274111.919906] peer2 systemd[1]: Startup finished in 12.816s. controller: (finished: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1, in 1.03 seconds) controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1 controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds) peer2: waiting for success: wg show wg-star peers | grep -q . peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds) peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64 peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds) controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds) peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds) peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1 peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds) (finished: run the VM test script, in 33.60 seconds) test script finished in 33.63s cleanup kill NspawnMachine (pid 50) controller # [2274113.053296] controller data-mesher[232]: time=2026-09-30T15:08:53.039Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [2274113.054080] controller data-mesher[232]: time=2026-09-30T15:08:53.039Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s controller # [2274113.056676] controller data-mesher[232]: time=2026-09-30T15:08:53.042Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK controller # [2274113.057276] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=DEBUG msg="new file detected" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY controller # [2274113.057435] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY controller # [2274113.057528] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK controller # [2274113.057873] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s controller # [2274113.057934] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=DEBUG msg="push/pull successful" interval=5s controller # [2274113.061583] controller data-mesher[232]: time=2026-09-30T15:08:53.047Z level=INFO msg="download complete" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK written=true elapsed=4.098576ms controller # [2274113.064621] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [2274113.229648] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [2274113.229792] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. controller # [2274113.360473] controller systemd-networkd[223]: eth1: Link DOWN peer2 # [2274113.050155] peer2 data-mesher[222]: time=2026-09-30T15:08:53.035Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf peer2 # [2274113.050155] peer2 data-mesher[222]: time=2026-09-30T15:08:53.035Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf peer2 # [2274113.052809] peer2 data-mesher[222]: time=2026-09-30T15:08:53.038Z level=INFO msg="received file request" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="file transfer complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer2 # [2274113.058147] peer2 data-mesher[222]: time=2026-09-30T15:08:53.043Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer2 # [2274113.059476] peer2 data-mesher[222]: time=2026-09-30T15:08:53.045Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer1 # [2274113.049347] peer1 data-mesher[221]: time=2026-09-30T15:08:53.035Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [2274113.049347] peer1 data-mesher[221]: time=2026-09-30T15:08:53.035Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s peer1 # [2274113.051292] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK peer1 # [2274113.051871] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=DEBUG msg="new file detected" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer1 # [2274113.052152] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY peer1 # [2274113.052152] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK peer1 # [2274113.052520] peer1 data-mesher[221]: time=2026-09-30T15:08:53.038Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s peer1 # [2274113.052600] peer1 data-mesher[221]: time=2026-09-30T15:08:53.038Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [2274113.057328] peer1 data-mesher[221]: time=2026-09-30T15:08:53.043Z level=INFO msg="download complete" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK written=true elapsed=5.208672ms peer1 # [2274113.060331] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer1 # [2274113.225322] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer1 # [2274113.225645] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. kill NspawnMachine (pid 53) Container controller terminated by signal KILL. kill NspawnMachine (pid 782) Container peer1 terminated by signal KILL. Container peer2 terminated by signal KILL. (finished: cleanup, in 0.65 seconds)