container-test-run-dm-wireguard-star
checks.aarch64-linux.dm-wireguard-star
· build #278
· raw
1build01: building nbjw4cx2i6xbr8sm9hhn4djacczgqf8g-container-test-run-dm-wireguard-star.drv2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)56Test will time out and terminate in 3600.0 seconds7run the VM test script8additionally exposed symbols:9 controller, peer1, peer2,10 vlan1,11 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_ssh12controller: systemd-nspawn running (pid 50)13controller: Waiting for journal at /build/vm-state-controller/var/log/journal...14peer1: systemd-nspawn running (pid 53)15peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...16controller: waiting for unit data-mesher.service17nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.21Note: 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.22Note: 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.23░ Spawning container controller on /build/vm-state-controller.24░ Spawning container peer1 on /build/vm-state-peer1.25controller # No journal boot entry found for the specified boot (+0).26peer1 # No journal boot entry found for the specified boot (+0).27peer1 # [136991.642173] peer1 systemd-journald[97]: Journal started28peer1 # [136991.642223] peer1 systemd-journald[97]: Runtime Journal (/run/log/journal/0339db5b87414b01bbeb3cd1de8d78ae) is 8M, max 2.5G, 2.4G free.29peer1 # [136991.651544] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.30peer1 # [136991.660451] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...31peer1 # [136991.661616] peer1 systemd[1]: Starting Network Name Resolution...32peer1 # [136991.662491] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...33peer1 # [136991.671043] peer1 systemd-journald[97]: Time spent on flushing to /var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae is 1.354ms for 6 entries.34peer1 # [136991.671043] peer1 systemd-journald[97]: System Journal (/var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae) is 8M, max 4G, 3.9G free.35peer1 # [136991.678840] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.36peer1 # [136991.679572] peer1 systemd[1]: Reached target Preparation for Local File Systems.37peer1 # [136991.679720] peer1 systemd[1]: Reached target Local File Systems.38peer1 # [136991.680718] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.39peer1 # [136991.680774] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container40peer1 # [136991.681659] peer1 systemd[1]: Starting Save Transient machine-id to Disk...41peer1 # [136991.681696] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys42peer1 # [136991.689357] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.43peer1 # [136991.690810] peer1 systemd[1]: Starting Create System Files and Directories...44peer1 # [136991.705890] peer1 systemd-tmpfiles[141]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted45peer1 # [136991.706089] peer1 systemd-tmpfiles[141]: fchmod() of /var/log/journal failed: Operation not permitted46peer1 # [136991.706218] peer1 systemd-tmpfiles[141]: fchmod() of /var/log/journal/0339db5b87414b01bbeb3cd1de8d78ae failed: Operation not permitted47peer1 # [136991.706406] peer1 systemd-tmpfiles[141]: fchmod() of /run/log/journal failed: Operation not permitted48peer1 # [136991.707851] peer1 systemd[1]: Finished Create System Files and Directories.49peer1 # [136991.708878] peer1 systemd[1]: Starting Rebuild Journal Catalog...50peer1 # [136991.709636] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...51peer1 # [136991.721535] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.52peer1 # [136991.727867] peer1 systemd[1]: Finished Rebuild Journal Catalog.53peer1 # [136991.729201] peer1 systemd[1]: Starting Update is Completed...54peer1 # [136991.741452] peer1 systemd[1]: Finished Update is Completed.55peer1 # [136991.812337] peer1 systemd[1]: Finished Firewall.56peer1 # [136991.812511] peer1 systemd[1]: Reached target Preparation for Network.57peer1 # [136991.812732] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.58peer1 # [136991.813802] peer1 systemd[1]: Starting Network Management...59peer1 # [136992.194898] peer1 systemd-networkd[214]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted60peer1 # [136992.194987] peer1 systemd-networkd[214]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted61peer1 # [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.62peer1 # [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.63peer1 # [136992.202446] peer1 systemd-networkd[214]: lo: Link UP64peer1 # [136992.202452] peer1 systemd-networkd[214]: lo: Gained carrier65peer1 # [136992.202646] peer1 systemd-networkd[214]: eth1: Configuring with /etc/systemd/network/40-eth1.network.66peer1 # [136992.203089] peer1 systemd[1]: Started Network Management.67peer1 # [136992.203761] peer1 systemd-networkd[214]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.68peer1 # [136992.204106] peer1 systemd-networkd[214]: wg-star: netdev ready69peer1 # [136992.204484] peer1 systemd-networkd[214]: eth1: Link UP70peer1 # [136992.204697] peer1 systemd-networkd[214]: eth1: Gained carrier71peer1 # [136992.204882] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...72peer1 # [136992.248958] peer1 systemd-networkd[214]: wg-star: Link UP73peer1 # [136992.248964] peer1 systemd-networkd[214]: wg-star: Gained carrier74peer1 # [136992.250549] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.75peer1 # [136992.282275] peer1 systemd-resolved[120]: Positive Trust Anchors:76peer1 # [136992.282287] peer1 systemd-resolved[120]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d77peer1 # [136992.282290] peer1 systemd-resolved[120]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1678peer1 # [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 test79controller # [136991.647045] controller systemd-journald[105]: Journal started80peer1 # [136992.304818] peer1 systemd-resolved[120]: Using system hostname 'peer1'.81controller # [136991.647103] controller systemd-journald[105]: Runtime Journal (/run/log/journal/337028c1143749e79dcaa91ab5a171f8) is 8M, max 2.5G, 2.4G free.82peer1 # [136992.306449] peer1 systemd[1]: Started Network Name Resolution.83controller # [136991.651512] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.84peer1 # [136992.306586] peer1 systemd[1]: Reached target Network.85controller # [136991.660311] controller systemd[1]: Starting Flush Journal to Persistent Storage...86peer1 # [136992.306720] peer1 systemd[1]: Reached target System Initialization.87controller # [136991.661322] controller systemd[1]: Starting Network Name Resolution...88peer1 # [136992.306894] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.89controller # [136991.662013] controller systemd[1]: Starting Create Static Device Nodes in /dev...90peer1 # [136992.306966] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.91controller # [136991.670806] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/337028c1143749e79dcaa91ab5a171f8 is 1.187ms for 6 entries.92peer1 # [136992.307033] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container93controller # [136991.670806] controller systemd-journald[105]: System Journal (/var/log/journal/337028c1143749e79dcaa91ab5a171f8) is 8M, max 4G, 3.9G free.94peer1 # [136992.307076] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.95controller # [136991.679280] controller systemd[1]: Finished Create Static Device Nodes in /dev.96peer1 # [136992.307118] peer1 systemd[1]: Reached target Path Units.97controller # [136991.679517] controller systemd[1]: Reached target Preparation for Local File Systems.98peer1 # [136992.307197] peer1 systemd[1]: Reached target Timer Units.99controller # [136991.679603] controller systemd[1]: Reached target Local File Systems.100peer1 # [136992.307433] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.101controller # [136991.680353] controller systemd[1]: Listening on Boot Loader Control Service Socket.102peer1 # [136992.307657] peer1 systemd[1]: Listening on Nix Daemon Socket.103controller # [136991.680400] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104peer1 # [136992.307891] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.105controller # [136991.681265] controller systemd[1]: Starting Save Transient machine-id to Disk...106peer1 # [136992.307941] peer1 systemd[1]: Reached target Socket Units.107controller # [136991.681301] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys108peer1 # [136992.308045] peer1 systemd[1]: Reached target Basic System.109controller # [136991.687732] controller systemd[1]: Finished Flush Journal to Persistent Storage.110peer1 # [136992.310493] peer1 systemd[1]: Starting data mesher daemon...111controller # [136991.688749] controller systemd[1]: Starting Create System Files and Directories...112peer1 # [136992.311953] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...113controller # [136991.707514] controller systemd-tmpfiles[149]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted114peer1 # [136992.313498] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...115controller # [136991.707710] controller systemd-tmpfiles[149]: fchmod() of /var/log/journal failed: Operation not permitted116peer1 # [136992.315834] peer1 systemd[1]: Starting D-Bus System Message Bus...117controller # [136991.707859] controller systemd-tmpfiles[149]: fchmod() of /var/log/journal/337028c1143749e79dcaa91ab5a171f8 failed: Operation not permitted118peer1 # [136992.334268] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.119controller # [136991.708194] controller systemd-tmpfiles[149]: fchmod() of /run/log/journal failed: Operation not permitted120peer1 # [136992.449686] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).121controller # [136991.709937] controller systemd[1]: Finished Create System Files and Directories.122peer1 # [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"123controller # [136991.711046] controller systemd[1]: Starting Rebuild Journal Catalog...124peer1 # [136992.449782] peer1 systemd[1]: Reached target Host and Network Name Lookups.125controller # [136991.711788] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...126peer1 # [136992.449891] peer1 systemd[1]: Reached target User and Group Name Lookups.127controller # [136991.725041] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.128peer1 # [136992.452080] peer1 systemd[1]: Starting User Login Management...129controller # [136991.732192] controller systemd[1]: Finished Rebuild Journal Catalog.130peer1 # [136992.453829] peer1 systemd[1]: Starting Permit User Sessions...131controller # [136991.733428] controller systemd[1]: Starting Update is Completed...132peer1 # [136992.504032] peer1 systemd[1]: Finished Permit User Sessions.133controller # [136991.744393] controller systemd[1]: Finished Update is Completed.134peer1 # [136992.505353] peer1 systemd[1]: Started Console Getty.135controller # [136991.817223] controller systemd[1]: Finished Firewall.136peer1 # [136992.505397] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0137controller # [136991.817386] controller systemd[1]: Reached target Preparation for Network.138peer1 # [136992.505419] peer1 systemd[1]: Reached target Login Prompts.139controller # [136991.817620] controller systemd[1]: Listening on Network Management Resolve Hook Socket.140peer1 # [136992.545516] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...141controller # [136991.818631] controller systemd[1]: Starting Network Management...142peer1 # [136992.546421] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'143controller # [136992.170593] controller systemd-networkd[224]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted144peer1 # [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"145controller # [136992.170681] controller systemd-networkd[224]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted146peer1 # [136992.546975] peer1 systemd[1]: Started D-Bus System Message Bus.147controller # [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.148peer1 # [136992.555328] peer1 dbus-broker-launch[222]: Ready149controller # [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.150peer1 # [136992.584012] peer1 systemd[1]: Finished Save Transient machine-id to Disk.151controller # [136992.178253] controller systemd-networkd[224]: lo: Link UP152peer1 # [136992.632342] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.153controller # [136992.178258] controller systemd-networkd[224]: lo: Gained carrier154controller # [136992.178437] controller systemd-networkd[224]: eth1: Configuring with /etc/systemd/network/40-eth1.network.155controller # [136992.178902] controller systemd[1]: Started Network Management.156controller # [136992.185313] controller systemd-networkd[224]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.157controller # [136992.185654] controller systemd-networkd[224]: wg-star: netdev ready158controller # [136992.185966] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...159controller # [136992.186291] controller systemd-networkd[224]: eth1: Link UP160controller # [136992.186510] controller systemd-networkd[224]: eth1: Gained carrier161controller # [136992.241004] controller systemd-networkd[224]: wg-star: Link UP162controller # [136992.241011] controller systemd-networkd[224]: wg-star: Gained carrier163controller # [136992.241788] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.164controller # [136992.275613] controller systemd-resolved[128]: Positive Trust Anchors:165controller # [136992.275626] controller systemd-resolved[128]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d166controller # [136992.275629] controller systemd-resolved[128]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16167controller # [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 test168controller # [136992.297746] controller systemd-resolved[128]: Using system hostname 'controller'.169controller # [136992.299372] controller systemd[1]: Started Network Name Resolution.170controller # [136992.299529] controller systemd[1]: Reached target Network.171controller # [136992.299666] controller systemd[1]: Reached target System Initialization.172controller # [136992.299843] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.173controller # [136992.299920] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container174controller # [136992.299970] controller systemd[1]: Started Daily Cleanup of Temporary Directories.175controller # [136992.300050] controller systemd[1]: Reached target Path Units.176controller # [136992.300131] controller systemd[1]: Reached target Timer Units.177controller # [136992.300371] controller systemd[1]: Listening on D-Bus System Message Bus Socket.178controller # [136992.300593] controller systemd[1]: Listening on Nix Daemon Socket.179controller # [136992.300816] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.180controller # [136992.300869] controller systemd[1]: Reached target Socket Units.181controller # [136992.300949] controller systemd[1]: Reached target Basic System.182controller # [136992.306240] controller systemd[1]: Starting data mesher daemon...183controller # [136992.307932] controller systemd[1]: Starting Import lastlog data into lastlog2 database...184controller # [136992.309636] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...185controller # [136992.312531] controller systemd[1]: Starting D-Bus System Message Bus...186controller # [136992.330493] controller systemd[1]: Finished Import lastlog data into lastlog2 database.187controller # [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"188controller # [136992.449700] controller systemd[1]: Started Name Service Cache Daemon (nsncd).189controller # [136992.449804] controller systemd[1]: Reached target Host and Network Name Lookups.190controller # [136992.449913] controller systemd[1]: Reached target User and Group Name Lookups.191controller # [136992.452598] controller systemd[1]: Starting User Login Management...192controller # [136992.454038] controller systemd[1]: Starting Permit User Sessions...193controller # [136992.502956] controller systemd[1]: Finished Permit User Sessions.194controller # [136992.504297] controller systemd[1]: Started Console Getty.195controller # [136992.504355] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0196controller # [136992.504383] controller systemd[1]: Reached target Login Prompts.197controller # [136992.584561] controller systemd[1]: Finished Save Transient machine-id to Disk.198controller # [136992.607110] controller dbus-broker-launch[232]: Looking up NSS user entry for 'systemd-timesync'...199controller # [136992.608172] controller dbus-broker-launch[232]: NSS returned no entry for 'systemd-timesync'200controller # [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"201controller # [136992.608724] controller systemd[1]: Started D-Bus System Message Bus.202controller # [136992.618535] controller dbus-broker-launch[232]: Ready203controller # [136992.642726] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.204controller # [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]205controller # [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=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk206controller # [136992.867378] controller data-mesher[229]: time=2026-10-17T23:26:37.839Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml207controller # [136992.868472] controller data-mesher[229]: time=2026-10-17T23:26:37.840Z level=INFO msg="checking file integrity"208controller # [136992.868581] controller data-mesher[229]: time=2026-10-17T23:26:37.840Z level=INFO msg="file integrity check complete"209controller # [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]"210controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=GET path=/files211controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name212controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name213controller # [136992.872489] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="starting server"214controller # [136992.872595] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="waiting for DHT to populate" delay=10s215controller # [136992.872696] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="HTTP server listening" address=[::1]:7331216controller # [136992.872734] controller data-mesher[229]: time=2026-10-17T23:26:37.844Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331217controller # [136993.042306] controller systemd-logind[249]: New seat seat0.218controller # [136993.043080] controller systemd[1]: Started User Login Management.219controller # [136993.052919] controller systemd[1]: Starting linger-users.service...220controller # [136993.064567] controller systemd[1]: linger-users.service: Deactivated successfully.221controller # [136993.064741] controller systemd[1]: Finished linger-users.service.222peer1 # [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]223peer1 # [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=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c224peer1 # [136992.853197] peer1 data-mesher[219]: time=2026-10-17T23:26:37.825Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml225peer1 # [136992.855775] peer1 data-mesher[219]: time=2026-10-17T23:26:37.827Z level=INFO msg="checking file integrity"226peer1 # [136992.855884] peer1 data-mesher[219]: time=2026-10-17T23:26:37.827Z level=INFO msg="file integrity check complete"227peer1 # [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]"228peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=GET path=/files229peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name230peer1 # [136992.859892] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name231peer1 # [136992.859954] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="starting server"232peer1 # [136992.860078] peer1 data-mesher[219]: time=2026-10-17T23:26:37.831Z level=INFO msg="waiting for DHT to populate" delay=10s233peer1 # [136992.860394] peer1 data-mesher[219]: time=2026-10-17T23:26:37.832Z level=INFO msg="HTTP server listening" address=[::1]:7331234peer1 # [136992.860438] peer1 data-mesher[219]: time=2026-10-17T23:26:37.832Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331235peer1 # [136993.055462] peer1 systemd-logind[239]: New seat seat0.236peer1 # [136993.055800] peer1 systemd[1]: Started User Login Management.237peer1 # [136993.057393] peer1 systemd[1]: Starting linger-users.service...238peer1 # [136993.069173] peer1 systemd[1]: linger-users.service: Deactivated successfully.239peer1 # [136993.069262] peer1 systemd[1]: Finished linger-users.service.240controller # [136993.820424] controller systemd-networkd[224]: eth1: Gained IPv6LL241peer1 # [136993.980159] peer1 systemd-networkd[214]: eth1: Gained IPv6LL242peer1 # [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/7946243controller # [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/7946244controller: still waiting for container 'controller' to reach ready state...245controller # [137002.861371] controller data-mesher[229]: time=2026-10-17T23:26:47.833Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c246controller # [137002.861371] controller data-mesher[229]: time=2026-10-17T23:26:47.833Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c247controller # [137002.873175] controller data-mesher[229]: time=2026-10-17T23:26:47.844Z level=INFO msg="performing state exchange with peers on join" count=1248controller # [137002.873348] controller data-mesher[229]: time=2026-10-17T23:26:47.845Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s249controller # [137002.874149] controller data-mesher[229]: time=2026-10-17T23:26:47.845Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c250controller # [137002.874149] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s251controller # [137002.874262] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="server started"252controller # [137002.874405] controller data-mesher[229]: time=2026-10-17T23:26:47.846Z level=INFO msg="starting expired-file sweeper" interval=1m0s253controller # [137002.874496] controller systemd[1]: Started data mesher daemon.254controller # [137002.904614] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...255controller # [137002.943332] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...256controller # [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=204257controller # [137002.951440] controller dm-wg-star-publish[296]: Status: 204 No Content258controller # [137002.954673] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.259controller # [137002.955262] controller systemd[1]: Reached target Multi-User System.260controller # [137003.039245] controller dm-wg-star-reconfig[323]: No peer data available yet, skipping261controller # [137003.040304] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.262controller # [137003.060407] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.263controller # [137003.060826] controller systemd[1]: Startup finished in 11.818s.264peer1 # [137002.860579] peer1 data-mesher[219]: time=2026-10-17T23:26:47.832Z level=INFO msg="performing state exchange with peers on join" count=1265peer1 # [137002.861329] peer1 data-mesher[219]: time=2026-10-17T23:26:47.832Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s266peer1 # [137002.861679] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk267peer1 # [137002.861679] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s268peer1 # [137002.861803] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="server started"269peer1 # [137002.861914] peer1 data-mesher[219]: time=2026-10-17T23:26:47.833Z level=INFO msg="starting expired-file sweeper" interval=1m0s270peer1 # [137002.861991] peer1 systemd[1]: Started data mesher daemon.271peer1 # [137002.863664] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...272peer1 # [137002.873855] peer1 data-mesher[219]: time=2026-10-17T23:26:47.845Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk273peer1 # [137002.873855] peer1 data-mesher[219]: time=2026-10-17T23:26:47.845Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk274peer1 # [137003.025443] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...275peer1 # [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=204276peer1 # [137003.026540] peer1 dm-wg-star-publish[285]: Status: 204 No Content277peer1 # [137003.029248] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.278peer1 # [137003.060307] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.279peer1 # [137003.060928] peer1 systemd[1]: Reached target Multi-User System.280peer1 # [137003.149527] peer1 dm-wg-star-reconfig[313]: No controller data available yet, skipping281controller: (finished: waiting for unit data-mesher.service, in 12.68 seconds)282peer1: waiting for unit data-mesher.service283peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds)284??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.285 File "/nix/store/8xlk88ia8b5yg9kfrg3skndwzgphipvr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39286controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller287??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.288 File "/nix/store/8xlk88ia8b5yg9kfrg3skndwzgphipvr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39289controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds)290peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller291peer1 # [137003.150842] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.292peer1 # [137003.150998] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.293peer1 # [137003.151573] peer1 systemd[1]: Startup finished in 11.923s.294controller # [137007.863252] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c295controller # [137007.863252] controller data-mesher[229]: time=2026-10-17T23:26:52.835Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c296controller # [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_xJi3k297controller # [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_xJi3k298controller # [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=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c299controller # [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/controller300controller # [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/controller301controller # [137007.872575] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...302controller # [137007.875126] controller data-mesher[229]: time=2026-10-17T23:26:52.846Z level=DEBUG msg="attempting push/pull" peer_count=1303controller # [137007.875126] controller data-mesher[229]: time=2026-10-17T23:26:52.847Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s304controller # [137007.876199] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c305controller # [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.489172ms306controller # [137007.876857] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s307controller # [137007.876915] controller data-mesher[229]: time=2026-10-17T23:26:52.848Z level=DEBUG msg="push/pull successful" interval=5s308controller # [137008.023092] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.309controller # [137008.023246] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.310peer1 # [137007.862392] peer1 data-mesher[219]: time=2026-10-17T23:26:52.834Z level=DEBUG msg="attempting push/pull" peer_count=1311peer1 # [137007.863072] peer1 data-mesher[219]: time=2026-10-17T23:26:52.834Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s312peer1 # [137007.864241] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk313peer1 # [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/controller314peer1 # [137007.864367] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s315peer1 # [137007.864367] peer1 data-mesher[219]: time=2026-10-17T23:26:52.836Z level=DEBUG msg="push/pull successful" interval=5s316peer1 # [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/controller317peer1 # [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=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk318peer1 # [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_xJi3k319peer1 # [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_xJi3k320peer1 # [137007.871188] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...321peer1 # [137007.875780] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk322peer1 # [137007.875780] peer1 data-mesher[219]: time=2026-10-17T23:26:52.847Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk323peer1 # [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/controller324peer1 # [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.539158ms325peer1 # [137008.018113] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.326peer1 # [137008.018510] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.327peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.05 seconds)328controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .329controller: (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)330controller: waiting for success: wg show wg-star peers | grep -q .331controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)332peer1: waiting for success: wg show wg-star peers | grep -q .333peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)334peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5335controller # [137012.865429] controller data-mesher[229]: time=2026-10-17T23:26:57.837Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c336controller # [137012.865429] controller data-mesher[229]: time=2026-10-17T23:26:57.837Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c337controller # [137012.877754] controller data-mesher[229]: time=2026-10-17T23:26:57.849Z level=DEBUG msg="attempting push/pull" peer_count=1338controller # [137012.877851] controller data-mesher[229]: time=2026-10-17T23:26:57.849Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s339controller # [137012.879460] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c340controller # [137012.880098] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s341controller # [137012.880190] controller data-mesher[229]: time=2026-10-17T23:26:57.851Z level=DEBUG msg="push/pull successful" interval=5s342peer1 # [137012.864655] peer1 data-mesher[219]: time=2026-10-17T23:26:57.836Z level=DEBUG msg="attempting push/pull" peer_count=1343peer1 # [137012.865398] peer1 data-mesher[219]: time=2026-10-17T23:26:57.836Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s344peer1 # [137012.866443] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk345peer1 # [137012.867052] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s346peer1 # [137012.867121] peer1 data-mesher[219]: time=2026-10-17T23:26:57.838Z level=DEBUG msg="push/pull successful" interval=5s347peer1 # [137012.878496] peer1 data-mesher[219]: time=2026-10-17T23:26:57.850Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk348peer1 # [137012.878573] peer1 data-mesher[219]: time=2026-10-17T23:26:57.850Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk349peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5, in 6.02 seconds)350controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b351controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b, in 0.01 seconds)352controller: must succeed: wg show wg-star peers | wc -l353controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)354peer2: systemd-nspawn running (pid 784)355peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...356peer2: waiting for unit data-mesher.service357nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE358nixos-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.359Note: 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.360░ Spawning container peer2 on /build/vm-state-peer2.361peer2 # No journal boot entry found for the specified boot (+0).362peer2 # [137015.480182] peer2 systemd-journald[94]: Journal started363peer2 # [137015.480240] peer2 systemd-journald[94]: Runtime Journal (/run/log/journal/8b387664a4b144ce81b847700604729b) is 8M, max 2.5G, 2.4G free.364peer2 # [137015.483200] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.365peer2 # [137015.492556] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...366peer2 # [137015.493513] peer2 systemd[1]: Starting Network Name Resolution...367peer2 # [137015.494470] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...368peer2 # [137015.501746] peer2 systemd-journald[94]: Time spent on flushing to /var/log/journal/8b387664a4b144ce81b847700604729b is 1.097ms for 6 entries.369peer2 # [137015.501746] peer2 systemd-journald[94]: System Journal (/var/log/journal/8b387664a4b144ce81b847700604729b) is 8M, max 4G, 3.9G free.370peer2 # [137015.510196] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.371peer2 # [137015.510414] peer2 systemd[1]: Reached target Preparation for Local File Systems.372peer2 # [137015.510491] peer2 systemd[1]: Reached target Local File Systems.373peer2 # [137015.511227] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.374peer2 # [137015.511269] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container375peer2 # [137015.512075] peer2 systemd[1]: Starting Save Transient machine-id to Disk...376peer2 # [137015.512107] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys377peer2 # [137015.513509] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.378peer2 # [137015.514332] peer2 systemd[1]: Starting Create System Files and Directories...379peer2 # [137015.530519] peer2 systemd[1]: Finished Save Transient machine-id to Disk.380peer2 # [137015.532326] peer2 systemd-tmpfiles[133]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted381peer2 # [137015.532524] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal failed: Operation not permitted382peer2 # [137015.532656] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal/8b387664a4b144ce81b847700604729b failed: Operation not permitted383peer2 # [137015.532853] peer2 systemd-tmpfiles[133]: fchmod() of /run/log/journal failed: Operation not permitted384peer2 # [137015.534291] peer2 systemd[1]: Finished Create System Files and Directories.385peer2 # [137015.535303] peer2 systemd[1]: Starting Rebuild Journal Catalog...386peer2 # [137015.536067] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...387peer2 # [137015.549561] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.388peer2 # [137015.558748] peer2 systemd[1]: Finished Rebuild Journal Catalog.389peer2 # [137015.559971] peer2 systemd[1]: Starting Update is Completed...390peer2 # [137015.570977] peer2 systemd[1]: Finished Update is Completed.391peer2 # [137015.647065] peer2 systemd[1]: Finished Firewall.392peer2 # [137015.647806] peer2 systemd[1]: Reached target Preparation for Network.393peer2 # [137015.648326] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.394peer2 # [137015.649879] peer2 systemd[1]: Starting Network Management...395peer2 # [137016.006564] peer2 systemd-networkd[212]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted396peer2 # [137016.006654] peer2 systemd-networkd[212]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted397peer2 # [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.398peer2 # [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.399peer2 # [137016.013890] peer2 systemd-networkd[212]: lo: Link UP400peer2 # [137016.013893] peer2 systemd-networkd[212]: lo: Gained carrier401peer2 # [137016.014084] peer2 systemd-networkd[212]: eth1: Configuring with /etc/systemd/network/40-eth1.network.402peer2 # [137016.014624] peer2 systemd[1]: Started Network Management.403peer2 # [137016.015702] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...404peer2 # [137016.015771] peer2 systemd-networkd[212]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.405peer2 # [137016.016108] peer2 systemd-networkd[212]: wg-star: netdev ready406peer2 # [137016.016509] peer2 systemd-networkd[212]: eth1: Link UP407peer2 # [137016.016726] peer2 systemd-networkd[212]: eth1: Gained carrier408peer2 # [137016.041290] peer2 systemd-resolved[116]: Positive Trust Anchors:409peer2 # [137016.041301] peer2 systemd-resolved[116]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d410peer2 # [137016.041306] peer2 systemd-resolved[116]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16411peer2 # [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 test412peer2 # [137016.052580] peer2 systemd-networkd[212]: wg-star: Link UP413peer2 # [137016.052586] peer2 systemd-networkd[212]: wg-star: Gained carrier414peer2 # [137016.062949] peer2 systemd-resolved[116]: Using system hostname 'peer2'.415peer2 # [137016.064566] peer2 systemd[1]: Started Network Name Resolution.416peer2 # [137016.064706] peer2 systemd[1]: Reached target Network.417peer2 # [137016.064815] peer2 systemd[1]: Reached target System Initialization.418peer2 # [137016.064998] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.419peer2 # [137016.065058] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.420peer2 # [137016.065102] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container421peer2 # [137016.065144] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.422peer2 # [137016.065190] peer2 systemd[1]: Reached target Path Units.423peer2 # [137016.065269] peer2 systemd[1]: Reached target Timer Units.424peer2 # [137016.065513] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.425peer2 # [137016.065742] peer2 systemd[1]: Listening on Nix Daemon Socket.426peer2 # [137016.065975] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.427peer2 # [137016.066023] peer2 systemd[1]: Reached target Socket Units.428peer2 # [137016.066099] peer2 systemd[1]: Reached target Basic System.429peer2 # [137016.068311] peer2 systemd[1]: Starting data mesher daemon...430peer2 # [137016.069740] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...431peer2 # [137016.071091] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...432peer2 # [137016.071594] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.433peer2 # [137016.075299] peer2 systemd[1]: Starting D-Bus System Message Bus...434peer2 # [137016.091054] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.435peer2 # [137016.172303] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).436peer2 # [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"437peer2 # [137016.172423] peer2 systemd[1]: Reached target Host and Network Name Lookups.438peer2 # [137016.172525] peer2 systemd[1]: Reached target User and Group Name Lookups.439peer2 # [137016.174715] peer2 systemd[1]: Starting User Login Management...440peer2 # [137016.176105] peer2 systemd[1]: Starting Permit User Sessions...441peer2 # [137016.220180] peer2 systemd[1]: Finished Permit User Sessions.442peer2 # [137016.221816] peer2 systemd[1]: Started Console Getty.443peer2 # [137016.221889] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0444peer2 # [137016.221929] peer2 systemd[1]: Reached target Login Prompts.445peer2 # [137016.236306] peer2 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'...446peer2 # [137016.237947] peer2 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync'447peer2 # [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"448peer2 # [137016.238384] peer2 systemd[1]: Started D-Bus System Message Bus.449peer2 # [137016.246361] peer2 dbus-broker-launch[221]: Ready450peer2 # [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]451peer2 # [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=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m452peer2 # [137016.455538] peer2 data-mesher[216]: time=2026-10-17T23:27:01.427Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml453peer2 # [137016.456826] peer2 data-mesher[216]: time=2026-10-17T23:27:01.428Z level=INFO msg="checking file integrity"454peer2 # [137016.456940] peer2 data-mesher[216]: time=2026-10-17T23:27:01.428Z level=INFO msg="file integrity check complete"455peer2 # [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]"456peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=GET path=/files457peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name458peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name459peer2 # [137016.460723] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="starting server"460peer2 # [137016.460902] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="waiting for DHT to populate" delay=10s461peer2 # [137016.460954] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="HTTP server listening" address=[::1]:7331462peer2 # [137016.461167] peer2 data-mesher[216]: time=2026-10-17T23:27:01.432Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331463peer2 # [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/7946464peer2 # [137016.475339] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.465peer2 # [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/7946466peer1 # [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/7946467peer2 # [137016.612843] peer2 systemd-logind[237]: New seat seat0.468peer2 # [137016.613061] peer2 systemd[1]: Started User Login Management.469peer2 # [137016.615302] peer2 systemd[1]: Starting linger-users.service...470peer2 # [137016.666642] peer2 systemd[1]: linger-users.service: Deactivated successfully.471peer2 # [137016.666969] peer2 systemd[1]: Finished linger-users.service.472controller # [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/7946473peer2 # [137017.404371] peer2 systemd-networkd[212]: eth1: Gained IPv6LL474controller # [137017.868861] controller data-mesher[229]: time=2026-10-17T23:27:02.840Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c475controller # [137017.868861] controller data-mesher[229]: time=2026-10-17T23:27:02.840Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c476controller # [137017.881211] controller data-mesher[229]: time=2026-10-17T23:27:02.852Z level=DEBUG msg="attempting push/pull" peer_count=1477controller # [137017.881211] controller data-mesher[229]: time=2026-10-17T23:27:02.852Z level=DEBUG msg="initiating state exchange" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s478controller # [137017.882588] controller data-mesher[229]: time=2026-10-17T23:27:02.854Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c479controller # [137017.883177] controller data-mesher[229]: time=2026-10-17T23:27:02.855Z level=INFO msg="state exchange complete" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c timeout=5s480controller # [137017.883244] controller data-mesher[229]: time=2026-10-17T23:27:02.855Z level=DEBUG msg="push/pull successful" interval=5s481peer1 # [137017.868117] peer1 data-mesher[219]: time=2026-10-17T23:27:02.839Z level=DEBUG msg="attempting push/pull" peer_count=1482peer1 # [137017.868810] peer1 data-mesher[219]: time=2026-10-17T23:27:02.840Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s483peer1 # [137017.869863] peer1 data-mesher[219]: time=2026-10-17T23:27:02.841Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk484peer1 # [137017.870449] peer1 data-mesher[219]: time=2026-10-17T23:27:02.842Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s485peer1 # [137017.870532] peer1 data-mesher[219]: time=2026-10-17T23:27:02.842Z level=DEBUG msg="push/pull successful" interval=5s486peer1 # [137017.881587] peer1 data-mesher[219]: time=2026-10-17T23:27:02.853Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk487peer1 # [137017.881587] peer1 data-mesher[219]: time=2026-10-17T23:27:02.853Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk488controller # [137022.871854] controller data-mesher[229]: time=2026-10-17T23:27:07.843Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c489controller # [137022.871854] controller data-mesher[229]: time=2026-10-17T23:27:07.843Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c490controller # [137022.883523] controller data-mesher[229]: time=2026-10-17T23:27:07.855Z level=DEBUG msg="attempting push/pull" peer_count=1491controller # [137022.883523] controller data-mesher[229]: time=2026-10-17T23:27:07.855Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s492controller # [137022.885765] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m493controller # [137022.885765] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=INFO msg="state exchange complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s494controller # [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/controller495controller # [137022.886487] controller data-mesher[229]: time=2026-10-17T23:27:07.857Z level=DEBUG msg="push/pull successful" interval=5s496controller # [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_xJi3k497controller # [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_xJi3k498controller # [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/controller499peer1 # [137022.871057] peer1 data-mesher[219]: time=2026-10-17T23:27:07.842Z level=DEBUG msg="attempting push/pull" peer_count=1500peer1 # [137022.871057] peer1 data-mesher[219]: time=2026-10-17T23:27:07.842Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s501peer1 # [137022.872894] peer1 data-mesher[219]: time=2026-10-17T23:27:07.844Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk502peer1 # [137022.873484] peer1 data-mesher[219]: time=2026-10-17T23:27:07.845Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s503peer1 # [137022.873563] peer1 data-mesher[219]: time=2026-10-17T23:27:07.845Z level=DEBUG msg="push/pull successful" interval=5s504peer2 # [137022.884495] peer2 data-mesher[216]: time=2026-10-17T23:27:07.856Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk505peer2 # [137022.884495] peer2 data-mesher[216]: time=2026-10-17T23:27:07.856Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk506peer2 # [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_xJi3k507peer2 # [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/controller508peer2 # [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_xJi3k509peer2 # [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/controller510peer2 # [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=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk511peer2 # [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=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk512peer2 # [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.434728ms513peer2 # [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.358994ms514peer2 # [137022.894392] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...515peer2 # [137023.060910] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.516peer2 # [137023.061253] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.517peer2: still waiting for container 'peer2' to reach ready state...518peer2 # [137026.461025] peer2 data-mesher[216]: time=2026-10-17T23:27:11.432Z level=INFO msg="performing state exchange with peers on join" count=1519peer2 # [137026.461025] peer2 data-mesher[216]: time=2026-10-17T23:27:11.432Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s520peer2 # [137026.463007] peer2 data-mesher[216]: time=2026-10-17T23:27:11.434Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk521peer2 # [137026.463618] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s522peer2 # [137026.463698] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="server started"523peer2 # [137026.463908] peer2 data-mesher[216]: time=2026-10-17T23:27:11.435Z level=INFO msg="starting expired-file sweeper" interval=1m0s524peer2 # [137026.464198] peer2 systemd[1]: Started data mesher daemon.525peer2 # [137026.466343] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...526peer2 # [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=204527peer2 # [137026.633949] peer2 dm-wg-star-publish[294]: Status: 204 No Content528peer2 # [137026.636224] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...529peer2 # [137026.638225] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.530peer2 # [137026.638543] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.531peer2 # [137026.639578] peer2 systemd[1]: Reached target Multi-User System.532controller # [137026.461886] controller data-mesher[229]: time=2026-10-17T23:27:11.433Z level=INFO msg="received state sync from peer" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m533controller # [137026.461886] controller data-mesher[229]: time=2026-10-17T23:27:11.433Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m534peer2 # [137026.784347] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.535peer2 # [137026.784671] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.536peer2 # [137026.785210] peer2 systemd[1]: Startup finished in 11.741s.537peer2: (finished: waiting for unit data-mesher.service, in 12.67 seconds)538??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.539 File "/nix/store/8xlk88ia8b5yg9kfrg3skndwzgphipvr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39540controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1541??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.542 File "/nix/store/8xlk88ia8b5yg9kfrg3skndwzgphipvr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39543controller # [137027.874438] controller data-mesher[229]: time=2026-10-17T23:27:12.846Z level=INFO msg="received state sync from peer" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c544controller # [137027.874438] controller data-mesher[229]: time=2026-10-17T23:27:12.846Z level=INFO msg="merging remote state" peer=12D3KooWF4sid5maaETzEuSUkMWxQtgSLYMgWHtmmDuvzD99BP4c545controller # [137027.887182] controller data-mesher[229]: time=2026-10-17T23:27:12.859Z level=DEBUG msg="attempting push/pull" peer_count=1546controller # [137027.887290] controller data-mesher[229]: time=2026-10-17T23:27:12.859Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s547controller # [137027.888939] controller data-mesher[229]: time=2026-10-17T23:27:12.860Z level=INFO msg="merging remote state" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m548controller # [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-R6M3gnlsuvhz5OELcL7Iv4549controller # [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-R6M3gnlsuvhz5OELcL7Iv4550controller # [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=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m551controller # [137027.890189] controller data-mesher[229]: time=2026-10-17T23:27:12.861Z level=INFO msg="state exchange complete" peer=12D3KooWDBQGctkvPPB3VYspoSj7QbVBnG1T3uUwhGqjRhpS9k8m timeout=5s552controller # [137027.890189] controller data-mesher[229]: time=2026-10-17T23:27:12.862Z level=DEBUG msg="push/pull successful" interval=5s553controller # [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.192911ms554controller # [137027.897882] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...555controller # [137028.055258] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.556controller # [137028.055603] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.557controller: (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)558controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1559controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)560peer2: waiting for success: wg show wg-star peers | grep -q .561peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)562peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5563peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b202:e78a:7743:0ac5, in 0.01 seconds)564controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944565controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944, in 0.01 seconds)566peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944567peer1 # [137027.873750] peer1 data-mesher[219]: time=2026-10-17T23:27:12.845Z level=DEBUG msg="attempting push/pull" peer_count=1568peer1 # [137027.874576] peer1 data-mesher[219]: time=2026-10-17T23:27:12.845Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s569peer1 # [137027.875583] peer1 data-mesher[219]: time=2026-10-17T23:27:12.847Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk570peer1 # [137027.876225] peer1 data-mesher[219]: time=2026-10-17T23:27:12.848Z level=INFO msg="state exchange complete" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk timeout=5s571peer1 # [137027.876326] peer1 data-mesher[219]: time=2026-10-17T23:27:12.848Z level=DEBUG msg="push/pull successful" interval=5s572peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::eb76:9549:900d:8944, in 0.01 seconds)573peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b574peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::4ba5:b0d0:89d4:774b, in 0.01 seconds)575(finished: run the VM test script, in 37.61 seconds)576test script finished in 37.64s577cleanup578kill NspawnMachine (pid 50)579peer2 # [137027.887863] peer2 data-mesher[216]: time=2026-10-17T23:27:12.859Z level=INFO msg="received state sync from peer" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk580peer2 # [137027.887863] peer2 data-mesher[216]: time=2026-10-17T23:27:12.859Z level=INFO msg="merging remote state" peer=12D3KooWAFieTHMHTAB9p9ag6LCWr4C2kimJv88B9hHj1HEePtZk581peer2 # [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-R6M3gnlsuvhz5OELcL7Iv4582peer2 # [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-R6M3gnlsuvhz5OELcL7Iv4583kill NspawnMachine (pid 53)584Container controller terminated by signal KILL.585kill NspawnMachine (pid 784)586Container peer1 terminated by signal KILL.587Container peer2 terminated by signal KILL.588(finished: cleanup, in 0.59 seconds)