container-test-run-dm-wireguard-star
checks.x86_64-linux.dm-wireguard-star
· build #124
· 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.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 # [391650.903270] peer1 systemd-journald[95]: Journal started29controller # [391650.905880] controller systemd-journald[104]: Journal started30controller # [391650.905944] controller systemd-journald[104]: Runtime Journal (/run/log/journal/31ded71201b447ada849d4aa66cbdd09) is 8M, max 3.7G, 3.7G free.31controller # [391650.955496] controller systemd[1]: Finished Apply Kernel Variables.32controller # [391650.965296] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.33controller # [391651.000142] controller systemd[1]: Starting Flush Journal to Persistent Storage...34controller # [391651.004345] controller systemd[1]: Starting Network Name Resolution...35controller # [391651.008207] controller systemd[1]: Starting Create Static Device Nodes in /dev...36controller # [391651.030796] controller systemd-journald[104]: Time spent on flushing to /var/log/journal/31ded71201b447ada849d4aa66cbdd09 is 1.986ms for 7 entries.37controller # [391651.030796] controller systemd-journald[104]: System Journal (/var/log/journal/31ded71201b447ada849d4aa66cbdd09) is 8M, max 4G, 3.9G free.38controller # [391651.040132] controller systemd[1]: Finished Create Static Device Nodes in /dev.39controller # [391651.040810] controller systemd[1]: Reached target Preparation for Local File Systems.40controller # [391651.040896] controller systemd[1]: Reached target Local File Systems.41controller # [391651.041621] controller systemd[1]: Listening on Boot Loader Control Service Socket.42controller # [391651.041665] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container43controller # [391651.042508] controller systemd[1]: Starting Save Transient machine-id to Disk...44controller # [391651.042535] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys45controller # [391651.108126] controller systemd[1]: Finished Firewall.46controller # [391651.108319] controller systemd[1]: Reached target Preparation for Network.47controller # [391651.108554] controller systemd[1]: Listening on Network Management Resolve Hook Socket.48controller # [391651.109607] controller systemd[1]: Starting Network Management...49controller # [391651.218948] controller systemd[1]: Finished Flush Journal to Persistent Storage.50controller # [391651.220095] controller systemd[1]: Starting Create System Files and Directories...51controller # [391651.240686] controller systemd-tmpfiles[217]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted52controller # [391651.240892] controller systemd-tmpfiles[217]: fchmod() of /var/log/journal failed: Operation not permitted53controller # [391651.241037] controller systemd-tmpfiles[217]: fchmod() of /var/log/journal/31ded71201b447ada849d4aa66cbdd09 failed: Operation not permitted54controller # [391651.241239] controller systemd-tmpfiles[217]: fchmod() of /run/log/journal failed: Operation not permitted55controller # [391651.245845] controller systemd[1]: Finished Create System Files and Directories.56controller # [391651.248639] controller systemd[1]: Starting Rebuild Journal Catalog...57controller # [391651.251919] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...58controller # [391651.280304] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.59controller # [391651.288846] controller systemd[1]: Finished Rebuild Journal Catalog.60controller # [391651.292387] controller systemd[1]: Starting Update is Completed...61controller # [391651.310525] controller systemd[1]: Finished Update is Completed.62peer1 # [391650.903321] peer1 systemd-journald[95]: Runtime Journal (/run/log/journal/5b15edffc438415ba924a6f48c65a1ed) is 8M, max 3.7G, 3.7G free.63peer1 # [391650.963511] peer1 systemd[1]: Finished Apply Kernel Variables.64peer1 # [391651.006807] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.65peer1 # [391651.041911] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...66peer1 # [391651.042864] peer1 systemd[1]: Starting Network Name Resolution...67peer1 # [391651.043667] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...68peer1 # [391651.066653] peer1 systemd-journald[95]: Time spent on flushing to /var/log/journal/5b15edffc438415ba924a6f48c65a1ed is 2.177ms for 7 entries.69peer1 # [391651.066653] peer1 systemd-journald[95]: System Journal (/var/log/journal/5b15edffc438415ba924a6f48c65a1ed) is 8M, max 4G, 3.9G free.70peer1 # [391651.087754] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.71peer1 # [391651.088422] peer1 systemd[1]: Reached target Preparation for Local File Systems.72peer1 # [391651.088496] peer1 systemd[1]: Reached target Local File Systems.73peer1 # [391651.088987] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.74peer1 # [391651.089025] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container75peer1 # [391651.089675] peer1 systemd[1]: Starting Save Transient machine-id to Disk...76peer1 # [391651.089695] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys77peer1 # [391651.196405] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.78peer1 # [391651.200127] peer1 systemd[1]: Starting Create System Files and Directories...79peer1 # [391651.237511] peer1 systemd-tmpfiles[158]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted80peer1 # [391651.237698] peer1 systemd-tmpfiles[158]: fchmod() of /var/log/journal failed: Operation not permitted81peer1 # [391651.237821] peer1 systemd-tmpfiles[158]: fchmod() of /var/log/journal/5b15edffc438415ba924a6f48c65a1ed failed: Operation not permitted82peer1 # [391651.238020] peer1 systemd-tmpfiles[158]: fchmod() of /run/log/journal failed: Operation not permitted83peer1 # [391651.241937] peer1 systemd[1]: Finished Create System Files and Directories.84peer1 # [391651.244106] peer1 systemd[1]: Starting Rebuild Journal Catalog...85peer1 # [391651.248181] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...86peer1 # [391651.283350] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.87peer1 # [391651.290740] peer1 systemd[1]: Finished Rebuild Journal Catalog.88peer1 # [391651.294194] peer1 systemd[1]: Starting Update is Completed...89peer1 # [391651.314287] peer1 systemd[1]: Finished Update is Completed.90peer1 # [391651.337353] peer1 systemd[1]: Finished Firewall.91peer1 # [391651.338134] peer1 systemd[1]: Reached target Preparation for Network.92peer1 # [391651.338416] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.93peer1 # [391651.339575] peer1 systemd[1]: Starting Network Management...94controller # [391652.846912] controller systemd-networkd[213]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted95controller # [391652.847037] controller systemd-networkd[213]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted96controller # [391652.901852] controller 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.97controller # [391652.902048] controller 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.98controller # [391652.902197] controller systemd-networkd[213]: lo: Link UP99controller # [391652.902200] controller systemd-networkd[213]: lo: Gained carrier100controller # [391652.902408] controller systemd-networkd[213]: eth1: Configuring with /etc/systemd/network/40-eth1.network.101controller # [391652.903353] controller systemd[1]: Started Network Management.102controller # [391652.905257] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...103controller # [391652.905921] controller systemd-networkd[213]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.104controller # [391652.906205] controller systemd-networkd[213]: wg-star: netdev ready105controller # [391652.909391] controller systemd-networkd[213]: eth1: Link UP106controller # [391652.909630] controller systemd-networkd[213]: eth1: Gained carrier107controller # [391652.922595] controller systemd-networkd[213]: wg-star: Link UP108controller # [391652.922603] controller systemd-networkd[213]: wg-star: Gained carrier109controller # [391652.937414] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.110peer1 # [391652.969632] peer1 systemd-networkd[212]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted111peer1 # [391652.969719] peer1 systemd-networkd[212]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted112peer1 # [391652.978918] peer1 systemd-networkd[212]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.113peer1 # [391652.979116] peer1 systemd-networkd[212]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.114peer1 # [391652.979231] peer1 systemd-networkd[212]: lo: Link UP115peer1 # [391652.979236] peer1 systemd-networkd[212]: lo: Gained carrier116peer1 # [391652.979436] peer1 systemd-networkd[212]: eth1: Configuring with /etc/systemd/network/40-eth1.network.117peer1 # [391652.979791] peer1 systemd[1]: Started Network Management.118peer1 # [391652.980354] peer1 systemd-networkd[212]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.119peer1 # [391652.980620] peer1 systemd-networkd[212]: wg-star: netdev ready120peer1 # [391652.980783] peer1 systemd-networkd[212]: eth1: Link UP121peer1 # [391652.980943] peer1 systemd-networkd[212]: eth1: Gained carrier122peer1 # [391652.981904] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...123peer1 # [391652.994426] peer1 systemd-networkd[212]: wg-star: Link UP124peer1 # [391652.994431] peer1 systemd-networkd[212]: wg-star: Gained carrier125peer1 # [391653.012467] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.126peer1 # [391653.491343] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.127peer1 # [391653.492244] peer1 systemd[1]: Finished Save Transient machine-id to Disk.128controller # [391653.493150] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.129controller # [391653.494035] controller systemd[1]: Finished Save Transient machine-id to Disk.130controller # [391653.974459] controller systemd-resolved[153]: Positive Trust Anchors:131controller # [391653.974473] controller systemd-resolved[153]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d132controller # [391653.974477] controller systemd-resolved[153]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16133controller # [391653.974500] controller systemd-resolved[153]: 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 test134controller # [391653.998391] controller systemd-resolved[153]: Using system hostname 'controller'.135controller # [391654.000178] controller systemd[1]: Started Network Name Resolution.136controller # [391654.000274] controller systemd[1]: Reached target Network.137controller # [391654.000326] controller systemd[1]: Reached target System Initialization.138controller # [391654.000411] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.139controller # [391654.000439] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container140controller # [391654.000459] controller systemd[1]: Started Daily Cleanup of Temporary Directories.141controller # [391654.000475] controller systemd[1]: Reached target Path Units.142controller # [391654.000500] controller systemd[1]: Reached target Timer Units.143controller # [391654.000619] controller systemd[1]: Listening on D-Bus System Message Bus Socket.144controller # [391654.001536] controller systemd[1]: Listening on Nix Daemon Socket.145controller # [391654.001676] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.146controller # [391654.001696] controller systemd[1]: Reached target Socket Units.147controller # [391654.001734] controller systemd[1]: Reached target Basic System.148controller # [391654.003703] controller systemd[1]: Starting data mesher daemon...149controller # [391654.004588] controller systemd[1]: Starting Import lastlog data into lastlog2 database...150controller # [391654.007922] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...151controller # [391654.023827] controller systemd[1]: Starting D-Bus System Message Bus...152controller # [391654.038945] controller systemd[1]: Finished Import lastlog data into lastlog2 database.153peer1 # [391654.785136] peer1 systemd-networkd[212]: eth1: Gained IPv6LL154controller # [391654.913147] controller systemd-networkd[213]: eth1: Gained IPv6LL155peer1 # [391655.506064] peer1 systemd-resolved[148]: Positive Trust Anchors:156peer1 # [391655.506132] peer1 systemd-resolved[148]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d157peer1 # [391655.506137] peer1 systemd-resolved[148]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16158peer1 # [391655.506161] peer1 systemd-resolved[148]: 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 test159peer1 # [391655.523436] peer1 systemd-resolved[148]: Using system hostname 'peer1'.160peer1 # [391655.525078] peer1 systemd[1]: Started Network Name Resolution.161peer1 # [391655.525168] peer1 systemd[1]: Reached target Network.162peer1 # [391655.525226] peer1 systemd[1]: Reached target System Initialization.163peer1 # [391655.525314] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.164peer1 # [391655.525351] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.165peer1 # [391655.525376] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container166peer1 # [391655.525394] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.167peer1 # [391655.525413] peer1 systemd[1]: Reached target Path Units.168peer1 # [391655.525446] peer1 systemd[1]: Reached target Timer Units.169peer1 # [391655.525561] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.170peer1 # [391655.525646] peer1 systemd[1]: Listening on Nix Daemon Socket.171peer1 # [391655.525816] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.172peer1 # [391655.525837] peer1 systemd[1]: Reached target Socket Units.173peer1 # [391655.525870] peer1 systemd[1]: Reached target Basic System.174peer1 # [391655.527440] peer1 systemd[1]: Starting data mesher daemon...175peer1 # [391655.528250] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...176peer1 # [391655.528974] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...177peer1 # [391655.529973] peer1 systemd[1]: Starting D-Bus System Message Bus...178peer1 # [391655.565406] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.179controller # [391655.558208] controller nsncd[231]: Sep 08 20:04:29.981 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"180controller # [391655.558487] controller systemd[1]: Started Name Service Cache Daemon (nsncd).181controller # [391655.558554] controller systemd[1]: Reached target Host and Network Name Lookups.182controller # [391655.558598] controller systemd[1]: Reached target User and Group Name Lookups.183controller # [391655.559802] controller systemd[1]: Starting User Login Management...184controller # [391655.560656] controller systemd[1]: Starting Permit User Sessions...185controller # [391655.568719] controller systemd[1]: Finished Permit User Sessions.186controller # [391655.569613] controller systemd[1]: Started Console Getty.187controller # [391655.569639] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0188controller # [391655.569651] controller systemd[1]: Reached target Login Prompts.189peer1 # [391656.059139] peer1 nsncd[220]: Sep 08 20:04:30.482 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"190peer1 # [391656.059538] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).191peer1 # [391656.059609] peer1 systemd[1]: Reached target Host and Network Name Lookups.192peer1 # [391656.059655] peer1 systemd[1]: Reached target User and Group Name Lookups.193peer1 # [391656.060809] peer1 systemd[1]: Starting User Login Management...194peer1 # [391656.061597] peer1 systemd[1]: Starting Permit User Sessions...195peer1 # [391656.101410] peer1 systemd[1]: Finished Permit User Sessions.196peer1 # [391656.104089] peer1 systemd[1]: Started Console Getty.197peer1 # [391656.104126] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0198peer1 # [391656.104141] peer1 systemd[1]: Reached target Login Prompts.199controller # [391656.463058] controller dbus-broker-launch[232]: Looking up NSS user entry for 'systemd-timesync'...200controller # [391656.465496] controller dbus-broker-launch[232]: NSS returned no entry for 'systemd-timesync'201controller # [391656.465496] controller dbus-broker-launch[232]: Invalid user-name in /nix/store/czz5jmv7wbdqn6q0lz0zg5p0mmzw7pn8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"202controller # [391656.466434] controller systemd[1]: Started D-Bus System Message Bus.203controller # [391656.477212] controller dbus-broker-launch[232]: Ready204peer1 # [391657.729893] peer1 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'...205peer1 # [391657.732024] peer1 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync'206peer1 # [391657.732024] peer1 dbus-broker-launch[221]: Invalid user-name in /nix/store/czz5jmv7wbdqn6q0lz0zg5p0mmzw7pn8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"207peer1 # [391657.732594] peer1 systemd[1]: Started D-Bus System Message Bus.208peer1 # [391657.738440] peer1 dbus-broker-launch[221]: Ready209controller # [391659.103271] controller data-mesher[229]: time=2026-09-08T20:04:33.526Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]210controller # [391659.105148] controller data-mesher[229]: time=2026-09-08T20:04:33.528Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ: [/dns/controller.clan/tcp/7946]} {12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p: [/dns/peer1.clan/tcp/7946]} {12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ211controller # [391659.105148] controller data-mesher[229]: time=2026-09-08T20:04:33.528Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml212controller # [391659.157339] controller data-mesher[229]: time=2026-09-08T20:04:33.580Z level=INFO msg="checking file integrity"213controller # [391659.157479] controller data-mesher[229]: time=2026-09-08T20:04:33.580Z level=INFO msg="file integrity check complete"214controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="libp2p host created" peer_id=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ 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::68c9:cea0:7ad3:6a46/tcp/7946]"215controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="registered HTTP route" method=GET path=/files216controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name217controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name218controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="starting server"219controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="waiting for DHT to populate" delay=10s220controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="HTTP server listening" address=[::1]:7331221controller # [391659.162346] controller data-mesher[229]: time=2026-09-08T20:04:33.584Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331222controller: still waiting for container 'controller' to reach ready state...223controller # [391660.196719] controller data-mesher[229]: time=2026-09-08T20:04:34.620Z level=INFO msg="peer connected" peer_id=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p remote_addr=/ip6/2001:db8:1::2/tcp/7946224peer1 # [391660.175221] peer1 data-mesher[218]: time=2026-09-08T20:04:34.598Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]225controller # [391660.394535] controller systemd-logind[247]: New seat seat0.226controller # [391660.394795] controller systemd[1]: Started User Login Management.227controller # [391660.396101] controller systemd[1]: Starting linger-users.service...228controller # [391660.428304] controller systemd[1]: linger-users.service: Deactivated successfully.229controller # [391660.428581] controller systemd[1]: Finished linger-users.service.230peer1 # [391660.177255] peer1 data-mesher[218]: time=2026-09-08T20:04:34.600Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ: [/dns/controller.clan/tcp/7946]} {12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p: [/dns/peer1.clan/tcp/7946]} {12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p231peer1 # [391660.177255] peer1 data-mesher[218]: time=2026-09-08T20:04:34.600Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml232peer1 # [391660.187572] peer1 data-mesher[218]: time=2026-09-08T20:04:34.610Z level=INFO msg="checking file integrity"233peer1 # [391660.187724] peer1 data-mesher[218]: time=2026-09-08T20:04:34.611Z level=INFO msg="file integrity check complete"234peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="libp2p host created" peer_id=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p 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::e12c:c7e2:7bb8:b3e3/tcp/7946]"235peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="registered HTTP route" method=GET path=/files236peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name237peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name238peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="starting server"239peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="waiting for DHT to populate" delay=10s240peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="HTTP server listening" address=[::1]:7331241peer1 # [391660.193040] peer1 data-mesher[218]: time=2026-09-08T20:04:34.615Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331242peer1 # [391660.196721] peer1 data-mesher[218]: time=2026-09-08T20:04:34.619Z level=INFO msg="peer connected" peer_id=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ remote_addr=/ip6/2001:db8:1::1/tcp/7946243peer1 # [391660.882062] peer1 systemd-logind[238]: New seat seat0.244peer1 # [391660.883151] peer1 systemd[1]: Started User Login Management.245peer1 # [391660.885285] peer1 systemd[1]: Starting linger-users.service...246peer1 # [391660.920320] peer1 systemd[1]: linger-users.service: Deactivated successfully.247peer1 # [391660.920514] peer1 systemd[1]: Finished linger-users.service.248controller # [391669.162168] controller data-mesher[229]: time=2026-09-08T20:04:43.585Z level=INFO msg="performing state exchange with peers on join" count=1249controller # [391669.162594] controller data-mesher[229]: time=2026-09-08T20:04:43.585Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s250controller # [391669.162594] controller data-mesher[229]: time=2026-09-08T20:04:43.585Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p251controller # [391669.162594] controller data-mesher[229]: time=2026-09-08T20:04:43.585Z level=INFO msg="state exchange complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s252controller # [391669.162650] controller data-mesher[229]: time=2026-09-08T20:04:43.585Z level=INFO msg="server started"253controller # [391669.162700] controller data-mesher[229]: time=2026-09-08T20:04:43.586Z level=INFO msg="starting expired-file sweeper" interval=1m0s254controller # [391669.162787] controller systemd[1]: Started data mesher daemon.255controller # [391669.163584] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...256controller # [391669.400546] controller data-mesher[229]: time=2026-09-08T20:04:43.823Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204257controller # [391669.400655] controller dm-wg-star-publish[280]: Status: 204 No Content258controller # [391669.400693] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...259controller # [391669.402628] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.260controller # [391669.402830] controller systemd[1]: Reached target Multi-User System.261controller: (finished: waiting for unit data-mesher.service, in 20.16 seconds)262peer1: waiting for unit data-mesher.service263peer1 # [391669.162526] peer1 data-mesher[218]: time=2026-09-08T20:04:43.585Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ264peer1 # [391669.162526] peer1 data-mesher[218]: time=2026-09-08T20:04:43.585Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ265controller # [391669.475750] controller dm-wg-star-reconfig[295]: No peer data available yet, skipping266controller # [391669.476513] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.267controller # [391669.476641] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.268controller # [391669.476954] controller systemd[1]: Startup finished in 19.252s.269peer1 # [391670.193062] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=INFO msg="performing state exchange with peers on join" count=1270peer1 # [391670.193062] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s271peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ272peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=DEBUG msg="new file detected" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller273peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=INFO msg="state exchange complete" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s274peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=INFO msg="server started"275peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.616Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller276peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.617Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 20:04:43.63 +0000 UTC" signed_by="PKlk8hemeNDxBd6SVkZfrB47os+Bu4NqUQlplTZt7KQ=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ277peer1 # [391670.382161] peer1 data-mesher[218]: time=2026-09-08T20:04:44.617Z level=INFO msg="starting expired-file sweeper" interval=1m0s278peer1 # [391670.193831] peer1 systemd[1]: Started data mesher daemon.279peer1 # [391670.194721] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...280peer1 # [391670.384729] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...281peer1 # [391670.384979] peer1 data-mesher[218]: time=2026-09-08T20:04:44.808Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 20:04:43.63 +0000 UTC" signed_by="PKlk8hemeNDxBd6SVkZfrB47os+Bu4NqUQlplTZt7KQ=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ written=true elapsed=191.291416ms282peer1 # [391670.407158] peer1 data-mesher[218]: time=2026-09-08T20:04:44.830Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk status=204283peer1 # [391670.407237] peer1 dm-wg-star-publish[271]: Status: 204 No Content284peer1 # [391670.409255] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.285peer1 # [391670.409361] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.286peer1 # [391670.409638] peer1 systemd[1]: Reached target Multi-User System.287controller # [391670.193402] controller data-mesher[229]: time=2026-09-08T20:04:44.616Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p288controller # [391670.193402] controller data-mesher[229]: time=2026-09-08T20:04:44.616Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p289controller # [391670.382191] controller data-mesher[229]: time=2026-09-08T20:04:44.617Z level=INFO msg="received file request" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/controller290controller # [391670.382191] controller data-mesher[229]: time=2026-09-08T20:04:44.805Z level=INFO msg="file transfer complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/controller291peer1: (finished: waiting for unit data-mesher.service, in 1.14 seconds)292??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.293 File "/nix/store/lpy0ms3by1jh6bllyr4fc0hv1dcr96q2-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39294controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller295??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.296 File "/nix/store/lpy0ms3by1jh6bllyr4fc0hv1dcr96q2-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39297controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)298peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller299peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)300controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .301peer1 # [391670.471111] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.302peer1 # [391670.471275] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.303peer1 # [391670.471535] peer1 systemd[1]: Startup finished in 20.247s.304peer1 # [391674.165315] peer1 data-mesher[218]: time=2026-09-08T20:04:48.588Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ305controller # [391674.164864] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=DEBUG msg="attempting push/pull" peer_count=1306peer1 # [391674.165315] peer1 data-mesher[218]: time=2026-09-08T20:04:48.588Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ307controller # [391674.164864] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s308peer1 # [391674.165796] peer1 data-mesher[218]: time=2026-09-08T20:04:48.589Z level=INFO msg="received file request" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk309controller # [391674.165467] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p310peer1 # [391674.166803] peer1 data-mesher[218]: time=2026-09-08T20:04:48.590Z level=INFO msg="file transfer complete" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk311controller # [391674.165557] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=DEBUG msg="new file detected" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk312controller # [391674.165557] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=INFO msg="state exchange complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s313controller # [391674.165622] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=DEBUG msg="push/pull successful" interval=5s314controller # [391674.165622] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk315controller # [391674.165622] controller data-mesher[229]: time=2026-09-08T20:04:48.588Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk signed_at="2026-09-08 20:04:44.694 +0000 UTC" signed_by="rPbrAJQgeN0ICcUq9O5ES+HH8jpfrE3tkDoyza5cfOk=" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p316controller # [391674.168658] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...317controller # [391674.237946] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.318controller # [391674.238086] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.319controller # [391674.309683] controller data-mesher[229]: time=2026-09-08T20:04:48.733Z level=INFO msg="download complete" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk signed_at="2026-09-08 20:04:44.694 +0000 UTC" signed_by="rPbrAJQgeN0ICcUq9O5ES+HH8jpfrE3tkDoyza5cfOk=" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p written=true elapsed=144.05827ms320controller: (finished: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q ., in 4.05 seconds)321controller: waiting for success: wg show wg-star peers | grep -q .322controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)323peer1: waiting for success: wg show wg-star peers | grep -q .324peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.02 seconds)325peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::68c9:cea0:7ad3:6a46326peer1 # [391675.194319] peer1 data-mesher[218]: time=2026-09-08T20:04:49.617Z level=DEBUG msg="attempting push/pull" peer_count=1327controller # [391675.194898] controller data-mesher[229]: time=2026-09-08T20:04:49.618Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p328peer1 # [391675.194781] peer1 data-mesher[218]: time=2026-09-08T20:04:49.617Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s329controller # [391675.194898] controller data-mesher[229]: time=2026-09-08T20:04:49.618Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p330peer1 # [391675.195151] peer1 data-mesher[218]: time=2026-09-08T20:04:49.618Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ331peer1 # [391675.195242] peer1 data-mesher[218]: time=2026-09-08T20:04:49.618Z level=INFO msg="state exchange complete" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s332peer1 # [391675.195267] peer1 data-mesher[218]: time=2026-09-08T20:04:49.618Z level=DEBUG msg="push/pull successful" interval=5s333peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::68c9:cea0:7ad3:6a46, in 0.95 seconds)334controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e12c:c7e2:7bb8:b3e3335controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e12c:c7e2:7bb8:b3e3, in 0.00 seconds)336controller: must succeed: wg show wg-star peers | wc -l337controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)338peer2: systemd-nspawn running (pid 740)339peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...340peer2: waiting for unit data-mesher.service341nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE342nixos-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.343Note: 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.344░ Spawning container peer2 on /build/vm-state-peer2.345peer2 # [391676.568433] peer2 systemd-journald[96]: Journal started346peer2 # [391676.568464] peer2 systemd-journald[96]: Runtime Journal (/run/log/journal/f529c50887cd4cd097e3ce8a7f648c79) is 8M, max 3.7G, 3.7G free.347peer2 # [391676.572904] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...348peer2 # [391676.573333] peer2 systemd[1]: Starting Network Name Resolution...349peer2 # [391676.573782] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...350peer2 # [391676.577732] peer2 systemd-journald[96]: Time spent on flushing to /var/log/journal/f529c50887cd4cd097e3ce8a7f648c79 is 1.107ms for 5 entries.351peer2 # [391676.577732] peer2 systemd-journald[96]: System Journal (/var/log/journal/f529c50887cd4cd097e3ce8a7f648c79) is 8M, max 4G, 3.9G free.352peer2 # [391676.582451] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.353peer2 # [391676.582587] peer2 systemd[1]: Reached target Preparation for Local File Systems.354peer2 # [391676.582630] peer2 systemd[1]: Reached target Local File Systems.355peer2 # [391676.583054] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.356peer2 # [391676.583082] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container357peer2 # [391676.583524] peer2 systemd[1]: Starting Save Transient machine-id to Disk...358peer2 # [391676.583542] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys359peer2 # [391676.662370] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.360peer2 # [391676.663214] peer2 systemd[1]: Starting Create System Files and Directories...361peer2 # [391676.698499] peer2 systemd[1]: Finished Firewall.362peer2 # [391676.698592] peer2 systemd[1]: Reached target Preparation for Network.363peer2 # [391676.698732] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.364peer2 # [391676.698805] peer2 systemd-tmpfiles[167]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted365peer2 # [391676.698955] peer2 systemd-tmpfiles[167]: fchmod() of /var/log/journal failed: Operation not permitted366peer2 # [391676.699063] peer2 systemd-tmpfiles[167]: fchmod() of /var/log/journal/f529c50887cd4cd097e3ce8a7f648c79 failed: Operation not permitted367peer2 # [391676.699217] peer2 systemd-tmpfiles[167]: fchmod() of /run/log/journal failed: Operation not permitted368peer2 # [391676.699279] peer2 systemd[1]: Starting Network Management...369peer2 # [391676.700034] peer2 systemd[1]: Finished Create System Files and Directories.370peer2 # [391676.700677] peer2 systemd[1]: Starting Rebuild Journal Catalog...371peer2 # [391676.701071] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...372peer2 # [391676.707098] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.373peer2 # [391676.712983] peer2 systemd[1]: Finished Rebuild Journal Catalog.374peer2 # [391676.713471] peer2 systemd[1]: Starting Update is Completed...375peer2 # [391676.718203] peer2 systemd[1]: Finished Update is Completed.376peer2 # [391676.953423] peer2 systemd-networkd[206]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted377peer2 # [391676.953501] peer2 systemd-networkd[206]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted378peer2 # [391676.959322] peer2 systemd-networkd[206]: /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.379peer2 # [391676.959468] peer2 systemd-networkd[206]: /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.380peer2 # [391676.959537] peer2 systemd-networkd[206]: lo: Link UP381peer2 # [391676.959540] peer2 systemd-networkd[206]: lo: Gained carrier382peer2 # [391676.959690] peer2 systemd-networkd[206]: eth1: Configuring with /etc/systemd/network/40-eth1.network.383peer2 # [391676.959942] peer2 systemd[1]: Started Network Management.384peer2 # [391676.960342] peer2 systemd-networkd[206]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.385peer2 # [391676.960556] peer2 systemd-networkd[206]: wg-star: netdev ready386peer2 # [391676.960661] peer2 systemd-networkd[206]: eth1: Link UP387peer2 # [391676.960679] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...388peer2 # [391676.960771] peer2 systemd-networkd[206]: eth1: Gained carrier389peer2 # [391676.977374] peer2 systemd-networkd[206]: wg-star: Link UP390peer2 # [391676.977377] peer2 systemd-networkd[206]: wg-star: Gained carrier391peer2 # [391676.985539] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.392peer2 # [391677.086167] peer2 systemd-resolved[119]: Positive Trust Anchors:393peer2 # [391677.086175] peer2 systemd-resolved[119]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d394peer2 # [391677.086178] peer2 systemd-resolved[119]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16395peer2 # [391677.086196] peer2 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 test396peer2 # [391677.096969] peer2 systemd-resolved[119]: Using system hostname 'peer2'.397peer2 # [391677.098425] peer2 systemd[1]: Started Network Name Resolution.398peer2 # [391677.098493] peer2 systemd[1]: Reached target Network.399peer2 # [391677.098543] peer2 systemd[1]: Reached target System Initialization.400peer2 # [391677.098621] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.401peer2 # [391677.098656] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.402peer2 # [391677.098684] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container403peer2 # [391677.098715] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.404peer2 # [391677.098737] peer2 systemd[1]: Reached target Path Units.405peer2 # [391677.098777] peer2 systemd[1]: Reached target Timer Units.406peer2 # [391677.098903] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.407peer2 # [391677.098980] peer2 systemd[1]: Listening on Nix Daemon Socket.408peer2 # [391677.099062] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.409peer2 # [391677.099075] peer2 systemd[1]: Reached target Socket Units.410peer2 # [391677.099096] peer2 systemd[1]: Reached target Basic System.411peer2 # [391677.099881] peer2 systemd[1]: Starting data mesher daemon...412peer2 # [391677.100255] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...413peer2 # [391677.100759] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...414peer2 # [391677.101381] peer2 systemd[1]: Starting D-Bus System Message Bus...415peer2 # [391677.135571] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.416peer2 # [391677.184743] peer2 nsncd[220]: Sep 08 20:04:51.608 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"417peer2 # [391677.184785] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).418peer2 # [391677.184832] peer2 systemd[1]: Reached target Host and Network Name Lookups.419peer2 # [391677.184867] peer2 systemd[1]: Reached target User and Group Name Lookups.420peer2 # [391677.185547] peer2 systemd[1]: Starting User Login Management...421peer2 # [391677.185868] peer2 systemd[1]: Starting Permit User Sessions...422peer2 # [391677.211195] peer2 systemd[1]: Finished Permit User Sessions.423peer2 # [391677.211717] peer2 systemd[1]: Started Console Getty.424peer2 # [391677.211742] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0425peer2 # [391677.211758] peer2 systemd[1]: Reached target Login Prompts.426peer2 # [391677.242929] peer2 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'...427peer2 # [391677.243361] peer2 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync'428peer2 # [391677.243361] peer2 dbus-broker-launch[221]: Invalid user-name in /nix/store/czz5jmv7wbdqn6q0lz0zg5p0mmzw7pn8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"429peer2 # [391677.243637] peer2 systemd[1]: Started D-Bus System Message Bus.430peer2 # [391677.246997] peer2 dbus-broker-launch[221]: Ready431peer1 # [391677.589787] peer1 data-mesher[218]: time=2026-09-08T20:04:52.013Z level=INFO msg="peer connected" peer_id=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY remote_addr=/ip4/192.168.1.3/tcp/7946432peer2 # [391677.577074] peer2 data-mesher[218]: time=2026-09-08T20:04:52.000Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]433controller # [391677.587191] controller data-mesher[229]: time=2026-09-08T20:04:52.010Z level=INFO msg="peer connected" peer_id=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY remote_addr=/ip4/192.168.1.3/tcp/7946434peer2 # [391677.577434] peer2 data-mesher[218]: time=2026-09-08T20:04:52.000Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ: [/dns/controller.clan/tcp/7946]} {12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p: [/dns/peer1.clan/tcp/7946]} {12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY435peer2 # [391677.577434] peer2 data-mesher[218]: time=2026-09-08T20:04:52.000Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml436peer2 # [391677.579678] peer2 data-mesher[218]: time=2026-09-08T20:04:52.002Z level=INFO msg="checking file integrity"437peer2 # [391677.581867] peer2 data-mesher[218]: time=2026-09-08T20:04:52.003Z level=INFO msg="file integrity check complete"438peer2 # [391677.584391] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="libp2p host created" peer_id=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY 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::e72d:3879:741e:fd3/tcp/7946]"439peer2 # [391677.584489] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="registered HTTP route" method=GET path=/files440peer2 # [391677.584489] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name441peer2 # [391677.584489] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name442peer2 # [391677.584489] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="starting server"443peer2 # [391677.584587] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="waiting for DHT to populate" delay=10s444peer2 # [391677.584705] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="HTTP server listening" address=[::1]:7331445peer2 # [391677.584705] peer2 data-mesher[218]: time=2026-09-08T20:04:52.007Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331446peer2 # [391677.586997] peer2 data-mesher[218]: time=2026-09-08T20:04:52.010Z level=INFO msg="peer connected" peer_id=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ remote_addr=/ip4/192.168.1.1/tcp/7946447peer2 # [391677.589572] peer2 data-mesher[218]: time=2026-09-08T20:04:52.012Z level=INFO msg="peer connected" peer_id=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p remote_addr=/ip4/192.168.1.2/tcp/7946448peer2 # [391677.591533] peer2 systemd-logind[238]: New seat seat0.449peer2 # [391677.591642] peer2 systemd[1]: Started User Login Management.450peer2 # [391677.592358] peer2 systemd[1]: Starting linger-users.service...451peer2 # [391677.613131] peer2 systemd[1]: linger-users.service: Deactivated successfully.452peer2 # [391677.613225] peer2 systemd[1]: Finished linger-users.service.453peer2 # [391678.186744] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.454peer2 # [391678.187863] peer2 systemd[1]: Finished Save Transient machine-id to Disk.455peer2 # [391678.720092] peer2 systemd-networkd[206]: eth1: Gained IPv6LL456peer2 # [391679.166844] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ457peer2 # [391679.166844] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ458peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=DEBUG msg="new file detected" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller459peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=DEBUG msg="new file detected" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk460peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller461peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk462peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk signed_at="2026-09-08 20:04:44.694 +0000 UTC" signed_by="rPbrAJQgeN0ICcUq9O5ES+HH8jpfrE3tkDoyza5cfOk=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ463peer2 # [391679.167149] peer2 data-mesher[218]: time=2026-09-08T20:04:53.590Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 20:04:43.63 +0000 UTC" signed_by="PKlk8hemeNDxBd6SVkZfrB47os+Bu4NqUQlplTZt7KQ=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ464peer2 # [391679.170521] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...465peer2 # [391679.239683] peer2 dm-wg-star-reconfig[270]: No controller data available yet, skipping466peer2 # [391679.240458] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.467peer2 # [391679.240605] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.468peer2 # [391679.328535] peer2 data-mesher[218]: time=2026-09-08T20:04:53.751Z level=INFO msg="download complete" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk signed_at="2026-09-08 20:04:44.694 +0000 UTC" signed_by="rPbrAJQgeN0ICcUq9O5ES+HH8jpfrE3tkDoyza5cfOk=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ written=true elapsed=161.536067ms469peer2 # [391679.329741] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...470peer2 # [391679.357560] peer2 data-mesher[218]: time=2026-09-08T20:04:53.780Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-08 20:04:43.63 +0000 UTC" signed_by="PKlk8hemeNDxBd6SVkZfrB47os+Bu4NqUQlplTZt7KQ=" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ written=true elapsed=190.487531ms471peer2 # [391679.402461] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.472peer2 # [391679.402548] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.473controller # [391679.166419] controller data-mesher[229]: time=2026-09-08T20:04:53.589Z level=DEBUG msg="attempting push/pull" peer_count=1474controller # [391679.166735] controller data-mesher[229]: time=2026-09-08T20:04:53.589Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s475controller # [391679.167036] controller data-mesher[229]: time=2026-09-08T20:04:53.590Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY476controller # [391679.167036] controller data-mesher[229]: time=2026-09-08T20:04:53.590Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s477controller # [391679.167101] controller data-mesher[229]: time=2026-09-08T20:04:53.590Z level=DEBUG msg="push/pull successful" interval=5s478controller # [391679.167291] controller data-mesher[229]: time=2026-09-08T20:04:53.590Z level=INFO msg="received file request" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk479controller # [391679.167321] controller data-mesher[229]: time=2026-09-08T20:04:53.590Z level=INFO msg="received file request" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/controller480controller # [391679.168150] controller data-mesher[229]: time=2026-09-08T20:04:53.591Z level=INFO msg="file transfer complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/rPbrAJQgeN0ICcUq9O5ES-HH8jpfrE3tkDoyza5cfOk481controller # [391679.168373] controller data-mesher[229]: time=2026-09-08T20:04:53.591Z level=INFO msg="file transfer complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/controller482peer2 # [391680.195975] peer2 data-mesher[218]: time=2026-09-08T20:04:54.619Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p483peer2 # [391680.195975] peer2 data-mesher[218]: time=2026-09-08T20:04:54.619Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p484peer1 # [391680.195564] peer1 data-mesher[218]: time=2026-09-08T20:04:54.618Z level=DEBUG msg="attempting push/pull" peer_count=1485peer1 # [391680.195852] peer1 data-mesher[218]: time=2026-09-08T20:04:54.618Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s486peer1 # [391680.196191] peer1 data-mesher[218]: time=2026-09-08T20:04:54.619Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY487peer1 # [391680.196243] peer1 data-mesher[218]: time=2026-09-08T20:04:54.619Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s488peer1 # [391680.196271] peer1 data-mesher[218]: time=2026-09-08T20:04:54.619Z level=DEBUG msg="push/pull successful" interval=5s489peer2 # [391684.167496] peer2 data-mesher[218]: time=2026-09-08T20:04:58.590Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ490peer2 # [391684.167496] peer2 data-mesher[218]: time=2026-09-08T20:04:58.590Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ491controller # [391684.167172] controller data-mesher[229]: time=2026-09-08T20:04:58.590Z level=DEBUG msg="attempting push/pull" peer_count=1492controller # [391684.167172] controller data-mesher[229]: time=2026-09-08T20:04:58.590Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s493controller # [391684.167732] controller data-mesher[229]: time=2026-09-08T20:04:58.591Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY494controller # [391684.167799] controller data-mesher[229]: time=2026-09-08T20:04:58.591Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s495controller # [391684.167843] controller data-mesher[229]: time=2026-09-08T20:04:58.591Z level=DEBUG msg="push/pull successful" interval=5s496peer2 # [391685.197372] peer2 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p497peer2 # [391685.197372] peer2 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p498peer1 # [391685.197162] peer1 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=DEBUG msg="attempting push/pull" peer_count=1499peer1 # [391685.197434] peer1 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s500peer1 # [391685.197499] peer1 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY501peer1 # [391685.197558] peer1 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s502peer1 # [391685.197578] peer1 data-mesher[218]: time=2026-09-08T20:04:59.620Z level=DEBUG msg="push/pull successful" interval=5s503peer2: still waiting for container 'peer2' to reach ready state...504peer2 # [391687.585151] peer2 data-mesher[218]: time=2026-09-08T20:05:02.008Z level=INFO msg="performing state exchange with peers on join" count=1505peer2 # [391687.585511] peer2 data-mesher[218]: time=2026-09-08T20:05:02.008Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s506peer2 # [391687.585546] peer2 data-mesher[218]: time=2026-09-08T20:05:02.008Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ507peer2 # [391687.585617] peer2 data-mesher[218]: time=2026-09-08T20:05:02.008Z level=INFO msg="state exchange complete" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ timeout=5s508peer2 # [391687.585650] peer2 data-mesher[218]: time=2026-09-08T20:05:02.008Z level=INFO msg="server started"509peer2 # [391687.585707] peer2 data-mesher[218]: time=2026-09-08T20:05:02.009Z level=INFO msg="starting expired-file sweeper" interval=1m0s510peer2 # [391687.585783] peer2 systemd[1]: Started data mesher daemon.511peer2 # [391687.586430] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...512peer2 # [391687.673433] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...513peer2 # [391687.726314] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.514controller # [391687.585388] controller data-mesher[229]: time=2026-09-08T20:05:02.008Z level=INFO msg="received state sync from peer" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY515controller # [391687.585388] controller data-mesher[229]: time=2026-09-08T20:05:02.008Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY516peer2: (finished: waiting for unit data-mesher.service, in 12.14 seconds)517??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.518 File "/nix/store/lpy0ms3by1jh6bllyr4fc0hv1dcr96q2-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39519controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1520??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.521 File "/nix/store/lpy0ms3by1jh6bllyr4fc0hv1dcr96q2-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39522peer2 # [391687.726400] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.523peer2 # [391687.838488] peer2 data-mesher[218]: time=2026-09-08T20:05:02.261Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs status=204524peer2 # [391687.838542] peer2 dm-wg-star-publish[289]: Status: 204 No Content525peer2 # [391687.841263] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.526peer2 # [391687.841418] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.527peer2 # [391687.841843] peer2 systemd[1]: Reached target Multi-User System.528peer2 # [391687.841971] peer2 systemd[1]: Startup finished in 11.772s.529controller # [391689.168878] controller data-mesher[229]: time=2026-09-08T20:05:03.592Z level=DEBUG msg="attempting push/pull" peer_count=1530controller # [391689.169112] controller data-mesher[229]: time=2026-09-08T20:05:03.592Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s531controller # [391689.169287] controller data-mesher[229]: time=2026-09-08T20:05:03.592Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p532controller # [391689.169346] controller data-mesher[229]: time=2026-09-08T20:05:03.592Z level=INFO msg="state exchange complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s533controller # [391689.169365] controller data-mesher[229]: time=2026-09-08T20:05:03.592Z level=DEBUG msg="push/pull successful" interval=5s534peer1 # [391689.169134] peer1 data-mesher[218]: time=2026-09-08T20:05:03.592Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ535peer1 # [391689.169134] peer1 data-mesher[218]: time=2026-09-08T20:05:03.592Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ536peer2 # [391690.198263] peer2 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p537peer2 # [391690.198263] peer2 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p538peer2 # [391690.198783] peer2 data-mesher[218]: time=2026-09-08T20:05:04.622Z level=INFO msg="received file request" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs539peer2 # [391690.199643] peer2 data-mesher[218]: time=2026-09-08T20:05:04.622Z level=INFO msg="file transfer complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs540peer1 # [391690.198026] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=DEBUG msg="attempting push/pull" peer_count=1541peer1 # [391690.198026] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s542peer1 # [391690.198443] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY543peer1 # [391690.198498] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=DEBUG msg="new file detected" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs544peer1 # [391690.198552] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s545peer1 # [391690.198576] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=DEBUG msg="push/pull successful" interval=5s546peer1 # [391690.198596] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs547peer1 # [391690.198622] peer1 data-mesher[218]: time=2026-09-08T20:05:04.621Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs signed_at="2026-09-08 20:05:02.083 +0000 UTC" signed_by="82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs=" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY548peer1 # [391690.201593] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...549peer1 # [391690.256278] peer1 data-mesher[218]: time=2026-09-08T20:05:04.679Z level=INFO msg="download complete" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs signed_at="2026-09-08 20:05:02.083 +0000 UTC" signed_by="82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs=" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY written=true elapsed=57.599015ms550peer1 # [391690.275889] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.551peer1 # [391690.276022] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.552peer2 # [391692.586260] peer2 data-mesher[218]: time=2026-09-08T20:05:07.009Z level=DEBUG msg="attempting push/pull" peer_count=2553peer2 # [391692.586533] peer2 data-mesher[218]: time=2026-09-08T20:05:07.009Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s554peer2 # [391692.586955] peer2 data-mesher[218]: time=2026-09-08T20:05:07.010Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p555peer2 # [391692.587121] peer2 data-mesher[218]: time=2026-09-08T20:05:07.010Z level=INFO msg="state exchange complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s556peer2 # [391692.587152] peer2 data-mesher[218]: time=2026-09-08T20:05:07.010Z level=DEBUG msg="push/pull successful" interval=5s557peer1 # [391692.586678] peer1 data-mesher[218]: time=2026-09-08T20:05:07.009Z level=INFO msg="received state sync from peer" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY558peer1 # [391692.586678] peer1 data-mesher[218]: time=2026-09-08T20:05:07.010Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY559peer1 # [391694.170649] peer1 data-mesher[218]: time=2026-09-08T20:05:08.593Z level=INFO msg="received state sync from peer" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ560controller # [391694.170311] controller data-mesher[229]: time=2026-09-08T20:05:08.593Z level=DEBUG msg="attempting push/pull" peer_count=1561peer1 # [391694.170649] peer1 data-mesher[218]: time=2026-09-08T20:05:08.593Z level=INFO msg="merging remote state" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ562controller # [391694.170311] controller data-mesher[229]: time=2026-09-08T20:05:08.593Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s563controller # [391694.170859] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p564peer1 # [391694.171154] peer1 data-mesher[218]: time=2026-09-08T20:05:08.594Z level=INFO msg="received file request" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs565controller # [391694.170937] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=DEBUG msg="new file detected" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs566controller # [391694.171007] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=INFO msg="state exchange complete" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p timeout=5s567controller # [391694.171041] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs568peer1 # [391694.171516] peer1 data-mesher[218]: time=2026-09-08T20:05:08.594Z level=INFO msg="file transfer complete" peer=12D3KooWMgGvRFTyvX36TqLaAER3KJbS4xhtQb1HnfjBbecErbZQ network="0sIo7YBMvbiT4ACD/n0sHmIQ32W0K1SCDe/DihxLyQQ=" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs569controller # [391694.171041] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=DEBUG msg="push/pull successful" interval=5s570controller # [391694.171081] controller data-mesher[229]: time=2026-09-08T20:05:08.594Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs signed_at="2026-09-08 20:05:02.083 +0000 UTC" signed_by="82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs=" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p571controller # [391694.173786] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...572controller # [391694.266770] controller data-mesher[229]: time=2026-09-08T20:05:08.690Z level=INFO msg="download complete" name=dm_wg_star_wg_star/82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs signed_at="2026-09-08 20:05:02.083 +0000 UTC" signed_by="82c9G1XKOaTnHMV1wQIpHZXMKSgO6EXtrD5CTYDyQhs=" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p written=true elapsed=95.661693ms573controller # [391694.285625] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.574controller # [391694.285769] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.575controller: (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 7.05 seconds)576controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1577controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)578peer2: waiting for success: wg show wg-star peers | grep -q .579peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)580peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::68c9:cea0:7ad3:6a46581peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::68c9:cea0:7ad3:6a46, in 0.24 seconds)582controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e72d:3879:741e:0fd3583controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e72d:3879:741e:0fd3, in 0.00 seconds)584peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e72d:3879:741e:0fd3585peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e72d:3879:741e:0fd3, in 0.00 seconds)586peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e12c:c7e2:7bb8:b3e3587peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::e12c:c7e2:7bb8:b3e3, in 0.00 seconds)588(finished: run the VM test script, in 45.81 seconds)589peer2 # [391695.199652] peer2 data-mesher[218]: time=2026-09-08T20:05:09.622Z level=INFO msg="received state sync from peer" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p590peer2 # [391695.199652] peer2 data-mesher[218]: time=2026-09-08T20:05:09.622Z level=INFO msg="merging remote state" peer=12D3KooWMTYfiY6zZWSiAjPjDG7DY2GaGdc5B73P5FVZK7YzcQ8p591peer1 # [391695.199243] peer1 data-mesher[218]: time=2026-09-08T20:05:09.622Z level=DEBUG msg="attempting push/pull" peer_count=1592peer1 # [391695.199514] peer1 data-mesher[218]: time=2026-09-08T20:05:09.622Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s593peer1 # [391695.199921] peer1 data-mesher[218]: time=2026-09-08T20:05:09.623Z level=INFO msg="merging remote state" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY594peer1 # [391695.200053] peer1 data-mesher[218]: time=2026-09-08T20:05:09.623Z level=INFO msg="state exchange complete" peer=12D3KooWSCWYWvY4pNgtFpxMHUhHUoVEwKmFKrwksJ7eiN2UKkhY timeout=5s595peer1 # [391695.200074] peer1 data-mesher[218]: time=2026-09-08T20:05:09.623Z level=DEBUG msg="push/pull successful" interval=5s596test script finished in 47.26s597cleanup598kill NspawnMachine (pid 50)599kill NspawnMachine (pid 53)600Container controller terminated by signal KILL.601kill NspawnMachine (pid 740)602Container peer1 terminated by signal KILL.603Container peer2 terminated by signal KILL.604(finished: cleanup, in 0.34 seconds)