container-test-run-dm-wireguard-star
checks.x86_64-linux.dm-wireguard-star
· build #103
· 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(controller): TAP vde-tap1 not found; container will be isolated from VDE17nixos-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.18nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE19nixos-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.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 # [8244293.114467] peer1 systemd-journald[96]: Journal started25controller # [8244293.120743] controller systemd-journald[106]: Journal started26peer1 # [8244293.114508] peer1 systemd-journald[96]: Runtime Journal (/run/log/journal/043904ce42da4489acc5f6c50c8b13ff) is 8M, max 3.7G, 3.7G free.27controller # [8244293.120774] controller systemd-journald[106]: Runtime Journal (/run/log/journal/d0b348bc9c364cb3b0f00ee871623a7a) is 8M, max 3.7G, 3.7G free.28peer1 # [8244293.114979] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29controller # [8244293.121498] controller systemd[1]: Finished Apply Kernel Variables.30peer1 # [8244293.119762] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...31controller # [8244293.126162] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.32peer1 # [8244293.120130] peer1 systemd[1]: Starting Network Name Resolution...33controller # [8244293.131850] controller systemd[1]: Starting Flush Journal to Persistent Storage...34controller # [8244293.132202] controller systemd[1]: Starting Network Name Resolution...35peer1 # [8244293.120464] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...36controller # [8244293.132597] controller systemd[1]: Starting Create Static Device Nodes in /dev...37peer1 # [8244293.125043] peer1 systemd-journald[96]: Time spent on flushing to /var/log/journal/043904ce42da4489acc5f6c50c8b13ff is 1.366ms for 6 entries.38controller # [8244293.136448] controller systemd-journald[106]: Time spent on flushing to /var/log/journal/d0b348bc9c364cb3b0f00ee871623a7a is 1.466ms for 7 entries.39peer1 # [8244293.125043] peer1 systemd-journald[96]: System Journal (/var/log/journal/043904ce42da4489acc5f6c50c8b13ff) is 8M, max 4G, 3.9G free.40controller # [8244293.136448] controller systemd-journald[106]: System Journal (/var/log/journal/d0b348bc9c364cb3b0f00ee871623a7a) is 8M, max 4G, 3.9G free.41peer1 # [8244293.129418] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.42controller # [8244293.140175] controller systemd[1]: Finished Create Static Device Nodes in /dev.43peer1 # [8244293.129731] peer1 systemd[1]: Reached target Preparation for Local File Systems.44peer1 # [8244293.129783] peer1 systemd[1]: Reached target Local File Systems.45controller # [8244293.140287] controller systemd[1]: Reached target Preparation for Local File Systems.46peer1 # [8244293.130241] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.47controller # [8244293.140331] controller systemd[1]: Reached target Local File Systems.48controller # [8244293.140727] controller systemd[1]: Listening on Boot Loader Control Service Socket.49peer1 # [8244293.130267] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container50controller # [8244293.140754] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container51controller # [8244293.141071] controller systemd[1]: Starting Save Transient machine-id to Disk...52controller # [8244293.141088] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys53peer1 # [8244293.130605] peer1 systemd[1]: Starting Save Transient machine-id to Disk...54peer1 # [8244293.130621] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys55controller # [8244293.218147] controller systemd[1]: Finished Firewall.56peer1 # [8244293.195575] peer1 systemd[1]: Finished Firewall.57controller # [8244293.218401] controller systemd[1]: Finished Flush Journal to Persistent Storage.58peer1 # [8244293.195672] peer1 systemd[1]: Reached target Preparation for Network.59controller # [8244293.218773] controller systemd[1]: Reached target Preparation for Network.60controller # [8244293.218938] controller systemd[1]: Listening on Network Management Resolve Hook Socket.61peer1 # [8244293.195813] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.62controller # [8244293.219545] controller systemd[1]: Starting Network Management...63peer1 # [8244293.196452] peer1 systemd[1]: Starting Network Management...64controller # [8244293.219837] controller systemd[1]: Starting Create System Files and Directories...65peer1 # [8244293.197025] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.66peer1 # [8244293.197618] peer1 systemd[1]: Starting Create System Files and Directories...67peer1 # [8244293.226959] peer1 systemd-tmpfiles[206]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted68controller # [8244293.229487] controller systemd-tmpfiles[218]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted69controller # [8244293.229633] controller systemd-tmpfiles[218]: fchmod() of /var/log/journal failed: Operation not permitted70peer1 # [8244293.227118] peer1 systemd-tmpfiles[206]: fchmod() of /var/log/journal failed: Operation not permitted71peer1 # [8244293.227225] peer1 systemd-tmpfiles[206]: fchmod() of /var/log/journal/043904ce42da4489acc5f6c50c8b13ff failed: Operation not permitted72controller # [8244293.229738] controller systemd-tmpfiles[218]: fchmod() of /var/log/journal/d0b348bc9c364cb3b0f00ee871623a7a failed: Operation not permitted73peer1 # [8244293.227380] peer1 systemd-tmpfiles[206]: fchmod() of /run/log/journal failed: Operation not permitted74controller # [8244293.229890] controller systemd-tmpfiles[218]: fchmod() of /run/log/journal failed: Operation not permitted75peer1 # [8244293.228276] peer1 systemd[1]: Finished Create System Files and Directories.76controller # [8244293.230656] controller systemd[1]: Finished Create System Files and Directories.77controller # [8244293.231145] controller systemd[1]: Starting Rebuild Journal Catalog...78peer1 # [8244293.228988] peer1 systemd[1]: Starting Rebuild Journal Catalog...79controller # [8244293.231565] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...80peer1 # [8244293.229426] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...81controller # [8244293.240128] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.82controller # [8244293.243234] controller systemd[1]: Finished Rebuild Journal Catalog.83peer1 # [8244293.236032] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.84controller # [8244293.243798] controller systemd[1]: Starting Update is Completed...85peer1 # [8244293.242048] peer1 systemd[1]: Finished Rebuild Journal Catalog.86controller # [8244293.248964] controller systemd[1]: Finished Update is Completed.87peer1 # [8244293.242500] peer1 systemd[1]: Starting Update is Completed...88peer1 # [8244293.247217] peer1 systemd[1]: Finished Update is Completed.89controller # [8244293.524534] controller systemd-networkd[217]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted90peer1 # [8244293.512187] peer1 systemd-networkd[204]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted91controller # [8244293.524609] controller systemd-networkd[217]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted92peer1 # [8244293.512272] peer1 systemd-networkd[204]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted93controller # [8244293.531510] controller systemd-networkd[217]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.94peer1 # [8244293.519332] peer1 systemd-networkd[204]: /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.95controller # [8244293.531663] controller systemd-networkd[217]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.96peer1 # [8244293.519483] peer1 systemd-networkd[204]: /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.97controller # [8244293.531740] controller systemd-networkd[217]: lo: Link UP98peer1 # [8244293.519565] peer1 systemd-networkd[204]: lo: Link UP99peer1 # [8244293.519569] peer1 systemd-networkd[204]: lo: Gained carrier100controller # [8244293.531743] controller systemd-networkd[217]: lo: Gained carrier101peer1 # [8244293.519736] peer1 systemd-networkd[204]: eth1: Configuring with /etc/systemd/network/40-eth1.network.102peer1 # [8244293.519988] peer1 systemd[1]: Started Network Management.103controller # [8244293.531888] controller systemd-networkd[217]: eth1: Configuring with /etc/systemd/network/40-eth1.network.104peer1 # [8244293.520459] peer1 systemd-networkd[204]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.105controller # [8244293.532160] controller systemd[1]: Started Network Management.106peer1 # [8244293.520658] peer1 systemd-networkd[204]: wg-star: netdev ready107controller # [8244293.543190] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...108peer1 # [8244293.520752] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...109controller # [8244293.543495] controller systemd-networkd[217]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.110peer1 # [8244293.520775] peer1 systemd-networkd[204]: eth1: Link UP111controller # [8244293.543682] controller systemd-networkd[217]: wg-star: netdev ready112peer1 # [8244293.520778] peer1 systemd-networkd[204]: eth1: Gained carrier113controller # [8244293.543779] controller systemd-networkd[217]: eth1: Link UP114peer1 # [8244293.542395] peer1 systemd-networkd[204]: wg-star: Link UP115controller # [8244293.543887] controller systemd-networkd[217]: eth1: Gained carrier116peer1 # [8244293.542400] peer1 systemd-networkd[204]: wg-star: Gained carrier117controller # [8244293.553591] controller systemd-networkd[217]: wg-star: Link UP118peer1 # [8244293.548867] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.119controller # [8244293.553596] controller systemd-networkd[217]: wg-star: Gained carrier120peer1 # [8244293.703840] peer1 systemd-resolved[120]: Positive Trust Anchors:121controller # [8244293.554252] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.122peer1 # [8244293.703851] peer1 systemd-resolved[120]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d123controller # [8244293.737730] controller systemd-resolved[132]: Positive Trust Anchors:124peer1 # [8244293.703854] peer1 systemd-resolved[120]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16125controller # [8244293.737739] controller systemd-resolved[132]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d126peer1 # [8244293.703870] peer1 systemd-resolved[120]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test127controller # [8244293.737741] controller systemd-resolved[132]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16128peer1 # [8244293.715859] peer1 systemd-resolved[120]: Using system hostname 'peer1'.129controller # [8244293.737759] controller systemd-resolved[132]: 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 test130controller # [8244293.749379] controller systemd-resolved[132]: Using system hostname 'controller'.131controller # [8244293.750594] controller systemd[1]: Started Network Name Resolution.132peer1 # [8244293.717542] peer1 systemd[1]: Started Network Name Resolution.133peer1 # [8244293.717624] peer1 systemd[1]: Reached target Network.134peer1 # [8244293.717687] peer1 systemd[1]: Reached target System Initialization.135peer1 # [8244293.717773] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.136controller # [8244293.750670] controller systemd[1]: Reached target Network.137peer1 # [8244293.717797] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.138controller # [8244293.750723] controller systemd[1]: Reached target System Initialization.139peer1 # [8244293.717821] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container140controller # [8244293.750799] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.141peer1 # [8244293.717841] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.142controller # [8244293.750825] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container143peer1 # [8244293.717858] peer1 systemd[1]: Reached target Path Units.144controller # [8244293.750852] controller systemd[1]: Started Daily Cleanup of Temporary Directories.145peer1 # [8244293.717886] peer1 systemd[1]: Reached target Timer Units.146controller # [8244293.750870] controller systemd[1]: Reached target Path Units.147peer1 # [8244293.718006] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.148controller # [8244293.750899] controller systemd[1]: Reached target Timer Units.149peer1 # [8244293.718099] peer1 systemd[1]: Listening on Nix Daemon Socket.150controller # [8244293.751019] controller systemd[1]: Listening on D-Bus System Message Bus Socket.151peer1 # [8244293.718199] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.152controller # [8244293.751113] controller systemd[1]: Listening on Nix Daemon Socket.153peer1 # [8244293.718219] peer1 systemd[1]: Reached target Socket Units.154controller # [8244293.751208] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.155peer1 # [8244293.718247] peer1 systemd[1]: Reached target Basic System.156controller # [8244293.751225] controller systemd[1]: Reached target Socket Units.157peer1 # [8244293.719370] peer1 systemd[1]: Starting data mesher daemon...158controller # [8244293.751254] controller systemd[1]: Reached target Basic System.159peer1 # [8244293.719841] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...160controller # [8244293.752138] controller systemd[1]: Starting data mesher daemon...161peer1 # [8244293.720347] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...162controller # [8244293.752482] controller systemd[1]: Starting Import lastlog data into lastlog2 database...163peer1 # [8244293.736165] peer1 systemd[1]: Starting D-Bus System Message Bus...164controller # [8244293.752865] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...165peer1 # [8244293.744569] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.166controller # [8244293.753564] controller systemd[1]: Starting D-Bus System Message Bus...167controller # [8244293.763860] controller systemd[1]: Finished Import lastlog data into lastlog2 database.168peer1 # [8244293.866295] peer1 nsncd[220]: Sep 03 20:05:51.231 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"169peer1 # [8244293.866367] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).170peer1 # [8244293.866421] peer1 systemd[1]: Reached target Host and Network Name Lookups.171peer1 # [8244293.866463] peer1 systemd[1]: Reached target User and Group Name Lookups.172peer1 # [8244293.867516] peer1 systemd[1]: Starting User Login Management...173peer1 # [8244293.867867] peer1 systemd[1]: Starting Permit User Sessions...174peer1 # [8244293.894490] peer1 systemd[1]: Finished Permit User Sessions.175peer1 # [8244293.894970] peer1 systemd[1]: Started Console Getty.176peer1 # [8244293.894990] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0177peer1 # [8244293.895007] peer1 systemd[1]: Reached target Login Prompts.178peer1 # [8244293.940647] peer1 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'...179peer1 # [8244293.941310] peer1 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync'180peer1 # [8244293.941310] peer1 dbus-broker-launch[221]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"181peer1 # [8244293.941630] peer1 systemd[1]: Started D-Bus System Message Bus.182peer1 # [8244293.945271] peer1 dbus-broker-launch[221]: Ready183controller # [8244293.881951] controller nsncd[232]: Sep 03 20:05:51.247 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"184controller # [8244293.882114] controller systemd[1]: Started Name Service Cache Daemon (nsncd).185controller # [8244293.882188] controller systemd[1]: Reached target Host and Network Name Lookups.186controller # [8244293.882237] controller systemd[1]: Reached target User and Group Name Lookups.187controller # [8244293.914191] controller systemd[1]: Starting User Login Management...188controller # [8244293.915175] controller systemd[1]: Starting Permit User Sessions...189controller # [8244293.938284] controller systemd[1]: Finished Permit User Sessions.190controller # [8244293.939738] controller systemd[1]: Started Console Getty.191controller # [8244293.939772] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0192controller # [8244293.939789] controller systemd[1]: Reached target Login Prompts.193controller # [8244293.963179] controller dbus-broker-launch[233]: Looking up NSS user entry for 'systemd-timesync'...194controller # [8244293.971644] controller dbus-broker-launch[233]: NSS returned no entry for 'systemd-timesync'195controller # [8244293.971644] controller dbus-broker-launch[233]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"196controller # [8244293.963912] controller systemd[1]: Started D-Bus System Message Bus.197controller # [8244293.967327] controller dbus-broker-launch[233]: Ready198controller # [8244294.243671] controller data-mesher[230]: time=2026-09-03T20:05:51.609Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]199controller # [8244294.243961] controller data-mesher[230]: time=2026-09-03T20:05:51.609Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe: [/dns/controller.clan/tcp/7946]} {12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6: [/dns/peer1.clan/tcp/7946]} {12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe200controller # [8244294.244017] controller data-mesher[230]: time=2026-09-03T20:05:51.609Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml201controller # [8244294.356242] controller data-mesher[230]: time=2026-09-03T20:05:51.721Z level=INFO msg="checking file integrity"202controller # [8244294.358250] controller systemd-logind[250]: New seat seat0.203controller # [8244294.358371] controller systemd[1]: Started User Login Management.204controller # [8244294.359242] controller systemd[1]: Starting linger-users.service...205controller # [8244294.366629] controller data-mesher[230]: time=2026-09-03T20:05:51.732Z level=INFO msg="file integrity check complete"206controller # [8244294.367801] controller systemd[1]: linger-users.service: Deactivated successfully.207controller # [8244294.367896] controller systemd[1]: Finished linger-users.service.208controller # [8244294.370005] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="libp2p host created" peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe 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::c394:99ee:a1d8:c56b/tcp/7946]"209controller # [8244294.370041] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="registered HTTP route" method=GET path=/files210controller # [8244294.370041] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name211controller # [8244294.370041] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name212controller # [8244294.370091] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="starting server"213controller # [8244294.370132] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="waiting for DHT to populate" delay=10s214controller # [8244294.370174] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="HTTP server listening" address=[::1]:7331215controller # [8244294.370195] controller data-mesher[230]: time=2026-09-03T20:05:51.735Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331216peer1 # [8244294.201189] peer1 data-mesher[218]: time=2026-09-03T20:05:51.566Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]217peer1 # [8244294.202669] peer1 data-mesher[218]: time=2026-09-03T20:05:51.568Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe: [/dns/controller.clan/tcp/7946]} {12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6: [/dns/peer1.clan/tcp/7946]} {12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6218peer1 # [8244294.202721] peer1 data-mesher[218]: time=2026-09-03T20:05:51.568Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml219peer1 # [8244294.313442] peer1 systemd-logind[238]: New seat seat0.220peer1 # [8244294.313637] peer1 systemd[1]: Started User Login Management.221peer1 # [8244294.314433] peer1 systemd[1]: Starting linger-users.service...222peer1 # [8244294.321243] peer1 systemd[1]: linger-users.service: Deactivated successfully.223peer1 # [8244294.321358] peer1 systemd[1]: Finished linger-users.service.224peer1 # [8244294.356261] peer1 data-mesher[218]: time=2026-09-03T20:05:51.721Z level=INFO msg="checking file integrity"225peer1 # [8244294.366691] peer1 data-mesher[218]: time=2026-09-03T20:05:51.732Z level=INFO msg="file integrity check complete"226peer1 # [8244294.370306] peer1 data-mesher[218]: time=2026-09-03T20:05:51.735Z level=INFO msg="libp2p host created" peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 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::d4f:1b69:5415:6cc4/tcp/7946]"227peer1 # [8244294.370369] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name228peer1 # [8244294.370369] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name229peer1 # [8244294.370369] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="registered HTTP route" method=GET path=/files230peer1 # [8244294.370369] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="starting server"231peer1 # [8244294.370426] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="HTTP server listening" address=[::1]:7331232peer1 # [8244294.370426] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331233peer1 # [8244294.370455] peer1 data-mesher[218]: time=2026-09-03T20:05:51.736Z level=INFO msg="waiting for DHT to populate" delay=10s234peer1 # [8244295.294122] peer1 systemd-networkd[204]: eth1: Gained IPv6LL235controller # [8244295.358176] controller systemd-networkd[217]: eth1: Gained IPv6LL236peer1 # [8244296.167722] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.237peer1 # [8244296.168493] peer1 systemd[1]: Finished Save Transient machine-id to Disk.238controller # [8244296.166888] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.239controller # [8244296.167793] controller systemd[1]: Finished Save Transient machine-id to Disk.240peer1 # [8244299.374082] peer1 data-mesher[218]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe remote_addr=/ip4/192.168.1.1/tcp/7946241peer1 # [8244299.374434] peer1 data-mesher[218]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe remote_addr=/ip6/2001:db8:1::1/tcp/7946242peer1 # [8244299.374434] peer1 data-mesher[218]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe remote_addr=/ip4/192.168.1.1/tcp/7946243controller # [8244299.373666] controller data-mesher[230]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 remote_addr=/ip4/192.168.1.2/tcp/7946244controller # [8244299.373666] controller data-mesher[230]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 remote_addr=/ip6/2001:db8:1::2/tcp/7946245controller # [8244299.374290] controller data-mesher[230]: time=2026-09-03T20:05:56.739Z level=INFO msg="peer connected" peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 remote_addr=/ip4/192.168.1.2/tcp/44650246controller: still waiting for container 'controller' to reach ready state...247controller: (finished: waiting for unit data-mesher.service, in 12.14 seconds)248peer1: waiting for unit data-mesher.service249peer1: (finished: waiting for unit data-mesher.service, in 0.01 seconds)250??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.251 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39252controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller253??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.254 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39255controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)256peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller257peer1 # [8244304.371233] peer1 data-mesher[218]: time=2026-09-03T20:06:01.736Z level=INFO msg="performing state exchange with peers on join" count=1258peer1 # [8244304.371233] peer1 data-mesher[218]: time=2026-09-03T20:06:01.736Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s259peer1 # [8244304.371558] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe260peer1 # [8244304.371558] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe261peer1 # [8244304.371558] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe262peer1 # [8244304.371558] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="state exchange complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s263peer1 # [8244304.371558] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="server started"264peer1 # [8244304.371661] peer1 data-mesher[218]: time=2026-09-03T20:06:01.737Z level=INFO msg="starting expired-file sweeper" interval=1m0s265peer1 # [8244304.371723] peer1 systemd[1]: Started data mesher daemon.266peer1 # [8244304.372605] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...267peer1 # [8244304.456854] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...268peer1 # [8244304.470941] peer1 data-mesher[218]: time=2026-09-03T20:06:01.836Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 status=204269peer1 # [8244304.471029] peer1 dm-wg-star-publish[274]: Status: 204 No Content270peer1 # [8244304.476088] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.271peer1 # [8244304.476131] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.272peer1 # [8244304.476504] peer1 systemd[1]: Reached target Multi-User System.273peer1 # [8244304.520560] peer1 dm-wg-star-reconfig[289]: No controller data available yet, skipping274peer1 # [8244304.521460] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.275peer1 # [8244304.521539] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.276peer1 # [8244304.521793] peer1 systemd[1]: Startup finished in 11.770s.277controller # [8244304.371160] controller data-mesher[230]: time=2026-09-03T20:06:01.736Z level=INFO msg="performing state exchange with peers on join" count=1278controller # [8244304.371160] controller data-mesher[230]: time=2026-09-03T20:06:01.736Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s279controller # [8244304.371559] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6280controller # [8244304.371559] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6281controller # [8244304.371559] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6282controller # [8244304.371559] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s283controller # [8244304.371559] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="server started"284controller # [8244304.371676] controller data-mesher[230]: time=2026-09-03T20:06:01.737Z level=INFO msg="starting expired-file sweeper" interval=1m0s285controller # [8244304.371723] controller systemd[1]: Started data mesher daemon.286controller # [8244304.372612] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...287controller # [8244304.413587] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...288controller # [8244304.457917] controller dm-wg-star-reconfig[299]: No peer data available yet, skipping289controller # [8244304.458588] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.290controller # [8244304.458697] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.291controller # [8244304.468831] controller data-mesher[230]: time=2026-09-03T20:06:01.834Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204292controller # [8244304.468960] controller dm-wg-star-publish[284]: Status: 204 No Content293controller # [8244304.476094] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.294controller # [8244304.476299] controller systemd[1]: Reached target Multi-User System.295controller # [8244304.476393] controller systemd[1]: Startup finished in 11.717s.296peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.02 seconds)297controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .298controller: (finished: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q ., in 0.00 seconds)299controller: waiting for success: wg show wg-star peers | grep -q .300controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)301peer1: waiting for success: wg show wg-star peers | grep -q .302peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)303peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c394:99ee:a1d8:c56b304peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c394:99ee:a1d8:c56b, in 0.00 seconds)305controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0d4f:1b69:5415:6cc4306controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0d4f:1b69:5415:6cc4, in 0.00 seconds)307controller: must succeed: wg show wg-star peers | wc -l308controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.00 seconds)309peer2: systemd-nspawn running (pid 733)310peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...311peer2: waiting for unit data-mesher.service312peer1 # [8244309.374173] peer1 data-mesher[218]: time=2026-09-03T20:06:06.739Z level=DEBUG msg="attempting push/pull" peer_count=1313peer1 # [8244309.374173] peer1 data-mesher[218]: time=2026-09-03T20:06:06.739Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s314peer1 # [8244309.374496] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe315peer1 # [8244309.374496] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe316peer1 # [8244309.374496] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="new file detected" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller317peer1 # [8244309.374633] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller318peer1 # [8244309.374633] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-03 20:06:01.776 +0000 UTC" signed_by="w7qwoaasGEKkVcvbHvbEpQUvz/s/kYAlR3Ls5BtKh7w=" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe319peer1 # [8244309.374712] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe320peer1 # [8244309.374731] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="new file detected" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller321peer1 # [8244309.374731] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="state exchange complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s322peer1 # [8244309.374756] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="push/pull successful" interval=5s323peer1 # [8244309.374813] peer1 data-mesher[218]: time=2026-09-03T20:06:06.740Z level=INFO msg="received file request" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0324peer1 # [8244309.375701] peer1 data-mesher[218]: time=2026-09-03T20:06:06.741Z level=INFO msg="file transfer complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0325peer1 # [8244309.377630] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...326peer1 # [8244309.424110] peer1 data-mesher[218]: time=2026-09-03T20:06:06.789Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-03 20:06:01.776 +0000 UTC" signed_by="w7qwoaasGEKkVcvbHvbEpQUvz/s/kYAlR3Ls5BtKh7w=" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe written=true elapsed=49.510498ms327peer1 # [8244309.451018] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.328peer1 # [8244309.451071] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.329nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE330nixos-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.331Note: 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.332░ Spawning container peer2 on /build/vm-state-peer2.333controller # [8244309.374090] controller data-mesher[230]: time=2026-09-03T20:06:06.739Z level=DEBUG msg="attempting push/pull" peer_count=1334controller # [8244309.374090] controller data-mesher[230]: time=2026-09-03T20:06:06.739Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s335controller # [8244309.374509] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6336controller # [8244309.374509] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6337controller # [8244309.374613] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6338controller # [8244309.374613] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="new file detected" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0339controller # [8244309.374662] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="new file detected" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0340controller # [8244309.374674] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s341controller # [8244309.374674] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0342controller # [8244309.374712] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 signed_at="2026-09-03 20:06:01.819 +0000 UTC" signed_by="A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6343controller # [8244309.374712] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=DEBUG msg="push/pull successful" interval=5s344controller # [8244309.374770] controller data-mesher[230]: time=2026-09-03T20:06:06.740Z level=INFO msg="received file request" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/controller345controller # [8244309.375671] controller data-mesher[230]: time=2026-09-03T20:06:06.741Z level=INFO msg="file transfer complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/controller346controller # [8244309.377631] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...347controller # [8244309.424263] controller data-mesher[230]: time=2026-09-03T20:06:06.789Z level=INFO msg="download complete" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 signed_at="2026-09-03 20:06:01.819 +0000 UTC" signed_by="A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 written=true elapsed=49.573526ms348controller # [8244309.446753] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.349controller # [8244309.446870] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.350peer2 # [8244310.215955] peer2 systemd-journald[97]: Journal started351peer2 # [8244310.215984] peer2 systemd-journald[97]: Runtime Journal (/run/log/journal/28731338042f40f5b24d332234e593d7) is 8M, max 3.7G, 3.7G free.352peer2 # [8244310.218931] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.353peer2 # [8244310.223531] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...354peer2 # [8244310.223903] peer2 systemd[1]: Starting Network Name Resolution...355peer2 # [8244310.224235] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...356peer2 # [8244310.227977] peer2 systemd-journald[97]: Time spent on flushing to /var/log/journal/28731338042f40f5b24d332234e593d7 is 1.001ms for 6 entries.357peer2 # [8244310.227977] peer2 systemd-journald[97]: System Journal (/var/log/journal/28731338042f40f5b24d332234e593d7) is 8M, max 4G, 3.9G free.358peer2 # [8244310.232351] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.359peer2 # [8244310.232456] peer2 systemd[1]: Reached target Preparation for Local File Systems.360peer2 # [8244310.232502] peer2 systemd[1]: Reached target Local File Systems.361peer2 # [8244310.232916] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.362peer2 # [8244310.232940] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container363peer2 # [8244310.233303] peer2 systemd[1]: Starting Save Transient machine-id to Disk...364peer2 # [8244310.233322] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys365peer2 # [8244310.270142] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.366peer2 # [8244310.270546] peer2 systemd[1]: Starting Create System Files and Directories...367peer2 # [8244310.297136] peer2 systemd[1]: Finished Firewall.368peer2 # [8244310.297264] peer2 systemd[1]: Reached target Preparation for Network.369peer2 # [8244310.297399] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.370peer2 # [8244310.297883] peer2 systemd[1]: Starting Network Management...371peer2 # [8244310.304692] peer2 systemd-tmpfiles[175]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted372peer2 # [8244310.304838] peer2 systemd-tmpfiles[175]: fchmod() of /var/log/journal failed: Operation not permitted373peer2 # [8244310.304938] peer2 systemd-tmpfiles[175]: fchmod() of /var/log/journal/28731338042f40f5b24d332234e593d7 failed: Operation not permitted374peer2 # [8244310.305097] peer2 systemd-tmpfiles[175]: fchmod() of /run/log/journal failed: Operation not permitted375peer2 # [8244310.305764] peer2 systemd[1]: Finished Create System Files and Directories.376peer2 # [8244310.306196] peer2 systemd[1]: Starting Rebuild Journal Catalog...377peer2 # [8244310.306497] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...378peer2 # [8244310.312018] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.379peer2 # [8244310.317851] peer2 systemd[1]: Finished Rebuild Journal Catalog.380peer2 # [8244310.318278] peer2 systemd[1]: Starting Update is Completed...381peer2 # [8244310.323057] peer2 systemd[1]: Finished Update is Completed.382peer2 # [8244310.544261] peer2 systemd-networkd[207]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted383peer2 # [8244310.544352] peer2 systemd-networkd[207]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted384peer2 # [8244310.550065] peer2 systemd-networkd[207]: /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.385peer2 # [8244310.550212] peer2 systemd-networkd[207]: /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.386peer2 # [8244310.550290] peer2 systemd-networkd[207]: lo: Link UP387peer2 # [8244310.550295] peer2 systemd-networkd[207]: lo: Gained carrier388peer2 # [8244310.550462] peer2 systemd-networkd[207]: eth1: Configuring with /etc/systemd/network/40-eth1.network.389peer2 # [8244310.550728] peer2 systemd[1]: Started Network Management.390peer2 # [8244310.551159] peer2 systemd-networkd[207]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.391peer2 # [8244310.551338] peer2 systemd-networkd[207]: wg-star: netdev ready392peer2 # [8244310.551456] peer2 systemd-networkd[207]: eth1: Link UP393peer2 # [8244310.551517] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...394peer2 # [8244310.551564] peer2 systemd-networkd[207]: eth1: Gained carrier395peer2 # [8244310.567445] peer2 systemd-networkd[207]: wg-star: Link UP396peer2 # [8244310.567448] peer2 systemd-networkd[207]: wg-star: Gained carrier397peer2 # [8244310.582727] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.398peer2 # [8244310.676196] peer2 systemd-resolved[119]: Positive Trust Anchors:399peer2 # [8244310.676204] peer2 systemd-resolved[119]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d400peer2 # [8244310.676208] peer2 systemd-resolved[119]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16401peer2 # [8244310.676222] 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 test402peer2 # [8244310.687140] peer2 systemd-resolved[119]: Using system hostname 'peer2'.403peer2 # [8244310.688146] peer2 systemd[1]: Started Network Name Resolution.404peer2 # [8244310.688193] peer2 systemd[1]: Reached target Network.405peer2 # [8244310.688232] peer2 systemd[1]: Reached target System Initialization.406peer2 # [8244310.688288] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.407peer2 # [8244310.688308] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.408peer2 # [8244310.688329] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container409peer2 # [8244310.688344] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.410peer2 # [8244310.688359] peer2 systemd[1]: Reached target Path Units.411peer2 # [8244310.688381] peer2 systemd[1]: Reached target Timer Units.412peer2 # [8244310.688454] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.413peer2 # [8244310.688515] peer2 systemd[1]: Listening on Nix Daemon Socket.414peer2 # [8244310.688596] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.415peer2 # [8244310.688609] peer2 systemd[1]: Reached target Socket Units.416peer2 # [8244310.688631] peer2 systemd[1]: Reached target Basic System.417peer2 # [8244310.689402] peer2 systemd[1]: Starting data mesher daemon...418peer2 # [8244310.689769] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...419peer2 # [8244310.690164] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...420peer2 # [8244310.690766] peer2 systemd[1]: Starting D-Bus System Message Bus...421peer2 # [8244310.727966] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.422peer2 # [8244310.786411] peer2 nsncd[221]: Sep 03 20:06:08.152 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"423peer2 # [8244310.786449] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).424peer2 # [8244310.786473] peer2 systemd[1]: Reached target Host and Network Name Lookups.425peer2 # [8244310.786497] peer2 systemd[1]: Reached target User and Group Name Lookups.426peer2 # [8244310.786983] peer2 systemd[1]: Starting User Login Management...427peer2 # [8244310.787298] peer2 systemd[1]: Starting Permit User Sessions...428peer2 # [8244310.812074] peer2 systemd[1]: Finished Permit User Sessions.429peer2 # [8244310.812468] peer2 systemd[1]: Started Console Getty.430peer2 # [8244310.812486] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0431peer2 # [8244310.812498] peer2 systemd[1]: Reached target Login Prompts.432peer2 # [8244310.830227] peer2 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...433peer2 # [8244310.830592] peer2 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'434peer2 # [8244310.830592] peer2 dbus-broker-launch[222]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"435peer2 # [8244310.830832] peer2 systemd[1]: Started D-Bus System Message Bus.436peer2 # [8244310.834168] peer2 dbus-broker-launch[222]: Ready437peer2 # [8244311.006582] peer2 data-mesher[219]: time=2026-09-03T20:06:08.372Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]438peer2 # [8244311.006902] peer2 data-mesher[219]: time=2026-09-03T20:06:08.372Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe: [/dns/controller.clan/tcp/7946]} {12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6: [/dns/peer1.clan/tcp/7946]} {12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z439peer2 # [8244311.006922] peer2 data-mesher[219]: time=2026-09-03T20:06:08.372Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml440peer2 # [8244311.094380] peer2 data-mesher[219]: time=2026-09-03T20:06:08.460Z level=INFO msg="checking file integrity"441peer2 # [8244311.094417] peer2 data-mesher[219]: time=2026-09-03T20:06:08.460Z level=INFO msg="file integrity check complete"442peer1 # [8244311.099618] peer1 data-mesher[218]: time=2026-09-03T20:06:08.465Z level=INFO msg="peer connected" peer_id=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z remote_addr=/ip4/192.168.1.3/tcp/7946443peer2 # [8244311.097374] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="libp2p host created" peer_id=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z 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::ec4b:f918:5c40:1320/tcp/7946]"444peer2 # [8244311.097414] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="registered HTTP route" method=GET path=/files445peer2 # [8244311.097414] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name446peer2 # [8244311.097414] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name447peer2 # [8244311.097414] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="starting server"448peer2 # [8244311.097489] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="waiting for DHT to populate" delay=10s449peer2 # [8244311.097519] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="HTTP server listening" address=[::1]:7331450peer2 # [8244311.097541] peer2 data-mesher[219]: time=2026-09-03T20:06:08.463Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331451peer2 # [8244311.099409] peer2 data-mesher[219]: time=2026-09-03T20:06:08.465Z level=INFO msg="peer connected" peer_id=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 remote_addr=/ip4/192.168.1.2/tcp/7946452peer2 # [8244311.101641] peer2 data-mesher[219]: time=2026-09-03T20:06:08.467Z level=INFO msg="peer connected" peer_id=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe remote_addr=/ip4/192.168.1.1/tcp/7946453peer2 # [8244311.114371] peer2 systemd-logind[239]: New seat seat0.454peer2 # [8244311.114454] peer2 systemd[1]: Started User Login Management.455peer2 # [8244311.114974] peer2 systemd[1]: Starting linger-users.service...456peer2 # [8244311.142478] peer2 systemd[1]: linger-users.service: Deactivated successfully.457peer2 # [8244311.142600] peer2 systemd[1]: Finished linger-users.service.458controller # [8244311.101840] controller data-mesher[230]: time=2026-09-03T20:06:08.467Z level=INFO msg="peer connected" peer_id=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z remote_addr=/ip4/192.168.1.3/tcp/7946459peer2 # [8244311.741096] peer2 systemd-networkd[207]: eth1: Gained IPv6LL460peer1 # [8244314.375073] peer1 data-mesher[218]: time=2026-09-03T20:06:11.740Z level=DEBUG msg="attempting push/pull" peer_count=1461peer1 # [8244314.375073] peer1 data-mesher[218]: time=2026-09-03T20:06:11.740Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s462peer1 # [8244314.375455] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe463peer1 # [8244314.375455] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe464peer1 # [8244314.375663] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z465peer1 # [8244314.375663] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s466peer1 # [8244314.375714] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=DEBUG msg="push/pull successful" interval=5s467peer1 # [8244314.375825] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="received file request" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0468peer1 # [8244314.375845] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="received file request" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/controller469peer1 # [8244314.376352] peer1 data-mesher[218]: time=2026-09-03T20:06:11.741Z level=INFO msg="file transfer complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0470peer1 # [8244314.377285] peer1 data-mesher[218]: time=2026-09-03T20:06:11.742Z level=INFO msg="file transfer complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/controller471peer2 # [8244314.375505] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6472peer2 # [8244314.375505] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6473peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=DEBUG msg="new file detected" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0474peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=DEBUG msg="new file detected" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller475peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0476peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller477peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-03 20:06:01.776 +0000 UTC" signed_by="w7qwoaasGEKkVcvbHvbEpQUvz/s/kYAlR3Ls5BtKh7w=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6478peer2 # [8244314.375756] peer2 data-mesher[219]: time=2026-09-03T20:06:11.741Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 signed_at="2026-09-03 20:06:01.819 +0000 UTC" signed_by="A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6479peer2 # [8244314.378867] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...480peer2 # [8244314.451612] peer2 dm-wg-star-reconfig[270]: No controller data available yet, skipping481peer2 # [8244314.452284] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.482peer2 # [8244314.513996] peer2 data-mesher[219]: time=2026-09-03T20:06:11.879Z level=INFO msg="download complete" name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 signed_at="2026-09-03 20:06:01.819 +0000 UTC" signed_by="A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 written=true elapsed=138.284443ms483peer2 # [8244314.452420] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.484peer2 # [8244314.514953] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...485peer2 # [8244314.524135] peer2 data-mesher[219]: time=2026-09-03T20:06:11.889Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-03 20:06:01.776 +0000 UTC" signed_by="w7qwoaasGEKkVcvbHvbEpQUvz/s/kYAlR3Ls5BtKh7w=" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 written=true elapsed=148.463424ms486peer2 # [8244314.580789] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.487peer2 # [8244314.580894] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.488controller # [8244314.375027] controller data-mesher[230]: time=2026-09-03T20:06:11.740Z level=DEBUG msg="attempting push/pull" peer_count=1489controller # [8244314.375027] controller data-mesher[230]: time=2026-09-03T20:06:11.740Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s490controller # [8244314.375662] controller data-mesher[230]: time=2026-09-03T20:06:11.741Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6491controller # [8244314.375745] controller data-mesher[230]: time=2026-09-03T20:06:11.741Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s492controller # [8244314.375774] controller data-mesher[230]: time=2026-09-03T20:06:11.741Z level=DEBUG msg="push/pull successful" interval=5s493peer2 # [8244317.185729] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.494peer2 # [8244317.186440] peer2 systemd[1]: Finished Save Transient machine-id to Disk.495peer1 # [8244319.375842] peer1 data-mesher[218]: time=2026-09-03T20:06:16.741Z level=DEBUG msg="attempting push/pull" peer_count=1496peer1 # [8244319.376203] peer1 data-mesher[218]: time=2026-09-03T20:06:16.741Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s497peer1 # [8244319.376560] peer1 data-mesher[218]: time=2026-09-03T20:06:16.742Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z498peer1 # [8244319.376644] peer1 data-mesher[218]: time=2026-09-03T20:06:16.742Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s499peer1 # [8244319.376671] peer1 data-mesher[218]: time=2026-09-03T20:06:16.742Z level=DEBUG msg="push/pull successful" interval=5s500peer2 # [8244319.376317] peer2 data-mesher[219]: time=2026-09-03T20:06:16.741Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6501peer2 # [8244319.376317] peer2 data-mesher[219]: time=2026-09-03T20:06:16.741Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6502peer2 # [8244319.376967] peer2 data-mesher[219]: time=2026-09-03T20:06:16.742Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe503peer2 # [8244319.376967] peer2 data-mesher[219]: time=2026-09-03T20:06:16.742Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe504controller # [8244319.376653] controller data-mesher[230]: time=2026-09-03T20:06:16.742Z level=DEBUG msg="attempting push/pull" peer_count=1505controller # [8244319.376653] controller data-mesher[230]: time=2026-09-03T20:06:16.742Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s506controller # [8244319.377186] controller data-mesher[230]: time=2026-09-03T20:06:16.742Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z507controller # [8244319.377266] controller data-mesher[230]: time=2026-09-03T20:06:16.742Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s508controller # [8244319.377283] controller data-mesher[230]: time=2026-09-03T20:06:16.742Z level=DEBUG msg="push/pull successful" interval=5s509peer2: still waiting for container 'peer2' to reach ready state...510peer1 # [8244321.098682] peer1 data-mesher[218]: time=2026-09-03T20:06:18.464Z level=INFO msg="received state sync from peer" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z511peer1 # [8244321.098682] peer1 data-mesher[218]: time=2026-09-03T20:06:18.464Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z512peer2 # [8244321.098221] peer2 data-mesher[219]: time=2026-09-03T20:06:18.463Z level=INFO msg="performing state exchange with peers on join" count=1513peer2 # [8244321.098584] peer2 data-mesher[219]: time=2026-09-03T20:06:18.463Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s514peer2 # [8244321.098916] peer2 data-mesher[219]: time=2026-09-03T20:06:18.464Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6515peer2 # [8244321.099025] peer2 data-mesher[219]: time=2026-09-03T20:06:18.464Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s516peer2 # [8244321.099052] peer2 data-mesher[219]: time=2026-09-03T20:06:18.464Z level=INFO msg="server started"517peer2 # [8244321.099165] peer2 data-mesher[219]: time=2026-09-03T20:06:18.464Z level=INFO msg="starting expired-file sweeper" interval=1m0s518peer2 # [8244321.099276] peer2 systemd[1]: Started data mesher daemon.519peer2 # [8244321.100130] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...520peer2 # [8244321.187105] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...521peer2 # [8244321.267120] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.522peer2 # [8244321.267224] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.523peer2: (finished: waiting for unit data-mesher.service, in 12.14 seconds)524??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.525 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39526controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1527??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.528 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39529peer2 # [8244321.445938] peer2 data-mesher[219]: time=2026-09-03T20:06:18.811Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU status=204530peer2 # [8244321.446029] peer2 dm-wg-star-publish[289]: Status: 204 No Content531peer2 # [8244321.448793] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.532peer2 # [8244321.448886] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.533peer2 # [8244321.449119] peer2 systemd[1]: Reached target Multi-User System.534peer2 # [8244321.449199] peer2 systemd[1]: Startup finished in 11.498s.535peer1 # [8244324.377184] peer1 data-mesher[218]: time=2026-09-03T20:06:21.742Z level=DEBUG msg="attempting push/pull" peer_count=1536peer1 # [8244324.377184] peer1 data-mesher[218]: time=2026-09-03T20:06:21.742Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s537peer1 # [8244324.377696] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z538peer1 # [8244324.377816] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=DEBUG msg="new file detected" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU539peer1 # [8244324.377833] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s540peer1 # [8244324.377856] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=DEBUG msg="push/pull successful" interval=5s541peer1 # [8244324.377890] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU542peer1 # [8244324.377916] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU signed_at="2026-09-03 20:06:18.549 +0000 UTC" signed_by="M0jNxKrKSySMbWFqWIDYj2Y/B46SJZjxyBkN3zlLpKU=" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z543peer1 # [8244324.378322] peer1 data-mesher[218]: time=2026-09-03T20:06:21.743Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe544peer1 # [8244324.378322] peer1 data-mesher[218]: time=2026-09-03T20:06:21.744Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe545peer1 # [8244324.380857] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...546peer1 # [8244324.438930] peer1 data-mesher[218]: time=2026-09-03T20:06:21.804Z level=INFO msg="download complete" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU signed_at="2026-09-03 20:06:18.549 +0000 UTC" signed_by="M0jNxKrKSySMbWFqWIDYj2Y/B46SJZjxyBkN3zlLpKU=" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z written=true elapsed=61.004856ms547peer1 # [8244324.460393] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.548peer1 # [8244324.460549] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.549peer2 # [8244324.377497] peer2 data-mesher[219]: time=2026-09-03T20:06:21.743Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6550peer2 # [8244324.377497] peer2 data-mesher[219]: time=2026-09-03T20:06:21.743Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6551peer2 # [8244324.378035] peer2 data-mesher[219]: time=2026-09-03T20:06:21.743Z level=INFO msg="received file request" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU552peer2 # [8244324.378940] peer2 data-mesher[219]: time=2026-09-03T20:06:21.744Z level=INFO msg="file transfer complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU553controller # [8244324.378097] controller data-mesher[230]: time=2026-09-03T20:06:21.743Z level=DEBUG msg="attempting push/pull" peer_count=1554controller # [8244324.378386] controller data-mesher[230]: time=2026-09-03T20:06:21.743Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s555controller # [8244324.378503] controller data-mesher[230]: time=2026-09-03T20:06:21.744Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6556controller # [8244324.378589] controller data-mesher[230]: time=2026-09-03T20:06:21.744Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s557controller # [8244324.378610] controller data-mesher[230]: time=2026-09-03T20:06:21.744Z level=DEBUG msg="push/pull successful" interval=5s558peer2 # [8244326.099866] peer2 data-mesher[219]: time=2026-09-03T20:06:23.465Z level=DEBUG msg="attempting push/pull" peer_count=2559peer2 # [8244326.100232] peer2 data-mesher[219]: time=2026-09-03T20:06:23.465Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s560peer2 # [8244326.100666] peer2 data-mesher[219]: time=2026-09-03T20:06:23.466Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe561peer2 # [8244326.100736] peer2 data-mesher[219]: time=2026-09-03T20:06:23.466Z level=INFO msg="state exchange complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s562peer2 # [8244326.100763] peer2 data-mesher[219]: time=2026-09-03T20:06:23.466Z level=DEBUG msg="push/pull successful" interval=5s563peer2 # [8244326.100763] peer2 data-mesher[219]: time=2026-09-03T20:06:23.466Z level=INFO msg="received file request" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU564peer2 # [8244326.101484] peer2 data-mesher[219]: time=2026-09-03T20:06:23.467Z level=INFO msg="file transfer complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe network="g2ZTI/6gnbyMCOXlIE8ank5M91poghR4g9oxd0PoeaY=" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU565controller # [8244326.100392] controller data-mesher[230]: time=2026-09-03T20:06:23.466Z level=INFO msg="received state sync from peer" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z566controller # [8244326.100392] controller data-mesher[230]: time=2026-09-03T20:06:23.466Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z567controller # [8244326.100671] controller data-mesher[230]: time=2026-09-03T20:06:23.466Z level=DEBUG msg="new file detected" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z name=dm_wg_star_wg_star/A5lkTYpGF6ZYbRxGF1fIiwvuIyGlK7vquNADObDXFF0 name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU568controller # [8244326.100671] controller data-mesher[230]: time=2026-09-03T20:06:23.466Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU569controller # [8244326.100671] controller data-mesher[230]: time=2026-09-03T20:06:23.466Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU signed_at="2026-09-03 20:06:18.549 +0000 UTC" signed_by="M0jNxKrKSySMbWFqWIDYj2Y/B46SJZjxyBkN3zlLpKU=" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z570controller # [8244326.103470] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...571controller # [8244326.149848] controller data-mesher[230]: time=2026-09-03T20:06:23.515Z level=INFO msg="download complete" name=dm_wg_star_wg_star/M0jNxKrKSySMbWFqWIDYj2Y_B46SJZjxyBkN3zlLpKU signed_at="2026-09-03 20:06:18.549 +0000 UTC" signed_by="M0jNxKrKSySMbWFqWIDYj2Y/B46SJZjxyBkN3zlLpKU=" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z written=true elapsed=49.201205ms572controller # [8244326.190325] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.573controller # [8244326.190425] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.574controller: (finished: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1, in 5.04 seconds)575controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1576controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.00 seconds)577peer2: waiting for success: wg show wg-star peers | grep -q .578peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)579peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c394:99ee:a1d8:c56b580peer1 # [8244329.378557] peer1 data-mesher[218]: time=2026-09-03T20:06:26.744Z level=DEBUG msg="attempting push/pull" peer_count=1581peer1 # [8244329.378902] peer1 data-mesher[218]: time=2026-09-03T20:06:26.744Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s582peer1 # [8244329.379207] peer1 data-mesher[218]: time=2026-09-03T20:06:26.744Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe583peer1 # [8244329.379316] peer1 data-mesher[218]: time=2026-09-03T20:06:26.745Z level=INFO msg="state exchange complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s584peer1 # [8244329.379340] peer1 data-mesher[218]: time=2026-09-03T20:06:26.745Z level=DEBUG msg="push/pull successful" interval=5s585peer2 # [8244329.379171] peer2 data-mesher[219]: time=2026-09-03T20:06:26.744Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe586peer2 # [8244329.379171] peer2 data-mesher[219]: time=2026-09-03T20:06:26.744Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe587controller # [8244329.378811] controller data-mesher[230]: time=2026-09-03T20:06:26.744Z level=DEBUG msg="attempting push/pull" peer_count=1588controller # [8244329.378811] controller data-mesher[230]: time=2026-09-03T20:06:26.744Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s589controller # [8244329.379165] controller data-mesher[230]: time=2026-09-03T20:06:26.744Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6590controller # [8244329.379165] controller data-mesher[230]: time=2026-09-03T20:06:26.744Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6591controller # [8244329.379412] controller data-mesher[230]: time=2026-09-03T20:06:26.745Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z592controller # [8244329.379513] controller data-mesher[230]: time=2026-09-03T20:06:26.745Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s593controller # [8244329.379528] controller data-mesher[230]: time=2026-09-03T20:06:26.745Z level=DEBUG msg="push/pull successful" interval=5s594peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c394:99ee:a1d8:c56b, in 3.51 seconds)595controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::ec4b:f918:5c40:1320596controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::ec4b:f918:5c40:1320, in 0.00 seconds)597peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::ec4b:f918:5c40:1320598peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::ec4b:f918:5c40:1320, in 0.00 seconds)599peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0d4f:1b69:5415:6cc4600peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::0d4f:1b69:5415:6cc4, in 0.00 seconds)601(finished: run the VM test script, in 37.92 seconds)602peer2 # [8244331.101596] peer2 data-mesher[219]: time=2026-09-03T20:06:28.467Z level=DEBUG msg="attempting push/pull" peer_count=2603peer2 # [8244331.101946] peer2 data-mesher[219]: time=2026-09-03T20:06:28.467Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s604peer2 # [8244331.102328] peer2 data-mesher[219]: time=2026-09-03T20:06:28.468Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe605peer2 # [8244331.102446] peer2 data-mesher[219]: time=2026-09-03T20:06:28.468Z level=INFO msg="state exchange complete" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe timeout=5s606peer2 # [8244331.102470] peer2 data-mesher[219]: time=2026-09-03T20:06:28.468Z level=DEBUG msg="push/pull successful" interval=5s607controller # [8244331.102009] controller data-mesher[230]: time=2026-09-03T20:06:28.467Z level=INFO msg="received state sync from peer" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z608controller # [8244331.102256] controller data-mesher[230]: time=2026-09-03T20:06:28.467Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z609peer1 # [8244334.379443] peer1 data-mesher[218]: time=2026-09-03T20:06:31.745Z level=DEBUG msg="attempting push/pull" peer_count=1610peer1 # [8244334.379443] peer1 data-mesher[218]: time=2026-09-03T20:06:31.745Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s611peer1 # [8244334.380367] peer1 data-mesher[218]: time=2026-09-03T20:06:31.746Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z612peer1 # [8244334.380495] peer1 data-mesher[218]: time=2026-09-03T20:06:31.746Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s613peer1 # [8244334.380559] peer1 data-mesher[218]: time=2026-09-03T20:06:31.746Z level=DEBUG msg="push/pull successful" interval=5s614peer2 # [8244334.379923] peer2 data-mesher[219]: time=2026-09-03T20:06:31.745Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6615peer2 # [8244334.379923] peer2 data-mesher[219]: time=2026-09-03T20:06:31.745Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6616peer2 # [8244334.380347] peer2 data-mesher[219]: time=2026-09-03T20:06:31.746Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe617peer2 # [8244334.380347] peer2 data-mesher[219]: time=2026-09-03T20:06:31.746Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe618controller # [8244334.380037] controller data-mesher[230]: time=2026-09-03T20:06:31.745Z level=DEBUG msg="attempting push/pull" peer_count=1619controller # [8244334.380037] controller data-mesher[230]: time=2026-09-03T20:06:31.745Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s620controller # [8244334.380564] controller data-mesher[230]: time=2026-09-03T20:06:31.746Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z621controller # [8244334.380675] controller data-mesher[230]: time=2026-09-03T20:06:31.746Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s622controller # [8244334.380691] controller data-mesher[230]: time=2026-09-03T20:06:31.746Z level=DEBUG msg="push/pull successful" interval=5s623peer1 # [8244336.102843] peer1 data-mesher[218]: time=2026-09-03T20:06:33.468Z level=INFO msg="received state sync from peer" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z624peer1 # [8244336.102843] peer1 data-mesher[218]: time=2026-09-03T20:06:33.468Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z625peer2 # [8244336.102519] peer2 data-mesher[219]: time=2026-09-03T20:06:33.468Z level=DEBUG msg="attempting push/pull" peer_count=2626peer2 # [8244336.102519] peer2 data-mesher[219]: time=2026-09-03T20:06:33.468Z level=DEBUG msg="initiating state exchange" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s627peer2 # [8244336.103238] peer2 data-mesher[219]: time=2026-09-03T20:06:33.468Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6628peer2 # [8244336.103348] peer2 data-mesher[219]: time=2026-09-03T20:06:33.469Z level=INFO msg="state exchange complete" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6 timeout=5s629peer2 # [8244336.103374] peer2 data-mesher[219]: time=2026-09-03T20:06:33.469Z level=DEBUG msg="push/pull successful" interval=5s630peer1 # [8244339.381249] peer1 data-mesher[218]: time=2026-09-03T20:06:36.746Z level=DEBUG msg="attempting push/pull" peer_count=1631peer1 # [8244339.381584] peer1 data-mesher[218]: time=2026-09-03T20:06:36.746Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s632peer1 # [8244339.382393] peer1 data-mesher[218]: time=2026-09-03T20:06:36.748Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z633peer1 # [8244339.382528] peer1 data-mesher[218]: time=2026-09-03T20:06:36.748Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s634peer1 # [8244339.382566] peer1 data-mesher[218]: time=2026-09-03T20:06:36.748Z level=DEBUG msg="push/pull successful" interval=5s635peer2 # [8244339.382154] peer2 data-mesher[219]: time=2026-09-03T20:06:36.747Z level=INFO msg="received state sync from peer" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6636peer2 # [8244339.382154] peer2 data-mesher[219]: time=2026-09-03T20:06:36.747Z level=INFO msg="merging remote state" peer=12D3KooWA4R3zWpUeZMFZ8iDaALBun4Ra2M67cRLFamDZ37ZaXD6637peer2 # [8244339.382578] peer2 data-mesher[219]: time=2026-09-03T20:06:36.747Z level=INFO msg="received state sync from peer" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe638peer2 # [8244339.382578] peer2 data-mesher[219]: time=2026-09-03T20:06:36.747Z level=INFO msg="merging remote state" peer=12D3KooWBjmQcHS1izNjwTUQnrtrJ7cyuQVoTBAwtUFMoV1wVzRe639controller # [8244339.381652] controller data-mesher[230]: time=2026-09-03T20:06:36.747Z level=DEBUG msg="attempting push/pull" peer_count=1640controller # [8244339.382053] controller data-mesher[230]: time=2026-09-03T20:06:36.747Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s641controller # [8244339.382557] controller data-mesher[230]: time=2026-09-03T20:06:36.748Z level=INFO msg="merging remote state" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z642controller # [8244339.382660] controller data-mesher[230]: time=2026-09-03T20:06:36.748Z level=INFO msg="state exchange complete" peer=12D3KooWDGZMDjgHefoT2wqpgbu8XByuDE6P7LSBkv7RSUt8ZZ7z timeout=5s643controller # [8244339.382685] controller data-mesher[230]: time=2026-09-03T20:06:36.748Z level=DEBUG msg="push/pull successful" interval=5s644test script finished in 48.32s645cleanup646kill NspawnMachine (pid 50)647kill NspawnMachine (pid 53)648Container controller terminated by signal KILL.649kill NspawnMachine (pid 733)650Container peer1 terminated by signal KILL.651Container peer2 terminated by signal KILL.652(finished: cleanup, in 0.34 seconds)