container-test-run-dm-wireguard-star
checks.aarch64-linux.dm-wireguard-star
· build #121
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.00 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 controller, peer1, peer2,9 vlan1,10 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_ssh11controller: systemd-nspawn running (pid 50)12controller: Waiting for journal at /build/vm-state-controller/var/log/journal...13peer1: systemd-nspawn running (pid 53)14peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...15controller: waiting for unit data-mesher.service16nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE17nixos-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.18nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE19nixos-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.20Note: 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.21░ Spawning container peer1 on /build/vm-state-peer1.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.24controller # No journal files were found.25controller # No journal boot entry found for the specified boot (+0).26peer1 # No journal files were found.27peer1 # No journal boot entry found for the specified boot (+0).28controller # [355210.698036] controller systemd-journald[105]: Journal started29controller # [355210.698087] controller systemd-journald[105]: Runtime Journal (/run/log/journal/6f82ab9e1760461e80a034d2ab3207c8) is 8M, max 2.5G, 2.4G free.30controller # [355210.848386] controller systemd[1]: Finished Apply Kernel Variables.31controller # [355210.895890] controller systemd[1]: Finished Firewall.32controller # [355210.896385] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.33controller # [355210.905956] controller systemd[1]: Reached target Preparation for Network.34controller # [355210.906243] controller systemd[1]: Listening on Network Management Resolve Hook Socket.35controller # [355210.936481] controller systemd[1]: Starting Flush Journal to Persistent Storage...36controller # [355210.937461] controller systemd[1]: Starting Network Name Resolution...37controller # [355210.939359] controller systemd[1]: Starting Create Static Device Nodes in /dev...38controller # [355210.945167] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/6f82ab9e1760461e80a034d2ab3207c8 is 1.801ms for 10 entries.39controller # [355210.945167] controller systemd-journald[105]: System Journal (/var/log/journal/6f82ab9e1760461e80a034d2ab3207c8) is 8M, max 4G, 3.9G free.40controller # [355210.963893] controller systemd[1]: Finished Create Static Device Nodes in /dev.41controller # [355210.964667] controller systemd[1]: Reached target Preparation for Local File Systems.42controller # [355210.964785] controller systemd[1]: Reached target Local File Systems.43controller # [355210.965654] controller systemd[1]: Listening on Boot Loader Control Service Socket.44controller # [355210.965702] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container45controller # [355210.966643] controller systemd[1]: Starting Save Transient machine-id to Disk...46controller # [355210.966680] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys47controller # [355210.967711] controller systemd[1]: Starting Network Management...48controller # [355210.990174] controller systemd[1]: Finished Flush Journal to Persistent Storage.49controller # [355210.991264] controller systemd[1]: Starting Create System Files and Directories...50controller # [355211.009085] controller systemd-tmpfiles[218]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted51controller # [355211.009256] controller systemd-tmpfiles[218]: fchmod() of /var/log/journal failed: Operation not permitted52controller # [355211.009370] controller systemd-tmpfiles[218]: fchmod() of /var/log/journal/6f82ab9e1760461e80a034d2ab3207c8 failed: Operation not permitted53controller # [355211.009539] controller systemd-tmpfiles[218]: fchmod() of /run/log/journal failed: Operation not permitted54controller # [355211.020359] controller systemd[1]: Finished Create System Files and Directories.55controller # [355211.021637] controller systemd[1]: Starting Rebuild Journal Catalog...56controller # [355211.022412] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...57controller # [355211.040308] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.58controller # [355211.042478] controller systemd[1]: Finished Rebuild Journal Catalog.59controller # [355211.044303] controller systemd[1]: Starting Update is Completed...60controller # [355211.055038] controller systemd[1]: Finished Update is Completed.61peer1 # [355210.689094] peer1 systemd-journald[96]: Journal started62peer1 # [355210.689148] peer1 systemd-journald[96]: Runtime Journal (/run/log/journal/e7e8b07c43464684a0abae1c2a4a1830) is 8M, max 2.5G, 2.4G free.63peer1 # [355210.790813] peer1 systemd[1]: Finished Apply Kernel Variables.64peer1 # [355210.824457] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.65peer1 # [355210.883600] peer1 systemd[1]: Finished Firewall.66peer1 # [355210.885470] peer1 systemd[1]: Reached target Preparation for Network.67peer1 # [355210.885734] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.68peer1 # [355210.886702] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...69peer1 # [355210.887571] peer1 systemd[1]: Starting Network Name Resolution...70peer1 # [355210.888310] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...71peer1 # [355210.941963] peer1 systemd-journald[96]: Time spent on flushing to /var/log/journal/e7e8b07c43464684a0abae1c2a4a1830 is 1.742ms for 10 entries.72peer1 # [355210.941963] peer1 systemd-journald[96]: System Journal (/var/log/journal/e7e8b07c43464684a0abae1c2a4a1830) is 8M, max 4G, 3.9G free.73peer1 # [355210.952801] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.74peer1 # [355210.953599] peer1 systemd[1]: Reached target Preparation for Local File Systems.75peer1 # [355210.953738] peer1 systemd[1]: Reached target Local File Systems.76peer1 # [355210.954666] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.77peer1 # [355210.954719] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container78peer1 # [355210.955677] peer1 systemd[1]: Starting Save Transient machine-id to Disk...79peer1 # [355210.955715] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys80peer1 # [355210.956774] peer1 systemd[1]: Starting Network Management...81peer1 # [355210.988347] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.82peer1 # [355210.990171] peer1 systemd[1]: Starting Create System Files and Directories...83peer1 # [355211.012692] peer1 systemd-tmpfiles[207]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted84peer1 # [355211.012885] peer1 systemd-tmpfiles[207]: fchmod() of /var/log/journal failed: Operation not permitted85peer1 # [355211.013011] peer1 systemd-tmpfiles[207]: fchmod() of /var/log/journal/e7e8b07c43464684a0abae1c2a4a1830 failed: Operation not permitted86peer1 # [355211.013199] peer1 systemd-tmpfiles[207]: fchmod() of /run/log/journal failed: Operation not permitted87peer1 # [355211.020656] peer1 systemd[1]: Finished Create System Files and Directories.88peer1 # [355211.022457] peer1 systemd[1]: Starting Rebuild Journal Catalog...89peer1 # [355211.023180] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...90peer1 # [355211.034743] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.91peer1 # [355211.043586] peer1 systemd[1]: Finished Rebuild Journal Catalog.92peer1 # [355211.044765] peer1 systemd[1]: Starting Update is Completed...93peer1 # [355211.055382] peer1 systemd[1]: Finished Update is Completed.94peer1 # [355211.849677] peer1 systemd-networkd[203]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted95peer1 # [355211.849777] peer1 systemd-networkd[203]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted96peer1 # [355211.930001] peer1 systemd-networkd[203]: /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.97peer1 # [355211.930445] peer1 systemd-networkd[203]: /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.98peer1 # [355211.930660] peer1 systemd-networkd[203]: lo: Link UP99peer1 # [355211.930665] peer1 systemd-networkd[203]: lo: Gained carrier100peer1 # [355211.930907] peer1 systemd-networkd[203]: eth1: Configuring with /etc/systemd/network/40-eth1.network.101peer1 # [355211.931397] peer1 systemd[1]: Started Network Management.102peer1 # [355211.937119] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...103peer1 # [355211.937423] peer1 systemd-networkd[203]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.104peer1 # [355211.937836] peer1 systemd-networkd[203]: wg-star: netdev ready105peer1 # [355211.938408] peer1 systemd-networkd[203]: eth1: Link UP106peer1 # [355211.938721] peer1 systemd-networkd[203]: eth1: Gained carrier107peer1 # [355211.969243] peer1 systemd-networkd[203]: wg-star: Link UP108peer1 # [355211.969250] peer1 systemd-networkd[203]: wg-star: Gained carrier109peer1 # [355211.970540] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.110peer1 # [355212.192619] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.111peer1 # [355212.194114] peer1 systemd[1]: Finished Save Transient machine-id to Disk.112controller # [355212.204837] controller systemd-networkd[214]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted113controller # [355212.204932] controller systemd-networkd[214]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted114controller # [355212.218125] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.115controller # [355212.219185] controller systemd[1]: Finished Save Transient machine-id to Disk.116controller # [355212.277082] controller 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.117controller # [355212.277278] controller 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.118controller # [355212.277473] controller systemd-networkd[214]: lo: Link UP119controller # [355212.277478] controller systemd-networkd[214]: lo: Gained carrier120controller # [355212.277700] controller systemd-networkd[214]: eth1: Configuring with /etc/systemd/network/40-eth1.network.121controller # [355212.278188] controller systemd[1]: Started Network Management.122controller # [355212.278816] controller systemd-networkd[214]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.123controller # [355212.279203] controller systemd-networkd[214]: wg-star: netdev ready124controller # [355212.279869] controller systemd-networkd[214]: eth1: Link UP125controller # [355212.280500] controller systemd-networkd[214]: eth1: Gained carrier126controller # [355212.280800] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...127controller # [355212.341354] controller systemd-networkd[214]: wg-star: Link UP128controller # [355212.341360] controller systemd-networkd[214]: wg-star: Gained carrier129controller # [355212.361573] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.130controller # [355213.380468] controller systemd-networkd[214]: eth1: Gained IPv6LL131peer1 # [355213.896142] peer1 systemd-networkd[203]: eth1: Gained IPv6LL132peer1 # [355215.103257] peer1 systemd-resolved[198]: Positive Trust Anchors:133peer1 # [355215.103270] peer1 systemd-resolved[198]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d134peer1 # [355215.103273] peer1 systemd-resolved[198]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16135peer1 # [355215.103308] peer1 systemd-resolved[198]: 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 test136peer1 # [355215.126296] peer1 systemd-resolved[198]: Using system hostname 'peer1'.137peer1 # [355215.128095] peer1 systemd[1]: Started Network Name Resolution.138peer1 # [355215.128214] peer1 systemd[1]: Reached target Network.139peer1 # [355215.128298] peer1 systemd[1]: Reached target System Initialization.140peer1 # [355215.128398] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.141peer1 # [355215.128440] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.142peer1 # [355215.128464] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container143peer1 # [355215.128480] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.144peer1 # [355215.128501] peer1 systemd[1]: Reached target Path Units.145peer1 # [355215.128533] peer1 systemd[1]: Reached target Timer Units.146peer1 # [355215.128674] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.147peer1 # [355215.128820] peer1 systemd[1]: Listening on Nix Daemon Socket.148peer1 # [355215.128946] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.149peer1 # [355215.128965] peer1 systemd[1]: Reached target Socket Units.150peer1 # [355215.129008] peer1 systemd[1]: Reached target Basic System.151peer1 # [355215.130287] peer1 systemd[1]: Starting data mesher daemon...152peer1 # [355215.131058] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...153peer1 # [355215.131962] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...154peer1 # [355215.133279] peer1 systemd[1]: Starting D-Bus System Message Bus...155peer1 # [355215.150629] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.156controller # [355215.094386] controller systemd-resolved[209]: Positive Trust Anchors:157controller # [355215.094398] controller systemd-resolved[209]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d158controller # [355215.094402] controller systemd-resolved[209]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16159controller # [355215.094438] controller systemd-resolved[209]: 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 test160controller # [355215.117600] controller systemd-resolved[209]: Using system hostname 'controller'.161controller # [355215.119313] controller systemd[1]: Started Network Name Resolution.162controller # [355215.119411] controller systemd[1]: Reached target Network.163controller # [355215.119481] controller systemd[1]: Reached target System Initialization.164controller # [355215.119579] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.165controller # [355215.119614] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container166controller # [355215.119644] controller systemd[1]: Started Daily Cleanup of Temporary Directories.167controller # [355215.119668] controller systemd[1]: Reached target Path Units.168controller # [355215.119703] controller systemd[1]: Reached target Timer Units.169controller # [355215.119852] controller systemd[1]: Listening on D-Bus System Message Bus Socket.170controller # [355215.119980] controller systemd[1]: Listening on Nix Daemon Socket.171controller # [355215.120130] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.172controller # [355215.120154] controller systemd[1]: Reached target Socket Units.173controller # [355215.120193] controller systemd[1]: Reached target Basic System.174controller # [355215.121548] controller systemd[1]: Starting data mesher daemon...175controller # [355215.122838] controller systemd[1]: Starting Import lastlog data into lastlog2 database...176controller # [355215.123750] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...177controller # [355215.125152] controller systemd[1]: Starting D-Bus System Message Bus...178controller # [355215.141582] controller systemd[1]: Finished Import lastlog data into lastlog2 database.179controller # [355215.430966] controller nsncd[232]: Sep 08 10:07:15.416 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"180controller # [355215.431007] controller systemd[1]: Started Name Service Cache Daemon (nsncd).181controller # [355215.431077] controller systemd[1]: Reached target Host and Network Name Lookups.182controller # [355215.431137] controller systemd[1]: Reached target User and Group Name Lookups.183controller # [355215.433569] controller systemd[1]: Starting User Login Management...184controller # [355215.434432] controller systemd[1]: Starting Permit User Sessions...185controller # [355215.487582] controller systemd[1]: Finished Permit User Sessions.186controller # [355215.488787] controller systemd[1]: Started Console Getty.187controller # [355215.488840] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0188controller # [355215.488861] controller systemd[1]: Reached target Login Prompts.189controller # [355215.568604] controller dbus-broker-launch[233]: Looking up NSS user entry for 'systemd-timesync'...190controller # [355215.569329] controller dbus-broker-launch[233]: NSS returned no entry for 'systemd-timesync'191controller # [355215.569329] controller dbus-broker-launch[233]: Invalid user-name in /nix/store/k4nrnizlfqpr5gg6w1i5jzkv59dh2p3l-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"192controller # [355215.569728] controller systemd[1]: Started D-Bus System Message Bus.193controller # [355215.577035] controller dbus-broker-launch[233]: Ready194peer1 # [355215.430918] peer1 nsncd[221]: Sep 08 10:07:15.416 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"195peer1 # [355215.431054] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).196peer1 # [355215.431134] peer1 systemd[1]: Reached target Host and Network Name Lookups.197peer1 # [355215.431197] peer1 systemd[1]: Reached target User and Group Name Lookups.198peer1 # [355215.432406] peer1 systemd[1]: Starting User Login Management...199peer1 # [355215.433177] peer1 systemd[1]: Starting Permit User Sessions...200peer1 # [355215.487589] peer1 systemd[1]: Finished Permit User Sessions.201peer1 # [355215.489256] peer1 systemd[1]: Started Console Getty.202peer1 # [355215.489309] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0203peer1 # [355215.489330] peer1 systemd[1]: Reached target Login Prompts.204peer1 # [355215.564963] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...205peer1 # [355215.565668] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'206peer1 # [355215.565668] peer1 dbus-broker-launch[222]: Invalid user-name in /nix/store/k4nrnizlfqpr5gg6w1i5jzkv59dh2p3l-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"207peer1 # [355215.566079] peer1 systemd[1]: Started D-Bus System Message Bus.208peer1 # [355215.573091] peer1 dbus-broker-launch[222]: Ready209controller # [355216.172530] controller data-mesher[230]: time=2026-09-08T10:07:16.158Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]210controller # [355216.173630] controller data-mesher[230]: time=2026-09-08T10:07:16.159Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV: [/dns/controller.clan/tcp/7946]} {12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3: [/dns/peer1.clan/tcp/7946]} {12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV211controller # [355216.173630] controller data-mesher[230]: time=2026-09-08T10:07:16.159Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml212controller # [355216.185830] controller data-mesher[230]: time=2026-09-08T10:07:16.171Z level=INFO msg="checking file integrity"213controller # [355216.185950] controller data-mesher[230]: time=2026-09-08T10:07:16.171Z level=INFO msg="file integrity check complete"214controller # [355216.190147] controller data-mesher[230]: time=2026-09-08T10:07:16.175Z level=INFO msg="libp2p host created" peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV 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::270:b550:118d:54ad/tcp/7946]"215controller # [355216.190220] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=GET path=/files216controller # [355216.190220] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name217controller # [355216.190220] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name218controller # [355216.190220] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="starting server"219controller # [355216.190811] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="HTTP server listening" address=[::1]:7331220controller # [355216.190848] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="waiting for DHT to populate" delay=10s221controller # [355216.190906] controller data-mesher[230]: time=2026-09-08T10:07:16.176Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331222controller # [355216.196026] controller data-mesher[230]: time=2026-09-08T10:07:16.181Z level=INFO msg="peer connected" peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 remote_addr=/ip6/2001:db8:1::2/tcp/7946223controller # [355216.196026] controller data-mesher[230]: time=2026-09-08T10:07:16.181Z level=INFO msg="peer connected" peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 remote_addr=/ip4/192.168.1.2/tcp/7946224controller # [355216.196026] controller data-mesher[230]: time=2026-09-08T10:07:16.181Z level=INFO msg="peer connected" peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 remote_addr=/ip6/2001:db8:1::2/tcp/7946225controller # [355216.433586] controller systemd-logind[250]: New seat seat0.226peer1 # [355216.179912] peer1 data-mesher[219]: time=2026-09-08T10:07:16.165Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]227peer1 # [355216.181047] peer1 data-mesher[219]: time=2026-09-08T10:07:16.166Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV: [/dns/controller.clan/tcp/7946]} {12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3: [/dns/peer1.clan/tcp/7946]} {12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3228peer1 # [355216.181102] peer1 data-mesher[219]: time=2026-09-08T10:07:16.166Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml229peer1 # [355216.185940] peer1 data-mesher[219]: time=2026-09-08T10:07:16.171Z level=INFO msg="checking file integrity"230peer1 # [355216.186045] peer1 data-mesher[219]: time=2026-09-08T10:07:16.171Z level=INFO msg="file integrity check complete"231peer1 # [355216.190171] peer1 data-mesher[219]: time=2026-09-08T10:07:16.175Z level=INFO msg="libp2p host created" peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 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::bb7b:3d3d:a93a:a4e5/tcp/7946]"232peer1 # [355216.190220] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=GET path=/files233peer1 # [355216.190220] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name234peer1 # [355216.190220] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name235peer1 # [355216.190220] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="starting server"236peer1 # [355216.190322] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="waiting for DHT to populate" delay=10s237peer1 # [355216.190386] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="HTTP server listening" address=[::1]:7331238peer1 # [355216.190422] peer1 data-mesher[219]: time=2026-09-08T10:07:16.176Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331239peer1 # [355216.195051] peer1 data-mesher[219]: time=2026-09-08T10:07:16.180Z level=INFO msg="peer connected" peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV remote_addr=/ip6/2001:db8:1::1/tcp/7946240peer1 # [355216.196329] peer1 data-mesher[219]: time=2026-09-08T10:07:16.182Z level=INFO msg="peer connected" peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV remote_addr=/ip4/192.168.1.1/tcp/47372241peer1 # [355216.197141] peer1 data-mesher[219]: time=2026-09-08T10:07:16.182Z level=INFO msg="peer connected" peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV remote_addr=/ip6/2001:db8:1::1/tcp/58368242controller # [355216.434760] controller systemd[1]: Started User Login Management.243controller # [355216.476959] controller systemd[1]: Starting linger-users.service...244controller # [355216.488692] controller systemd[1]: linger-users.service: Deactivated successfully.245controller # [355216.488957] controller systemd[1]: Finished linger-users.service.246peer1 # [355216.448314] peer1 systemd-logind[239]: New seat seat0.247peer1 # [355216.448532] peer1 systemd[1]: Started User Login Management.248peer1 # [355216.476923] peer1 systemd[1]: Starting linger-users.service...249peer1 # [355216.488710] peer1 systemd[1]: linger-users.service: Deactivated successfully.250peer1 # [355216.488966] peer1 systemd[1]: Finished linger-users.service.251controller: still waiting for container 'controller' to reach ready state...252peer1 # [355226.191495] peer1 data-mesher[219]: time=2026-09-08T10:07:26.177Z level=INFO msg="performing state exchange with peers on join" count=1253peer1 # [355226.191495] peer1 data-mesher[219]: time=2026-09-08T10:07:26.177Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s254peer1 # [355226.192542] peer1 data-mesher[219]: time=2026-09-08T10:07:26.178Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV255peer1 # [355226.192592] peer1 data-mesher[219]: time=2026-09-08T10:07:26.178Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV256peer1 # [355226.192965] peer1 data-mesher[219]: time=2026-09-08T10:07:26.178Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV257peer1 # [355226.192989] peer1 data-mesher[219]: time=2026-09-08T10:07:26.178Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s258peer1 # [355226.193171] peer1 data-mesher[219]: time=2026-09-08T10:07:26.178Z level=INFO msg="server started"259peer1 # [355226.193217] peer1 data-mesher[219]: time=2026-09-08T10:07:26.179Z level=INFO msg="starting expired-file sweeper" interval=1m0s260peer1 # [355226.193451] peer1 systemd[1]: Started data mesher daemon.261peer1 # [355226.194803] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...262peer1 # [355226.356273] peer1 data-mesher[219]: time=2026-09-08T10:07:26.342Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww status=204263peer1 # [355226.356405] peer1 dm-wg-star-publish[283]: Status: 204 No Content264peer1 # [355226.357176] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...265peer1 # [355226.359862] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.266peer1 # [355226.360190] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.267peer1 # [355226.361295] peer1 systemd[1]: Reached target Multi-User System.268peer1 # [355226.440952] peer1 dm-wg-star-reconfig[309]: No controller data available yet, skipping269peer1 # [355226.441920] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.270peer1 # [355226.442022] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.271controller # [355226.191372] controller data-mesher[230]: time=2026-09-08T10:07:26.177Z level=INFO msg="performing state exchange with peers on join" count=1272controller # [355226.191863] controller data-mesher[230]: time=2026-09-08T10:07:26.177Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s273controller # [355226.192698] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3274controller # [355226.192751] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3275controller # [355226.192939] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3276controller # [355226.192939] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s277controller # [355226.192999] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="server started"278controller # [355226.193083] controller data-mesher[230]: time=2026-09-08T10:07:26.178Z level=INFO msg="starting expired-file sweeper" interval=1m0s279controller # [355226.193205] controller systemd[1]: Started data mesher daemon.280controller # [355226.195460] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...281controller # [355226.271892] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...282controller # [355226.323996] controller data-mesher[230]: time=2026-09-08T10:07:26.309Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204283controller # [355226.324220] controller dm-wg-star-publish[294]: Status: 204 No Content284controller # [355226.327519] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.285controller # [355226.328187] controller systemd[1]: Reached target Multi-User System.286controller # [355226.375796] controller dm-wg-star-reconfig[322]: No peer data available yet, skipping287controller # [355226.376350] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.288controller # [355226.376528] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.289controller # [355226.376928] controller systemd[1]: Startup finished in 16.096s.290peer1 # [355226.442382] peer1 systemd[1]: Startup finished in 16.240s.291controller: (finished: waiting for unit data-mesher.service, in 17.16 seconds)292peer1: waiting for unit data-mesher.service293peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds)294??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.295 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39296controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller297??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.298 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39299controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds)300peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller301controller # [355231.193320] controller data-mesher[230]: time=2026-09-08T10:07:31.179Z level=DEBUG msg="attempting push/pull" peer_count=1302controller # [355231.193776] controller data-mesher[230]: time=2026-09-08T10:07:31.179Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s303controller # [355231.194516] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3304controller # [355231.194516] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3305controller # [355231.194616] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3306controller # [355231.194747] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=DEBUG msg="new file detected" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww307controller # [355231.194792] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="received file request" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/controller308controller # [355231.194873] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww309controller # [355231.194930] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww signed_at="2026-09-08 10:07:26.337 +0000 UTC" signed_by="AIWMxTKKxcqAfnwpDD+kBhhbX+zWXgN3dGMVzsmy1Ww=" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3310controller # [355231.195160] controller data-mesher[230]: time=2026-09-08T10:07:31.180Z level=DEBUG msg="new file detected" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww311controller # [355231.195195] controller data-mesher[230]: time=2026-09-08T10:07:31.181Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s312controller # [355231.195240] controller data-mesher[230]: time=2026-09-08T10:07:31.181Z level=DEBUG msg="push/pull successful" interval=5s313controller # [355231.197887] controller data-mesher[230]: time=2026-09-08T10:07:31.183Z level=INFO msg="file transfer complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/controller314controller # [355231.200951] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...315controller # [355231.312578] controller data-mesher[230]: time=2026-09-08T10:07:31.298Z level=INFO msg="download complete" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww signed_at="2026-09-08 10:07:26.337 +0000 UTC" signed_by="AIWMxTKKxcqAfnwpDD+kBhhbX+zWXgN3dGMVzsmy1Ww=" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 written=true elapsed=117.648249ms316controller # [355231.351556] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.317controller # [355231.351905] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.318peer1 # [355231.193975] peer1 data-mesher[219]: time=2026-09-08T10:07:31.179Z level=DEBUG msg="attempting push/pull" peer_count=1319peer1 # [355231.194287] peer1 data-mesher[219]: time=2026-09-08T10:07:31.179Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s320peer1 # [355231.194287] peer1 data-mesher[219]: time=2026-09-08T10:07:31.179Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV321peer1 # [355231.194287] peer1 data-mesher[219]: time=2026-09-08T10:07:31.179Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV322peer1 # [355231.194287] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=DEBUG msg="new file detected" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller323peer1 # [355231.194287] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller324peer1 # [355231.194408] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 10:07:26.253 +0000 UTC" signed_by="P0MqPDt/zOfflF4XmdXb9dZ3SJiWaZVHcTYfCo+uZ2I=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV325peer1 # [355231.195003] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV326peer1 # [355231.195037] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=DEBUG msg="new file detected" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller327peer1 # [355231.195057] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s328peer1 # [355231.195099] peer1 data-mesher[219]: time=2026-09-08T10:07:31.180Z level=DEBUG msg="push/pull successful" interval=5s329peer1 # [355231.195265] peer1 data-mesher[219]: time=2026-09-08T10:07:31.181Z level=INFO msg="received file request" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww330peer1 # [355231.197068] peer1 data-mesher[219]: time=2026-09-08T10:07:31.182Z level=INFO msg="file transfer complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww331peer1 # [355231.240546] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...332peer1 # [355231.312694] peer1 data-mesher[219]: time=2026-09-08T10:07:31.298Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 10:07:26.253 +0000 UTC" signed_by="P0MqPDt/zOfflF4XmdXb9dZ3SJiWaZVHcTYfCo+uZ2I=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV written=true elapsed=118.322019ms333peer1 # [355231.359307] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.334peer1 # [355231.359452] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.335peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.04 seconds)336controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .337controller: (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)338controller: waiting for success: wg show wg-star peers | grep -q .339controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)340peer1: waiting for success: wg show wg-star peers | grep -q .341peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)342peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0270:b550:118d:54ad343peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0270:b550:118d:54ad, in 0.01 seconds)344controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bb7b:3d3d:a93a:a4e5345controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bb7b:3d3d:a93a:a4e5, in 0.01 seconds)346controller: must succeed: wg show wg-star peers | wc -l347controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)348peer2: systemd-nspawn running (pid 781)349peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...350peer2: waiting for unit data-mesher.service351nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE352nixos-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.353Note: 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.354░ Spawning container peer2 on /build/vm-state-peer2.355peer2 # No journal boot entry found for the specified boot (+0).356peer2 # [355232.810781] peer2 systemd-journald[95]: Journal started357peer2 # [355232.810841] peer2 systemd-journald[95]: Runtime Journal (/run/log/journal/f0d6efc184a14679a59323a2fea7aed8) is 8M, max 2.5G, 2.4G free.358peer2 # [355232.812165] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.359peer2 # [355232.821003] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...360peer2 # [355232.821981] peer2 systemd[1]: Starting Network Name Resolution...361peer2 # [355232.822826] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...362peer2 # [355232.832461] peer2 systemd-journald[95]: Time spent on flushing to /var/log/journal/f0d6efc184a14679a59323a2fea7aed8 is 1.639ms for 6 entries.363peer2 # [355232.832461] peer2 systemd-journald[95]: System Journal (/var/log/journal/f0d6efc184a14679a59323a2fea7aed8) is 8M, max 4G, 3.9G free.364peer2 # [355232.837375] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.365peer2 # [355232.838035] peer2 systemd[1]: Reached target Preparation for Local File Systems.366peer2 # [355232.838164] peer2 systemd[1]: Reached target Local File Systems.367peer2 # [355232.838984] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.368peer2 # [355232.839027] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container369peer2 # [355232.840054] peer2 systemd[1]: Starting Save Transient machine-id to Disk...370peer2 # [355232.840090] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys371peer2 # [355232.900819] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.372peer2 # [355232.903072] peer2 systemd[1]: Starting Create System Files and Directories...373peer2 # [355232.964247] peer2 systemd-tmpfiles[166]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted374peer2 # [355232.964423] peer2 systemd-tmpfiles[166]: fchmod() of /var/log/journal failed: Operation not permitted375peer2 # [355232.964541] peer2 systemd-tmpfiles[166]: fchmod() of /var/log/journal/f0d6efc184a14679a59323a2fea7aed8 failed: Operation not permitted376peer2 # [355232.964721] peer2 systemd-tmpfiles[166]: fchmod() of /run/log/journal failed: Operation not permitted377peer2 # [355232.966359] peer2 systemd[1]: Finished Create System Files and Directories.378peer2 # [355232.967531] peer2 systemd[1]: Starting Rebuild Journal Catalog...379peer2 # [355232.968314] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...380peer2 # [355232.976607] peer2 systemd[1]: Finished Firewall.381peer2 # [355232.976805] peer2 systemd[1]: Reached target Preparation for Network.382peer2 # [355232.977058] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.383peer2 # [355232.978167] peer2 systemd[1]: Starting Network Management...384peer2 # [355232.981339] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.385peer2 # [355232.991617] peer2 systemd[1]: Finished Rebuild Journal Catalog.386peer2 # [355232.992981] peer2 systemd[1]: Starting Update is Completed...387peer2 # [355233.003563] peer2 systemd[1]: Finished Update is Completed.388peer2 # [355233.337144] peer2 systemd-networkd[208]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted389peer2 # [355233.337235] peer2 systemd-networkd[208]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted390peer2 # [355233.344594] peer2 systemd-networkd[208]: /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.391peer2 # [355233.344768] peer2 systemd-networkd[208]: /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.392peer2 # [355233.344913] peer2 systemd-networkd[208]: lo: Link UP393peer2 # [355233.344918] peer2 systemd-networkd[208]: lo: Gained carrier394peer2 # [355233.345114] peer2 systemd-networkd[208]: eth1: Configuring with /etc/systemd/network/40-eth1.network.395peer2 # [355233.345509] peer2 systemd[1]: Started Network Management.396peer2 # [355233.384831] peer2 systemd-networkd[208]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.397peer2 # [355233.385127] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...398peer2 # [355233.385172] peer2 systemd-networkd[208]: wg-star: netdev ready399peer2 # [355233.385596] peer2 systemd-networkd[208]: eth1: Link UP400peer2 # [355233.386055] peer2 systemd-networkd[208]: eth1: Gained carrier401peer2 # [355233.416595] peer2 systemd-networkd[208]: wg-star: Link UP402peer2 # [355233.416601] peer2 systemd-networkd[208]: wg-star: Gained carrier403peer2 # [355233.418686] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.404peer2 # [355233.470028] peer2 systemd-resolved[118]: Positive Trust Anchors:405peer2 # [355233.470040] peer2 systemd-resolved[118]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d406peer2 # [355233.470043] peer2 systemd-resolved[118]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16407peer2 # [355233.470080] peer2 systemd-resolved[118]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test408peer2 # [355233.492684] peer2 systemd-resolved[118]: Using system hostname 'peer2'.409peer2 # [355233.494266] peer2 systemd[1]: Started Network Name Resolution.410peer2 # [355233.494371] peer2 systemd[1]: Reached target Network.411peer2 # [355233.494445] peer2 systemd[1]: Reached target System Initialization.412peer2 # [355233.494562] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.413peer2 # [355233.494612] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.414peer2 # [355233.494652] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container415peer2 # [355233.494677] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.416peer2 # [355233.494703] peer2 systemd[1]: Reached target Path Units.417peer2 # [355233.494745] peer2 systemd[1]: Reached target Timer Units.418peer2 # [355233.494885] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.419peer2 # [355233.495050] peer2 systemd[1]: Listening on Nix Daemon Socket.420peer2 # [355233.495185] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.421peer2 # [355233.495211] peer2 systemd[1]: Reached target Socket Units.422peer2 # [355233.495254] peer2 systemd[1]: Reached target Basic System.423peer2 # [355233.496758] peer2 systemd[1]: Starting data mesher daemon...424peer2 # [355233.497835] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...425peer2 # [355233.498864] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...426peer2 # [355233.500376] peer2 systemd[1]: Starting D-Bus System Message Bus...427peer2 # [355233.517150] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.428peer2 # [355233.603673] peer2 nsncd[219]: Sep 08 10:07:33.589 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"429peer2 # [355233.603633] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).430peer2 # [355233.603745] peer2 systemd[1]: Reached target Host and Network Name Lookups.431peer2 # [355233.603846] peer2 systemd[1]: Reached target User and Group Name Lookups.432peer2 # [355233.605867] peer2 systemd[1]: Starting User Login Management...433peer2 # [355233.607329] peer2 systemd[1]: Starting Permit User Sessions...434peer2 # [355233.656706] peer2 systemd[1]: Finished Permit User Sessions.435peer2 # [355233.658341] peer2 systemd[1]: Started Console Getty.436peer2 # [355233.658417] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0437peer2 # [355233.658458] peer2 systemd[1]: Reached target Login Prompts.438peer2 # [355233.687796] peer2 dbus-broker-launch[220]: Looking up NSS user entry for 'systemd-timesync'...439peer2 # [355233.688977] peer2 dbus-broker-launch[220]: NSS returned no entry for 'systemd-timesync'440peer2 # [355233.689019] peer2 dbus-broker-launch[220]: Invalid user-name in /nix/store/k4nrnizlfqpr5gg6w1i5jzkv59dh2p3l-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"441peer2 # [355233.689543] peer2 systemd[1]: Started D-Bus System Message Bus.442peer2 # [355233.697495] peer2 dbus-broker-launch[220]: Ready443peer2 # [355233.931886] peer2 data-mesher[217]: time=2026-09-08T10:07:33.917Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]444peer2 # [355233.932924] peer2 data-mesher[217]: time=2026-09-08T10:07:33.918Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV: [/dns/controller.clan/tcp/7946]} {12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3: [/dns/peer1.clan/tcp/7946]} {12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br445peer2 # [355233.932924] peer2 data-mesher[217]: time=2026-09-08T10:07:33.918Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml446peer2 # [355234.037595] peer2 data-mesher[217]: time=2026-09-08T10:07:34.023Z level=INFO msg="checking file integrity"447peer2 # [355234.037765] peer2 data-mesher[217]: time=2026-09-08T10:07:34.023Z level=INFO msg="file integrity check complete"448peer2 # [355234.042765] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="libp2p host created" peer_id=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br 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::2538:a0ca:3a29:2510/tcp/7946]"449peer2 # [355234.042836] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name450peer2 # [355234.042836] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="registered HTTP route" method=GET path=/files451peer2 # [355234.042884] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name452peer2 # [355234.042884] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="starting server"453peer2 # [355234.043022] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="waiting for DHT to populate" delay=10s454peer2 # [355234.043076] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="HTTP server listening" address=[::1]:7331455peer2 # [355234.043102] peer2 data-mesher[217]: time=2026-09-08T10:07:34.028Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331456peer2 # [355234.050959] peer2 data-mesher[217]: time=2026-09-08T10:07:34.036Z level=INFO msg="peer connected" peer_id=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 remote_addr=/ip4/192.168.1.2/tcp/7946457peer2 # [355234.059401] peer2 data-mesher[217]: time=2026-09-08T10:07:34.045Z level=INFO msg="peer connected" peer_id=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV remote_addr=/ip4/192.168.1.1/tcp/7946458peer2 # [355234.084744] peer2 systemd-logind[237]: New seat seat0.459peer2 # [355234.084933] peer2 systemd[1]: Started User Login Management.460peer2 # [355234.086462] peer2 systemd[1]: Starting linger-users.service...461peer2 # [355234.133681] peer2 systemd[1]: linger-users.service: Deactivated successfully.462peer2 # [355234.134042] peer2 systemd[1]: Finished linger-users.service.463peer1 # [355234.052732] peer1 data-mesher[219]: time=2026-09-08T10:07:34.038Z level=INFO msg="peer connected" peer_id=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br remote_addr=/ip4/192.168.1.3/tcp/7946464controller # [355234.060651] controller data-mesher[230]: time=2026-09-08T10:07:34.046Z level=INFO msg="peer connected" peer_id=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br remote_addr=/ip4/192.168.1.3/tcp/7946465peer2 # [355234.848163] peer2 systemd-networkd[208]: eth1: Gained IPv6LL466peer1 # [355236.195685] peer1 data-mesher[219]: time=2026-09-08T10:07:36.181Z level=DEBUG msg="attempting push/pull" peer_count=1467peer1 # [355236.195685] peer1 data-mesher[219]: time=2026-09-08T10:07:36.181Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s468peer1 # [355236.196358] peer1 data-mesher[219]: time=2026-09-08T10:07:36.182Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV469peer1 # [355236.196407] peer1 data-mesher[219]: time=2026-09-08T10:07:36.182Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV470peer1 # [355236.196717] peer1 data-mesher[219]: time=2026-09-08T10:07:36.182Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV471peer1 # [355236.197199] peer1 data-mesher[219]: time=2026-09-08T10:07:36.183Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s472peer1 # [355236.197249] peer1 data-mesher[219]: time=2026-09-08T10:07:36.183Z level=DEBUG msg="push/pull successful" interval=5s473controller # [355236.195735] controller data-mesher[230]: time=2026-09-08T10:07:36.181Z level=DEBUG msg="attempting push/pull" peer_count=1474controller # [355236.196152] controller data-mesher[230]: time=2026-09-08T10:07:36.181Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s475controller # [355236.196204] controller data-mesher[230]: time=2026-09-08T10:07:36.182Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3476controller # [355236.196204] controller data-mesher[230]: time=2026-09-08T10:07:36.182Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3477controller # [355236.197412] controller data-mesher[230]: time=2026-09-08T10:07:36.183Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3478controller # [355236.198015] controller data-mesher[230]: time=2026-09-08T10:07:36.183Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s479controller # [355236.198071] controller data-mesher[230]: time=2026-09-08T10:07:36.183Z level=DEBUG msg="push/pull successful" interval=5s480peer2 # [355238.166703] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.481peer2 # [355238.167892] peer2 systemd[1]: Finished Save Transient machine-id to Disk.482peer1 # [355241.197528] peer1 data-mesher[219]: time=2026-09-08T10:07:41.183Z level=DEBUG msg="attempting push/pull" peer_count=1483peer1 # [355241.197958] peer1 data-mesher[219]: time=2026-09-08T10:07:41.183Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s484peer1 # [355241.199023] peer1 data-mesher[219]: time=2026-09-08T10:07:41.184Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV485peer1 # [355241.199237] peer1 data-mesher[219]: time=2026-09-08T10:07:41.185Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s486peer1 # [355241.199267] peer1 data-mesher[219]: time=2026-09-08T10:07:41.185Z level=DEBUG msg="push/pull successful" interval=5s487peer1 # [355241.199502] peer1 data-mesher[219]: time=2026-09-08T10:07:41.185Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV488peer1 # [355241.199502] peer1 data-mesher[219]: time=2026-09-08T10:07:41.185Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV489controller # [355241.198115] controller data-mesher[230]: time=2026-09-08T10:07:41.183Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3490controller # [355241.198115] controller data-mesher[230]: time=2026-09-08T10:07:41.183Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3491controller # [355241.198918] controller data-mesher[230]: time=2026-09-08T10:07:41.184Z level=DEBUG msg="attempting push/pull" peer_count=1492controller # [355241.199037] controller data-mesher[230]: time=2026-09-08T10:07:41.184Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s493controller # [355241.199998] controller data-mesher[230]: time=2026-09-08T10:07:41.185Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3494controller # [355241.200234] controller data-mesher[230]: time=2026-09-08T10:07:41.186Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s495controller # [355241.200330] controller data-mesher[230]: time=2026-09-08T10:07:41.186Z level=DEBUG msg="push/pull successful" interval=5s496peer2: still waiting for container 'peer2' to reach ready state...497peer2 # [355244.043279] peer2 data-mesher[217]: time=2026-09-08T10:07:44.029Z level=INFO msg="performing state exchange with peers on join" count=1498peer2 # [355244.043659] peer2 data-mesher[217]: time=2026-09-08T10:07:44.029Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s499peer2 # [355244.044065] peer2 data-mesher[217]: time=2026-09-08T10:07:44.029Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV500peer2 # [355244.044373] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=DEBUG msg="new file detected" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww501peer2 # [355244.044412] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=DEBUG msg="new file detected" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller502peer2 # [355244.044412] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s503peer2 # [355244.044462] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="server started"504peer2 # [355244.044532] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww505peer2 # [355244.044532] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller506peer2 # [355244.044591] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 10:07:26.253 +0000 UTC" signed_by="P0MqPDt/zOfflF4XmdXb9dZ3SJiWaZVHcTYfCo+uZ2I=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV507peer2 # [355244.044620] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="starting expired-file sweeper" interval=1m0s508peer2 # [355244.044673] peer2 data-mesher[217]: time=2026-09-08T10:07:44.030Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww signed_at="2026-09-08 10:07:26.337 +0000 UTC" signed_by="AIWMxTKKxcqAfnwpDD+kBhhbX+zWXgN3dGMVzsmy1Ww=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV509peer2 # [355244.044778] peer2 systemd[1]: Started data mesher daemon.510peer2 # [355244.046258] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...511peer2 # [355244.050533] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...512peer2 # [355244.143580] peer2 dm-wg-star-reconfig[282]: No controller data available yet, skipping513peer2 # [355244.145339] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.514peer2 # [355244.145671] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.515peer2 # [355244.310484] peer2 data-mesher[217]: time=2026-09-08T10:07:44.296Z level=INFO msg="download complete" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww signed_at="2026-09-08 10:07:26.337 +0000 UTC" signed_by="AIWMxTKKxcqAfnwpDD+kBhhbX+zWXgN3dGMVzsmy1Ww=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV written=true elapsed=265.717765ms516controller # [355244.043739] controller data-mesher[230]: time=2026-09-08T10:07:44.029Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br517controller # [355244.043739] controller data-mesher[230]: time=2026-09-08T10:07:44.029Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br518controller # [355244.044958] controller data-mesher[230]: time=2026-09-08T10:07:44.030Z level=INFO msg="received file request" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/controller519controller # [355244.045085] controller data-mesher[230]: time=2026-09-08T10:07:44.030Z level=INFO msg="received file request" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww520controller # [355244.046798] controller data-mesher[230]: time=2026-09-08T10:07:44.032Z level=INFO msg="file transfer complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/controller521controller # [355244.046869] controller data-mesher[230]: time=2026-09-08T10:07:44.032Z level=INFO msg="file transfer complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww522peer2: (finished: waiting for unit data-mesher.service, in 12.66 seconds)523??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.524 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39525controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1526??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.527 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39528peer2 # [355244.313309] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...529peer2 # [355244.326257] peer2 data-mesher[217]: time=2026-09-08T10:07:44.312Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 10:07:26.253 +0000 UTC" signed_by="P0MqPDt/zOfflF4XmdXb9dZ3SJiWaZVHcTYfCo+uZ2I=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV written=true elapsed=281.662749ms530peer2 # [355244.327404] peer2 data-mesher[217]: time=2026-09-08T10:07:44.313Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E status=204531peer2 # [355244.327782] peer2 dm-wg-star-publish[286]: Status: 204 No Content532peer2 # [355244.332722] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.533peer2 # [355244.356228] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.534peer2 # [355244.356874] peer2 systemd[1]: Reached target Multi-User System.535peer2 # [355244.464226] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.536peer2 # [355244.464572] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.537peer2 # [355244.465103] peer2 systemd[1]: Startup finished in 12.150s.538peer1 # [355246.199960] peer1 data-mesher[219]: time=2026-09-08T10:07:46.185Z level=DEBUG msg="attempting push/pull" peer_count=1539peer1 # [355246.199960] peer1 data-mesher[219]: time=2026-09-08T10:07:46.185Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s540controller # [355246.200557] controller data-mesher[230]: time=2026-09-08T10:07:46.186Z level=DEBUG msg="attempting push/pull" peer_count=1541peer1 # [355246.201056] peer1 data-mesher[219]: time=2026-09-08T10:07:46.186Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV542controller # [355246.200557] controller data-mesher[230]: time=2026-09-08T10:07:46.186Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s543peer1 # [355246.201056] peer1 data-mesher[219]: time=2026-09-08T10:07:46.186Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV544controller # [355246.200975] controller data-mesher[230]: time=2026-09-08T10:07:46.186Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3545peer1 # [355246.201820] peer1 data-mesher[219]: time=2026-09-08T10:07:46.187Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV546controller # [355246.200975] controller data-mesher[230]: time=2026-09-08T10:07:46.186Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3547peer1 # [355246.202146] peer1 data-mesher[219]: time=2026-09-08T10:07:46.187Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s548controller # [355246.201562] controller data-mesher[230]: time=2026-09-08T10:07:46.187Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3549peer1 # [355246.202206] peer1 data-mesher[219]: time=2026-09-08T10:07:46.188Z level=DEBUG msg="push/pull successful" interval=5s550controller # [355246.202216] controller data-mesher[230]: time=2026-09-08T10:07:46.187Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s551controller # [355246.202216] controller data-mesher[230]: time=2026-09-08T10:07:46.187Z level=DEBUG msg="push/pull successful" interval=5s552controller # [355249.045919] controller data-mesher[230]: time=2026-09-08T10:07:49.031Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br553controller # [355249.045919] controller data-mesher[230]: time=2026-09-08T10:07:49.031Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br554controller # [355249.046659] controller data-mesher[230]: time=2026-09-08T10:07:49.032Z level=DEBUG msg="new file detected" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E555controller # [355249.046726] controller data-mesher[230]: time=2026-09-08T10:07:49.032Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E556controller # [355249.047115] controller data-mesher[230]: time=2026-09-08T10:07:49.032Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E signed_at="2026-09-08 10:07:44.148 +0000 UTC" signed_by="iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E=" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br557controller # [355249.054326] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...558controller # [355249.153133] controller data-mesher[230]: time=2026-09-08T10:07:49.138Z level=INFO msg="download complete" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E signed_at="2026-09-08 10:07:44.148 +0000 UTC" signed_by="iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E=" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br written=true elapsed=106.051047ms559controller # [355249.225720] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.560controller # [355249.226072] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.561peer2 # [355249.045275] peer2 data-mesher[217]: time=2026-09-08T10:07:49.031Z level=DEBUG msg="attempting push/pull" peer_count=2562peer2 # [355249.045275] peer2 data-mesher[217]: time=2026-09-08T10:07:49.031Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s563peer2 # [355249.046915] peer2 data-mesher[217]: time=2026-09-08T10:07:49.032Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV564peer2 # [355249.047275] peer2 data-mesher[217]: time=2026-09-08T10:07:49.033Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s565peer2 # [355249.047350] peer2 data-mesher[217]: time=2026-09-08T10:07:49.033Z level=DEBUG msg="push/pull successful" interval=5s566peer2 # [355249.047626] peer2 data-mesher[217]: time=2026-09-08T10:07:49.033Z level=INFO msg="received file request" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E567peer2 # [355249.048970] peer2 data-mesher[217]: time=2026-09-08T10:07:49.034Z level=INFO msg="file transfer complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E568controller: (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 5.08 seconds)569controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1570controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.02 seconds)571peer2: waiting for success: wg show wg-star peers | grep -q .572peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.02 seconds)573peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0270:b550:118d:54ad574peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0270:b550:118d:54ad, in 0.01 seconds)575controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::2538:a0ca:3a29:2510576controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::2538:a0ca:3a29:2510, in 0.01 seconds)577peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::2538:a0ca:3a29:2510578peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::2538:a0ca:3a29:2510, in 0.01 seconds)579peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bb7b:3d3d:a93a:a4e5580peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bb7b:3d3d:a93a:a4e5, in 0.01 seconds)581(finished: run the VM test script, in 40.11 seconds)582peer2 # [355251.203389] peer2 data-mesher[217]: time=2026-09-08T10:07:51.189Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV583peer2 # [355251.203389] peer2 data-mesher[217]: time=2026-09-08T10:07:51.189Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV584peer1 # [355251.202498] peer1 data-mesher[219]: time=2026-09-08T10:07:51.188Z level=DEBUG msg="attempting push/pull" peer_count=1585peer1 # [355251.202866] peer1 data-mesher[219]: time=2026-09-08T10:07:51.188Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s586peer1 # [355251.203438] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV587peer1 # [355251.203860] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=DEBUG msg="new file detected" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV name=dm_wg_star_wg_star/AIWMxTKKxcqAfnwpDD-kBhhbX-zWXgN3dGMVzsmy1Ww name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E588controller # [355251.202865] controller data-mesher[230]: time=2026-09-08T10:07:51.188Z level=DEBUG msg="attempting push/pull" peer_count=1589peer1 # [355251.203899] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s590controller # [355251.202865] controller data-mesher[230]: time=2026-09-08T10:07:51.188Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s591peer1 # [355251.203899] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=DEBUG msg="push/pull successful" interval=5s592controller # [355251.203236] controller data-mesher[230]: time=2026-09-08T10:07:51.188Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3593peer1 # [355251.203959] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E594controller # [355251.203236] controller data-mesher[230]: time=2026-09-08T10:07:51.188Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3595peer1 # [355251.204140] peer1 data-mesher[219]: time=2026-09-08T10:07:51.189Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E signed_at="2026-09-08 10:07:44.148 +0000 UTC" signed_by="iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV596peer1 # [355251.229366] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...597peer1 # [355251.329497] peer1 data-mesher[219]: time=2026-09-08T10:07:51.315Z level=INFO msg="download complete" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E signed_at="2026-09-08 10:07:44.148 +0000 UTC" signed_by="iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E=" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV written=true elapsed=125.48308ms598peer1 # [355251.349297] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.599peer1 # [355251.349511] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.600controller # [355251.204132] controller data-mesher[230]: time=2026-09-08T10:07:51.189Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br601controller # [355251.204506] controller data-mesher[230]: time=2026-09-08T10:07:51.190Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s602controller # [355251.204557] controller data-mesher[230]: time=2026-09-08T10:07:51.190Z level=INFO msg="received file request" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E603controller # [355251.204666] controller data-mesher[230]: time=2026-09-08T10:07:51.190Z level=DEBUG msg="push/pull successful" interval=5s604controller # [355251.205321] controller data-mesher[230]: time=2026-09-08T10:07:51.191Z level=INFO msg="file transfer complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 network="cSkyXZbuHK1aVuWZS92qC7MtRzdBd6c/sw0Zzn5HBrU=" name=dm_wg_star_wg_star/iOi04ay5QO0ePSxmHKIKLScUxAuZKoOWcZ5PuNECw2E605peer2 # [355254.048110] peer2 data-mesher[217]: time=2026-09-08T10:07:54.033Z level=DEBUG msg="attempting push/pull" peer_count=2606controller # [355254.049217] controller data-mesher[230]: time=2026-09-08T10:07:54.035Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br607peer2 # [355254.049136] peer2 data-mesher[217]: time=2026-09-08T10:07:54.033Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s608controller # [355254.049217] controller data-mesher[230]: time=2026-09-08T10:07:54.035Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br609peer2 # [355254.050795] peer2 data-mesher[217]: time=2026-09-08T10:07:54.036Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV610peer2 # [355254.051911] peer2 data-mesher[217]: time=2026-09-08T10:07:54.037Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s611peer2 # [355254.051986] peer2 data-mesher[217]: time=2026-09-08T10:07:54.037Z level=DEBUG msg="push/pull successful" interval=5s612peer2 # [355256.207136] peer2 data-mesher[217]: time=2026-09-08T10:07:56.192Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV613peer2 # [355256.207136] peer2 data-mesher[217]: time=2026-09-08T10:07:56.192Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV614peer1 # [355256.203986] peer1 data-mesher[219]: time=2026-09-08T10:07:56.189Z level=DEBUG msg="attempting push/pull" peer_count=1615peer1 # [355256.204789] peer1 data-mesher[219]: time=2026-09-08T10:07:56.189Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s616peer1 # [355256.206743] peer1 data-mesher[219]: time=2026-09-08T10:07:56.192Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV617peer1 # [355256.207331] peer1 data-mesher[219]: time=2026-09-08T10:07:56.193Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s618peer1 # [355256.207415] peer1 data-mesher[219]: time=2026-09-08T10:07:56.193Z level=DEBUG msg="push/pull successful" interval=5s619controller # [355256.204748] controller data-mesher[230]: time=2026-09-08T10:07:56.190Z level=DEBUG msg="attempting push/pull" peer_count=1620controller # [355256.204748] controller data-mesher[230]: time=2026-09-08T10:07:56.190Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s621controller # [355256.205807] controller data-mesher[230]: time=2026-09-08T10:07:56.191Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3622controller # [355256.205807] controller data-mesher[230]: time=2026-09-08T10:07:56.191Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3623controller # [355256.207225] controller data-mesher[230]: time=2026-09-08T10:07:56.193Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br624controller # [355256.207690] controller data-mesher[230]: time=2026-09-08T10:07:56.193Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s625controller # [355256.207764] controller data-mesher[230]: time=2026-09-08T10:07:56.193Z level=DEBUG msg="push/pull successful" interval=5s626peer1 # [355259.055097] peer1 data-mesher[219]: time=2026-09-08T10:07:59.040Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br627peer1 # [355259.055097] peer1 data-mesher[219]: time=2026-09-08T10:07:59.040Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br628peer2 # [355259.053265] peer2 data-mesher[217]: time=2026-09-08T10:07:59.038Z level=DEBUG msg="attempting push/pull" peer_count=2629peer2 # [355259.053265] peer2 data-mesher[217]: time=2026-09-08T10:07:59.038Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s630peer2 # [355259.056749] peer2 data-mesher[217]: time=2026-09-08T10:07:59.042Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3631peer2 # [355259.057856] peer2 data-mesher[217]: time=2026-09-08T10:07:59.043Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s632peer2 # [355259.057939] peer2 data-mesher[217]: time=2026-09-08T10:07:59.043Z level=DEBUG msg="push/pull successful" interval=5s633controller # [355261.208860] controller data-mesher[230]: time=2026-09-08T10:08:01.194Z level=DEBUG msg="attempting push/pull" peer_count=1634controller # [355261.208860] controller data-mesher[230]: time=2026-09-08T10:08:01.194Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s635controller # [355261.209825] controller data-mesher[230]: time=2026-09-08T10:08:01.195Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3636controller # [355261.209825] controller data-mesher[230]: time=2026-09-08T10:08:01.195Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3637controller # [355261.212105] controller data-mesher[230]: time=2026-09-08T10:08:01.196Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3638peer1 # [355261.208375] peer1 data-mesher[219]: time=2026-09-08T10:08:01.194Z level=DEBUG msg="attempting push/pull" peer_count=1639controller # [355261.212472] controller data-mesher[230]: time=2026-09-08T10:08:01.198Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s640peer1 # [355261.208875] peer1 data-mesher[219]: time=2026-09-08T10:08:01.194Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s641controller # [355261.212472] controller data-mesher[230]: time=2026-09-08T10:08:01.198Z level=DEBUG msg="push/pull successful" interval=5s642peer1 # [355261.209651] peer1 data-mesher[219]: time=2026-09-08T10:08:01.195Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV643peer1 # [355261.209701] peer1 data-mesher[219]: time=2026-09-08T10:08:01.195Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV644peer1 # [355261.211211] peer1 data-mesher[219]: time=2026-09-08T10:08:01.197Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV645peer1 # [355261.212474] peer1 data-mesher[219]: time=2026-09-08T10:08:01.198Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s646peer1 # [355261.212474] peer1 data-mesher[219]: time=2026-09-08T10:08:01.198Z level=DEBUG msg="push/pull successful" interval=5s647peer1 # [355264.059837] peer1 data-mesher[219]: time=2026-09-08T10:08:04.045Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br648peer1 # [355264.059837] peer1 data-mesher[219]: time=2026-09-08T10:08:04.045Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br649peer2 # [355264.058946] peer2 data-mesher[217]: time=2026-09-08T10:08:04.044Z level=DEBUG msg="attempting push/pull" peer_count=2650peer2 # [355264.060218] peer2 data-mesher[217]: time=2026-09-08T10:08:04.044Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s651peer2 # [355264.060827] peer2 data-mesher[217]: time=2026-09-08T10:08:04.046Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3652peer2 # [355264.061892] peer2 data-mesher[217]: time=2026-09-08T10:08:04.047Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s653peer2 # [355264.061985] peer2 data-mesher[217]: time=2026-09-08T10:08:04.047Z level=DEBUG msg="push/pull successful" interval=5s654peer2 # [355266.214552] peer2 data-mesher[217]: time=2026-09-08T10:08:06.200Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3655peer2 # [355266.214552] peer2 data-mesher[217]: time=2026-09-08T10:08:06.200Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3656peer2 # [355266.214959] peer2 data-mesher[217]: time=2026-09-08T10:08:06.200Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV657peer2 # [355266.214998] peer2 data-mesher[217]: time=2026-09-08T10:08:06.200Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV658peer1 # [355266.212832] peer1 data-mesher[219]: time=2026-09-08T10:08:06.198Z level=DEBUG msg="attempting push/pull" peer_count=1659peer1 # [355266.213741] peer1 data-mesher[219]: time=2026-09-08T10:08:06.198Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s660peer1 # [355266.215218] peer1 data-mesher[219]: time=2026-09-08T10:08:06.201Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br661peer1 # [355266.215690] peer1 data-mesher[219]: time=2026-09-08T10:08:06.201Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s662peer1 # [355266.215780] peer1 data-mesher[219]: time=2026-09-08T10:08:06.201Z level=DEBUG msg="push/pull successful" interval=5s663controller # [355266.212878] controller data-mesher[230]: time=2026-09-08T10:08:06.198Z level=DEBUG msg="attempting push/pull" peer_count=1664controller # [355266.212878] controller data-mesher[230]: time=2026-09-08T10:08:06.198Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s665controller # [355266.216851] controller data-mesher[230]: time=2026-09-08T10:08:06.202Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br666controller # [355266.217845] controller data-mesher[230]: time=2026-09-08T10:08:06.203Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s667controller # [355266.217845] controller data-mesher[230]: time=2026-09-08T10:08:06.203Z level=DEBUG msg="push/pull successful" interval=5s668peer1 # [355269.063410] peer1 data-mesher[219]: time=2026-09-08T10:08:09.049Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br669peer1 # [355269.063410] peer1 data-mesher[219]: time=2026-09-08T10:08:09.049Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br670peer2 # [355269.062503] peer2 data-mesher[217]: time=2026-09-08T10:08:09.048Z level=DEBUG msg="attempting push/pull" peer_count=2671peer2 # [355269.063243] peer2 data-mesher[217]: time=2026-09-08T10:08:09.048Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s672peer2 # [355269.064964] peer2 data-mesher[217]: time=2026-09-08T10:08:09.050Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3673peer2 # [355269.065621] peer2 data-mesher[217]: time=2026-09-08T10:08:09.051Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s674peer2 # [355269.065724] peer2 data-mesher[217]: time=2026-09-08T10:08:09.051Z level=DEBUG msg="push/pull successful" interval=5s675peer1 # [355271.216733] peer1 data-mesher[219]: time=2026-09-08T10:08:11.202Z level=DEBUG msg="attempting push/pull" peer_count=1676peer1 # [355271.217241] peer1 data-mesher[219]: time=2026-09-08T10:08:11.202Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s677peer1 # [355271.218332] peer1 data-mesher[219]: time=2026-09-08T10:08:11.204Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV678peer1 # [355271.218616] peer1 data-mesher[219]: time=2026-09-08T10:08:11.204Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV679peer1 # [355271.218616] peer1 data-mesher[219]: time=2026-09-08T10:08:11.204Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV680peer1 # [355271.218965] peer1 data-mesher[219]: time=2026-09-08T10:08:11.204Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s681peer1 # [355271.219026] peer1 data-mesher[219]: time=2026-09-08T10:08:11.204Z level=DEBUG msg="push/pull successful" interval=5s682controller # [355271.217353] controller data-mesher[230]: time=2026-09-08T10:08:11.203Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3683controller # [355271.217353] controller data-mesher[230]: time=2026-09-08T10:08:11.203Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3684controller # [355271.218483] controller data-mesher[230]: time=2026-09-08T10:08:11.203Z level=DEBUG msg="attempting push/pull" peer_count=1685controller # [355271.218483] controller data-mesher[230]: time=2026-09-08T10:08:11.204Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s686controller # [355271.219599] controller data-mesher[230]: time=2026-09-08T10:08:11.205Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3687controller # [355271.220205] controller data-mesher[230]: time=2026-09-08T10:08:11.205Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s688controller # [355271.220205] controller data-mesher[230]: time=2026-09-08T10:08:11.206Z level=DEBUG msg="push/pull successful" interval=5s689peer1 # [355274.068147] peer1 data-mesher[219]: time=2026-09-08T10:08:14.053Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br690peer2 # [355274.066528] peer2 data-mesher[217]: time=2026-09-08T10:08:14.052Z level=DEBUG msg="attempting push/pull" peer_count=2691peer1 # [355274.068147] peer1 data-mesher[219]: time=2026-09-08T10:08:14.053Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br692peer2 # [355274.066528] peer2 data-mesher[217]: time=2026-09-08T10:08:14.052Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s693peer2 # [355274.069004] peer2 data-mesher[217]: time=2026-09-08T10:08:14.054Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3694peer2 # [355274.069435] peer2 data-mesher[217]: time=2026-09-08T10:08:14.055Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s695peer2 # [355274.069520] peer2 data-mesher[217]: time=2026-09-08T10:08:14.055Z level=DEBUG msg="push/pull successful" interval=5s696peer2 # [355276.220805] peer2 data-mesher[217]: time=2026-09-08T10:08:16.206Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3697peer2 # [355276.220805] peer2 data-mesher[217]: time=2026-09-08T10:08:16.206Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3698controller # [355276.220959] controller data-mesher[230]: time=2026-09-08T10:08:16.206Z level=DEBUG msg="attempting push/pull" peer_count=1699peer1 # [355276.220150] peer1 data-mesher[219]: time=2026-09-08T10:08:16.205Z level=DEBUG msg="attempting push/pull" peer_count=1700peer2 # [355276.221669] peer2 data-mesher[217]: time=2026-09-08T10:08:16.207Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV701controller # [355276.220959] controller data-mesher[230]: time=2026-09-08T10:08:16.206Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s702peer2 # [355276.221669] peer2 data-mesher[217]: time=2026-09-08T10:08:16.207Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV703controller # [355276.223122] controller data-mesher[230]: time=2026-09-08T10:08:16.208Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br704peer1 # [355276.220150] peer1 data-mesher[219]: time=2026-09-08T10:08:16.205Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s705controller # [355276.223535] controller data-mesher[230]: time=2026-09-08T10:08:16.209Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s706peer1 # [355276.222410] peer1 data-mesher[219]: time=2026-09-08T10:08:16.208Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br707controller # [355276.223610] controller data-mesher[230]: time=2026-09-08T10:08:16.209Z level=DEBUG msg="push/pull successful" interval=5s708peer1 # [355276.223567] peer1 data-mesher[219]: time=2026-09-08T10:08:16.209Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s709peer1 # [355276.223648] peer1 data-mesher[219]: time=2026-09-08T10:08:16.209Z level=DEBUG msg="push/pull successful" interval=5s710controller # [355279.071418] controller data-mesher[230]: time=2026-09-08T10:08:19.057Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br711peer2 # [355279.070532] peer2 data-mesher[217]: time=2026-09-08T10:08:19.056Z level=DEBUG msg="attempting push/pull" peer_count=2712controller # [355279.071418] controller data-mesher[230]: time=2026-09-08T10:08:19.057Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br713peer2 # [355279.070532] peer2 data-mesher[217]: time=2026-09-08T10:08:19.056Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s714peer2 # [355279.073067] peer2 data-mesher[217]: time=2026-09-08T10:08:19.058Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV715peer2 # [355279.074220] peer2 data-mesher[217]: time=2026-09-08T10:08:19.060Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s716peer2 # [355279.074313] peer2 data-mesher[217]: time=2026-09-08T10:08:19.060Z level=DEBUG msg="push/pull successful" interval=5s717peer1 # [355281.223809] peer1 data-mesher[219]: time=2026-09-08T10:08:21.209Z level=DEBUG msg="attempting push/pull" peer_count=1718peer1 # [355281.224229] peer1 data-mesher[219]: time=2026-09-08T10:08:21.209Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s719peer1 # [355281.225080] peer1 data-mesher[219]: time=2026-09-08T10:08:21.210Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV720peer1 # [355281.225118] peer1 data-mesher[219]: time=2026-09-08T10:08:21.210Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV721peer1 # [355281.226229] peer1 data-mesher[219]: time=2026-09-08T10:08:21.212Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV722peer1 # [355281.227355] peer1 data-mesher[219]: time=2026-09-08T10:08:21.213Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s723peer1 # [355281.227415] peer1 data-mesher[219]: time=2026-09-08T10:08:21.213Z level=DEBUG msg="push/pull successful" interval=5s724controller # [355281.224723] controller data-mesher[230]: time=2026-09-08T10:08:21.210Z level=DEBUG msg="attempting push/pull" peer_count=1725controller # [355281.224723] controller data-mesher[230]: time=2026-09-08T10:08:21.210Z level=DEBUG msg="initiating state exchange" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s726controller # [355281.224723] controller data-mesher[230]: time=2026-09-08T10:08:21.210Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3727controller # [355281.224723] controller data-mesher[230]: time=2026-09-08T10:08:21.210Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3728controller # [355281.226662] controller data-mesher[230]: time=2026-09-08T10:08:21.212Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3729controller # [355281.227772] controller data-mesher[230]: time=2026-09-08T10:08:21.213Z level=INFO msg="state exchange complete" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3 timeout=5s730controller # [355281.227842] controller data-mesher[230]: time=2026-09-08T10:08:21.213Z level=DEBUG msg="push/pull successful" interval=5s731controller # [355284.075387] controller data-mesher[230]: time=2026-09-08T10:08:24.061Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br732controller # [355284.075387] controller data-mesher[230]: time=2026-09-08T10:08:24.061Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br733peer2 # [355284.074954] peer2 data-mesher[217]: time=2026-09-08T10:08:24.060Z level=DEBUG msg="attempting push/pull" peer_count=2734peer2 # [355284.074954] peer2 data-mesher[217]: time=2026-09-08T10:08:24.060Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s735peer2 # [355284.076349] peer2 data-mesher[217]: time=2026-09-08T10:08:24.062Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV736peer2 # [355284.076948] peer2 data-mesher[217]: time=2026-09-08T10:08:24.062Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s737peer2 # [355284.077021] peer2 data-mesher[217]: time=2026-09-08T10:08:24.062Z level=DEBUG msg="push/pull successful" interval=5s738peer1 # [355286.227722] peer1 data-mesher[219]: time=2026-09-08T10:08:26.213Z level=DEBUG msg="attempting push/pull" peer_count=1739peer2 # [355286.229122] peer2 data-mesher[217]: time=2026-09-08T10:08:26.214Z level=INFO msg="received state sync from peer" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV740controller # [355286.228258] controller data-mesher[230]: time=2026-09-08T10:08:26.214Z level=DEBUG msg="attempting push/pull" peer_count=1741peer1 # [355286.228272] peer1 data-mesher[219]: time=2026-09-08T10:08:26.213Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s742peer2 # [355286.229122] peer2 data-mesher[217]: time=2026-09-08T10:08:26.214Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV743peer1 # [355286.230176] peer1 data-mesher[219]: time=2026-09-08T10:08:26.215Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV744controller # [355286.229045] controller data-mesher[230]: time=2026-09-08T10:08:26.214Z level=DEBUG msg="initiating state exchange" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s745peer1 # [355286.231341] peer1 data-mesher[219]: time=2026-09-08T10:08:26.217Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s746controller # [355286.229045] controller data-mesher[230]: time=2026-09-08T10:08:26.214Z level=INFO msg="received state sync from peer" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3747peer1 # [355286.231393] peer1 data-mesher[219]: time=2026-09-08T10:08:26.217Z level=DEBUG msg="push/pull successful" interval=5s748controller # [355286.229045] controller data-mesher[230]: time=2026-09-08T10:08:26.214Z level=INFO msg="merging remote state" peer=12D3KooW9rQHFZ4QgLFenSTop6W3ZXezigv1JyzaxV63hGQjBCt3749controller # [355286.230620] controller data-mesher[230]: time=2026-09-08T10:08:26.216Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br750controller # [355286.231779] controller data-mesher[230]: time=2026-09-08T10:08:26.217Z level=INFO msg="state exchange complete" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br timeout=5s751controller # [355286.231861] controller data-mesher[230]: time=2026-09-08T10:08:26.217Z level=DEBUG msg="push/pull successful" interval=5s752controller # [355289.078378] controller data-mesher[230]: time=2026-09-08T10:08:29.064Z level=INFO msg="received state sync from peer" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br753controller # [355289.078378] controller data-mesher[230]: time=2026-09-08T10:08:29.064Z level=INFO msg="merging remote state" peer=12D3KooWK2oRTo4deYVaXQfjJrVQP6tGu9kdNnMYVLkqsmjQ86br754peer2 # [355289.077366] peer2 data-mesher[217]: time=2026-09-08T10:08:29.063Z level=DEBUG msg="attempting push/pull" peer_count=2755peer2 # [355289.077944] peer2 data-mesher[217]: time=2026-09-08T10:08:29.063Z level=DEBUG msg="initiating state exchange" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s756peer2 # [355289.080153] peer2 data-mesher[217]: time=2026-09-08T10:08:29.065Z level=INFO msg="merging remote state" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV757peer2 # [355289.081262] peer2 data-mesher[217]: time=2026-09-08T10:08:29.067Z level=INFO msg="state exchange complete" peer=12D3KooWAx4in8wVGAb9KD3rWPsZjfgPd4SM4J8DnnhDBN5NWsrV timeout=5s758peer2 # [355289.081343] peer2 data-mesher[217]: time=2026-09-08T10:08:29.067Z level=DEBUG msg="push/pull successful" interval=5s759test script finished in 80.42s760cleanup761kill NspawnMachine (pid 50)762kill NspawnMachine (pid 53)763Container controller terminated by signal KILL.764kill NspawnMachine (pid 781)765Container peer1 terminated by signal KILL.766Container peer2 terminated by signal KILL.767(finished: cleanup, in 0.69 seconds)