container-test-run-dm-wireguard-star
checks.aarch64-linux.dm-wireguard-star
· build #214
· raw
1build01: building pi7hk2mpgjvknsmcgmslfq2c99rhd7ja-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(peer1): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.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 peer1 on /build/vm-state-peer1.24░ Spawning container controller on /build/vm-state-controller.25controller # No journal files were found.26controller # No journal boot entry found for the specified boot (+0).27peer1 # No journal files were found.28peer1 # No journal boot entry found for the specified boot (+0).29controller # [2479123.681506] controller systemd-journald[108]: Journal started30controller # [2479123.681564] controller systemd-journald[108]: Runtime Journal (/run/log/journal/dd349bdfd36e408dbe57d80b29a4217a) is 8M, max 2.5G, 2.4G free.31controller # [2479123.685643] controller systemd[1]: Finished Apply Kernel Variables.32controller # [2479123.697223] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.33controller # [2479123.710438] controller systemd[1]: Starting Flush Journal to Persistent Storage...34controller # [2479123.748337] controller systemd[1]: Starting Network Name Resolution...35controller # [2479123.749179] controller systemd[1]: Starting Create Static Device Nodes in /dev...36controller # [2479123.755461] controller systemd-journald[108]: Time spent on flushing to /var/log/journal/dd349bdfd36e408dbe57d80b29a4217a is 1.729ms for 7 entries.37controller # [2479123.755461] controller systemd-journald[108]: System Journal (/var/log/journal/dd349bdfd36e408dbe57d80b29a4217a) is 8M, max 4G, 3.9G free.38controller # [2479123.785369] controller systemd[1]: Finished Flush Journal to Persistent Storage.39controller # [2479123.785900] controller systemd[1]: Finished Create Static Device Nodes in /dev.40controller # [2479123.786951] controller systemd[1]: Reached target Preparation for Local File Systems.41controller # [2479123.787048] controller systemd[1]: Reached target Local File Systems.42controller # [2479123.787846] controller systemd[1]: Listening on Boot Loader Control Service Socket.43controller # [2479123.787892] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container44controller # [2479123.788683] controller systemd[1]: Starting Save Transient machine-id to Disk...45controller # [2479123.789315] controller systemd[1]: Starting Create System Files and Directories...46controller # [2479123.789349] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys47controller # [2479123.803645] controller systemd-tmpfiles[183]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted48controller # [2479123.803820] controller systemd-tmpfiles[183]: fchmod() of /var/log/journal failed: Operation not permitted49controller # [2479123.803943] controller systemd-tmpfiles[183]: fchmod() of /var/log/journal/dd349bdfd36e408dbe57d80b29a4217a failed: Operation not permitted50controller # [2479123.804138] controller systemd-tmpfiles[183]: fchmod() of /run/log/journal failed: Operation not permitted51controller # [2479123.805855] controller systemd[1]: Finished Create System Files and Directories.52controller # [2479123.807155] controller systemd[1]: Starting Rebuild Journal Catalog...53controller # [2479123.808177] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...54controller # [2479123.824988] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.55controller # [2479123.830013] controller systemd[1]: Finished Save Transient machine-id to Disk.56controller # [2479123.831802] controller systemd[1]: Finished Rebuild Journal Catalog.57controller # [2479123.833110] controller systemd[1]: systemd-update-done.service: Failed to spawn executor: No such file or directory58controller # [2479123.833143] controller systemd[1]: systemd-update-done.service: Failed to spawn 'start' task: No such file or directory59controller # [2479123.833206] controller systemd[1]: systemd-update-done.service: Failed with result 'resources'.60controller # [2479123.833294] controller systemd[1]: Failed to start Update is Completed.61controller # [2479123.859332] controller systemd[1]: Finished Firewall.62controller # [2479123.859591] controller systemd[1]: Reached target Preparation for Network.63controller # [2479123.859991] controller systemd[1]: Listening on Network Management Resolve Hook Socket.64controller # [2479123.861585] controller systemd[1]: Starting Network Management...65controller # [2479124.500707] controller systemd-networkd[227]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted66controller # [2479124.500796] controller systemd-networkd[227]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted67controller # [2479124.510954] controller systemd-networkd[227]: /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.68controller # [2479124.511118] controller systemd-networkd[227]: /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.69controller # [2479124.511269] controller systemd-networkd[227]: lo: Link UP70controller # [2479124.511274] controller systemd-networkd[227]: lo: Gained carrier71controller # [2479124.511478] controller systemd-networkd[227]: eth1: Configuring with /etc/systemd/network/40-eth1.network.72controller # [2479124.511837] controller systemd[1]: Started Network Management.73controller # [2479124.512666] controller systemd-networkd[227]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.74controller # [2479124.512998] controller systemd-networkd[227]: wg-star: netdev ready75controller # [2479124.513533] controller systemd-networkd[227]: eth1: Link UP76controller # [2479124.514732] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...77controller # [2479124.514850] controller systemd-networkd[227]: eth1: Gained carrier78controller # [2479124.570258] controller systemd-networkd[227]: wg-star: Link UP79controller # [2479124.570262] controller systemd-networkd[227]: wg-star: Gained carrier80controller # [2479124.581946] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.81peer1 # [2479123.671102] peer1 systemd-journald[99]: Journal started82peer1 # [2479123.671162] peer1 systemd-journald[99]: Runtime Journal (/run/log/journal/b0e3c6d39b4749ccb399e50f774b32b8) is 8M, max 2.5G, 2.4G free.83peer1 # [2479123.678287] peer1 systemd[1]: Finished Apply Kernel Variables.84peer1 # [2479123.691091] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.85peer1 # [2479123.706297] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...86peer1 # [2479123.707275] peer1 systemd[1]: Starting Network Name Resolution...87peer1 # [2479123.707926] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...88peer1 # [2479123.754830] peer1 systemd-journald[99]: Time spent on flushing to /var/log/journal/b0e3c6d39b4749ccb399e50f774b32b8 is 1.943ms for 7 entries.89peer1 # [2479123.754830] peer1 systemd-journald[99]: System Journal (/var/log/journal/b0e3c6d39b4749ccb399e50f774b32b8) is 8M, max 4G, 3.9G free.90peer1 # [2479123.773334] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.91peer1 # [2479123.773989] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.92peer1 # [2479123.775177] peer1 systemd[1]: Reached target Preparation for Local File Systems.93peer1 # [2479123.775301] peer1 systemd[1]: Reached target Local File Systems.94peer1 # [2479123.776314] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.95peer1 # [2479123.776370] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container96peer1 # [2479123.777402] peer1 systemd[1]: Starting Save Transient machine-id to Disk...97peer1 # [2479123.778176] peer1 systemd[1]: Starting Create System Files and Directories...98peer1 # [2479123.778214] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys99peer1 # [2479123.794399] peer1 systemd-tmpfiles[174]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted100peer1 # [2479123.794585] peer1 systemd-tmpfiles[174]: fchmod() of /var/log/journal failed: Operation not permitted101peer1 # [2479123.794712] peer1 systemd-tmpfiles[174]: fchmod() of /var/log/journal/b0e3c6d39b4749ccb399e50f774b32b8 failed: Operation not permitted102peer1 # [2479123.794902] peer1 systemd-tmpfiles[174]: fchmod() of /run/log/journal failed: Operation not permitted103peer1 # [2479123.796280] peer1 systemd[1]: Finished Create System Files and Directories.104peer1 # [2479123.797524] peer1 systemd[1]: Starting Rebuild Journal Catalog...105peer1 # [2479123.798276] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...106peer1 # [2479123.814665] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.107peer1 # [2479123.820548] peer1 systemd[1]: Finished Rebuild Journal Catalog.108peer1 # [2479123.822106] peer1 systemd[1]: Starting Update is Completed...109peer1 # [2479123.829676] peer1 systemd[1]: Finished Save Transient machine-id to Disk.110peer1 # [2479123.833087] peer1 systemd[1]: Finished Update is Completed.111peer1 # [2479123.843796] peer1 systemd[1]: Finished Firewall.112peer1 # [2479123.843937] peer1 systemd[1]: Reached target Preparation for Network.113peer1 # [2479123.844167] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.114peer1 # [2479123.845301] peer1 systemd[1]: Starting Network Management...115peer1 # [2479124.506785] peer1 systemd-networkd[217]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted116peer1 # [2479124.506878] peer1 systemd-networkd[217]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted117peer1 # [2479124.523054] peer1 systemd-networkd[217]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.118peer1 # [2479124.523417] peer1 systemd-networkd[217]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.119peer1 # [2479124.523551] peer1 systemd-networkd[217]: lo: Link UP120peer1 # [2479124.523556] peer1 systemd-networkd[217]: lo: Gained carrier121peer1 # [2479124.523754] peer1 systemd-networkd[217]: eth1: Configuring with /etc/systemd/network/40-eth1.network.122peer1 # [2479124.524305] peer1 systemd[1]: Started Network Management.123peer1 # [2479124.572557] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...124peer1 # [2479124.573054] peer1 systemd-networkd[217]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.125peer1 # [2479124.573387] peer1 systemd-networkd[217]: wg-star: netdev ready126peer1 # [2479124.573889] peer1 systemd-networkd[217]: eth1: Link UP127peer1 # [2479124.574117] peer1 systemd-networkd[217]: eth1: Gained carrier128peer1 # [2479124.628910] peer1 systemd-networkd[217]: wg-star: Link UP129peer1 # [2479124.628915] peer1 systemd-networkd[217]: wg-star: Gained carrier130peer1 # [2479124.629981] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.131controller # [2479124.690949] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.132peer1 # [2479124.665949] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.133peer1 # [2479124.905247] peer1 systemd-resolved[133]: Positive Trust Anchors:134peer1 # [2479124.905259] peer1 systemd-resolved[133]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d135peer1 # [2479124.905262] peer1 systemd-resolved[133]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16136peer1 # [2479124.905295] peer1 systemd-resolved[133]: 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 test137peer1 # [2479124.925702] peer1 systemd-resolved[133]: Using system hostname 'peer1'.138peer1 # [2479124.927222] peer1 systemd[1]: Started Network Name Resolution.139peer1 # [2479124.927351] peer1 systemd[1]: Reached target Network.140peer1 # [2479124.927470] peer1 systemd[1]: Reached target System Initialization.141peer1 # [2479124.927632] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.142peer1 # [2479124.927686] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.143peer1 # [2479124.927727] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container144peer1 # [2479124.927765] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.145peer1 # [2479124.927802] peer1 systemd[1]: Reached target Path Units.146peer1 # [2479124.927872] peer1 systemd[1]: Reached target Timer Units.147peer1 # [2479124.928122] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.148peer1 # [2479124.928330] peer1 systemd[1]: Listening on Nix Daemon Socket.149peer1 # [2479124.928547] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.150peer1 # [2479124.928592] peer1 systemd[1]: Reached target Socket Units.151peer1 # [2479124.928680] peer1 systemd[1]: Reached target Basic System.152peer1 # [2479124.952831] peer1 systemd[1]: Starting data mesher daemon...153peer1 # [2479124.954130] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...154peer1 # [2479124.955631] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...155peer1 # [2479124.957600] peer1 systemd[1]: Starting D-Bus System Message Bus...156peer1 # [2479124.977179] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.157peer1 # [2479125.166755] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).158peer1 # [2479125.166848] peer1 systemd[1]: Reached target Host and Network Name Lookups.159peer1 # [2479125.166964] peer1 systemd[1]: Reached target User and Group Name Lookups.160peer1 # [2479125.167167] peer1 nsncd[224]: Oct 03 00:05:45.152 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"161controller # [2479124.878807] controller systemd-resolved[139]: Positive Trust Anchors:162controller # [2479124.878817] controller systemd-resolved[139]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d163controller # [2479124.878820] controller systemd-resolved[139]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16164controller # [2479124.878855] controller systemd-resolved[139]: 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 test165controller # [2479124.899617] controller systemd-resolved[139]: Using system hostname 'controller'.166controller # [2479124.903277] controller systemd[1]: Started Network Name Resolution.167controller # [2479124.903361] controller systemd[1]: Reached target Network.168controller # [2479124.903436] controller systemd[1]: Reached target System Initialization.169controller # [2479124.903556] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.170controller # [2479124.903578] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container171controller # [2479124.903602] controller systemd[1]: Started Daily Cleanup of Temporary Directories.172controller # [2479124.903621] controller systemd[1]: Reached target Path Units.173controller # [2479124.903657] controller systemd[1]: Reached target Timer Units.174controller # [2479124.903807] controller systemd[1]: Listening on D-Bus System Message Bus Socket.175controller # [2479124.903937] controller systemd[1]: Listening on Nix Daemon Socket.176controller # [2479124.904124] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.177controller # [2479124.904145] controller systemd[1]: Reached target Socket Units.178controller # [2479124.904196] controller systemd[1]: Reached target Basic System.179controller # [2479124.906066] controller systemd[1]: Starting data mesher daemon...180controller # [2479124.906922] controller systemd[1]: Starting Import lastlog data into lastlog2 database...181controller # [2479124.907927] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...182controller # [2479124.909280] controller systemd[1]: Starting D-Bus System Message Bus...183controller # [2479124.970689] controller systemd[1]: Finished Import lastlog data into lastlog2 database.184controller # [2479125.180309] controller systemd[1]: Started Name Service Cache Daemon (nsncd).185controller # [2479125.180402] controller systemd[1]: Reached target Host and Network Name Lookups.186controller # [2479125.180507] controller systemd[1]: Reached target User and Group Name Lookups.187controller # [2479125.180740] controller nsncd[234]: Oct 03 00:05:45.166 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"188peer1 # [2479125.169044] peer1 systemd[1]: Starting User Login Management...189peer1 # [2479125.170470] peer1 systemd[1]: Starting Permit User Sessions...190peer1 # [2479125.220545] peer1 systemd[1]: Finished Permit User Sessions.191peer1 # [2479125.222451] peer1 systemd[1]: Started Console Getty.192peer1 # [2479125.222541] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0193peer1 # [2479125.222581] peer1 systemd[1]: Reached target Login Prompts.194peer1 # [2479125.322694] peer1 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'...195peer1 # [2479125.324703] peer1 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync'196peer1 # [2479125.324703] peer1 dbus-broker-launch[225]: Invalid user-name in /nix/store/6vm4jv8dfnmyv9by9r6gwshp9hz8yq8m-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"197peer1 # [2479125.325221] peer1 systemd[1]: Started D-Bus System Message Bus.198peer1 # [2479125.334257] peer1 dbus-broker-launch[225]: Ready199controller # [2479125.212730] controller systemd[1]: Starting User Login Management...200controller # [2479125.214113] controller systemd[1]: Starting Permit User Sessions...201controller # [2479125.226751] controller systemd[1]: Finished Permit User Sessions.202controller # [2479125.228394] controller systemd[1]: Started Console Getty.203controller # [2479125.228470] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0204controller # [2479125.228515] controller systemd[1]: Reached target Login Prompts.205controller # [2479125.333147] controller dbus-broker-launch[235]: Looking up NSS user entry for 'systemd-timesync'...206controller # [2479125.334934] controller dbus-broker-launch[235]: NSS returned no entry for 'systemd-timesync'207controller # [2479125.334934] controller dbus-broker-launch[235]: Invalid user-name in /nix/store/6vm4jv8dfnmyv9by9r6gwshp9hz8yq8m-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"208controller # [2479125.335372] controller systemd[1]: Started D-Bus System Message Bus.209controller # [2479125.344520] controller dbus-broker-launch[235]: Ready210controller # [2479125.568147] controller systemd-networkd[227]: eth1: Gained IPv6LL211controller # [2479125.743145] controller data-mesher[232]: time=2026-10-03T00:05:45.728Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]212controller # [2479125.744841] controller data-mesher[232]: time=2026-10-03T00:05:45.730Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ213controller # [2479125.744841] controller data-mesher[232]: time=2026-10-03T00:05:45.730Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml214controller # [2479125.748772] controller data-mesher[232]: time=2026-10-03T00:05:45.734Z level=INFO msg="checking file integrity"215controller # [2479125.748932] controller data-mesher[232]: time=2026-10-03T00:05:45.734Z level=INFO msg="file integrity check complete"216controller # [2479125.752948] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="libp2p host created" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.1/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::1/tcp/7946 /ip6/fda1:5c8::28bc:6cf0:1e15:8c64/tcp/7946]"217controller # [2479125.753030] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name218controller # [2479125.753030] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name219controller # [2479125.753030] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="registered HTTP route" method=GET path=/files220controller # [2479125.753030] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="starting server"221controller # [2479125.753214] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="waiting for DHT to populate" delay=10s222controller # [2479125.753214] controller data-mesher[232]: time=2026-10-03T00:05:45.738Z level=INFO msg="HTTP server listening" address=[::1]:7331223controller # [2479125.753214] controller data-mesher[232]: time=2026-10-03T00:05:45.739Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331224controller # [2479125.761119] controller data-mesher[232]: time=2026-10-03T00:05:45.746Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946225peer1 # [2479125.734479] peer1 data-mesher[222]: time=2026-10-03T00:05:45.720Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]226peer1 # [2479125.735647] peer1 data-mesher[222]: time=2026-10-03T00:05:45.721Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf227peer1 # [2479125.735647] peer1 data-mesher[222]: time=2026-10-03T00:05:45.721Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml228peer1 # [2479125.748785] peer1 data-mesher[222]: time=2026-10-03T00:05:45.734Z level=INFO msg="checking file integrity"229peer1 # [2479125.748920] peer1 data-mesher[222]: time=2026-10-03T00:05:45.734Z level=INFO msg="file integrity check complete"230peer1 # [2479125.754277] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="libp2p host created" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.2/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::2/tcp/7946 /ip6/fda1:5c8::23fd:a719:7f48:87f1/tcp/7946]"231peer1 # [2479125.754336] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="registered HTTP route" method=GET path=/files232peer1 # [2479125.754336] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name233peer1 # [2479125.754336] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name234peer1 # [2479125.754336] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="starting server"235peer1 # [2479125.754469] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="waiting for DHT to populate" delay=10s236peer1 # [2479125.754503] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="HTTP server listening" address=[::1]:7331237peer1 # [2479125.754534] peer1 data-mesher[222]: time=2026-10-03T00:05:45.740Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331238peer1 # [2479125.760483] peer1 data-mesher[222]: time=2026-10-03T00:05:45.746Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946239controller # [2479125.996923] controller systemd-logind[252]: New seat seat0.240controller # [2479125.997116] controller systemd[1]: Started User Login Management.241controller # [2479125.999427] controller systemd[1]: Starting linger-users.service...242controller # [2479126.050767] controller systemd[1]: linger-users.service: Deactivated successfully.243controller # [2479126.050892] controller systemd[1]: Finished linger-users.service.244peer1 # [2479126.010346] peer1 systemd-logind[242]: New seat seat0.245peer1 # [2479126.010535] peer1 systemd[1]: Started User Login Management.246peer1 # [2479126.036675] peer1 systemd[1]: Starting linger-users.service...247peer1 # [2479126.050383] peer1 systemd[1]: linger-users.service: Deactivated successfully.248peer1 # [2479126.050744] peer1 systemd[1]: Finished linger-users.service.249peer1 # [2479126.176456] peer1 systemd-networkd[217]: eth1: Gained IPv6LL250controller: still waiting for container 'controller' to reach ready state...251peer1 # [2479135.754311] peer1 data-mesher[222]: time=2026-10-03T00:05:55.740Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ252peer1 # [2479135.754311] peer1 data-mesher[222]: time=2026-10-03T00:05:55.740Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ253peer1 # [2479135.755089] peer1 data-mesher[222]: time=2026-10-03T00:05:55.740Z level=INFO msg="performing state exchange with peers on join" count=1254peer1 # [2479135.755089] peer1 data-mesher[222]: time=2026-10-03T00:05:55.740Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s255peer1 # [2479135.755637] peer1 data-mesher[222]: time=2026-10-03T00:05:55.741Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ256peer1 # [2479135.755637] peer1 data-mesher[222]: time=2026-10-03T00:05:55.741Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s257peer1 # [2479135.755774] peer1 data-mesher[222]: time=2026-10-03T00:05:55.741Z level=INFO msg="server started"258peer1 # [2479135.755939] peer1 data-mesher[222]: time=2026-10-03T00:05:55.741Z level=INFO msg="starting expired-file sweeper" interval=1m0s259peer1 # [2479135.756349] peer1 systemd[1]: Started data mesher daemon.260peer1 # [2479135.758366] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...261peer1 # [2479135.922193] peer1 data-mesher[222]: time=2026-10-03T00:05:55.907Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 status=204262peer1 # [2479135.922325] peer1 dm-wg-star-publish[287]: Status: 204 No Content263peer1 # [2479135.925188] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...264peer1 # [2479135.925874] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.265peer1 # [2479135.926175] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.266peer1 # [2479135.927856] peer1 systemd[1]: Reached target Multi-User System.267peer1 # [2479136.035333] peer1 dm-wg-star-reconfig[315]: No controller data available yet, skipping268controller # [2479135.753513] controller data-mesher[232]: time=2026-10-03T00:05:55.739Z level=INFO msg="performing state exchange with peers on join" count=1269controller # [2479135.754307] controller data-mesher[232]: time=2026-10-03T00:05:55.739Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s270controller # [2479135.754663] controller data-mesher[232]: time=2026-10-03T00:05:55.740Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf271controller # [2479135.754663] controller data-mesher[232]: time=2026-10-03T00:05:55.740Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s272controller # [2479135.754791] controller data-mesher[232]: time=2026-10-03T00:05:55.740Z level=INFO msg="server started"273controller # [2479135.754902] controller data-mesher[232]: time=2026-10-03T00:05:55.740Z level=INFO msg="starting expired-file sweeper" interval=1m0s274controller # [2479135.755121] controller systemd[1]: Started data mesher daemon.275controller # [2479135.755793] controller data-mesher[232]: time=2026-10-03T00:05:55.741Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf276controller # [2479135.755793] controller data-mesher[232]: time=2026-10-03T00:05:55.741Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf277controller # [2479135.757325] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...278controller # [2479135.832187] controller data-mesher[232]: time=2026-10-03T00:05:55.817Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204279controller # [2479135.832471] controller dm-wg-star-publish[295]: Status: 204 No Content280controller # [2479135.834846] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...281controller # [2479135.836347] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.282controller # [2479135.837155] controller systemd[1]: Reached target Multi-User System.283controller # [2479135.930297] controller dm-wg-star-reconfig[323]: No peer data available yet, skipping284controller # [2479135.931525] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.285controller # [2479135.956578] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.286controller # [2479135.957173] controller systemd[1]: Startup finished in 12.732s.287controller: (finished: waiting for unit data-mesher.service, in 13.68 seconds)288peer1: waiting for unit data-mesher.service289peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds)290??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.291 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39292controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller293??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.294 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39295controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds)296peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller297peer1 # [2479136.036139] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.298peer1 # [2479136.036262] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.299peer1 # [2479136.036879] peer1 systemd[1]: Startup finished in 12.844s.300controller # [2479140.757132] controller data-mesher[232]: time=2026-10-03T00:06:00.742Z level=DEBUG msg="attempting push/pull" peer_count=1301controller # [2479140.757896] controller data-mesher[232]: time=2026-10-03T00:06:00.742Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s302controller # [2479140.758683] controller data-mesher[232]: time=2026-10-03T00:06:00.744Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf303controller # [2479140.758779] controller data-mesher[232]: time=2026-10-03T00:06:00.744Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf304controller # [2479140.758852] controller data-mesher[232]: time=2026-10-03T00:06:00.744Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf305controller # [2479140.758903] controller data-mesher[232]: time=2026-10-03T00:06:00.744Z level=INFO msg="received file request" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller306controller # [2479140.759291] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4307controller # [2479140.759291] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s308controller # [2479140.759410] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=DEBUG msg="push/pull successful" interval=5s309controller # [2479140.759410] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4310controller # [2479140.759501] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4311controller # [2479140.759501] controller data-mesher[232]: time=2026-10-03T00:06:00.745Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-10-03 00:05:55.904 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf312controller # [2479140.760565] controller data-mesher[232]: time=2026-10-03T00:06:00.746Z level=INFO msg="file transfer complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller313controller # [2479140.765838] controller data-mesher[232]: time=2026-10-03T00:06:00.751Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-10-03 00:05:55.904 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf written=true elapsed=6.336846ms314controller # [2479140.768551] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...315controller # [2479140.914298] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.316controller # [2479140.914676] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.317peer1 # [2479140.757593] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=DEBUG msg="attempting push/pull" peer_count=1318peer1 # [2479140.757593] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s319peer1 # [2479140.758442] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ320peer1 # [2479140.758442] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ321peer1 # [2479140.758442] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller322peer1 # [2479140.758442] peer1 data-mesher[222]: time=2026-10-03T00:06:00.743Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller323peer1 # [2479140.758442] peer1 data-mesher[222]: time=2026-10-03T00:06:00.744Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-10-03 00:05:55.814 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ324peer1 # [2479140.759915] peer1 data-mesher[222]: time=2026-10-03T00:06:00.745Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ325peer1 # [2479140.760050] peer1 data-mesher[222]: time=2026-10-03T00:06:00.745Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller326peer1 # [2479140.760050] peer1 data-mesher[222]: time=2026-10-03T00:06:00.745Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s327peer1 # [2479140.760050] peer1 data-mesher[222]: time=2026-10-03T00:06:00.745Z level=DEBUG msg="push/pull successful" interval=5s328peer1 # [2479140.761013] peer1 data-mesher[222]: time=2026-10-03T00:06:00.746Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4329peer1 # [2479140.763679] peer1 data-mesher[222]: time=2026-10-03T00:06:00.749Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4330peer1 # [2479140.765571] peer1 data-mesher[222]: time=2026-10-03T00:06:00.751Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-10-03 00:05:55.814 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=7.36166ms331peer1 # [2479140.768203] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...332peer1 # [2479140.915202] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.333peer1 # [2479140.915356] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.334peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.05 seconds)335controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .336controller: (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)337controller: waiting for success: wg show wg-star peers | grep -q .338controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)339peer1: waiting for success: wg show wg-star peers | grep -q .340peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)341peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64342peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds)343controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1344controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds)345controller: must succeed: wg show wg-star peers | wc -l346controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)347peer2: systemd-nspawn running (pid 785)348peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...349peer2: waiting for unit data-mesher.service350nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE351nixos-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.352Note: 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.353░ Spawning container peer2 on /build/vm-state-peer2.354peer2 # No journal files were found.355peer2 # No journal boot entry found for the specified boot (+0).356peer2 # [2479142.490212] peer2 systemd-journald[99]: Journal started357peer2 # [2479142.490271] peer2 systemd-journald[99]: Runtime Journal (/run/log/journal/85a1987f679c4396acadd30b3214fef6) is 8M, max 2.5G, 2.4G free.358peer2 # [2479142.494537] peer2 systemd[1]: Finished Apply Kernel Variables.359peer2 # [2479142.506004] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.360peer2 # [2479142.518860] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...361peer2 # [2479142.519725] peer2 systemd[1]: Starting Network Name Resolution...362peer2 # [2479142.520434] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...363peer2 # [2479142.530734] peer2 systemd-journald[99]: Time spent on flushing to /var/log/journal/85a1987f679c4396acadd30b3214fef6 is 2.352ms for 7 entries.364peer2 # [2479142.530734] peer2 systemd-journald[99]: System Journal (/var/log/journal/85a1987f679c4396acadd30b3214fef6) is 8M, max 4G, 3.9G free.365peer2 # [2479142.537768] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.366peer2 # [2479142.538336] peer2 systemd[1]: Reached target Preparation for Local File Systems.367peer2 # [2479142.538446] peer2 systemd[1]: Reached target Local File Systems.368peer2 # [2479142.539314] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.369peer2 # [2479142.539366] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container370peer2 # [2479142.540493] peer2 systemd[1]: Starting Save Transient machine-id to Disk...371peer2 # [2479142.540533] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys372peer2 # [2479142.541042] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.373peer2 # [2479142.542555] peer2 systemd[1]: Starting Create System Files and Directories...374peer2 # [2479142.560410] peer2 systemd-tmpfiles[148]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted375peer2 # [2479142.560619] peer2 systemd-tmpfiles[148]: fchmod() of /var/log/journal failed: Operation not permitted376peer2 # [2479142.560762] peer2 systemd-tmpfiles[148]: fchmod() of /var/log/journal/85a1987f679c4396acadd30b3214fef6 failed: Operation not permitted377peer2 # [2479142.560972] peer2 systemd-tmpfiles[148]: fchmod() of /run/log/journal failed: Operation not permitted378peer2 # [2479142.562355] peer2 systemd[1]: Finished Create System Files and Directories.379peer2 # [2479142.563457] peer2 systemd[1]: Starting Rebuild Journal Catalog...380peer2 # [2479142.564495] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...381peer2 # [2479142.580705] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.382peer2 # [2479142.582329] peer2 systemd[1]: Finished Save Transient machine-id to Disk.383peer2 # [2479142.587210] peer2 systemd[1]: Finished Rebuild Journal Catalog.384peer2 # [2479142.588528] peer2 systemd[1]: Starting Update is Completed...385peer2 # [2479142.599999] peer2 systemd[1]: Finished Update is Completed.386peer2 # [2479142.670413] peer2 systemd[1]: Finished Firewall.387peer2 # [2479142.670578] peer2 systemd[1]: Reached target Preparation for Network.388peer2 # [2479142.670795] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.389peer2 # [2479142.671892] peer2 systemd[1]: Starting Network Management...390peer2 # [2479143.363520] peer2 systemd-networkd[217]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted391peer2 # [2479143.363607] peer2 systemd-networkd[217]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted392peer2 # [2479143.373263] peer2 systemd-networkd[217]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.393peer2 # [2479143.373426] peer2 systemd-networkd[217]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.394peer2 # [2479143.373568] peer2 systemd-networkd[217]: lo: Link UP395peer2 # [2479143.373573] peer2 systemd-networkd[217]: lo: Gained carrier396peer2 # [2479143.373748] peer2 systemd-networkd[217]: eth1: Configuring with /etc/systemd/network/40-eth1.network.397peer2 # [2479143.374160] peer2 systemd[1]: Started Network Management.398peer2 # [2479143.374657] peer2 systemd-networkd[217]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.399peer2 # [2479143.374957] peer2 systemd-networkd[217]: wg-star: netdev ready400peer2 # [2479143.375520] peer2 systemd-networkd[217]: eth1: Link UP401peer2 # [2479143.375930] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...402peer2 # [2479143.375932] peer2 systemd-networkd[217]: eth1: Gained carrier403peer2 # [2479143.404462] peer2 systemd-networkd[217]: wg-star: Link UP404peer2 # [2479143.404467] peer2 systemd-networkd[217]: wg-star: Gained carrier405peer2 # [2479143.429226] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.406peer2 # [2479143.500564] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.407peer2 # [2479143.564869] peer2 systemd-resolved[130]: Positive Trust Anchors:408peer2 # [2479143.564879] peer2 systemd-resolved[130]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d409peer2 # [2479143.564882] peer2 systemd-resolved[130]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16410peer2 # [2479143.564919] peer2 systemd-resolved[130]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test411peer2 # [2479143.584978] peer2 systemd-resolved[130]: Using system hostname 'peer2'.412peer2 # [2479143.586506] peer2 systemd[1]: Started Network Name Resolution.413peer2 # [2479143.586636] peer2 systemd[1]: Reached target Network.414peer2 # [2479143.586746] peer2 systemd[1]: Reached target System Initialization.415peer2 # [2479143.586918] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.416peer2 # [2479143.586972] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.417peer2 # [2479143.587010] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container418peer2 # [2479143.587044] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.419peer2 # [2479143.587082] peer2 systemd[1]: Reached target Path Units.420peer2 # [2479143.587151] peer2 systemd[1]: Reached target Timer Units.421peer2 # [2479143.587370] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.422peer2 # [2479143.587574] peer2 systemd[1]: Listening on Nix Daemon Socket.423peer2 # [2479143.587791] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.424peer2 # [2479143.587833] peer2 systemd[1]: Reached target Socket Units.425peer2 # [2479143.587910] peer2 systemd[1]: Reached target Basic System.426peer2 # [2479143.590108] peer2 systemd[1]: Starting data mesher daemon...427peer2 # [2479143.591456] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...428peer2 # [2479143.592889] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...429peer2 # [2479143.594951] peer2 systemd[1]: Starting D-Bus System Message Bus...430peer2 # [2479143.646697] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.431peer2 # [2479143.806959] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).432peer2 # [2479143.807072] peer2 systemd[1]: Reached target Host and Network Name Lookups.433peer2 # [2479143.807176] peer2 systemd[1]: Reached target User and Group Name Lookups.434peer2 # [2479143.807527] peer2 nsncd[224]: Oct 03 00:06:03.793 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"435peer2 # [2479143.809329] peer2 systemd[1]: Starting User Login Management...436peer2 # [2479143.810826] peer2 systemd[1]: Starting Permit User Sessions...437peer2 # [2479143.860419] peer2 systemd[1]: Finished Permit User Sessions.438peer2 # [2479143.862024] peer2 systemd[1]: Started Console Getty.439peer2 # [2479143.862103] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0440peer2 # [2479143.862143] peer2 systemd[1]: Reached target Login Prompts.441peer2 # [2479143.943243] peer2 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'...442peer2 # [2479143.944443] peer2 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync'443peer2 # [2479143.944443] peer2 dbus-broker-launch[225]: Invalid user-name in /nix/store/6vm4jv8dfnmyv9by9r6gwshp9hz8yq8m-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"444peer2 # [2479143.945147] peer2 systemd[1]: Started D-Bus System Message Bus.445peer2 # [2479143.953763] peer2 dbus-broker-launch[225]: Ready446peer2 # [2479144.360995] peer2 data-mesher[222]: time=2026-10-03T00:06:04.346Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]447peer2 # [2479144.362100] peer2 data-mesher[222]: time=2026-10-03T00:06:04.347Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK448peer2 # [2479144.362100] peer2 data-mesher[222]: time=2026-10-03T00:06:04.347Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml449peer2 # [2479144.363998] peer2 data-mesher[222]: time=2026-10-03T00:06:04.349Z level=INFO msg="checking file integrity"450peer2 # [2479144.364142] peer2 data-mesher[222]: time=2026-10-03T00:06:04.349Z level=INFO msg="file integrity check complete"451peer2 # [2479144.367930] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="libp2p host created" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.3/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::3/tcp/7946 /ip6/fda1:5c8::c289:fe9d:a6bc:e45b/tcp/7946]"452peer2 # [2479144.368012] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="registered HTTP route" method=GET path=/files453peer2 # [2479144.368012] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name454peer2 # [2479144.368012] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name455peer2 # [2479144.368012] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="starting server"456peer2 # [2479144.368203] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="HTTP server listening" address=[::1]:7331457peer2 # [2479144.368203] peer2 data-mesher[222]: time=2026-10-03T00:06:04.353Z level=INFO msg="waiting for DHT to populate" delay=10s458peer2 # [2479144.368203] peer2 data-mesher[222]: time=2026-10-03T00:06:04.354Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331459peer2 # [2479144.374958] peer2 data-mesher[222]: time=2026-10-03T00:06:04.360Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946460peer2 # [2479144.381083] peer2 data-mesher[222]: time=2026-10-03T00:06:04.366Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946461peer1 # [2479144.382198] peer1 data-mesher[222]: time=2026-10-03T00:06:04.367Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946462controller # [2479144.376799] controller data-mesher[232]: time=2026-10-03T00:06:04.362Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946463peer2 # [2479144.617285] peer2 systemd-logind[242]: New seat seat0.464peer2 # [2479144.617493] peer2 systemd[1]: Started User Login Management.465peer2 # [2479144.619550] peer2 systemd[1]: Starting linger-users.service...466peer2 # [2479144.671094] peer2 systemd[1]: linger-users.service: Deactivated successfully.467peer2 # [2479144.671404] peer2 systemd[1]: Finished linger-users.service.468peer2 # [2479144.736119] peer2 systemd-networkd[217]: eth1: Gained IPv6LL469controller # [2479145.759699] controller data-mesher[232]: time=2026-10-03T00:06:05.745Z level=DEBUG msg="attempting push/pull" peer_count=1470controller # [2479145.759699] controller data-mesher[232]: time=2026-10-03T00:06:05.745Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s471controller # [2479145.761457] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK472controller # [2479145.761457] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s473controller # [2479145.761585] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=DEBUG msg="push/pull successful" interval=5s474controller # [2479145.761720] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf475controller # [2479145.761796] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf476controller # [2479145.761939] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller477controller # [2479145.762005] controller data-mesher[232]: time=2026-10-03T00:06:05.747Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4478controller # [2479145.763143] controller data-mesher[232]: time=2026-10-03T00:06:05.748Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4479controller # [2479145.764524] controller data-mesher[232]: time=2026-10-03T00:06:05.750Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller480peer2 # [2479145.760559] peer2 data-mesher[222]: time=2026-10-03T00:06:05.746Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ481peer2 # [2479145.760559] peer2 data-mesher[222]: time=2026-10-03T00:06:05.746Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ482peer2 # [2479145.761267] peer2 data-mesher[222]: time=2026-10-03T00:06:05.746Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4483peer2 # [2479145.761267] peer2 data-mesher[222]: time=2026-10-03T00:06:05.747Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller484peer2 # [2479145.761377] peer2 data-mesher[222]: time=2026-10-03T00:06:05.747Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4485peer2 # [2479145.761377] peer2 data-mesher[222]: time=2026-10-03T00:06:05.747Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller486peer2 # [2479145.761477] peer2 data-mesher[222]: time=2026-10-03T00:06:05.747Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-10-03 00:05:55.814 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ487peer2 # [2479145.761477] peer2 data-mesher[222]: time=2026-10-03T00:06:05.747Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-10-03 00:05:55.904 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ488peer2 # [2479145.767087] peer2 data-mesher[222]: time=2026-10-03T00:06:05.752Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-10-03 00:05:55.904 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=5.696118ms489peer2 # [2479145.768126] peer2 data-mesher[222]: time=2026-10-03T00:06:05.753Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-10-03 00:05:55.814 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=6.747532ms490peer2 # [2479145.769747] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...491peer2 # [2479145.924254] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.492peer2 # [2479145.924567] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.493peer1 # [2479145.760811] peer1 data-mesher[222]: time=2026-10-03T00:06:05.746Z level=DEBUG msg="attempting push/pull" peer_count=1494peer1 # [2479145.761394] peer1 data-mesher[222]: time=2026-10-03T00:06:05.746Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s495peer1 # [2479145.764802] peer1 data-mesher[222]: time=2026-10-03T00:06:05.750Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ496peer1 # [2479145.765432] peer1 data-mesher[222]: time=2026-10-03T00:06:05.751Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s497peer1 # [2479145.765502] peer1 data-mesher[222]: time=2026-10-03T00:06:05.751Z level=DEBUG msg="push/pull successful" interval=5s498controller # [2479150.761930] controller data-mesher[232]: time=2026-10-03T00:06:10.747Z level=DEBUG msg="attempting push/pull" peer_count=1499controller # [2479150.762607] controller data-mesher[232]: time=2026-10-03T00:06:10.747Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s500controller # [2479150.763649] controller data-mesher[232]: time=2026-10-03T00:06:10.749Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf501controller # [2479150.764290] controller data-mesher[232]: time=2026-10-03T00:06:10.750Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s502controller # [2479150.764429] controller data-mesher[232]: time=2026-10-03T00:06:10.750Z level=DEBUG msg="push/pull successful" interval=5s503controller # [2479150.767018] controller data-mesher[232]: time=2026-10-03T00:06:10.752Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf504controller # [2479150.767018] controller data-mesher[232]: time=2026-10-03T00:06:10.752Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf505peer1 # [2479150.762642] peer1 data-mesher[222]: time=2026-10-03T00:06:10.748Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ506peer1 # [2479150.762642] peer1 data-mesher[222]: time=2026-10-03T00:06:10.748Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ507peer1 # [2479150.765610] peer1 data-mesher[222]: time=2026-10-03T00:06:10.751Z level=DEBUG msg="attempting push/pull" peer_count=1508peer1 # [2479150.765704] peer1 data-mesher[222]: time=2026-10-03T00:06:10.751Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s509peer1 # [2479150.767199] peer1 data-mesher[222]: time=2026-10-03T00:06:10.752Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ510peer1 # [2479150.767786] peer1 data-mesher[222]: time=2026-10-03T00:06:10.753Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s511peer1 # [2479150.767865] peer1 data-mesher[222]: time=2026-10-03T00:06:10.753Z level=DEBUG msg="push/pull successful" interval=5s512peer2: still waiting for container 'peer2' to reach ready state...513peer2 # [2479154.369276] peer2 data-mesher[222]: time=2026-10-03T00:06:14.355Z level=INFO msg="performing state exchange with peers on join" count=1514peer2 # [2479154.369276] peer2 data-mesher[222]: time=2026-10-03T00:06:14.355Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s515peer2 # [2479154.371063] peer2 data-mesher[222]: time=2026-10-03T00:06:14.356Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ516peer2 # [2479154.371674] peer2 data-mesher[222]: time=2026-10-03T00:06:14.357Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s517peer2 # [2479154.371747] peer2 data-mesher[222]: time=2026-10-03T00:06:14.357Z level=INFO msg="server started"518peer2 # [2479154.371909] peer2 data-mesher[222]: time=2026-10-03T00:06:14.357Z level=INFO msg="starting expired-file sweeper" interval=1m0s519peer2 # [2479154.372252] peer2 systemd[1]: Started data mesher daemon.520peer2 # [2479154.374506] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...521peer2 # [2479154.537449] peer2 data-mesher[222]: time=2026-10-03T00:06:14.523Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY status=204522peer2 # [2479154.537614] peer2 dm-wg-star-publish[298]: Status: 204 No Content523peer2 # [2479154.539885] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...524peer2 # [2479154.541723] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.525peer2 # [2479154.542048] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.526peer2 # [2479154.543078] peer2 systemd[1]: Reached target Multi-User System.527controller # [2479154.370851] controller data-mesher[232]: time=2026-10-03T00:06:14.355Z level=INFO msg="received state sync from peer" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK528controller # [2479154.370851] controller data-mesher[232]: time=2026-10-03T00:06:14.355Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK529peer2 # [2479154.686876] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.530peer2 # [2479154.687191] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.531peer2 # [2479154.687842] peer2 systemd[1]: Startup finished in 12.654s.532peer2: (finished: waiting for unit data-mesher.service, in 13.68 seconds)533??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.534 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39535controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1536??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.537 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39538controller # [2479155.765366] controller data-mesher[232]: time=2026-10-03T00:06:15.751Z level=DEBUG msg="attempting push/pull" peer_count=1539controller # [2479155.765366] controller data-mesher[232]: time=2026-10-03T00:06:15.751Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s540controller # [2479155.767269] controller data-mesher[232]: time=2026-10-03T00:06:15.753Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK541controller # [2479155.767867] controller data-mesher[232]: time=2026-10-03T00:06:15.753Z level=DEBUG msg="new file detected" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY542controller # [2479155.768322] controller data-mesher[232]: time=2026-10-03T00:06:15.754Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY543controller # [2479155.768417] controller data-mesher[232]: time=2026-10-03T00:06:15.754Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-10-03 00:06:14.519 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK544controller # [2479155.768492] controller data-mesher[232]: time=2026-10-03T00:06:15.754Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s545controller # [2479155.768563] controller data-mesher[232]: time=2026-10-03T00:06:15.754Z level=DEBUG msg="push/pull successful" interval=5s546controller # [2479155.770448] controller data-mesher[232]: time=2026-10-03T00:06:15.755Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf547controller # [2479155.770448] controller data-mesher[232]: time=2026-10-03T00:06:15.755Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf548controller # [2479155.774613] controller data-mesher[232]: time=2026-10-03T00:06:15.760Z level=INFO msg="download complete" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-10-03 00:06:14.519 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK written=true elapsed=6.233805ms549controller # [2479155.777816] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...550controller # [2479155.943396] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.551controller # [2479155.943747] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.552controller: (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)553controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1554controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)555peer2: waiting for success: wg show wg-star peers | grep -q .556peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)557peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64558peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds)559controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b560peer2 # [2479155.766162] peer2 data-mesher[222]: time=2026-10-03T00:06:15.751Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ561peer2 # [2479155.766162] peer2 data-mesher[222]: time=2026-10-03T00:06:15.751Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ562peer2 # [2479155.769048] peer2 data-mesher[222]: time=2026-10-03T00:06:15.754Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY563peer2 # [2479155.772256] peer2 data-mesher[222]: time=2026-10-03T00:06:15.758Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY564controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds)565peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b566peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds)567peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1568peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds)569(finished: run the VM test script, in 33.61 seconds)570peer1 # [2479155.769047] peer1 data-mesher[222]: time=2026-10-03T00:06:15.754Z level=DEBUG msg="attempting push/pull" peer_count=1571peer1 # [2479155.769047] peer1 data-mesher[222]: time=2026-10-03T00:06:15.754Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s572peer1 # [2479155.770461] peer1 data-mesher[222]: time=2026-10-03T00:06:15.756Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ573peer1 # [2479155.770907] peer1 data-mesher[222]: time=2026-10-03T00:06:15.756Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s574peer1 # [2479155.770983] peer1 data-mesher[222]: time=2026-10-03T00:06:15.756Z level=DEBUG msg="push/pull successful" interval=5s575test script finished in 33.65s576cleanup577kill NspawnMachine (pid 50)578kill NspawnMachine (pid 53)579Container controller terminated by signal KILL.580kill NspawnMachine (pid 785)581Container peer1 terminated by signal KILL.582Container peer2 terminated by signal KILL.583(finished: cleanup, in 0.59 seconds)