container-test-run-dm-wireguard-star
checks.aarch64-linux.dm-wireguard-star
· build #117
· 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.21Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.22░ Spawning container peer1 on /build/vm-state-peer1.23░ Spawning container controller on /build/vm-state-controller.24peer1 # No journal files were found.25peer1 # No journal boot entry found for the specified boot (+0).26controller # No journal files were found.27controller # No journal boot entry found for the specified boot (+0).28peer1 # [164832.361683] peer1 systemd-journald[96]: Journal started29peer1 # [164832.361740] peer1 systemd-journald[96]: Runtime Journal (/run/log/journal/932e1ba26de34c149f4917ae61791cc9) is 8M, max 2.5G, 2.4G free.30peer1 # [164832.364771] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.31peer1 # [164832.374909] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...32peer1 # [164832.375837] peer1 systemd[1]: Starting Network Name Resolution...33peer1 # [164832.376508] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...34peer1 # [164832.386432] peer1 systemd-journald[96]: Time spent on flushing to /var/log/journal/932e1ba26de34c149f4917ae61791cc9 is 2.360ms for 6 entries.35peer1 # [164832.386432] peer1 systemd-journald[96]: System Journal (/var/log/journal/932e1ba26de34c149f4917ae61791cc9) is 8M, max 4G, 3.9G free.36peer1 # [164832.392511] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.37peer1 # [164832.392757] peer1 systemd[1]: Reached target Preparation for Local File Systems.38peer1 # [164832.392839] peer1 systemd[1]: Reached target Local File Systems.39peer1 # [164832.393585] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.40controller # [164832.375587] controller systemd-journald[105]: Journal started41peer1 # [164832.393634] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container42peer1 # [164832.394469] peer1 systemd[1]: Starting Save Transient machine-id to Disk...43peer1 # [164832.394502] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys44peer1 # [164832.401406] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.45peer1 # [164832.402944] peer1 systemd[1]: Starting Create System Files and Directories...46peer1 # [164832.422413] peer1 systemd-tmpfiles[139]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted47peer1 # [164832.422646] peer1 systemd-tmpfiles[139]: fchmod() of /var/log/journal failed: Operation not permitted48peer1 # [164832.422810] peer1 systemd-tmpfiles[139]: fchmod() of /var/log/journal/932e1ba26de34c149f4917ae61791cc9 failed: Operation not permitted49peer1 # [164832.423067] peer1 systemd-tmpfiles[139]: fchmod() of /run/log/journal failed: Operation not permitted50controller # [164832.375646] controller systemd-journald[105]: Runtime Journal (/run/log/journal/3a69f6e857264641a1b164cceb0cc157) is 8M, max 2.5G, 2.4G free.51controller # [164832.386748] controller systemd[1]: Starting Flush Journal to Persistent Storage...52peer1 # [164832.425242] peer1 systemd[1]: Finished Create System Files and Directories.53peer1 # [164832.426349] peer1 systemd[1]: Starting Rebuild Journal Catalog...54peer1 # [164832.427292] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...55peer1 # [164832.440661] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.56peer1 # [164832.446240] peer1 systemd[1]: Finished Rebuild Journal Catalog.57peer1 # [164832.447513] peer1 systemd[1]: Starting Update is Completed...58controller # [164832.387608] controller systemd[1]: Starting Network Name Resolution...59peer1 # [164832.458492] peer1 systemd[1]: Finished Update is Completed.60controller # [164832.388268] controller systemd[1]: Starting Create Static Device Nodes in /dev...61peer1 # [164832.531409] peer1 systemd[1]: Finished Firewall.62controller # [164832.398780] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/3a69f6e857264641a1b164cceb0cc157 is 1.290ms for 5 entries.63peer1 # [164832.531572] peer1 systemd[1]: Reached target Preparation for Network.64controller # [164832.398780] controller systemd-journald[105]: System Journal (/var/log/journal/3a69f6e857264641a1b164cceb0cc157) is 8M, max 4G, 3.9G free.65peer1 # [164832.531811] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.66controller # [164832.407247] controller systemd[1]: Finished Create Static Device Nodes in /dev.67peer1 # [164832.532939] peer1 systemd[1]: Starting Network Management...68controller # [164832.407495] controller systemd[1]: Finished Flush Journal to Persistent Storage.69peer1 # [164832.537808] peer1 systemd[1]: Finished Save Transient machine-id to Disk.70controller # [164832.408201] controller systemd[1]: Reached target Preparation for Local File Systems.71peer1 # [164833.030409] peer1 systemd-networkd[213]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted72controller # [164832.408319] controller systemd[1]: Reached target Local File Systems.73peer1 # [164833.030503] peer1 systemd-networkd[213]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted74controller # [164832.409389] controller systemd[1]: Listening on Boot Loader Control Service Socket.75peer1 # [164833.038061] peer1 systemd-networkd[213]: /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.76controller # [164832.409444] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container77peer1 # [164833.038225] peer1 systemd-networkd[213]: /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.78controller # [164832.410346] controller systemd[1]: Starting Save Transient machine-id to Disk...79peer1 # [164833.038390] peer1 systemd-networkd[213]: lo: Link UP80controller # [164832.411016] controller systemd[1]: Starting Create System Files and Directories...81peer1 # [164833.038394] peer1 systemd-networkd[213]: lo: Gained carrier82controller # [164832.411050] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys83peer1 # [164833.038576] peer1 systemd-networkd[213]: eth1: Configuring with /etc/systemd/network/40-eth1.network.84controller # [164832.430282] controller systemd-tmpfiles[146]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85peer1 # [164833.038999] peer1 systemd[1]: Started Network Management.86controller # [164832.430501] controller systemd-tmpfiles[146]: fchmod() of /var/log/journal failed: Operation not permitted87peer1 # [164833.040225] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...88controller # [164832.430650] controller systemd-tmpfiles[146]: fchmod() of /var/log/journal/3a69f6e857264641a1b164cceb0cc157 failed: Operation not permitted89peer1 # [164833.040824] peer1 systemd-networkd[213]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.90controller # [164832.430876] controller systemd-tmpfiles[146]: fchmod() of /run/log/journal failed: Operation not permitted91peer1 # [164833.041162] peer1 systemd-networkd[213]: wg-star: netdev ready92controller # [164832.435069] controller systemd[1]: Finished Create System Files and Directories.93peer1 # [164833.041530] peer1 systemd-networkd[213]: eth1: Link UP94controller # [164832.436480] controller systemd[1]: Starting Rebuild Journal Catalog...95peer1 # [164833.041736] peer1 systemd-networkd[213]: eth1: Gained carrier96controller # [164832.437359] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...97peer1 # [164833.076983] peer1 systemd-networkd[213]: wg-star: Link UP98controller # [164832.452641] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.99peer1 # [164833.076989] peer1 systemd-networkd[213]: wg-star: Gained carrier100controller # [164832.461478] controller systemd[1]: Finished Rebuild Journal Catalog.101peer1 # [164833.084080] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.102controller # [164832.462798] controller systemd[1]: Starting Update is Completed...103peer1 # [164833.201712] peer1 systemd-resolved[119]: Positive Trust Anchors:104controller # [164832.474414] controller systemd[1]: Finished Update is Completed.105peer1 # [164833.201725] peer1 systemd-resolved[119]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d106controller # [164832.537825] controller systemd[1]: Finished Save Transient machine-id to Disk.107peer1 # [164833.201728] peer1 systemd-resolved[119]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16108controller # [164832.551221] controller systemd[1]: Finished Firewall.109peer1 # [164833.201761] peer1 systemd-resolved[119]: 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 test110controller # [164832.551379] controller systemd[1]: Reached target Preparation for Network.111peer1 # [164833.223698] peer1 systemd-resolved[119]: Using system hostname 'peer1'.112controller # [164832.551598] controller systemd[1]: Listening on Network Management Resolve Hook Socket.113peer1 # [164833.225730] peer1 systemd[1]: Started Network Name Resolution.114peer1 # [164833.225841] peer1 systemd[1]: Reached target Network.115peer1 # [164833.225931] peer1 systemd[1]: Reached target System Initialization.116peer1 # [164833.226044] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.117peer1 # [164833.226084] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.118peer1 # [164833.226122] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container119peer1 # [164833.226157] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.120peer1 # [164833.226184] peer1 systemd[1]: Reached target Path Units.121controller # [164832.552639] controller systemd[1]: Starting Network Management...122peer1 # [164833.226226] peer1 systemd[1]: Reached target Timer Units.123controller # [164833.079135] controller systemd-networkd[225]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted124peer1 # [164833.226370] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.125controller # [164833.079228] controller systemd-networkd[225]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted126peer1 # [164833.226521] peer1 systemd[1]: Listening on Nix Daemon Socket.127controller # [164833.086605] controller systemd-networkd[225]: /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.128peer1 # [164833.226661] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.129controller # [164833.086771] controller systemd-networkd[225]: /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.130peer1 # [164833.226690] peer1 systemd[1]: Reached target Socket Units.131controller # [164833.086933] controller systemd-networkd[225]: lo: Link UP132peer1 # [164833.226734] peer1 systemd[1]: Reached target Basic System.133controller # [164833.086936] controller systemd-networkd[225]: lo: Gained carrier134peer1 # [164833.228338] peer1 systemd[1]: Starting data mesher daemon...135controller # [164833.087141] controller systemd-networkd[225]: eth1: Configuring with /etc/systemd/network/40-eth1.network.136peer1 # [164833.229391] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...137controller # [164833.087546] controller systemd[1]: Started Network Management.138peer1 # [164833.230349] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...139controller # [164833.088287] controller systemd-networkd[225]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.140peer1 # [164833.231861] peer1 systemd[1]: Starting D-Bus System Message Bus...141controller # [164833.088633] controller systemd-networkd[225]: wg-star: netdev ready142peer1 # [164833.250845] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.143controller # [164833.089016] controller systemd-networkd[225]: eth1: Link UP144peer1 # [164833.354111] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.145controller # [164833.089233] controller systemd-networkd[225]: eth1: Gained carrier146controller # [164833.089238] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...147controller # [164833.129062] controller systemd-networkd[225]: wg-star: Link UP148controller # [164833.129066] controller systemd-networkd[225]: wg-star: Gained carrier149controller # [164833.129631] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.150controller # [164833.212028] controller systemd-resolved[128]: Positive Trust Anchors:151controller # [164833.212041] controller systemd-resolved[128]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d152controller # [164833.212044] controller systemd-resolved[128]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16153controller # [164833.212078] controller systemd-resolved[128]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test154controller # [164833.235365] controller systemd-resolved[128]: Using system hostname 'controller'.155controller # [164833.277999] controller systemd[1]: Started Network Name Resolution.156controller # [164833.278125] controller systemd[1]: Reached target Network.157controller # [164833.278216] controller systemd[1]: Reached target System Initialization.158controller # [164833.278322] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.159controller # [164833.278365] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container160controller # [164833.278409] controller systemd[1]: Started Daily Cleanup of Temporary Directories.161controller # [164833.278450] controller systemd[1]: Reached target Path Units.162controller # [164833.278486] controller systemd[1]: Reached target Timer Units.163controller # [164833.278656] controller systemd[1]: Listening on D-Bus System Message Bus Socket.164controller # [164833.278794] controller systemd[1]: Listening on Nix Daemon Socket.165controller # [164833.278936] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.166controller # [164833.278958] controller systemd[1]: Reached target Socket Units.167controller # [164833.278997] controller systemd[1]: Reached target Basic System.168controller # [164833.280373] controller systemd[1]: Starting data mesher daemon...169controller # [164833.281234] controller systemd[1]: Starting Import lastlog data into lastlog2 database...170controller # [164833.282168] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...171controller # [164833.283621] controller systemd[1]: Starting D-Bus System Message Bus...172controller # [164833.303309] controller systemd[1]: Finished Import lastlog data into lastlog2 database.173peer1 # [164833.386540] peer1 nsncd[221]: Sep 06 05:14:13.372 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"174peer1 # [164833.386631] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).175peer1 # [164833.386689] peer1 systemd[1]: Reached target Host and Network Name Lookups.176peer1 # [164833.386744] peer1 systemd[1]: Reached target User and Group Name Lookups.177peer1 # [164833.388287] peer1 systemd[1]: Starting User Login Management...178peer1 # [164833.389325] peer1 systemd[1]: Starting Permit User Sessions...179peer1 # [164833.436165] peer1 systemd[1]: Finished Permit User Sessions.180peer1 # [164833.438336] peer1 systemd[1]: Started Console Getty.181peer1 # [164833.438390] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0182peer1 # [164833.438423] peer1 systemd[1]: Reached target Login Prompts.183peer1 # [164833.531165] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...184peer1 # [164833.532251] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'185peer1 # [164833.532251] 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"186peer1 # [164833.533022] peer1 systemd[1]: Started D-Bus System Message Bus.187peer1 # [164833.542466] peer1 dbus-broker-launch[222]: Ready188controller # [164833.370123] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.189controller # [164833.444666] controller nsncd[232]: Sep 06 05:14:13.430 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"190controller # [164833.444738] controller systemd[1]: Started Name Service Cache Daemon (nsncd).191controller # [164833.444805] controller systemd[1]: Reached target Host and Network Name Lookups.192controller # [164833.444873] controller systemd[1]: Reached target User and Group Name Lookups.193controller # [164833.446402] controller systemd[1]: Starting User Login Management...194controller # [164833.447258] controller systemd[1]: Starting Permit User Sessions...195controller # [164833.457444] controller systemd[1]: Finished Permit User Sessions.196controller # [164833.459067] controller systemd[1]: Started Console Getty.197controller # [164833.459139] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0198controller # [164833.459183] controller systemd[1]: Reached target Login Prompts.199controller # [164833.549256] controller dbus-broker-launch[233]: Looking up NSS user entry for 'systemd-timesync'...200controller # [164833.550672] controller dbus-broker-launch[233]: NSS returned no entry for 'systemd-timesync'201controller # [164833.550672] 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"202controller # [164833.551079] controller systemd[1]: Started D-Bus System Message Bus.203controller # [164833.558219] controller dbus-broker-launch[233]: Ready204peer1 # [164833.941264] peer1 data-mesher[219]: time=2026-09-06T05:14:13.926Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]205peer1 # [164833.947603] peer1 data-mesher[219]: time=2026-09-06T05:14:13.933Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj: [/dns/controller.clan/tcp/7946]} {12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s: [/dns/peer1.clan/tcp/7946]} {12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s206peer1 # [164833.947603] peer1 data-mesher[219]: time=2026-09-06T05:14:13.933Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml207peer1 # [164833.950278] peer1 data-mesher[219]: time=2026-09-06T05:14:13.936Z level=INFO msg="checking file integrity"208peer1 # [164833.950400] peer1 data-mesher[219]: time=2026-09-06T05:14:13.936Z level=INFO msg="file integrity check complete"209peer1 # [164833.959606] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="libp2p host created" peer_id=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s 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::e1e5:ecb7:222:3324/tcp/7946]"210peer1 # [164833.959716] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="registered HTTP route" method=GET path=/files211peer1 # [164833.959716] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name212peer1 # [164833.959716] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name213peer1 # [164833.959716] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="starting server"214peer1 # [164833.959937] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="waiting for DHT to populate" delay=10s215peer1 # [164833.960052] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="HTTP server listening" address=[::1]:7331216peer1 # [164833.960121] peer1 data-mesher[219]: time=2026-09-06T05:14:13.945Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331217peer1 # [164834.094027] peer1 data-mesher[219]: time=2026-09-06T05:14:14.079Z level=INFO msg="peer connected" peer_id=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj remote_addr=/ip4/192.168.1.1/tcp/7946218controller # [164834.063014] controller data-mesher[230]: time=2026-09-06T05:14:14.048Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]219controller # [164834.064214] controller data-mesher[230]: time=2026-09-06T05:14:14.049Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj: [/dns/controller.clan/tcp/7946]} {12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s: [/dns/peer1.clan/tcp/7946]} {12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj220controller # [164834.064263] controller data-mesher[230]: time=2026-09-06T05:14:14.050Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml221controller # [164834.082463] controller data-mesher[230]: time=2026-09-06T05:14:14.068Z level=INFO msg="checking file integrity"222controller # [164834.082580] controller data-mesher[230]: time=2026-09-06T05:14:14.068Z level=INFO msg="file integrity check complete"223controller # [164834.086596] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="libp2p host created" peer_id=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj 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::79c8:a0b:faba:7896/tcp/7946]"224controller # [164834.086660] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="registered HTTP route" method=GET path=/files225controller # [164834.086660] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name226controller # [164834.086660] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name227controller # [164834.086660] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="starting server"228controller # [164834.086773] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="waiting for DHT to populate" delay=10s229controller # [164834.086825] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="HTTP server listening" address=[::1]:7331230controller # [164834.086857] controller data-mesher[230]: time=2026-09-06T05:14:14.072Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331231controller # [164834.093386] controller data-mesher[230]: time=2026-09-06T05:14:14.079Z level=INFO msg="peer connected" peer_id=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s remote_addr=/ip4/192.168.1.2/tcp/7946232peer1 # [164834.212175] peer1 systemd-networkd[213]: eth1: Gained IPv6LL233controller # [164834.687873] controller systemd-logind[250]: New seat seat0.234controller # [164834.688360] controller systemd[1]: Started User Login Management.235controller # [164834.690833] controller systemd[1]: Starting linger-users.service...236controller # [164834.738433] controller systemd[1]: linger-users.service: Deactivated successfully.237controller # [164834.738786] controller systemd[1]: Finished linger-users.service.238controller # [164834.944273] controller systemd-networkd[225]: eth1: Gained IPv6LL239peer1 # [164834.925656] peer1 systemd-logind[239]: New seat seat0.240peer1 # [164834.925938] peer1 systemd[1]: Started User Login Management.241peer1 # [164834.928210] peer1 systemd[1]: Starting linger-users.service...242peer1 # [164834.989724] peer1 systemd[1]: linger-users.service: Deactivated successfully.243peer1 # [164834.989952] peer1 systemd[1]: Finished linger-users.service.244controller: still waiting for container 'controller' to reach ready state...245controller # [164843.961102] controller data-mesher[230]: time=2026-09-06T05:14:23.946Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s246controller # [164843.961102] controller data-mesher[230]: time=2026-09-06T05:14:23.946Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s247controller # [164844.087190] controller data-mesher[230]: time=2026-09-06T05:14:24.072Z level=INFO msg="performing state exchange with peers on join" count=1248controller # [164844.087190] controller data-mesher[230]: time=2026-09-06T05:14:24.073Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s249controller # [164844.088593] controller data-mesher[230]: time=2026-09-06T05:14:24.074Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s250controller # [164844.088593] controller data-mesher[230]: time=2026-09-06T05:14:24.074Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s251controller # [164844.088675] controller data-mesher[230]: time=2026-09-06T05:14:24.074Z level=INFO msg="server started"252controller # [164844.088957] controller data-mesher[230]: time=2026-09-06T05:14:24.074Z level=INFO msg="starting expired-file sweeper" interval=1m0s253controller # [164844.089026] controller systemd[1]: Started data mesher daemon.254controller # [164844.091405] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...255controller # [164844.168813] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...256controller # [164844.176983] controller data-mesher[230]: time=2026-09-06T05:14:24.162Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204257controller # [164844.177131] controller dm-wg-star-publish[295]: Status: 204 No Content258controller # [164844.180622] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.259controller # [164844.181013] controller systemd[1]: Reached target Multi-User System.260peer1 # [164843.960417] peer1 data-mesher[219]: time=2026-09-06T05:14:23.946Z level=INFO msg="performing state exchange with peers on join" count=1261peer1 # [164843.960417] peer1 data-mesher[219]: time=2026-09-06T05:14:23.946Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s262peer1 # [164843.961418] peer1 data-mesher[219]: time=2026-09-06T05:14:23.947Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj263peer1 # [164843.961497] peer1 data-mesher[219]: time=2026-09-06T05:14:23.947Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s264peer1 # [164843.961497] peer1 data-mesher[219]: time=2026-09-06T05:14:23.947Z level=INFO msg="server started"265peer1 # [164843.961604] peer1 data-mesher[219]: time=2026-09-06T05:14:23.947Z level=INFO msg="starting expired-file sweeper" interval=1m0s266peer1 # [164843.961816] peer1 systemd[1]: Started data mesher daemon.267peer1 # [164843.963831] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...268peer1 # [164844.089142] peer1 data-mesher[219]: time=2026-09-06T05:14:24.074Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj269peer1 # [164844.089142] peer1 data-mesher[219]: time=2026-09-06T05:14:24.074Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj270peer1 # [164844.152291] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...271peer1 # [164844.176829] peer1 data-mesher[219]: time=2026-09-06T05:14:24.162Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew status=204272peer1 # [164844.177012] peer1 dm-wg-star-publish[284]: Status: 204 No Content273peer1 # [164844.180703] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.274peer1 # [164844.180780] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.275peer1 # [164844.181312] peer1 systemd[1]: Reached target Multi-User System.276controller: (finished: waiting for unit data-mesher.service, in 13.16 seconds)277peer1: waiting for unit data-mesher.service278peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds)279??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.280 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39281controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller282??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.283 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39284controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds)285peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller286peer1 # [164844.249971] peer1 dm-wg-star-reconfig[311]: No controller data available yet, skipping287peer1 # [164844.251022] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.288peer1 # [164844.251206] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.289peer1 # [164844.251677] peer1 systemd[1]: Startup finished in 12.318s.290controller # [164844.259317] controller dm-wg-star-reconfig[321]: No peer data available yet, skipping291controller # [164844.260243] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.292controller # [164844.260342] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.293controller # [164844.260728] controller systemd[1]: Startup finished in 12.327s.294controller # [164848.963149] controller data-mesher[230]: time=2026-09-06T05:14:28.948Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s295controller # [164848.963149] controller data-mesher[230]: time=2026-09-06T05:14:28.948Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s296controller # [164848.963884] controller data-mesher[230]: time=2026-09-06T05:14:28.949Z level=DEBUG msg="new file detected" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew297controller # [164848.963884] controller data-mesher[230]: time=2026-09-06T05:14:28.949Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew298controller # [164848.963884] controller data-mesher[230]: time=2026-09-06T05:14:28.949Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew signed_at="2026-09-06 05:14:24.132 +0000 UTC" signed_by="hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s299controller # [164848.964650] controller data-mesher[230]: time=2026-09-06T05:14:28.950Z level=INFO msg="received file request" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/controller300controller # [164848.967683] controller data-mesher[230]: time=2026-09-06T05:14:28.953Z level=INFO msg="file transfer complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/controller301controller # [164848.972998] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...302controller # [164848.978377] controller data-mesher[230]: time=2026-09-06T05:14:28.964Z level=INFO msg="download complete" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew signed_at="2026-09-06 05:14:24.132 +0000 UTC" signed_by="hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s written=true elapsed=14.593598ms303controller # [164849.089512] controller data-mesher[230]: time=2026-09-06T05:14:29.075Z level=DEBUG msg="attempting push/pull" peer_count=1304controller # [164849.089691] controller data-mesher[230]: time=2026-09-06T05:14:29.075Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s305controller # [164849.090993] controller data-mesher[230]: time=2026-09-06T05:14:29.076Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s306controller # [164849.091299] controller data-mesher[230]: time=2026-09-06T05:14:29.077Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s307controller # [164849.091371] controller data-mesher[230]: time=2026-09-06T05:14:29.077Z level=DEBUG msg="push/pull successful" interval=5s308controller # [164849.130928] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.309controller # [164849.131252] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.310peer1 # [164848.962380] peer1 data-mesher[219]: time=2026-09-06T05:14:28.948Z level=DEBUG msg="attempting push/pull" peer_count=1311peer1 # [164848.962380] peer1 data-mesher[219]: time=2026-09-06T05:14:28.948Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s312peer1 # [164848.963856] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj313peer1 # [164848.963856] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=DEBUG msg="new file detected" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller314peer1 # [164848.964064] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s315peer1 # [164848.964064] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=DEBUG msg="push/pull successful" interval=5s316peer1 # [164848.964064] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller317peer1 # [164848.964258] peer1 data-mesher[219]: time=2026-09-06T05:14:28.949Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-06 05:14:24.147 +0000 UTC" signed_by="ejrrdMsEzmW4pUiQ41S5FZ+rZRpjbTSAm1Pb8x+L+Ts=" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj318peer1 # [164848.964521] peer1 data-mesher[219]: time=2026-09-06T05:14:28.950Z level=INFO msg="received file request" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew319peer1 # [164848.967461] peer1 data-mesher[219]: time=2026-09-06T05:14:28.953Z level=INFO msg="file transfer complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew320peer1 # [164848.972951] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...321peer1 # [164848.978371] peer1 data-mesher[219]: time=2026-09-06T05:14:28.964Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-06 05:14:24.147 +0000 UTC" signed_by="ejrrdMsEzmW4pUiQ41S5FZ+rZRpjbTSAm1Pb8x+L+Ts=" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj written=true elapsed=14.204192ms322peer1 # [164849.090408] peer1 data-mesher[219]: time=2026-09-06T05:14:29.076Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj323peer1 # [164849.090408] peer1 data-mesher[219]: time=2026-09-06T05:14:29.076Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj324peer1 # [164849.142276] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.325peer1 # [164849.142470] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.326peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.05 seconds)327controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .328controller: (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)329controller: waiting for success: wg show wg-star peers | grep -q .330controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)331peer1: waiting for success: wg show wg-star peers | grep -q .332peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)333peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::79c8:0a0b:faba:7896334peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::79c8:0a0b:faba:7896, in 0.01 seconds)335controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e1e5:ecb7:0222:3324336controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e1e5:ecb7:0222:3324, in 0.01 seconds)337controller: must succeed: wg show wg-star peers | wc -l338controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)339peer2: systemd-nspawn running (pid 779)340peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...341peer2: waiting for unit data-mesher.service342nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE343nixos-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.344Note: 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.345░ Spawning container peer2 on /build/vm-state-peer2.346peer2 # No journal boot entry found for the specified boot (+0).347peer2 # [164850.638035] peer2 systemd-journald[95]: Journal started348peer2 # [164850.638095] peer2 systemd-journald[95]: Runtime Journal (/run/log/journal/b0dfc8874a044b8baaef61bba47a65cb) is 8M, max 2.5G, 2.4G free.349peer2 # [164850.646191] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...350peer2 # [164850.647021] peer2 systemd[1]: Starting Network Name Resolution...351peer2 # [164850.647845] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...352peer2 # [164850.658342] peer2 systemd-journald[95]: Time spent on flushing to /var/log/journal/b0dfc8874a044b8baaef61bba47a65cb is 1.835ms for 5 entries.353peer2 # [164850.658342] peer2 systemd-journald[95]: System Journal (/var/log/journal/b0dfc8874a044b8baaef61bba47a65cb) is 8M, max 4G, 3.9G free.354peer2 # [164850.663466] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.355peer2 # [164850.663715] peer2 systemd[1]: Reached target Preparation for Local File Systems.356peer2 # [164850.663801] peer2 systemd[1]: Reached target Local File Systems.357peer2 # [164850.664610] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.358peer2 # [164850.664656] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container359peer2 # [164850.665534] peer2 systemd[1]: Starting Save Transient machine-id to Disk...360peer2 # [164850.665570] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys361peer2 # [164850.756065] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.362peer2 # [164850.757751] peer2 systemd[1]: Starting Create System Files and Directories...363peer2 # [164850.815174] peer2 systemd-tmpfiles[175]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted364peer2 # [164850.815453] peer2 systemd-tmpfiles[175]: fchmod() of /var/log/journal failed: Operation not permitted365peer2 # [164850.815504] peer2 systemd[1]: Finished Firewall.366peer2 # [164850.815637] peer2 systemd-tmpfiles[175]: fchmod() of /var/log/journal/b0dfc8874a044b8baaef61bba47a65cb failed: Operation not permitted367peer2 # [164850.815669] peer2 systemd[1]: Reached target Preparation for Network.368peer2 # [164850.815893] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.369peer2 # [164850.815917] peer2 systemd-tmpfiles[175]: fchmod() of /run/log/journal failed: Operation not permitted370peer2 # [164850.816979] peer2 systemd[1]: Starting Network Management...371peer2 # [164850.817344] peer2 systemd[1]: Finished Create System Files and Directories.372peer2 # [164850.818862] peer2 systemd[1]: Starting Rebuild Journal Catalog...373peer2 # [164850.819590] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...374peer2 # [164850.833157] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.375peer2 # [164850.842945] peer2 systemd[1]: Finished Rebuild Journal Catalog.376peer2 # [164850.844016] peer2 systemd[1]: Starting Update is Completed...377peer2 # [164850.856262] peer2 systemd[1]: Finished Update is Completed.378peer2 # [164851.178970] peer2 systemd-networkd[205]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted379peer2 # [164851.179063] peer2 systemd-networkd[205]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted380peer2 # [164851.186347] peer2 systemd-networkd[205]: /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.381peer2 # [164851.186512] peer2 systemd-networkd[205]: /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.382peer2 # [164851.186679] peer2 systemd-networkd[205]: lo: Link UP383peer2 # [164851.186683] peer2 systemd-networkd[205]: lo: Gained carrier384peer2 # [164851.186869] peer2 systemd-networkd[205]: eth1: Configuring with /etc/systemd/network/40-eth1.network.385peer2 # [164851.187321] peer2 systemd[1]: Started Network Management.386peer2 # [164851.187887] peer2 systemd-networkd[205]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.387peer2 # [164851.188474] peer2 systemd-networkd[205]: wg-star: netdev ready388peer2 # [164851.188888] peer2 systemd-networkd[205]: eth1: Link UP389peer2 # [164851.189104] peer2 systemd-networkd[205]: eth1: Gained carrier390peer2 # [164851.189717] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...391peer2 # [164851.220676] peer2 systemd-networkd[205]: wg-star: Link UP392peer2 # [164851.220683] peer2 systemd-networkd[205]: wg-star: Gained carrier393peer2 # [164851.233543] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.394peer2 # [164851.262799] peer2 systemd-resolved[117]: Positive Trust Anchors:395peer2 # [164851.262812] peer2 systemd-resolved[117]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d396peer2 # [164851.262815] peer2 systemd-resolved[117]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16397peer2 # [164851.262849] peer2 systemd-resolved[117]: 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 test398peer2 # [164851.284759] peer2 systemd-resolved[117]: Using system hostname 'peer2'.399peer2 # [164851.286373] peer2 systemd[1]: Started Network Name Resolution.400peer2 # [164851.286515] peer2 systemd[1]: Reached target Network.401peer2 # [164851.286640] peer2 systemd[1]: Reached target System Initialization.402peer2 # [164851.286829] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.403peer2 # [164851.286895] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.404peer2 # [164851.286951] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container405peer2 # [164851.287005] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.406peer2 # [164851.287048] peer2 systemd[1]: Reached target Path Units.407peer2 # [164851.287121] peer2 systemd[1]: Reached target Timer Units.408peer2 # [164851.287342] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.409peer2 # [164851.287559] peer2 systemd[1]: Listening on Nix Daemon Socket.410peer2 # [164851.287782] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.411peer2 # [164851.287833] peer2 systemd[1]: Reached target Socket Units.412peer2 # [164851.287912] peer2 systemd[1]: Reached target Basic System.413peer2 # [164851.290147] peer2 systemd[1]: Starting data mesher daemon...414peer2 # [164851.291419] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...415peer2 # [164851.292948] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...416peer2 # [164851.295149] peer2 systemd[1]: Starting D-Bus System Message Bus...417peer2 # [164851.354364] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.418peer2 # [164851.469044] peer2 nsncd[219]: Sep 06 05:14:31.454 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"419peer2 # [164851.468966] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).420peer2 # [164851.469072] peer2 systemd[1]: Reached target Host and Network Name Lookups.421peer2 # [164851.469170] peer2 systemd[1]: Reached target User and Group Name Lookups.422peer2 # [164851.471086] peer2 systemd[1]: Starting User Login Management...423peer2 # [164851.472480] peer2 systemd[1]: Starting Permit User Sessions...424peer2 # [164851.520795] peer2 systemd[1]: Finished Permit User Sessions.425peer2 # [164851.522451] peer2 systemd[1]: Started Console Getty.426peer2 # [164851.522538] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0427peer2 # [164851.522588] peer2 systemd[1]: Reached target Login Prompts.428peer2 # [164851.531265] peer2 dbus-broker-launch[220]: Looking up NSS user entry for 'systemd-timesync'...429peer2 # [164851.532715] peer2 dbus-broker-launch[220]: NSS returned no entry for 'systemd-timesync'430peer2 # [164851.532715] 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"431peer2 # [164851.533272] peer2 systemd[1]: Started D-Bus System Message Bus.432peer2 # [164851.541674] peer2 dbus-broker-launch[220]: Ready433peer1 # [164851.817815] peer1 data-mesher[219]: time=2026-09-06T05:14:31.803Z level=INFO msg="peer connected" peer_id=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp remote_addr=/ip4/192.168.1.3/tcp/7946434peer2 # [164851.776706] peer2 data-mesher[217]: time=2026-09-06T05:14:31.762Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]435peer2 # [164851.778331] peer2 data-mesher[217]: time=2026-09-06T05:14:31.764Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj: [/dns/controller.clan/tcp/7946]} {12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s: [/dns/peer1.clan/tcp/7946]} {12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp436peer2 # [164851.778331] peer2 data-mesher[217]: time=2026-09-06T05:14:31.764Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml437peer2 # [164851.802436] peer2 data-mesher[217]: time=2026-09-06T05:14:31.788Z level=INFO msg="checking file integrity"438peer2 # [164851.802779] peer2 data-mesher[217]: time=2026-09-06T05:14:31.788Z level=INFO msg="file integrity check complete"439peer2 # [164851.808624] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="libp2p host created" peer_id=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp 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::99be:f278:f8ac:825c/tcp/7946]"440peer2 # [164851.808745] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name441peer2 # [164851.808745] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="registered HTTP route" method=GET path=/files442peer2 # [164851.808745] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name443peer2 # [164851.808745] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="starting server"444peer2 # [164851.808942] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="waiting for DHT to populate" delay=10s445peer2 # [164851.808990] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="HTTP server listening" address=[::1]:7331446peer2 # [164851.809072] peer2 data-mesher[217]: time=2026-09-06T05:14:31.794Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331447peer2 # [164851.816521] peer2 data-mesher[217]: time=2026-09-06T05:14:31.802Z level=INFO msg="peer connected" peer_id=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s remote_addr=/ip4/192.168.1.2/tcp/7946448peer2 # [164851.826802] peer2 data-mesher[217]: time=2026-09-06T05:14:31.812Z level=INFO msg="peer connected" peer_id=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj remote_addr=/ip4/192.168.1.1/tcp/7946449peer2 # [164851.940906] peer2 systemd-logind[237]: New seat seat0.450peer2 # [164851.941164] peer2 systemd[1]: Started User Login Management.451peer2 # [164851.943488] peer2 systemd[1]: Starting linger-users.service...452peer2 # [164852.000768] peer2 systemd[1]: linger-users.service: Deactivated successfully.453peer2 # [164852.001101] peer2 systemd[1]: Finished linger-users.service.454controller # [164851.828813] controller data-mesher[230]: time=2026-09-06T05:14:31.814Z level=INFO msg="peer connected" peer_id=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp remote_addr=/ip4/192.168.1.3/tcp/7946455peer2 # [164852.228170] peer2 systemd-networkd[205]: eth1: Gained IPv6LL456peer2 # [164852.542319] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.457peer2 # [164852.544729] peer2 systemd[1]: Finished Save Transient machine-id to Disk.458peer2 # [164853.965882] peer2 data-mesher[217]: time=2026-09-06T05:14:33.951Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s459peer2 # [164853.965882] peer2 data-mesher[217]: time=2026-09-06T05:14:33.951Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s460peer2 # [164853.966627] peer2 data-mesher[217]: time=2026-09-06T05:14:33.951Z level=DEBUG msg="new file detected" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller461peer2 # [164853.966627] peer2 data-mesher[217]: time=2026-09-06T05:14:33.951Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller462peer2 # [164853.966627] peer2 data-mesher[217]: time=2026-09-06T05:14:33.952Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-06 05:14:24.147 +0000 UTC" signed_by="ejrrdMsEzmW4pUiQ41S5FZ+rZRpjbTSAm1Pb8x+L+Ts=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s463peer2 # [164853.966627] peer2 data-mesher[217]: time=2026-09-06T05:14:33.952Z level=DEBUG msg="new file detected" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew464peer2 # [164853.966845] peer2 data-mesher[217]: time=2026-09-06T05:14:33.952Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew465peer2 # [164853.966845] peer2 data-mesher[217]: time=2026-09-06T05:14:33.952Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew signed_at="2026-09-06 05:14:24.132 +0000 UTC" signed_by="hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s466peer2 # [164853.971578] peer2 data-mesher[217]: time=2026-09-06T05:14:33.957Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-06 05:14:24.147 +0000 UTC" signed_by="ejrrdMsEzmW4pUiQ41S5FZ+rZRpjbTSAm1Pb8x+L+Ts=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s written=true elapsed=5.345912ms467peer2 # [164853.974137] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...468peer2 # [164853.974802] peer2 data-mesher[217]: time=2026-09-06T05:14:33.960Z level=INFO msg="download complete" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew signed_at="2026-09-06 05:14:24.132 +0000 UTC" signed_by="hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s written=true elapsed=8.044869ms469peer2 # [164854.142555] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.470peer2 # [164854.142755] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.471peer1 # [164853.964996] peer1 data-mesher[219]: time=2026-09-06T05:14:33.950Z level=DEBUG msg="attempting push/pull" peer_count=1472peer1 # [164853.964996] peer1 data-mesher[219]: time=2026-09-06T05:14:33.950Z level=DEBUG msg="initiating state exchange" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s473peer1 # [164853.966750] peer1 data-mesher[219]: time=2026-09-06T05:14:33.952Z level=INFO msg="received file request" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/controller474peer1 # [164853.967223] peer1 data-mesher[219]: time=2026-09-06T05:14:33.953Z level=INFO msg="file transfer complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/controller475peer1 # [164853.968407] peer1 data-mesher[219]: time=2026-09-06T05:14:33.954Z level=INFO msg="received file request" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew476peer1 # [164853.969600] peer1 data-mesher[219]: time=2026-09-06T05:14:33.955Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp477peer1 # [164853.969600] peer1 data-mesher[219]: time=2026-09-06T05:14:33.955Z level=INFO msg="state exchange complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s478peer1 # [164853.969717] peer1 data-mesher[219]: time=2026-09-06T05:14:33.955Z level=DEBUG msg="push/pull successful" interval=5s479peer1 # [164853.971923] peer1 data-mesher[219]: time=2026-09-06T05:14:33.957Z level=INFO msg="file transfer complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/hSpRauCGDhQm41KvB0auPWOosOxRaxxvD89DC2WI4Ew480peer1 # [164854.092599] peer1 data-mesher[219]: time=2026-09-06T05:14:34.078Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj481peer1 # [164854.092599] peer1 data-mesher[219]: time=2026-09-06T05:14:34.078Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj482controller # [164854.091626] controller data-mesher[230]: time=2026-09-06T05:14:34.077Z level=DEBUG msg="attempting push/pull" peer_count=1483controller # [164854.091626] controller data-mesher[230]: time=2026-09-06T05:14:34.077Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s484controller # [164854.093461] controller data-mesher[230]: time=2026-09-06T05:14:34.079Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s485controller # [164854.093871] controller data-mesher[230]: time=2026-09-06T05:14:34.079Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s486controller # [164854.093957] controller data-mesher[230]: time=2026-09-06T05:14:34.079Z level=DEBUG msg="push/pull successful" interval=5s487controller # [164858.971909] controller data-mesher[230]: time=2026-09-06T05:14:38.957Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s488controller # [164858.971909] controller data-mesher[230]: time=2026-09-06T05:14:38.957Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s489controller # [164859.094444] controller data-mesher[230]: time=2026-09-06T05:14:39.080Z level=DEBUG msg="attempting push/pull" peer_count=1490controller # [164859.094444] controller data-mesher[230]: time=2026-09-06T05:14:39.080Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s491controller # [164859.095631] controller data-mesher[230]: time=2026-09-06T05:14:39.081Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s492controller # [164859.095915] controller data-mesher[230]: time=2026-09-06T05:14:39.081Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s493controller # [164859.095992] controller data-mesher[230]: time=2026-09-06T05:14:39.081Z level=DEBUG msg="push/pull successful" interval=5s494peer1 # [164858.970805] peer1 data-mesher[219]: time=2026-09-06T05:14:38.956Z level=DEBUG msg="attempting push/pull" peer_count=1495peer1 # [164858.970805] peer1 data-mesher[219]: time=2026-09-06T05:14:38.956Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s496peer1 # [164858.973000] peer1 data-mesher[219]: time=2026-09-06T05:14:38.958Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj497peer1 # [164858.973634] peer1 data-mesher[219]: time=2026-09-06T05:14:38.959Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s498peer1 # [164858.973734] peer1 data-mesher[219]: time=2026-09-06T05:14:38.959Z level=DEBUG msg="push/pull successful" interval=5s499peer1 # [164859.095051] peer1 data-mesher[219]: time=2026-09-06T05:14:39.080Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj500peer1 # [164859.095051] peer1 data-mesher[219]: time=2026-09-06T05:14:39.080Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj501peer2: still waiting for container 'peer2' to reach ready state...502peer2 # [164861.809529] peer2 data-mesher[217]: time=2026-09-06T05:14:41.795Z level=INFO msg="performing state exchange with peers on join" count=1503peer2 # [164861.809529] peer2 data-mesher[217]: time=2026-09-06T05:14:41.795Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s504peer2 # [164861.810857] peer2 data-mesher[217]: time=2026-09-06T05:14:41.796Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj505peer2 # [164861.811466] peer2 data-mesher[217]: time=2026-09-06T05:14:41.797Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s506peer2 # [164861.811559] peer2 data-mesher[217]: time=2026-09-06T05:14:41.797Z level=INFO msg="server started"507peer2 # [164861.811625] peer2 data-mesher[217]: time=2026-09-06T05:14:41.797Z level=INFO msg="starting expired-file sweeper" interval=1m0s508peer2 # [164861.811827] peer2 systemd[1]: Started data mesher daemon.509peer2 # [164861.814007] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...510peer2 # [164861.970255] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...511peer2 # [164861.975137] peer2 data-mesher[217]: time=2026-09-06T05:14:41.960Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 status=204512peer2 # [164861.975319] peer2 dm-wg-star-publish[295]: Status: 204 No Content513peer2 # [164861.978806] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.514peer2 # [164862.000231] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.515peer2 # [164862.001127] peer2 systemd[1]: Reached target Multi-User System.516controller # [164861.810185] controller data-mesher[230]: time=2026-09-06T05:14:41.795Z level=INFO msg="received state sync from peer" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp517controller # [164861.810185] controller data-mesher[230]: time=2026-09-06T05:14:41.795Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp518peer2: (finished: waiting for unit data-mesher.service, in 12.67 seconds)519??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.520 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39521controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1522??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.523 File "/nix/store/cag5izn0mcnmyi82zb3rwfs1s1afa6q5-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39524peer2 # [164862.120264] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.525peer2 # [164862.120602] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.526peer2 # [164862.124124] peer2 systemd[1]: Startup finished in 11.909s.527controller: (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 2.04 seconds)528controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1529controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)530peer2: waiting for success: wg show wg-star peers | grep -q .531peer1 # [164863.974365] peer1 data-mesher[219]: time=2026-09-06T05:14:43.959Z level=DEBUG msg="attempting push/pull" peer_count=1532peer1 # [164863.974365] peer1 data-mesher[219]: time=2026-09-06T05:14:43.959Z level=DEBUG msg="initiating state exchange" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s533peer1 # [164863.976034] peer1 data-mesher[219]: time=2026-09-06T05:14:43.961Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp534peer1 # [164863.976601] peer1 data-mesher[219]: time=2026-09-06T05:14:43.962Z level=DEBUG msg="new file detected" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00535peer1 # [164863.976785] peer1 data-mesher[219]: time=2026-09-06T05:14:43.962Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00536peer1 # [164863.976931] peer1 data-mesher[219]: time=2026-09-06T05:14:43.962Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 signed_at="2026-09-06 05:14:41.949 +0000 UTC" signed_by="3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1/lKNyX00=" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp537peer1 # [164863.977202] peer1 data-mesher[219]: time=2026-09-06T05:14:43.963Z level=INFO msg="state exchange complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s538peer1 # [164863.977277] peer1 data-mesher[219]: time=2026-09-06T05:14:43.963Z level=DEBUG msg="push/pull successful" interval=5s539peer1 # [164863.985360] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...540peer1 # [164864.046260] peer1 data-mesher[219]: time=2026-09-06T05:14:44.032Z level=INFO msg="download complete" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 signed_at="2026-09-06 05:14:41.949 +0000 UTC" signed_by="3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1/lKNyX00=" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp written=true elapsed=69.422781ms541peer1 # [164864.097015] peer1 data-mesher[219]: time=2026-09-06T05:14:44.082Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj542peer1 # [164864.097015] peer1 data-mesher[219]: time=2026-09-06T05:14:44.082Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj543peer1 # [164864.100036] peer1 data-mesher[219]: time=2026-09-06T05:14:44.085Z level=INFO msg="received file request" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00544peer1 # [164864.100657] peer1 data-mesher[219]: time=2026-09-06T05:14:44.086Z level=INFO msg="file transfer complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00545peer1 # [164864.154138] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.546peer1 # [164864.160297] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.547peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.02 seconds)548peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::79c8:0a0b:faba:7896549peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::79c8:0a0b:faba:7896, in 0.01 seconds)550controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::99be:f278:f8ac:825c551controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::99be:f278:f8ac:825c, in 0.01 seconds)552peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::99be:f278:f8ac:825c553peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::99be:f278:f8ac:825c, in 0.01 seconds)554peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e1e5:ecb7:0222:3324555peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e1e5:ecb7:0222:3324, in 0.01 seconds)556(finished: run the VM test script, in 33.09 seconds)557peer2 # [164863.974828] peer2 data-mesher[217]: time=2026-09-06T05:14:43.960Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s558peer2 # [164863.974828] peer2 data-mesher[217]: time=2026-09-06T05:14:43.960Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s559peer2 # [164863.977392] peer2 data-mesher[217]: time=2026-09-06T05:14:43.963Z level=INFO msg="received file request" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00560peer2 # [164863.980070] peer2 data-mesher[217]: time=2026-09-06T05:14:43.965Z level=INFO msg="file transfer complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s network="IxE2BW0JAPh2oTIep6xEro3NgWWLB9Kb8rMDg/uTAkU=" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00561controller # [164864.096431] controller data-mesher[230]: time=2026-09-06T05:14:44.082Z level=DEBUG msg="attempting push/pull" peer_count=1562controller # [164864.096431] controller data-mesher[230]: time=2026-09-06T05:14:44.082Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s563controller # [164864.098088] controller data-mesher[230]: time=2026-09-06T05:14:44.083Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s564controller # [164864.098656] controller data-mesher[230]: time=2026-09-06T05:14:44.084Z level=DEBUG msg="new file detected" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00565controller # [164864.098834] controller data-mesher[230]: time=2026-09-06T05:14:44.084Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00566controller # [164864.098938] controller data-mesher[230]: time=2026-09-06T05:14:44.084Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 signed_at="2026-09-06 05:14:41.949 +0000 UTC" signed_by="3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1/lKNyX00=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s567controller # [164864.099245] controller data-mesher[230]: time=2026-09-06T05:14:44.085Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s568controller # [164864.099338] controller data-mesher[230]: time=2026-09-06T05:14:44.085Z level=DEBUG msg="push/pull successful" interval=5s569controller # [164864.105309] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...570controller # [164864.131876] controller data-mesher[230]: time=2026-09-06T05:14:44.117Z level=INFO msg="download complete" name=dm_wg_star_wg_star/3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1_lKNyX00 signed_at="2026-09-06 05:14:41.949 +0000 UTC" signed_by="3IgitHEjGBuud0UMDRmFUwFrS3ckNlLm4E1/lKNyX00=" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s written=true elapsed=32.990887ms571controller # [164864.278733] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.572controller # [164864.278884] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.573peer1 # [164866.812750] peer1 data-mesher[219]: time=2026-09-06T05:14:46.798Z level=INFO msg="received state sync from peer" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp574peer2 # [164866.811752] peer2 data-mesher[217]: time=2026-09-06T05:14:46.797Z level=DEBUG msg="attempting push/pull" peer_count=2575peer1 # [164866.812750] peer1 data-mesher[219]: time=2026-09-06T05:14:46.798Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp576peer2 # [164866.812234] peer2 data-mesher[217]: time=2026-09-06T05:14:46.797Z level=DEBUG msg="initiating state exchange" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s577peer2 # [164866.816124] peer2 data-mesher[217]: time=2026-09-06T05:14:46.801Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s578peer2 # [164866.817284] peer2 data-mesher[217]: time=2026-09-06T05:14:46.803Z level=INFO msg="state exchange complete" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s timeout=5s579peer2 # [164866.817342] peer2 data-mesher[217]: time=2026-09-06T05:14:46.803Z level=DEBUG msg="push/pull successful" interval=5s580peer1 # [164868.977590] peer1 data-mesher[219]: time=2026-09-06T05:14:48.963Z level=DEBUG msg="attempting push/pull" peer_count=1581peer1 # [164869.121969] peer1 data-mesher[219]: time=2026-09-06T05:14:48.963Z level=DEBUG msg="initiating state exchange" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s582peer1 # [164869.121969] peer1 data-mesher[219]: time=2026-09-06T05:14:48.965Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp583peer1 # [164869.121969] peer1 data-mesher[219]: time=2026-09-06T05:14:48.966Z level=INFO msg="state exchange complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s584peer1 # [164869.121969] peer1 data-mesher[219]: time=2026-09-06T05:14:48.967Z level=DEBUG msg="push/pull successful" interval=5s585peer2 # [164868.978444] peer2 data-mesher[217]: time=2026-09-06T05:14:48.964Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s586peer2 # [164868.978444] peer2 data-mesher[217]: time=2026-09-06T05:14:48.964Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s587peer2 # [164869.121862] peer2 data-mesher[217]: time=2026-09-06T05:14:49.086Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj588peer2 # [164869.121862] peer2 data-mesher[217]: time=2026-09-06T05:14:49.086Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj589controller # [164869.100390] controller data-mesher[230]: time=2026-09-06T05:14:49.086Z level=DEBUG msg="attempting push/pull" peer_count=1590controller # [164869.121884] controller data-mesher[230]: time=2026-09-06T05:14:49.086Z level=DEBUG msg="initiating state exchange" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s591controller # [164869.121884] controller data-mesher[230]: time=2026-09-06T05:14:49.088Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp592controller # [164869.121884] controller data-mesher[230]: time=2026-09-06T05:14:49.089Z level=INFO msg="state exchange complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s593controller # [164869.121884] controller data-mesher[230]: time=2026-09-06T05:14:49.089Z level=DEBUG msg="push/pull successful" interval=5s594peer2 # [164871.818339] peer2 data-mesher[217]: time=2026-09-06T05:14:51.804Z level=DEBUG msg="attempting push/pull" peer_count=2595peer2 # [164871.819014] peer2 data-mesher[217]: time=2026-09-06T05:14:51.804Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s596peer2 # [164871.820793] peer2 data-mesher[217]: time=2026-09-06T05:14:51.806Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj597peer2 # [164871.821922] peer2 data-mesher[217]: time=2026-09-06T05:14:51.807Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s598peer2 # [164871.821989] peer2 data-mesher[217]: time=2026-09-06T05:14:51.807Z level=DEBUG msg="push/pull successful" interval=5s599controller # [164871.819147] controller data-mesher[230]: time=2026-09-06T05:14:51.804Z level=INFO msg="received state sync from peer" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp600controller # [164871.819147] controller data-mesher[230]: time=2026-09-06T05:14:51.804Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp601peer1 # [164873.981763] peer1 data-mesher[219]: time=2026-09-06T05:14:53.967Z level=DEBUG msg="attempting push/pull" peer_count=1602peer1 # [164873.981763] peer1 data-mesher[219]: time=2026-09-06T05:14:53.967Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s603peer1 # [164873.983624] peer1 data-mesher[219]: time=2026-09-06T05:14:53.969Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj604peer1 # [164873.984776] peer1 data-mesher[219]: time=2026-09-06T05:14:53.970Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s605peer1 # [164873.984840] peer1 data-mesher[219]: time=2026-09-06T05:14:53.970Z level=DEBUG msg="push/pull successful" interval=5s606peer2 # [164874.104725] peer2 data-mesher[217]: time=2026-09-06T05:14:54.090Z level=INFO msg="received state sync from peer" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj607peer2 # [164874.104725] peer2 data-mesher[217]: time=2026-09-06T05:14:54.090Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj608controller # [164873.982580] controller data-mesher[230]: time=2026-09-06T05:14:53.968Z level=INFO msg="received state sync from peer" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s609controller # [164873.982580] controller data-mesher[230]: time=2026-09-06T05:14:53.968Z level=INFO msg="merging remote state" peer=12D3KooWJnBpT2hUHb6GxaeXS2onNbhmKNu1jNoAjub6YfmzEn4s610controller # [164874.103861] controller data-mesher[230]: time=2026-09-06T05:14:54.089Z level=DEBUG msg="attempting push/pull" peer_count=1611controller # [164874.104058] controller data-mesher[230]: time=2026-09-06T05:14:54.089Z level=DEBUG msg="initiating state exchange" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s612controller # [164874.106344] controller data-mesher[230]: time=2026-09-06T05:14:54.092Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp613controller # [164874.107835] controller data-mesher[230]: time=2026-09-06T05:14:54.093Z level=INFO msg="state exchange complete" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp timeout=5s614controller # [164874.107835] controller data-mesher[230]: time=2026-09-06T05:14:54.093Z level=DEBUG msg="push/pull successful" interval=5s615peer2 # [164876.823041] peer2 data-mesher[217]: time=2026-09-06T05:14:56.808Z level=DEBUG msg="attempting push/pull" peer_count=2616peer2 # [164876.823041] peer2 data-mesher[217]: time=2026-09-06T05:14:56.808Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s617peer2 # [164876.825463] peer2 data-mesher[217]: time=2026-09-06T05:14:56.810Z level=INFO msg="merging remote state" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj618peer2 # [164876.825463] peer2 data-mesher[217]: time=2026-09-06T05:14:56.811Z level=INFO msg="state exchange complete" peer=12D3KooWKBAbSDnifjyFEho8uVqV5gTvHqb33WrhJ9PUzMABvrcj timeout=5s619peer2 # [164876.825463] peer2 data-mesher[217]: time=2026-09-06T05:14:56.811Z level=DEBUG msg="push/pull successful" interval=5s620controller # [164876.823486] controller data-mesher[230]: time=2026-09-06T05:14:56.809Z level=INFO msg="received state sync from peer" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp621controller # [164876.823486] controller data-mesher[230]: time=2026-09-06T05:14:56.809Z level=INFO msg="merging remote state" peer=12D3KooWQfEG7GtDJctqEpJizuAdsXx6wMVEbvnMGS6DrSujarnp622test script finished in 47.30s623cleanup624kill NspawnMachine (pid 50)625kill NspawnMachine (pid 53)626Container controller terminated by signal KILL.627kill NspawnMachine (pid 779)628Container peer1 terminated by signal KILL.629Container peer2 terminated by signal KILL.630(finished: cleanup, in 0.59 seconds)