build01: building nbjw4cx2i6xbr8sm9hhn4djacczgqf8g-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 boot entry found for the specified boot (+0). peer1 # No journal boot entry found for the specified boot (+0). peer1 # [136991.642173] peer1 systemd-journald[97]: Journal started peer1 # [136991.642223] peer1 systemd-journald[97]: Runtime Journal (/run/log/journal/0339db5b87414b01bbeb3cd1de8d78ae) is 8M, max 2.5G, 2.4G free. peer1 # [136991.651544] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully. peer1 # [136991.660451] peer1 systemd[1]: Starting Flush Journal to Persistent Storage... peer1 # [136991.661616] peer1 systemd[1]: Starting Network Name Resolution... peer1 # [136991.662491] peer1 systemd[1]: Starting Create Static Device Nodes in /dev... peer1 # [136991.671043] peer1 systemd-journald[97]: Time spent on flushing to /var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae is 1.354ms for 6 entries. peer1 # [136991.671043] peer1 systemd-journald[97]: System Journal (/var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae) is 8M, max 4G, 3.9G free. peer1 # [136991.678840] peer1 systemd[1]: Finished Create Static Device Nodes in /dev. peer1 # [136991.679572] peer1 systemd[1]: Reached target Preparation for Local File Systems. peer1 # [136991.679720] peer1 systemd[1]: Reached target Local File Systems. peer1 # [136991.680718] peer1 systemd[1]: Listening on Boot Loader Control Service Socket. peer1 # [136991.680774] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer1 # [136991.681659] peer1 systemd[1]: Starting Save Transient machine-id to Disk... peer1 # [136991.681696] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer1 # [136991.689357] peer1 systemd[1]: Finished Flush Journal to Persistent Storage. peer1 # [136991.690810] peer1 systemd[1]: Starting Create System Files and Directories... peer1 # [136991.705890] peer1 systemd-tmpfiles[141]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer1 # [136991.706089] peer1 systemd-tmpfiles[141]: fchmod() of /var/log/journal failed: Operation not permitted peer1 # [136991.706218] peer1 systemd-tmpfiles[141]: fchmod() of /var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae failed: Operation not permitted peer1 # [136991.706406] peer1 systemd-tmpfiles[141]: fchmod() of /run/log/journal failed: Operation not permitted peer1 # [136991.707851] peer1 systemd[1]: Finished Create System Files and Directories. peer1 # [136991.708878] peer1 systemd[1]: Starting Rebuild Journal Catalog... peer1 # [136991.709636] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer1 # [136991.721535] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer1 # [136991.727867] peer1 systemd[1]: Finished Rebuild Journal Catalog. peer1 # [136991.729201] peer1 systemd[1]: Starting Update is Completed... peer1 # [136991.741452] peer1 systemd[1]: Finished Update is Completed. peer1 # [136991.812337] peer1 systemd[1]: Finished Firewall. peer1 # [136991.812511] peer1 systemd[1]: Reached target Preparation for Network. peer1 # [136991.812732] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket. peer1 # [136991.813802] peer1 systemd[1]: Starting Network Management... peer1 # [136992.194898] peer1 systemd-networkd[214]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer1 # [136992.194987] peer1 systemd-networkd[214]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer1 # [136992.202132] peer1 systemd-networkd[214]: /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 # [136992.202303] peer1 systemd-networkd[214]: /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 # [136992.202446] peer1 systemd-networkd[214]: lo: Link UP peer1 # [136992.202452] peer1 systemd-networkd[214]: lo: Gained carrier peer1 # [136992.202646] peer1 systemd-networkd[214]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer1 # [136992.203089] peer1 systemd[1]: Started Network Management. peer1 # [136992.203761] peer1 systemd-networkd[214]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. peer1 # [136992.204106] peer1 systemd-networkd[214]: wg-star: netdev ready peer1 # [136992.204484] peer1 systemd-networkd[214]: eth1: Link UP peer1 # [136992.204697] peer1 systemd-networkd[214]: eth1: Gained carrier peer1 # [136992.204882] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer1 # [136992.248958] peer1 systemd-networkd[214]: wg-star: Link UP peer1 # [136992.248964] peer1 systemd-networkd[214]: wg-star: Gained carrier peer1 # [136992.250549] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer1 # [136992.282275] peer1 systemd-resolved[120]: Positive Trust Anchors: peer1 # [136992.282287] peer1 systemd-resolved[120]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer1 # [136992.282290] peer1 systemd-resolved[120]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer1 # [136992.282324] peer1 systemd-resolved[120]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test controller # [136991.647045] controller systemd-journald[105]: Journal started peer1 # [136992.304818] peer1 systemd-resolved[120]: Using system hostname 'peer1'. controller # [136991.647103] controller systemd-journald[105]: Runtime Journal (/run/log/journal/337028c1143749e79dcaa91ab5a171f8) is 8M, max 2.5G, 2.4G free. peer1 # [136992.306449] peer1 systemd[1]: Started Network Name Resolution. controller # [136991.651512] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully. peer1 # [136992.306586] peer1 systemd[1]: Reached target Network. controller # [136991.660311] controller systemd[1]: Starting Flush Journal to Persistent Storage... peer1 # [136992.306720] peer1 systemd[1]: Reached target System Initialization. controller # [136991.661322] controller systemd[1]: Starting Network Name Resolution... peer1 # [136992.306894] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher. controller # [136991.662013] controller systemd[1]: Starting Create Static Device Nodes in /dev... peer1 # [136992.306966] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer. controller # [136991.670806] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/337028c1143749e79dcaa91ab5a171f8 is 1.187ms for 6 entries. peer1 # [136992.307033] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container controller # [136991.670806] controller systemd-journald[105]: System Journal (/var/log/journal/337028c1143749e79dcaa91ab5a171f8) is 8M, max 4G, 3.9G free. peer1 # [136992.307076] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories. controller # [136991.679280] controller systemd[1]: Finished Create Static Device Nodes in /dev. peer1 # [136992.307118] peer1 systemd[1]: Reached target Path Units. controller # [136991.679517] controller systemd[1]: Reached target Preparation for Local File Systems. peer1 # [136992.307197] peer1 systemd[1]: Reached target Timer Units. controller # [136991.679603] controller systemd[1]: Reached target Local File Systems. peer1 # [136992.307433] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket. controller # [136991.680353] controller systemd[1]: Listening on Boot Loader Control Service Socket. peer1 # [136992.307657] peer1 systemd[1]: Listening on Nix Daemon Socket. controller # [136991.680400] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer1 # [136992.307891] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. controller # [136991.681265] controller systemd[1]: Starting Save Transient machine-id to Disk... peer1 # [136992.307941] peer1 systemd[1]: Reached target Socket Units. controller # [136991.681301] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer1 # [136992.308045] peer1 systemd[1]: Reached target Basic System. controller # [136991.687732] controller systemd[1]: Finished Flush Journal to Persistent Storage. peer1 # [136992.310493] peer1 systemd[1]: Starting data mesher daemon... controller # [136991.688749] controller systemd[1]: Starting Create System Files and Directories... peer1 # [136992.311953] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database... controller # [136991.707514] controller systemd-tmpfiles[149]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer1 # [136992.313498] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)... controller # [136991.707710] controller systemd-tmpfiles[149]: fchmod() of /var/log/journal failed: Operation not permitted peer1 # [136992.315834] peer1 systemd[1]: Starting D-Bus System Message Bus... controller # [136991.707859] controller systemd-tmpfiles[149]: fchmod() of /var/log/journal/337028c1143749e79dcaa91ab5a171f8 failed: Operation not permitted peer1 # [136992.334268] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database. controller # [136991.708194] controller systemd-tmpfiles[149]: fchmod() of /run/log/journal failed: Operation not permitted peer1 # [136992.449686] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd). controller # [136991.709937] controller systemd[1]: Finished Create System Files and Directories. peer1 # [136992.449916] peer1 nsncd[221]: Oct 17 23:26:37.421 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" controller # [136991.711046] controller systemd[1]: Starting Rebuild Journal Catalog... peer1 # [136992.449782] peer1 systemd[1]: Reached target Host and Network Name Lookups. controller # [136991.711788] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer1 # [136992.449891] peer1 systemd[1]: Reached target User and Group Name Lookups. controller # [136991.725041] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer1 # [136992.452080] peer1 systemd[1]: Starting User Login Management... controller # [136991.732192] controller systemd[1]: Finished Rebuild Journal Catalog. peer1 # [136992.453829] peer1 systemd[1]: Starting Permit User Sessions... controller # [136991.733428] controller systemd[1]: Starting Update is Completed... peer1 # [136992.504032] peer1 systemd[1]: Finished Permit User Sessions. controller # [136991.744393] controller systemd[1]: Finished Update is Completed. peer1 # [136992.505353] peer1 systemd[1]: Started Console Getty. controller # [136991.817223] controller systemd[1]: Finished Firewall. peer1 # [136992.505397] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 controller # [136991.817386] controller systemd[1]: Reached target Preparation for Network. peer1 # [136992.505419] peer1 systemd[1]: Reached target Login Prompts. controller # [136991.817620] controller systemd[1]: Listening on Network Management Resolve Hook Socket. peer1 # [136992.545516] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'... controller # [136991.818631] controller systemd[1]: Starting Network Management... peer1 # [136992.546421] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync' controller # [136992.170593] controller systemd-networkd[224]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer1 # [136992.546421] peer1 dbus-broker-launch[222]: Invalid user-name in /nix/store/sc7aavcyam9q7nbjzhwaxdpvfqz19nxc-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" controller # [136992.170681] controller systemd-networkd[224]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer1 # [136992.546975] peer1 systemd[1]: Started D-Bus System Message Bus. controller # [136992.177937] controller systemd-networkd[224]: /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 # [136992.555328] peer1 dbus-broker-launch[222]: Ready controller # [136992.178107] controller systemd-networkd[224]: /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 # [136992.584012] peer1 systemd[1]: Finished Save Transient machine-id to Disk. controller # [136992.178253] controller systemd-networkd[224]: lo: Link UP peer1 # [136992.632342] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. controller # [136992.178258] controller systemd-networkd[224]: lo: Gained carrier controller # [136992.178437] controller systemd-networkd[224]: eth1: Configuring with /etc/systemd/network/40-eth1.network. controller # [136992.178902] controller systemd[1]: Started Network Management. controller # [136992.185313] controller systemd-networkd[224]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. controller # [136992.185654] controller systemd-networkd[224]: wg-star: netdev ready controller # [136992.185966] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd... controller # [136992.186291] controller systemd-networkd[224]: eth1: Link UP controller # [136992.186510] controller systemd-networkd[224]: eth1: Gained carrier controller # [136992.241004] controller systemd-networkd[224]: wg-star: Link UP controller # [136992.241011] controller systemd-networkd[224]: wg-star: Gained carrier controller # [136992.241788] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd. controller # [136992.275613] controller systemd-resolved[128]: Positive Trust Anchors: controller # [136992.275626] controller systemd-resolved[128]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d controller # [136992.275629] controller systemd-resolved[128]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 controller # [136992.275664] controller systemd-resolved[128]: 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 # [136992.297746] controller systemd-resolved[128]: Using system hostname 'controller'. controller # [136992.299372] controller systemd[1]: Started Network Name Resolution. controller # [136992.299529] controller systemd[1]: Reached target Network. controller # [136992.299666] controller systemd[1]: Reached target System Initialization. controller # [136992.299843] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher. controller # [136992.299920] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container controller # [136992.299970] controller systemd[1]: Started Daily Cleanup of Temporary Directories. controller # [136992.300050] controller systemd[1]: Reached target Path Units. controller # [136992.300131] controller systemd[1]: Reached target Timer Units. controller # [136992.300371] controller systemd[1]: Listening on D-Bus System Message Bus Socket. controller # [136992.300593] controller systemd[1]: Listening on Nix Daemon Socket. controller # [136992.300816] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. controller # [136992.300869] controller systemd[1]: Reached target Socket Units. controller # [136992.300949] controller systemd[1]: Reached target Basic System. controller # [136992.306240] controller systemd[1]: Starting data mesher daemon... controller # [136992.307932] controller systemd[1]: Starting Import lastlog data into lastlog2 database... controller # [136992.309636] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)... controller # [136992.312531] controller systemd[1]: Starting D-Bus System Message Bus... controller # [136992.330493] controller systemd[1]: Finished Import lastlog data into lastlog2 database. controller # [136992.449870] controller nsncd[231]: Oct 17 23:26:37.421 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" controller # [136992.449700] controller systemd[1]: Started Name Service Cache Daemon (nsncd). controller # [136992.449804] controller systemd[1]: Reached target Host and Network Name Lookups. controller # [136992.449913] controller systemd[1]: Reached target User and Group Name Lookups. controller # [136992.452598] controller systemd[1]: Starting User Login Management... controller # [136992.454038] controller systemd[1]: Starting Permit User Sessions... controller # [136992.502956] controller systemd[1]: Finished Permit User Sessions. controller # [136992.504297] controller systemd[1]: Started Console Getty. controller # [136992.504355] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 controller # [136992.504383] controller systemd[1]: Reached target Login Prompts. controller # [136992.584561] controller systemd[1]: Finished Save Transient machine-id to Disk. controller # [136992.607110] controller dbus-broker-launch[232]: Looking up NSS user entry for 'systemd-timesync'... controller # [136992.608172] controller dbus-broker-launch[232]: NSS returned no entry for 'systemd-timesync' controller # [136992.608172] controller dbus-broker-launch[232]: Invalid user-name in /nix/store/sc7aavcyam9q7nbjzhwaxdpvfqz19nxc-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" controller # [136992.608724] controller systemd[1]: Started D-Bus System Message Bus. controller # [136992.618535] controller dbus-broker-launch[232]: Ready controller # [136992.642726] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully. controller # [136992.866368] controller data-mesher[229]: time=2026-10-17T23:26:37.838Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] controller # [136992.867378] controller data-mesher[229]: time=2026-10-17T23:26:37.839Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk: [/dns/controller.clan/tcp/7946]} {12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c: [/dns/peer1.clan/tcp/7946]} {12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk controller # [136992.867378] controller data-mesher[229]: time=2026-10-17T23:26:37.839Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml controller # [136992.868472] controller data-mesher[229]: time=2026-10-17T23:26:37.840Z level=INFO msg="checking file integrity" controller # [136992.868581] controller data-mesher[229]: time=2026-10-17T23:26:37.840Z level=INFO msg="file integrity check complete" controller # [136992.872449] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="libp2p host created" peer_id=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk 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::b202:e78a:7743:ac5/tcp/7946]" controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=GET path=/files controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="starting server" controller # [136992.872595] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="waiting for DHT to populate" delay=10s controller # [136992.872696] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="HTTP server listening" address=[::1]:7331 controller # [136992.872734] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 controller # [136993.042306] controller systemd-logind[249]: New seat seat0. controller # [136993.043080] controller systemd[1]: Started User Login Management. controller # [136993.052919] controller systemd[1]: Starting linger-users.service... controller # [136993.064567] controller systemd[1]: linger-users.service: Deactivated successfully. controller # [136993.064741] controller systemd[1]: Finished linger-users.service. peer1 # [136992.852117] peer1 data-mesher[219]: time=2026-10-17T23:26:37.823Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] peer1 # [136992.853197] peer1 data-mesher[219]: time=2026-10-17T23:26:37.825Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk: [/dns/controller.clan/tcp/7946]} {12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c: [/dns/peer1.clan/tcp/7946]} {12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c peer1 # [136992.853197] peer1 data-mesher[219]: time=2026-10-17T23:26:37.825Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml peer1 # [136992.855775] peer1 data-mesher[219]: time=2026-10-17T23:26:37.827Z level=INFO msg="checking file integrity" peer1 # [136992.855884] peer1 data-mesher[219]: time=2026-10-17T23:26:37.827Z level=INFO msg="file integrity check complete" peer1 # [136992.859854] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="libp2p host created" peer_id=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c 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::4ba5:b0d0:89d4:774b/tcp/7946]" peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=GET path=/files peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name peer1 # [136992.859954] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="starting server" peer1 # [136992.860078] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="waiting for DHT to populate" delay=10s peer1 # [136992.860394] peer1 data-mesher[219]: time=2026-10-17T23:26:37.832Z level=INFO msg="HTTP server listening" address=[::1]:7331 peer1 # [136992.860438] peer1 data-mesher[219]: time=2026-10-17T23:26:37.832Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 peer1 # [136993.055462] peer1 systemd-logind[239]: New seat seat0. peer1 # [136993.055800] peer1 systemd[1]: Started User Login Management. peer1 # [136993.057393] peer1 systemd[1]: Starting linger-users.service... peer1 # [136993.069173] peer1 systemd[1]: linger-users.service: Deactivated successfully. peer1 # [136993.069262] peer1 systemd[1]: Finished linger-users.service. controller # [136993.820424] controller systemd-networkd[224]: eth1: Gained IPv6LL peer1 # [136993.980159] peer1 systemd-networkd[214]: eth1: Gained IPv6LL peer1 # [136997.883673] peer1 data-mesher[219]: time=2026-10-17T23:26:42.855Z level=INFO msg="peer connected" peer_id=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk remote_addr=/ip6/2001:db8:1::1/tcp/7946 controller # [136997.881808] controller data-mesher[229]: time=2026-10-17T23:26:42.853Z level=INFO msg="peer connected" peer_id=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c remote_addr=/ip6/2001:db8:1::2/tcp/7946 controller: still waiting for container 'controller' to reach ready state... controller # [137002.861371] controller data-mesher[229]: time=2026-10-17T23:26:47.833Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137002.861371] controller data-mesher[229]: time=2026-10-17T23:26:47.833Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137002.873175] controller data-mesher[229]: time=2026-10-17T23:26:47.844Z level=INFO msg="performing state exchange with peers on join" count=1 controller # [137002.873348] controller data-mesher[229]: time=2026-10-17T23:26:47.845Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137002.874149] controller data-mesher[229]: time=2026-10-17T23:26:47.845Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137002.874149] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137002.874262] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="server started" controller # [137002.874405] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="starting expired-file sweeper" interval=1m0s controller # [137002.874496] controller systemd[1]: Started data mesher daemon. controller # [137002.904614] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher... controller # [137002.943332] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [137002.951281] controller data-mesher[229]: time=2026-10-17T23:26:47.923Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204 controller # [137002.951440] controller dm-wg-star-publish[296]: Status: 204 No Content controller # [137002.954673] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher. controller # [137002.955262] controller systemd[1]: Reached target Multi-User System. controller # [137003.039245] controller dm-wg-star-reconfig[323]: No peer data available yet, skipping controller # [137003.040304] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [137003.060407] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. controller # [137003.060826] controller systemd[1]: Startup finished in 11.818s. peer1 # [137002.860579] peer1 data-mesher[219]: time=2026-10-17T23:26:47.832Z level=INFO msg="performing state exchange with peers on join" count=1 peer1 # [137002.861329] peer1 data-mesher[219]: time=2026-10-17T23:26:47.832Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137002.861679] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137002.861679] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137002.861803] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="server started" peer1 # [137002.861914] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="starting expired-file sweeper" interval=1m0s peer1 # [137002.861991] peer1 systemd[1]: Started data mesher daemon. peer1 # [137002.863664] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher... peer1 # [137002.873855] peer1 data-mesher[219]: time=2026-10-17T23:26:47.845Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137002.873855] peer1 data-mesher[219]: time=2026-10-17T23:26:47.845Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137003.025443] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer1 # [137003.026415] peer1 data-mesher[219]: time=2026-10-17T23:26:47.998Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k status=204 peer1 # [137003.026540] peer1 dm-wg-star-publish[285]: Status: 204 No Content peer1 # [137003.029248] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully. peer1 # [137003.060307] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher. peer1 # [137003.060928] peer1 systemd[1]: Reached target Multi-User System. peer1 # [137003.149527] peer1 dm-wg-star-reconfig[313]: No controller data available yet, skipping controller: (finished: waiting for unit data-mesher.service, in 12.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/8xlk88ia8b5yg9kfrg3skndwzgphipvr-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/8xlk88ia8b5yg9kfrg3skndwzgphipvr-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 # [137003.150842] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer1 # [137003.150998] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer1 # [137003.151573] peer1 systemd[1]: Startup finished in 11.923s. controller # [137007.863252] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137007.863252] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137007.863991] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=DEBUG msg="new file detected" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k controller # [137007.864100] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k controller # [137007.864188] controller data-mesher[229]: time=2026-10-17T23:26:52.836Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k signed_at="2026-10-17 23:26:47.992 +0000 UTC" signed_by="TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM/xJi3k=" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137007.865175] controller data-mesher[229]: time=2026-10-17T23:26:52.837Z level=INFO msg="received file request" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/controller controller # [137007.867442] controller data-mesher[229]: time=2026-10-17T23:26:52.839Z level=INFO msg="file transfer complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/controller controller # [137007.872575] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [137007.875126] controller data-mesher[229]: time=2026-10-17T23:26:52.846Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [137007.875126] controller data-mesher[229]: time=2026-10-17T23:26:52.847Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137007.876199] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137007.876643] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=INFO msg="download complete" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k signed_at="2026-10-17 23:26:47.992 +0000 UTC" signed_by="TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM/xJi3k=" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c written=true elapsed=12.489172ms controller # [137007.876857] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137007.876915] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=DEBUG msg="push/pull successful" interval=5s controller # [137008.023092] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [137008.023246] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. peer1 # [137007.862392] peer1 data-mesher[219]: time=2026-10-17T23:26:52.834Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [137007.863072] peer1 data-mesher[219]: time=2026-10-17T23:26:52.834Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137007.864241] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137007.864241] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=DEBUG msg="new file detected" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer1 # [137007.864367] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137007.864367] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [137007.864367] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller peer1 # [137007.864514] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-10-17 23:26:47.909 +0000 UTC" signed_by="vc56aLNWYkmsIoih9geuAdIW+euKM0kLd62fxmFBpJE=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137007.864724] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="received file request" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k peer1 # [137007.867155] peer1 data-mesher[219]: time=2026-10-17T23:26:52.838Z level=INFO msg="file transfer complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k peer1 # [137007.871188] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer1 # [137007.875780] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137007.875780] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137007.875923] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=DEBUG msg="new file detected" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer1 # [137007.875923] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-10-17 23:26:47.909 +0000 UTC" signed_by="vc56aLNWYkmsIoih9geuAdIW+euKM0kLd62fxmFBpJE=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk written=true elapsed=11.539158ms peer1 # [137008.018113] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer1 # [137008.018510] 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::b202:e78a:7743:0ac5 controller # [137012.865429] controller data-mesher[229]: time=2026-10-17T23:26:57.837Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137012.865429] controller data-mesher[229]: time=2026-10-17T23:26:57.837Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137012.877754] controller data-mesher[229]: time=2026-10-17T23:26:57.849Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [137012.877851] controller data-mesher[229]: time=2026-10-17T23:26:57.849Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137012.879460] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137012.880098] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137012.880190] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [137012.864655] peer1 data-mesher[219]: time=2026-10-17T23:26:57.836Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [137012.865398] peer1 data-mesher[219]: time=2026-10-17T23:26:57.836Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137012.866443] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137012.867052] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137012.867121] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [137012.878496] peer1 data-mesher[219]: time=2026-10-17T23:26:57.850Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137012.878573] peer1 data-mesher[219]: time=2026-10-17T23:26:57.850Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5, in 6.02 seconds) controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b, 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 784) 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 boot entry found for the specified boot (+0). peer2 # [137015.480182] peer2 systemd-journald[94]: Journal started peer2 # [137015.480240] peer2 systemd-journald[94]: Runtime Journal (/run/log/journal/8b387664a4b144ce81b847700604729b) is 8M, max 2.5G, 2.4G free. peer2 # [137015.483200] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully. peer2 # [137015.492556] peer2 systemd[1]: Starting Flush Journal to Persistent Storage... peer2 # [137015.493513] peer2 systemd[1]: Starting Network Name Resolution... peer2 # [137015.494470] peer2 systemd[1]: Starting Create Static Device Nodes in /dev... peer2 # [137015.501746] peer2 systemd-journald[94]: Time spent on flushing to /var/log/journal/8b387664a4b144ce81b847700604729b is 1.097ms for 6 entries. peer2 # [137015.501746] peer2 systemd-journald[94]: System Journal (/var/log/journal/8b387664a4b144ce81b847700604729b) is 8M, max 4G, 3.9G free. peer2 # [137015.510196] peer2 systemd[1]: Finished Create Static Device Nodes in /dev. peer2 # [137015.510414] peer2 systemd[1]: Reached target Preparation for Local File Systems. peer2 # [137015.510491] peer2 systemd[1]: Reached target Local File Systems. peer2 # [137015.511227] peer2 systemd[1]: Listening on Boot Loader Control Service Socket. peer2 # [137015.511269] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container peer2 # [137015.512075] peer2 systemd[1]: Starting Save Transient machine-id to Disk... peer2 # [137015.512107] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys peer2 # [137015.513509] peer2 systemd[1]: Finished Flush Journal to Persistent Storage. peer2 # [137015.514332] peer2 systemd[1]: Starting Create System Files and Directories... peer2 # [137015.530519] peer2 systemd[1]: Finished Save Transient machine-id to Disk. peer2 # [137015.532326] peer2 systemd-tmpfiles[133]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted peer2 # [137015.532524] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal failed: Operation not permitted peer2 # [137015.532656] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal/8b387664a4b144ce81b847700604729b failed: Operation not permitted peer2 # [137015.532853] peer2 systemd-tmpfiles[133]: fchmod() of /run/log/journal failed: Operation not permitted peer2 # [137015.534291] peer2 systemd[1]: Finished Create System Files and Directories. peer2 # [137015.535303] peer2 systemd[1]: Starting Rebuild Journal Catalog... peer2 # [137015.536067] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP... peer2 # [137015.549561] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP. peer2 # [137015.558748] peer2 systemd[1]: Finished Rebuild Journal Catalog. peer2 # [137015.559971] peer2 systemd[1]: Starting Update is Completed... peer2 # [137015.570977] peer2 systemd[1]: Finished Update is Completed. peer2 # [137015.647065] peer2 systemd[1]: Finished Firewall. peer2 # [137015.647806] peer2 systemd[1]: Reached target Preparation for Network. peer2 # [137015.648326] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket. peer2 # [137015.649879] peer2 systemd[1]: Starting Network Management... peer2 # [137016.006564] peer2 systemd-networkd[212]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted peer2 # [137016.006654] peer2 systemd-networkd[212]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted peer2 # [137016.013579] peer2 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. peer2 # [137016.013746] peer2 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. peer2 # [137016.013890] peer2 systemd-networkd[212]: lo: Link UP peer2 # [137016.013893] peer2 systemd-networkd[212]: lo: Gained carrier peer2 # [137016.014084] peer2 systemd-networkd[212]: eth1: Configuring with /etc/systemd/network/40-eth1.network. peer2 # [137016.014624] peer2 systemd[1]: Started Network Management. peer2 # [137016.015702] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd... peer2 # [137016.015771] peer2 systemd-networkd[212]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network. peer2 # [137016.016108] peer2 systemd-networkd[212]: wg-star: netdev ready peer2 # [137016.016509] peer2 systemd-networkd[212]: eth1: Link UP peer2 # [137016.016726] peer2 systemd-networkd[212]: eth1: Gained carrier peer2 # [137016.041290] peer2 systemd-resolved[116]: Positive Trust Anchors: peer2 # [137016.041301] peer2 systemd-resolved[116]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d peer2 # [137016.041306] peer2 systemd-resolved[116]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 peer2 # [137016.041340] peer2 systemd-resolved[116]: 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 # [137016.052580] peer2 systemd-networkd[212]: wg-star: Link UP peer2 # [137016.052586] peer2 systemd-networkd[212]: wg-star: Gained carrier peer2 # [137016.062949] peer2 systemd-resolved[116]: Using system hostname 'peer2'. peer2 # [137016.064566] peer2 systemd[1]: Started Network Name Resolution. peer2 # [137016.064706] peer2 systemd[1]: Reached target Network. peer2 # [137016.064815] peer2 systemd[1]: Reached target System Initialization. peer2 # [137016.064998] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher. peer2 # [137016.065058] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer. peer2 # [137016.065102] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container peer2 # [137016.065144] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories. peer2 # [137016.065190] peer2 systemd[1]: Reached target Path Units. peer2 # [137016.065269] peer2 systemd[1]: Reached target Timer Units. peer2 # [137016.065513] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket. peer2 # [137016.065742] peer2 systemd[1]: Listening on Nix Daemon Socket. peer2 # [137016.065975] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. peer2 # [137016.066023] peer2 systemd[1]: Reached target Socket Units. peer2 # [137016.066099] peer2 systemd[1]: Reached target Basic System. peer2 # [137016.068311] peer2 systemd[1]: Starting data mesher daemon... peer2 # [137016.069740] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database... peer2 # [137016.071091] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)... peer2 # [137016.071594] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd. peer2 # [137016.075299] peer2 systemd[1]: Starting D-Bus System Message Bus... peer2 # [137016.091054] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database. peer2 # [137016.172303] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd). peer2 # [137016.172444] peer2 nsncd[218]: Oct 17 23:27:01.144 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" peer2 # [137016.172423] peer2 systemd[1]: Reached target Host and Network Name Lookups. peer2 # [137016.172525] peer2 systemd[1]: Reached target User and Group Name Lookups. peer2 # [137016.174715] peer2 systemd[1]: Starting User Login Management... peer2 # [137016.176105] peer2 systemd[1]: Starting Permit User Sessions... peer2 # [137016.220180] peer2 systemd[1]: Finished Permit User Sessions. peer2 # [137016.221816] peer2 systemd[1]: Started Console Getty. peer2 # [137016.221889] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 peer2 # [137016.221929] peer2 systemd[1]: Reached target Login Prompts. peer2 # [137016.236306] peer2 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'... peer2 # [137016.237947] peer2 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync' peer2 # [137016.237947] peer2 dbus-broker-launch[221]: Invalid user-name in /nix/store/sc7aavcyam9q7nbjzhwaxdpvfqz19nxc-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" peer2 # [137016.238384] peer2 systemd[1]: Started D-Bus System Message Bus. peer2 # [137016.246361] peer2 dbus-broker-launch[221]: Ready peer2 # [137016.454435] peer2 data-mesher[216]: time=2026-10-17T23:27:01.426Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo] peer2 # [137016.455538] peer2 data-mesher[216]: time=2026-10-17T23:27:01.427Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk: [/dns/controller.clan/tcp/7946]} {12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c: [/dns/peer1.clan/tcp/7946]} {12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m peer2 # [137016.455538] peer2 data-mesher[216]: time=2026-10-17T23:27:01.427Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml peer2 # [137016.456826] peer2 data-mesher[216]: time=2026-10-17T23:27:01.428Z level=INFO msg="checking file integrity" peer2 # [137016.456940] peer2 data-mesher[216]: time=2026-10-17T23:27:01.428Z level=INFO msg="file integrity check complete" peer2 # [137016.460645] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="libp2p host created" peer_id=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m 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::eb76:9549:900d:8944/tcp/7946]" peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=GET path=/files peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="starting server" peer2 # [137016.460902] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="waiting for DHT to populate" delay=10s peer2 # [137016.460954] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="HTTP server listening" address=[::1]:7331 peer2 # [137016.461167] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331 peer2 # [137016.468504] peer2 data-mesher[216]: time=2026-10-17T23:27:01.440Z level=INFO msg="peer connected" peer_id=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c remote_addr=/ip4/192.168.1.2/tcp/7946 peer2 # [137016.475339] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. peer2 # [137016.476229] peer2 data-mesher[216]: time=2026-10-17T23:27:01.448Z level=INFO msg="peer connected" peer_id=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk remote_addr=/ip4/192.168.1.1/tcp/7946 peer1 # [137016.469505] peer1 data-mesher[219]: time=2026-10-17T23:27:01.441Z level=INFO msg="peer connected" peer_id=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m remote_addr=/ip4/192.168.1.3/tcp/7946 peer2 # [137016.612843] peer2 systemd-logind[237]: New seat seat0. peer2 # [137016.613061] peer2 systemd[1]: Started User Login Management. peer2 # [137016.615302] peer2 systemd[1]: Starting linger-users.service... peer2 # [137016.666642] peer2 systemd[1]: linger-users.service: Deactivated successfully. peer2 # [137016.666969] peer2 systemd[1]: Finished linger-users.service. controller # [137016.478131] controller data-mesher[229]: time=2026-10-17T23:27:01.449Z level=INFO msg="peer connected" peer_id=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m remote_addr=/ip4/192.168.1.3/tcp/7946 peer2 # [137017.404371] peer2 systemd-networkd[212]: eth1: Gained IPv6LL controller # [137017.868861] controller data-mesher[229]: time=2026-10-17T23:27:02.840Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137017.868861] controller data-mesher[229]: time=2026-10-17T23:27:02.840Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137017.881211] controller data-mesher[229]: time=2026-10-17T23:27:02.852Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [137017.881211] controller data-mesher[229]: time=2026-10-17T23:27:02.852Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137017.882588] controller data-mesher[229]: time=2026-10-17T23:27:02.854Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137017.883177] controller data-mesher[229]: time=2026-10-17T23:27:02.855Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s controller # [137017.883244] controller data-mesher[229]: time=2026-10-17T23:27:02.855Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [137017.868117] peer1 data-mesher[219]: time=2026-10-17T23:27:02.839Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [137017.868810] peer1 data-mesher[219]: time=2026-10-17T23:27:02.840Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137017.869863] peer1 data-mesher[219]: time=2026-10-17T23:27:02.841Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137017.870449] peer1 data-mesher[219]: time=2026-10-17T23:27:02.842Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137017.870532] peer1 data-mesher[219]: time=2026-10-17T23:27:02.842Z level=DEBUG msg="push/pull successful" interval=5s peer1 # [137017.881587] peer1 data-mesher[219]: time=2026-10-17T23:27:02.853Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137017.881587] peer1 data-mesher[219]: time=2026-10-17T23:27:02.853Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk controller # [137022.871854] controller data-mesher[229]: time=2026-10-17T23:27:07.843Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137022.871854] controller data-mesher[229]: time=2026-10-17T23:27:07.843Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137022.883523] controller data-mesher[229]: time=2026-10-17T23:27:07.855Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [137022.883523] controller data-mesher[229]: time=2026-10-17T23:27:07.855Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s controller # [137022.885765] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m controller # [137022.885765] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=INFO msg="state exchange complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s controller # [137022.885977] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=INFO msg="received file request" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/controller controller # [137022.886487] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=DEBUG msg="push/pull successful" interval=5s controller # [137022.886487] controller data-mesher[229]: time=2026-10-17T23:27:07.858Z level=INFO msg="received file request" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k controller # [137022.889244] controller data-mesher[229]: time=2026-10-17T23:27:07.861Z level=INFO msg="file transfer complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k controller # [137022.889244] controller data-mesher[229]: time=2026-10-17T23:27:07.861Z level=INFO msg="file transfer complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/controller peer1 # [137022.871057] peer1 data-mesher[219]: time=2026-10-17T23:27:07.842Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [137022.871057] peer1 data-mesher[219]: time=2026-10-17T23:27:07.842Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137022.872894] peer1 data-mesher[219]: time=2026-10-17T23:27:07.844Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137022.873484] peer1 data-mesher[219]: time=2026-10-17T23:27:07.845Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137022.873563] peer1 data-mesher[219]: time=2026-10-17T23:27:07.845Z level=DEBUG msg="push/pull successful" interval=5s peer2 # [137022.884495] peer2 data-mesher[216]: time=2026-10-17T23:27:07.856Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137022.884495] peer2 data-mesher[216]: time=2026-10-17T23:27:07.856Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137022.885328] peer2 data-mesher[216]: time=2026-10-17T23:27:07.856Z level=DEBUG msg="new file detected" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k peer2 # [137022.885328] peer2 data-mesher[216]: time=2026-10-17T23:27:07.857Z level=DEBUG msg="new file detected" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller peer2 # [137022.885328] peer2 data-mesher[216]: time=2026-10-17T23:27:07.857Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k peer2 # [137022.885328] peer2 data-mesher[216]: time=2026-10-17T23:27:07.857Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller peer2 # [137022.885526] peer2 data-mesher[216]: time=2026-10-17T23:27:07.857Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-10-17 23:26:47.909 +0000 UTC" signed_by="vc56aLNWYkmsIoih9geuAdIW+euKM0kLd62fxmFBpJE=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137022.885526] peer2 data-mesher[216]: time=2026-10-17T23:27:07.857Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k signed_at="2026-10-17 23:26:47.992 +0000 UTC" signed_by="TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM/xJi3k=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137022.891816] peer2 data-mesher[216]: time=2026-10-17T23:27:07.863Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-10-17 23:26:47.909 +0000 UTC" signed_by="vc56aLNWYkmsIoih9geuAdIW+euKM0kLd62fxmFBpJE=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk written=true elapsed=6.434728ms peer2 # [137022.894135] peer2 data-mesher[216]: time=2026-10-17T23:27:07.865Z level=INFO msg="download complete" name=dm_wg_star_wg_star/TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM_xJi3k signed_at="2026-10-17 23:26:47.992 +0000 UTC" signed_by="TgH6Uxy06GHAZnZZWIzHaNV0jGNbqTVzfk9VM/xJi3k=" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk written=true elapsed=8.358994ms peer2 # [137022.894392] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer2 # [137023.060910] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer2 # [137023.061253] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer2: still waiting for container 'peer2' to reach ready state... peer2 # [137026.461025] peer2 data-mesher[216]: time=2026-10-17T23:27:11.432Z level=INFO msg="performing state exchange with peers on join" count=1 peer2 # [137026.461025] peer2 data-mesher[216]: time=2026-10-17T23:27:11.432Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer2 # [137026.463007] peer2 data-mesher[216]: time=2026-10-17T23:27:11.434Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137026.463618] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer2 # [137026.463698] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="server started" peer2 # [137026.463908] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="starting expired-file sweeper" interval=1m0s peer2 # [137026.464198] peer2 systemd[1]: Started data mesher daemon. peer2 # [137026.466343] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher... peer2 # [137026.633719] peer2 data-mesher[216]: time=2026-10-17T23:27:11.605Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 status=204 peer2 # [137026.633949] peer2 dm-wg-star-publish[294]: Status: 204 No Content peer2 # [137026.636224] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher... peer2 # [137026.638225] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully. peer2 # [137026.638543] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher. peer2 # [137026.639578] peer2 systemd[1]: Reached target Multi-User System. controller # [137026.461886] controller data-mesher[229]: time=2026-10-17T23:27:11.433Z level=INFO msg="received state sync from peer" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m controller # [137026.461886] controller data-mesher[229]: time=2026-10-17T23:27:11.433Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m peer2 # [137026.784347] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. peer2 # [137026.784671] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher. peer2 # [137026.785210] peer2 systemd[1]: Startup finished in 11.741s. peer2: (finished: waiting for unit data-mesher.service, in 12.67 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 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/8xlk88ia8b5yg9kfrg3skndwzgphipvr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 controller # [137027.874438] controller data-mesher[229]: time=2026-10-17T23:27:12.846Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137027.874438] controller data-mesher[229]: time=2026-10-17T23:27:12.846Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c controller # [137027.887182] controller data-mesher[229]: time=2026-10-17T23:27:12.859Z level=DEBUG msg="attempting push/pull" peer_count=1 controller # [137027.887290] controller data-mesher[229]: time=2026-10-17T23:27:12.859Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s controller # [137027.888939] controller data-mesher[229]: time=2026-10-17T23:27:12.860Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m controller # [137027.889552] controller data-mesher[229]: time=2026-10-17T23:27:12.861Z level=DEBUG msg="new file detected" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 controller # [137027.889721] controller data-mesher[229]: time=2026-10-17T23:27:12.861Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 controller # [137027.889848] controller data-mesher[229]: time=2026-10-17T23:27:12.861Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 signed_at="2026-10-17 23:27:11.601 +0000 UTC" signed_by="MfaiOwfdzb+LFVSD0fRH+R6M3gnlsuvhz5OELcL7Iv4=" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m controller # [137027.890189] controller data-mesher[229]: time=2026-10-17T23:27:12.861Z level=INFO msg="state exchange complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s controller # [137027.890189] controller data-mesher[229]: time=2026-10-17T23:27:12.862Z level=DEBUG msg="push/pull successful" interval=5s controller # [137027.894968] controller data-mesher[229]: time=2026-10-17T23:27:12.866Z level=INFO msg="download complete" name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 signed_at="2026-10-17 23:27:11.601 +0000 UTC" signed_by="MfaiOwfdzb+LFVSD0fRH+R6M3gnlsuvhz5OELcL7Iv4=" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m written=true elapsed=5.192911ms controller # [137027.897882] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher... controller # [137028.055258] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully. controller # [137028.055603] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher. 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::b202:e78a:7743:0ac5 peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5, in 0.01 seconds) controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944 controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944, in 0.01 seconds) peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944 peer1 # [137027.873750] peer1 data-mesher[219]: time=2026-10-17T23:27:12.845Z level=DEBUG msg="attempting push/pull" peer_count=1 peer1 # [137027.874576] peer1 data-mesher[219]: time=2026-10-17T23:27:12.845Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137027.875583] peer1 data-mesher[219]: time=2026-10-17T23:27:12.847Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer1 # [137027.876225] peer1 data-mesher[219]: time=2026-10-17T23:27:12.848Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s peer1 # [137027.876326] peer1 data-mesher[219]: time=2026-10-17T23:27:12.848Z level=DEBUG msg="push/pull successful" interval=5s peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944, in 0.01 seconds) peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b, in 0.01 seconds) (finished: run the VM test script, in 37.61 seconds) test script finished in 37.64s cleanup kill NspawnMachine (pid 50) peer2 # [137027.887863] peer2 data-mesher[216]: time=2026-10-17T23:27:12.859Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137027.887863] peer2 data-mesher[216]: time=2026-10-17T23:27:12.859Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk peer2 # [137027.890276] peer2 data-mesher[216]: time=2026-10-17T23:27:12.862Z level=INFO msg="received file request" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 peer2 # [137027.892802] peer2 data-mesher[216]: time=2026-10-17T23:27:12.864Z level=INFO msg="file transfer complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk network="pI3i8tlhi0bx2FmxJgwaW+6zM6MLcaJzbif7Re+xE+0=" name=dm_wg_star_wg_star/MfaiOwfdzb-LFVSD0fRH-R6M3gnlsuvhz5OELcL7Iv4 kill NspawnMachine (pid 53) Container controller terminated by signal KILL. kill NspawnMachine (pid 784) Container peer1 terminated by signal KILL. Container peer2 terminated by signal KILL. (finished: cleanup, in 0.59 seconds)