container-test-run-dm-wireguard-star
checks.aarch64-linux.dm-wireguard-star
· build #200
· raw
1build01: building bfpp4691j3ldjczl330gnlklpz0fsw51-container-test-run-dm-wireguard-star.drv2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)56Test will time out and terminate in 3600.0 seconds7run the VM test script8additionally exposed symbols:9 controller, peer1, peer2,10 vlan1,11 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh12controller: systemd-nspawn running (pid 50)13controller: Waiting for journal at /build/vm-state-controller/var/log/journal...14peer1: systemd-nspawn running (pid 53)15peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...16controller: waiting for unit data-mesher.service17nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.21Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.22Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.23░ Spawning container controller on /build/vm-state-controller.24░ Spawning container peer1 on /build/vm-state-peer1.25controller # No journal files were found.26controller # No journal boot entry found for the specified boot (+0).27peer1 # No journal files were found.28peer1 # No journal boot entry found for the specified boot (+0).29controller # [2274080.827251] controller systemd-journald[107]: Journal started30controller # [2274080.827314] controller systemd-journald[107]: Runtime Journal (/run/log/journal/52b3f62625d84cd892ded5858e941ea8) is 8M, max 2.5G, 2.4G free.31controller # [2274080.898147] controller systemd[1]: Finished Apply Kernel Variables.32controller # [2274080.911979] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.33controller # [2274080.943915] controller systemd[1]: Starting Flush Journal to Persistent Storage...34controller # [2274080.944967] controller systemd[1]: Starting Network Name Resolution...35controller # [2274080.945617] controller systemd[1]: Starting Create Static Device Nodes in /dev...36controller # [2274080.953860] controller systemd-journald[107]: Time spent on flushing to /var/log/journal/52b3f62625d84cd892ded5858e941ea8 is 1.586ms for 7 entries.37controller # [2274080.953860] controller systemd-journald[107]: System Journal (/var/log/journal/52b3f62625d84cd892ded5858e941ea8) is 8M, max 4G, 3.9G free.38controller # [2274080.970774] controller systemd[1]: Finished Flush Journal to Persistent Storage.39controller # [2274080.971268] controller systemd[1]: Finished Create Static Device Nodes in /dev.40controller # [2274080.972434] controller systemd[1]: Reached target Preparation for Local File Systems.41controller # [2274080.972539] controller systemd[1]: Reached target Local File Systems.42controller # [2274080.973381] controller systemd[1]: Listening on Boot Loader Control Service Socket.43controller # [2274080.973431] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container44controller # [2274080.974232] controller systemd[1]: Starting Save Transient machine-id to Disk...45controller # [2274080.975002] controller systemd[1]: Starting Create System Files and Directories...46controller # [2274080.975036] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys47controller # [2274080.991260] controller systemd-tmpfiles[202]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted48controller # [2274080.991464] controller systemd-tmpfiles[202]: fchmod() of /var/log/journal failed: Operation not permitted49controller # [2274080.991599] controller systemd-tmpfiles[202]: fchmod() of /var/log/journal/52b3f62625d84cd892ded5858e941ea8 failed: Operation not permitted50controller # [2274080.991810] controller systemd-tmpfiles[202]: fchmod() of /run/log/journal failed: Operation not permitted51controller # [2274080.993283] controller systemd[1]: Finished Create System Files and Directories.52controller # [2274080.994360] controller systemd[1]: Starting Rebuild Journal Catalog...53controller # [2274080.995155] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...54controller # [2274081.009651] controller systemd[1]: Finished Firewall.55controller # [2274081.010326] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.56controller # [2274081.013280] controller systemd[1]: Reached target Preparation for Network.57controller # [2274081.013596] controller systemd[1]: Listening on Network Management Resolve Hook Socket.58controller # [2274081.014764] controller systemd[1]: Starting Network Management...59controller # [2274081.015116] controller systemd[1]: Finished Rebuild Journal Catalog.60controller # [2274081.016802] controller systemd[1]: Starting Update is Completed...61controller # [2274081.021069] controller systemd[1]: Finished Save Transient machine-id to Disk.62controller # [2274081.027864] controller systemd[1]: Finished Update is Completed.63peer1 # [2274080.815742] peer1 systemd-journald[98]: Journal started64peer1 # [2274080.815804] peer1 systemd-journald[98]: Runtime Journal (/run/log/journal/a02720fe6cf644789cb252c4f5e25874) is 8M, max 2.5G, 2.4G free.65peer1 # [2274080.840668] peer1 systemd[1]: Finished Apply Kernel Variables.66peer1 # [2274080.891874] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.67peer1 # [2274080.906402] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...68peer1 # [2274080.908193] peer1 systemd[1]: Starting Network Name Resolution...69peer1 # [2274080.909023] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...70peer1 # [2274080.918377] peer1 systemd-journald[98]: Time spent on flushing to /var/log/journal/a02720fe6cf644789cb252c4f5e25874 is 1.903ms for 7 entries.71peer1 # [2274080.918377] peer1 systemd-journald[98]: System Journal (/var/log/journal/a02720fe6cf644789cb252c4f5e25874) is 8M, max 4G, 3.9G free.72peer1 # [2274080.949820] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.73peer1 # [2274080.950214] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.74peer1 # [2274080.951359] peer1 systemd[1]: Reached target Preparation for Local File Systems.75peer1 # [2274080.951467] peer1 systemd[1]: Reached target Local File Systems.76peer1 # [2274080.952347] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.77peer1 # [2274080.952410] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container78peer1 # [2274080.953339] peer1 systemd[1]: Starting Save Transient machine-id to Disk...79peer1 # [2274080.954235] peer1 systemd[1]: Starting Create System Files and Directories...80peer1 # [2274080.954276] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys81peer1 # [2274080.974458] peer1 systemd-tmpfiles[187]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted82peer1 # [2274080.974683] peer1 systemd-tmpfiles[187]: fchmod() of /var/log/journal failed: Operation not permitted83peer1 # [2274080.974833] peer1 systemd-tmpfiles[187]: fchmod() of /var/log/journal/a02720fe6cf644789cb252c4f5e25874 failed: Operation not permitted84peer1 # [2274080.975058] peer1 systemd-tmpfiles[187]: fchmod() of /run/log/journal failed: Operation not permitted85peer1 # [2274080.976647] peer1 systemd[1]: Finished Create System Files and Directories.86peer1 # [2274080.977803] peer1 systemd[1]: Starting Rebuild Journal Catalog...87peer1 # [2274080.978555] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...88peer1 # [2274080.991599] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.89peer1 # [2274080.995106] peer1 systemd[1]: Finished Firewall.90peer1 # [2274080.995295] peer1 systemd[1]: Reached target Preparation for Network.91peer1 # [2274080.995575] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.92peer1 # [2274080.996879] peer1 systemd[1]: Starting Network Management...93peer1 # [2274081.001413] peer1 systemd[1]: Finished Rebuild Journal Catalog.94peer1 # [2274081.002774] peer1 systemd[1]: Starting Update is Completed...95peer1 # [2274081.013509] peer1 systemd[1]: Finished Update is Completed.96peer1 # [2274081.021086] peer1 systemd[1]: Finished Save Transient machine-id to Disk.97controller # [2274081.755735] controller systemd-networkd[223]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted98controller # [2274081.755826] controller systemd-networkd[223]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted99controller # [2274081.767289] controller systemd-networkd[223]: /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.100controller # [2274081.767519] controller systemd-networkd[223]: /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.101controller # [2274081.767683] controller systemd-networkd[223]: lo: Link UP102controller # [2274081.767689] controller systemd-networkd[223]: lo: Gained carrier103controller # [2274081.767873] controller systemd-networkd[223]: eth1: Configuring with /etc/systemd/network/40-eth1.network.104controller # [2274081.768597] controller systemd[1]: Started Network Management.105controller # [2274081.769375] controller systemd-networkd[223]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.106controller # [2274081.769696] controller systemd-networkd[223]: wg-star: netdev ready107controller # [2274081.770315] controller systemd-networkd[223]: eth1: Link UP108controller # [2274081.770549] controller systemd-networkd[223]: eth1: Gained carrier109controller # [2274081.770674] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...110controller # [2274081.808599] controller systemd-networkd[223]: wg-star: Link UP111controller # [2274081.808605] controller systemd-networkd[223]: wg-star: Gained carrier112controller # [2274081.840201] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.113controller # [2274081.842073] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.114peer1 # [2274081.782113] peer1 systemd-networkd[212]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted115peer1 # [2274081.782207] peer1 systemd-networkd[212]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted116peer1 # [2274081.792544] 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.117peer1 # [2274081.792715] 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.118peer1 # [2274081.792860] peer1 systemd-networkd[212]: lo: Link UP119peer1 # [2274081.792866] peer1 systemd-networkd[212]: lo: Gained carrier120peer1 # [2274081.793045] peer1 systemd-networkd[212]: eth1: Configuring with /etc/systemd/network/40-eth1.network.121peer1 # [2274081.806279] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.122peer1 # [2274081.806989] peer1 systemd[1]: Started Network Management.123peer1 # [2274081.809196] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...124peer1 # [2274081.809479] peer1 systemd-networkd[212]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.125peer1 # [2274081.809803] peer1 systemd-networkd[212]: wg-star: netdev ready126peer1 # [2274081.810212] peer1 systemd-networkd[212]: eth1: Link UP127peer1 # [2274081.810430] peer1 systemd-networkd[212]: eth1: Gained carrier128peer1 # [2274081.840994] peer1 systemd-networkd[212]: wg-star: Link UP129peer1 # [2274081.841004] peer1 systemd-networkd[212]: wg-star: Gained carrier130peer1 # [2274081.842810] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.131controller # [2274082.194151] controller systemd-resolved[181]: Positive Trust Anchors:132controller # [2274082.194163] controller systemd-resolved[181]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d133controller # [2274082.194165] controller systemd-resolved[181]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16134controller # [2274082.194199] controller systemd-resolved[181]: 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 test135controller # [2274082.214223] controller systemd-resolved[181]: Using system hostname 'controller'.136controller # [2274082.215804] controller systemd[1]: Started Network Name Resolution.137controller # [2274082.215947] controller systemd[1]: Reached target Network.138controller # [2274082.216095] controller systemd[1]: Reached target System Initialization.139controller # [2274082.216265] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.140controller # [2274082.216321] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container141controller # [2274082.216371] controller systemd[1]: Started Daily Cleanup of Temporary Directories.142controller # [2274082.216414] controller systemd[1]: Reached target Path Units.143controller # [2274082.216491] controller systemd[1]: Reached target Timer Units.144controller # [2274082.216725] controller systemd[1]: Listening on D-Bus System Message Bus Socket.145controller # [2274082.216973] controller systemd[1]: Listening on Nix Daemon Socket.146controller # [2274082.217214] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.147controller # [2274082.217273] controller systemd[1]: Reached target Socket Units.148controller # [2274082.217358] controller systemd[1]: Reached target Basic System.149controller # [2274082.219829] controller systemd[1]: Starting data mesher daemon...150controller # [2274082.221098] controller systemd[1]: Starting Import lastlog data into lastlog2 database...151controller # [2274082.222618] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...152controller # [2274082.224696] controller systemd[1]: Starting D-Bus System Message Bus...153controller # [2274082.287205] controller systemd[1]: Finished Import lastlog data into lastlog2 database.154peer1 # [2274082.193901] peer1 systemd-resolved[158]: Positive Trust Anchors:155peer1 # [2274082.193916] peer1 systemd-resolved[158]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d156peer1 # [2274082.193918] peer1 systemd-resolved[158]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16157peer1 # [2274082.193953] peer1 systemd-resolved[158]: 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 test158peer1 # [2274082.214112] peer1 systemd-resolved[158]: Using system hostname 'peer1'.159peer1 # [2274082.215711] peer1 systemd[1]: Started Network Name Resolution.160peer1 # [2274082.215851] peer1 systemd[1]: Reached target Network.161peer1 # [2274082.215966] peer1 systemd[1]: Reached target System Initialization.162peer1 # [2274082.216170] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.163peer1 # [2274082.216241] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.164peer1 # [2274082.216285] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container165peer1 # [2274082.216326] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.166peer1 # [2274082.216380] peer1 systemd[1]: Reached target Path Units.167peer1 # [2274082.216464] peer1 systemd[1]: Reached target Timer Units.168peer1 # [2274082.216698] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.169peer1 # [2274082.216959] peer1 systemd[1]: Listening on Nix Daemon Socket.170peer1 # [2274082.217191] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.171peer1 # [2274082.217235] peer1 systemd[1]: Reached target Socket Units.172peer1 # [2274082.217315] peer1 systemd[1]: Reached target Basic System.173peer1 # [2274082.219664] peer1 systemd[1]: Starting data mesher daemon...174peer1 # [2274082.220937] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...175peer1 # [2274082.222409] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...176peer1 # [2274082.224887] peer1 systemd[1]: Starting D-Bus System Message Bus...177peer1 # [2274082.287062] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.178peer1 # [2274082.478651] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).179peer1 # [2274082.478836] peer1 nsncd[223]: Sep 30 15:08:22.464 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"180peer1 # [2274082.478768] peer1 systemd[1]: Reached target Host and Network Name Lookups.181peer1 # [2274082.478878] peer1 systemd[1]: Reached target User and Group Name Lookups.182peer1 # [2274082.480921] peer1 systemd[1]: Starting User Login Management...183peer1 # [2274082.482275] peer1 systemd[1]: Starting Permit User Sessions...184controller # [2274082.477978] controller nsncd[234]: Sep 30 15:08:22.463 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"185peer1 # [2274082.540046] peer1 systemd[1]: Finished Permit User Sessions.186controller # [2274082.477986] controller systemd[1]: Started Name Service Cache Daemon (nsncd).187peer1 # [2274082.541813] peer1 systemd[1]: Started Console Getty.188controller # [2274082.478095] controller systemd[1]: Reached target Host and Network Name Lookups.189peer1 # [2274082.541884] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0190controller # [2274082.478203] controller systemd[1]: Reached target User and Group Name Lookups.191peer1 # [2274082.541923] peer1 systemd[1]: Reached target Login Prompts.192controller # [2274082.480670] controller systemd[1]: Starting User Login Management...193peer1 # [2274082.602455] peer1 dbus-broker-launch[224]: Looking up NSS user entry for 'systemd-timesync'...194controller # [2274082.482041] controller systemd[1]: Starting Permit User Sessions...195peer1 # [2274082.603670] peer1 dbus-broker-launch[224]: NSS returned no entry for 'systemd-timesync'196controller # [2274082.540397] controller systemd[1]: Finished Permit User Sessions.197peer1 # [2274082.603670] peer1 dbus-broker-launch[224]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"198controller # [2274082.541950] controller systemd[1]: Started Console Getty.199peer1 # [2274082.604283] peer1 systemd[1]: Started D-Bus System Message Bus.200controller # [2274082.542032] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0201peer1 # [2274082.613270] peer1 dbus-broker-launch[224]: Ready202controller # [2274082.542072] controller systemd[1]: Reached target Login Prompts.203controller # [2274082.610763] controller dbus-broker-launch[235]: Looking up NSS user entry for 'systemd-timesync'...204controller # [2274082.611979] controller dbus-broker-launch[235]: NSS returned no entry for 'systemd-timesync'205controller # [2274082.611979] controller dbus-broker-launch[235]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"206controller # [2274082.612437] controller systemd[1]: Started D-Bus System Message Bus.207controller # [2274082.621246] controller dbus-broker-launch[235]: Ready208peer1 # [2274083.029468] peer1 data-mesher[221]: time=2026-09-30T15:08:23.015Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]209peer1 # [2274083.030902] peer1 data-mesher[221]: time=2026-09-30T15:08:23.016Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf210peer1 # [2274083.030902] peer1 data-mesher[221]: time=2026-09-30T15:08:23.016Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml211peer1 # [2274083.032279] peer1 data-mesher[221]: time=2026-09-30T15:08:23.018Z level=INFO msg="checking file integrity"212peer1 # [2274083.034085] peer1 data-mesher[221]: time=2026-09-30T15:08:23.018Z level=INFO msg="file integrity check complete"213peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="libp2p host created" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.2/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::2/tcp/7946 /ip6/fda1:5c8::23fd:a719:7f48:87f1/tcp/7946]"214peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name215peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name216peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="registered HTTP route" method=GET path=/files217peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="starting server"218peer1 # [2274083.036574] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="waiting for DHT to populate" delay=10s219peer1 # [2274083.036742] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="HTTP server listening" address=[::1]:7331220peer1 # [2274083.036742] peer1 data-mesher[221]: time=2026-09-30T15:08:23.022Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331221peer1 # [2274083.048454] peer1 data-mesher[221]: time=2026-09-30T15:08:23.034Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946222controller # [2274083.036676] controller data-mesher[232]: time=2026-09-30T15:08:23.022Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]223controller # [2274083.037759] controller data-mesher[232]: time=2026-09-30T15:08:23.023Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ224controller # [2274083.037759] controller data-mesher[232]: time=2026-09-30T15:08:23.023Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml225controller # [2274083.039005] controller data-mesher[232]: time=2026-09-30T15:08:23.024Z level=INFO msg="checking file integrity"226controller # [2274083.040021] controller data-mesher[232]: time=2026-09-30T15:08:23.024Z level=INFO msg="file integrity check complete"227controller # [2274083.042997] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="libp2p host created" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.1/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::1/tcp/7946 /ip6/fda1:5c8::28bc:6cf0:1e15:8c64/tcp/7946]"228controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name229controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=GET path=/files230controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name231controller # [2274083.043047] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="starting server"232controller # [2274083.043119] controller data-mesher[232]: time=2026-09-30T15:08:23.028Z level=INFO msg="waiting for DHT to populate" delay=10s233controller # [2274083.043243] controller data-mesher[232]: time=2026-09-30T15:08:23.029Z level=INFO msg="HTTP server listening" address=[::1]:7331234controller # [2274083.043243] controller data-mesher[232]: time=2026-09-30T15:08:23.029Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331235controller # [2274083.047896] controller data-mesher[232]: time=2026-09-30T15:08:23.033Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946236controller # [2274083.076262] controller systemd-networkd[223]: eth1: Gained IPv6LL237controller # [2274083.324922] controller systemd-logind[252]: New seat seat0.238controller # [2274083.325103] controller systemd[1]: Started User Login Management.239controller # [2274083.332671] controller systemd[1]: Starting linger-users.service...240controller # [2274083.346470] controller systemd[1]: linger-users.service: Deactivated successfully.241controller # [2274083.346596] controller systemd[1]: Finished linger-users.service.242peer1 # [2274083.291856] peer1 systemd-logind[241]: New seat seat0.243peer1 # [2274083.292111] peer1 systemd[1]: Started User Login Management.244peer1 # [2274083.293474] peer1 systemd[1]: Starting linger-users.service...245peer1 # [2274083.343645] peer1 systemd[1]: linger-users.service: Deactivated successfully.246peer1 # [2274083.343903] peer1 systemd[1]: Finished linger-users.service.247peer1 # [2274083.648121] peer1 systemd-networkd[212]: eth1: Gained IPv6LL248controller: still waiting for container 'controller' to reach ready state...249peer1 # [2274093.036971] peer1 data-mesher[221]: time=2026-09-30T15:08:33.022Z level=INFO msg="performing state exchange with peers on join" count=1250peer1 # [2274093.037508] peer1 data-mesher[221]: time=2026-09-30T15:08:33.022Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s251peer1 # [2274093.037911] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ252peer1 # [2274093.037911] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s253peer1 # [2274093.038003] peer1 data-mesher[221]: time=2026-09-30T15:08:33.023Z level=INFO msg="server started"254peer1 # [2274093.038210] peer1 systemd[1]: Started data mesher daemon.255peer1 # [2274093.038788] peer1 data-mesher[221]: time=2026-09-30T15:08:33.024Z level=INFO msg="starting expired-file sweeper" interval=1m0s256peer1 # [2274093.039744] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...257peer1 # [2274093.044298] peer1 data-mesher[221]: time=2026-09-30T15:08:33.030Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ258peer1 # [2274093.044364] peer1 data-mesher[221]: time=2026-09-30T15:08:33.030Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ259peer1 # [2274093.205198] peer1 data-mesher[221]: time=2026-09-30T15:08:33.190Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 status=204260peer1 # [2274093.205685] peer1 dm-wg-star-publish[286]: Status: 204 No Content261peer1 # [2274093.207721] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...262peer1 # [2274093.209365] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.263peer1 # [2274093.209665] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.264peer1 # [2274093.210654] peer1 systemd[1]: Reached target Multi-User System.265peer1 # [2274093.302905] peer1 dm-wg-star-reconfig[312]: No controller data available yet, skipping266controller # [2274093.037689] controller data-mesher[232]: time=2026-09-30T15:08:33.023Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf267controller # [2274093.037689] controller data-mesher[232]: time=2026-09-30T15:08:33.023Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf268controller # [2274093.043593] controller data-mesher[232]: time=2026-09-30T15:08:33.029Z level=INFO msg="performing state exchange with peers on join" count=1269controller # [2274093.043593] controller data-mesher[232]: time=2026-09-30T15:08:33.029Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s270controller # [2274093.044460] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf271controller # [2274093.044460] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s272controller # [2274093.044581] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="server started"273controller # [2274093.044653] controller data-mesher[232]: time=2026-09-30T15:08:33.030Z level=INFO msg="starting expired-file sweeper" interval=1m0s274controller # [2274093.044741] controller systemd[1]: Started data mesher daemon.275controller # [2274093.088753] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...276controller # [2274093.132901] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...277controller # [2274093.141736] controller data-mesher[232]: time=2026-09-30T15:08:33.127Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204278controller # [2274093.142021] controller dm-wg-star-publish[297]: Status: 204 No Content279controller # [2274093.145747] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.280controller # [2274093.146569] controller systemd[1]: Reached target Multi-User System.281controller # [2274093.230665] controller dm-wg-star-reconfig[323]: No peer data available yet, skipping282controller # [2274093.232017] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.283controller # [2274093.232285] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.284controller # [2274093.232846] controller systemd[1]: Startup finished in 12.872s.285controller: (finished: waiting for unit data-mesher.service, in 13.68 seconds)286peer1: waiting for unit data-mesher.service287peer1: (finished: waiting for unit data-mesher.service, in 0.02 seconds)288??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.289 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39290controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller291??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.292 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39293controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.01 seconds)294peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller295peer1 # [2274093.304119] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.296peer1 # [2274093.304280] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.297peer1 # [2274093.304800] peer1 systemd[1]: Startup finished in 12.962s.298controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf299controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf300controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.027Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4301controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.028Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4302controller # [2274098.042555] controller data-mesher[232]: time=2026-09-30T15:08:38.028Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf303controller # [2274098.044094] controller data-mesher[232]: time=2026-09-30T15:08:38.029Z level=INFO msg="received file request" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller304controller # [2274098.044856] controller data-mesher[232]: time=2026-09-30T15:08:38.030Z level=DEBUG msg="attempting push/pull" peer_count=1305controller # [2274098.044992] controller data-mesher[232]: time=2026-09-30T15:08:38.030Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s306controller # [2274098.046411] controller data-mesher[232]: time=2026-09-30T15:08:38.032Z level=INFO msg="file transfer complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller307controller # [2274098.047232] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf308controller # [2274098.047839] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=DEBUG msg="new file detected" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4309controller # [2274098.047923] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s310controller # [2274098.047923] controller data-mesher[232]: time=2026-09-30T15:08:38.033Z level=DEBUG msg="push/pull successful" interval=5s311controller # [2274098.048372] controller data-mesher[232]: time=2026-09-30T15:08:38.034Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf written=true elapsed=6.071683ms312controller # [2274098.050222] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...313controller # [2274098.192375] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.314controller # [2274098.192525] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.315peer1 # [2274098.040292] peer1 data-mesher[221]: time=2026-09-30T15:08:38.026Z level=DEBUG msg="attempting push/pull" peer_count=1316peer1 # [2274098.041029] peer1 data-mesher[221]: time=2026-09-30T15:08:38.026Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s317peer1 # [2274098.042279] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ318peer1 # [2274098.042279] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller319peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s320peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=DEBUG msg="push/pull successful" interval=5s321peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller322peer1 # [2274098.042479] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ323peer1 # [2274098.043148] peer1 data-mesher[221]: time=2026-09-30T15:08:38.028Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4324peer1 # [2274098.044311] peer1 data-mesher[221]: time=2026-09-30T15:08:38.030Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4325peer1 # [2274098.046787] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ326peer1 # [2274098.046834] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ327peer1 # [2274098.046834] peer1 data-mesher[221]: time=2026-09-30T15:08:38.032Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller328peer1 # [2274098.049432] peer1 data-mesher[221]: time=2026-09-30T15:08:38.035Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=6.949896ms329peer1 # [2274098.052164] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...330peer1 # [2274098.168465] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.331peer1 # [2274098.192422] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.332peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.05 seconds)333controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .334controller: (finished: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q ., in 0.01 seconds)335controller: waiting for success: wg show wg-star peers | grep -q .336controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)337peer1: waiting for success: wg show wg-star peers | grep -q .338peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)339peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64340peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds)341controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1342controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds)343controller: must succeed: wg show wg-star peers | wc -l344controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)345peer2: systemd-nspawn running (pid 782)346peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...347peer2: waiting for unit data-mesher.service348nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE349nixos-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.350Note: 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.351░ Spawning container peer2 on /build/vm-state-peer2.352peer2 # No journal files were found.353peer2 # No journal boot entry found for the specified boot (+0).354peer2 # [2274099.575779] peer2 systemd-journald[99]: Journal started355peer2 # [2274099.575831] peer2 systemd-journald[99]: Runtime Journal (/run/log/journal/9c8783ffa30f405ea91870b02260e851) is 8M, max 2.5G, 2.4G free.356peer2 # [2274099.584385] peer2 systemd[1]: Finished Apply Kernel Variables.357peer2 # [2274099.596409] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.358peer2 # [2274099.610214] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...359peer2 # [2274099.611008] peer2 systemd[1]: Starting Network Name Resolution...360peer2 # [2274099.611855] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...361peer2 # [2274099.646935] peer2 systemd-journald[99]: Time spent on flushing to /var/log/journal/9c8783ffa30f405ea91870b02260e851 is 2.198ms for 7 entries.362peer2 # [2274099.646935] peer2 systemd-journald[99]: System Journal (/var/log/journal/9c8783ffa30f405ea91870b02260e851) is 8M, max 4G, 3.9G free.363peer2 # [2274099.662251] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.364peer2 # [2274099.662920] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.365peer2 # [2274099.663882] peer2 systemd[1]: Reached target Preparation for Local File Systems.366peer2 # [2274099.663994] peer2 systemd[1]: Reached target Local File Systems.367peer2 # [2274099.664936] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.368peer2 # [2274099.665000] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container369peer2 # [2274099.665910] peer2 systemd[1]: Starting Save Transient machine-id to Disk...370peer2 # [2274099.666675] peer2 systemd[1]: Starting Create System Files and Directories...371peer2 # [2274099.666711] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys372peer2 # [2274099.685599] peer2 systemd-tmpfiles[165]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted373peer2 # [2274099.686425] peer2 systemd-tmpfiles[165]: fchmod() of /var/log/journal failed: Operation not permitted374peer2 # [2274099.686551] peer2 systemd-tmpfiles[165]: fchmod() of /var/log/journal/9c8783ffa30f405ea91870b02260e851 failed: Operation not permitted375peer2 # [2274099.686735] peer2 systemd-tmpfiles[165]: fchmod() of /run/log/journal failed: Operation not permitted376peer2 # [2274099.689329] peer2 systemd[1]: Finished Create System Files and Directories.377peer2 # [2274099.690719] peer2 systemd[1]: Starting Rebuild Journal Catalog...378peer2 # [2274099.691749] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...379peer2 # [2274099.695890] peer2 systemd[1]: Finished Save Transient machine-id to Disk.380peer2 # [2274099.705519] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.381peer2 # [2274099.715229] peer2 systemd[1]: Finished Rebuild Journal Catalog.382peer2 # [2274099.716274] peer2 systemd[1]: Starting Update is Completed...383peer2 # [2274099.727473] peer2 systemd[1]: Finished Update is Completed.384peer2 # [2274099.754696] peer2 systemd[1]: Finished Firewall.385peer2 # [2274099.754855] peer2 systemd[1]: Reached target Preparation for Network.386peer2 # [2274099.755061] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.387peer2 # [2274099.756008] peer2 systemd[1]: Starting Network Management...388peer2 # [2274100.403884] peer2 systemd-networkd[217]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted389peer2 # [2274100.403979] peer2 systemd-networkd[217]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted390peer2 # [2274100.413703] peer2 systemd-networkd[217]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.391peer2 # [2274100.413868] peer2 systemd-networkd[217]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.392peer2 # [2274100.414002] peer2 systemd-networkd[217]: lo: Link UP393peer2 # [2274100.414006] peer2 systemd-networkd[217]: lo: Gained carrier394peer2 # [2274100.414185] peer2 systemd-networkd[217]: eth1: Configuring with /etc/systemd/network/40-eth1.network.395peer2 # [2274100.414732] peer2 systemd[1]: Started Network Management.396peer2 # [2274100.416120] peer2 systemd-networkd[217]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.397peer2 # [2274100.416208] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...398peer2 # [2274100.416417] peer2 systemd-networkd[217]: wg-star: netdev ready399peer2 # [2274100.416789] peer2 systemd-networkd[217]: eth1: Link UP400peer2 # [2274100.416994] peer2 systemd-networkd[217]: eth1: Gained carrier401peer2 # [2274100.460621] peer2 systemd-networkd[217]: wg-star: Link UP402peer2 # [2274100.460628] peer2 systemd-networkd[217]: wg-star: Gained carrier403peer2 # [2274100.469563] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.404peer2 # [2274100.590495] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.405peer2 # [2274100.752188] peer2 systemd-resolved[130]: Positive Trust Anchors:406peer2 # [2274100.752201] peer2 systemd-resolved[130]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d407peer2 # [2274100.752205] peer2 systemd-resolved[130]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16408peer2 # [2274100.752240] peer2 systemd-resolved[130]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test409peer2 # [2274100.772297] peer2 systemd-resolved[130]: Using system hostname 'peer2'.410peer2 # [2274100.773881] peer2 systemd[1]: Started Network Name Resolution.411peer2 # [2274100.774015] peer2 systemd[1]: Reached target Network.412peer2 # [2274100.774133] peer2 systemd[1]: Reached target System Initialization.413peer2 # [2274100.774295] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.414peer2 # [2274100.774348] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.415peer2 # [2274100.774388] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container416peer2 # [2274100.774425] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.417peer2 # [2274100.774467] peer2 systemd[1]: Reached target Path Units.418peer2 # [2274100.774544] peer2 systemd[1]: Reached target Timer Units.419peer2 # [2274100.774761] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.420peer2 # [2274100.774978] peer2 systemd[1]: Listening on Nix Daemon Socket.421peer2 # [2274100.775193] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.422peer2 # [2274100.775234] peer2 systemd[1]: Reached target Socket Units.423peer2 # [2274100.775308] peer2 systemd[1]: Reached target Basic System.424peer2 # [2274100.777937] peer2 systemd[1]: Starting data mesher daemon...425peer2 # [2274100.779302] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...426peer2 # [2274100.780700] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...427peer2 # [2274100.782961] peer2 systemd[1]: Starting D-Bus System Message Bus...428peer2 # [2274100.846657] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.429peer2 # [2274101.007655] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).430peer2 # [2274101.007766] peer2 systemd[1]: Reached target Host and Network Name Lookups.431peer2 # [2274101.007872] peer2 systemd[1]: Reached target User and Group Name Lookups.432peer2 # [2274101.008437] peer2 nsncd[224]: Sep 30 15:08:40.994 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"433peer2 # [2274101.010003] peer2 systemd[1]: Starting User Login Management...434peer2 # [2274101.011332] peer2 systemd[1]: Starting Permit User Sessions...435peer2 # [2274101.048286] peer2 systemd[1]: Finished Permit User Sessions.436peer2 # [2274101.049883] peer2 systemd[1]: Started Console Getty.437peer2 # [2274101.049971] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0438peer2 # [2274101.050006] peer2 systemd[1]: Reached target Login Prompts.439peer2 # [2274101.145891] peer2 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'...440peer2 # [2274101.147394] peer2 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync'441peer2 # [2274101.147394] peer2 dbus-broker-launch[225]: Invalid user-name in /nix/store/wbzvym3x60fvhvwrlxgff96536rq3714-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"442peer2 # [2274101.147879] peer2 systemd[1]: Started D-Bus System Message Bus.443peer2 # [2274101.155315] peer2 dbus-broker-launch[225]: Ready444peer2 # [2274101.578053] peer2 data-mesher[222]: time=2026-09-30T15:08:41.563Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]445peer2 # [2274101.579140] peer2 data-mesher[222]: time=2026-09-30T15:08:41.564Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ: [/dns/controller.clan/tcp/7946]} {12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf: [/dns/peer1.clan/tcp/7946]} {12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK446peer2 # [2274101.579140] peer2 data-mesher[222]: time=2026-09-30T15:08:41.564Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml447peer2 # [2274101.582694] peer2 data-mesher[222]: time=2026-09-30T15:08:41.568Z level=INFO msg="checking file integrity"448peer2 # [2274101.582841] peer2 data-mesher[222]: time=2026-09-30T15:08:41.568Z level=INFO msg="file integrity check complete"449peer2 # [2274101.588573] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="libp2p host created" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK addresses="[/ip4/127.0.0.1/tcp/7946 /ip4/192.168.1.3/tcp/7946 /ip6/::1/tcp/7946 /ip6/2001:db8:1::3/tcp/7946 /ip6/fda1:5c8::c289:fe9d:a6bc:e45b/tcp/7946]"450peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=GET path=/files451peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name452peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name453peer2 # [2274101.588671] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="starting server"454peer2 # [2274101.588863] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="waiting for DHT to populate" delay=10s455peer2 # [2274101.588863] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="HTTP server listening" address=[::1]:7331456peer2 # [2274101.588961] peer2 data-mesher[222]: time=2026-09-30T15:08:41.574Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331457peer2 # [2274101.594114] peer2 data-mesher[222]: time=2026-09-30T15:08:41.579Z level=INFO msg="peer connected" peer_id=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ remote_addr=/ip4/192.168.1.1/tcp/7946458peer2 # [2274101.600177] peer2 systemd-networkd[217]: eth1: Gained IPv6LL459peer2 # [2274101.601979] peer2 data-mesher[222]: time=2026-09-30T15:08:41.587Z level=INFO msg="peer connected" peer_id=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf remote_addr=/ip4/192.168.1.2/tcp/7946460peer2 # [2274101.805576] peer2 systemd-logind[242]: New seat seat0.461peer2 # [2274101.805795] peer2 systemd[1]: Started User Login Management.462peer2 # [2274101.806895] peer2 systemd[1]: Starting linger-users.service...463controller # [2274101.595582] controller data-mesher[232]: time=2026-09-30T15:08:41.581Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946464peer1 # [2274101.603132] peer1 data-mesher[221]: time=2026-09-30T15:08:41.588Z level=INFO msg="peer connected" peer_id=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK remote_addr=/ip4/192.168.1.3/tcp/7946465peer2 # [2274101.862009] peer2 systemd[1]: linger-users.service: Deactivated successfully.466peer2 # [2274101.862163] peer2 systemd[1]: Finished linger-users.service.467controller # [2274103.043780] controller data-mesher[232]: time=2026-09-30T15:08:43.029Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf468controller # [2274103.043780] controller data-mesher[232]: time=2026-09-30T15:08:43.029Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf469controller # [2274103.048609] controller data-mesher[232]: time=2026-09-30T15:08:43.034Z level=DEBUG msg="attempting push/pull" peer_count=1470controller # [2274103.048609] controller data-mesher[232]: time=2026-09-30T15:08:43.034Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s471controller # [2274103.049784] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf472controller # [2274103.049994] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s473controller # [2274103.050044] controller data-mesher[232]: time=2026-09-30T15:08:43.035Z level=DEBUG msg="push/pull successful" interval=5s474peer1 # [2274103.043224] peer1 data-mesher[221]: time=2026-09-30T15:08:43.028Z level=DEBUG msg="attempting push/pull" peer_count=1475peer1 # [2274103.043224] peer1 data-mesher[221]: time=2026-09-30T15:08:43.029Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s476peer1 # [2274103.044559] peer1 data-mesher[221]: time=2026-09-30T15:08:43.030Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ477peer1 # [2274103.045136] peer1 data-mesher[221]: time=2026-09-30T15:08:43.030Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s478peer1 # [2274103.045207] peer1 data-mesher[221]: time=2026-09-30T15:08:43.031Z level=DEBUG msg="push/pull successful" interval=5s479peer1 # [2274103.048905] peer1 data-mesher[221]: time=2026-09-30T15:08:43.034Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ480peer1 # [2274103.048983] peer1 data-mesher[221]: time=2026-09-30T15:08:43.034Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ481controller # [2274108.046536] controller data-mesher[232]: time=2026-09-30T15:08:48.032Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf482controller # [2274108.046536] controller data-mesher[232]: time=2026-09-30T15:08:48.032Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf483controller # [2274108.050678] controller data-mesher[232]: time=2026-09-30T15:08:48.036Z level=DEBUG msg="attempting push/pull" peer_count=1484controller # [2274108.050678] controller data-mesher[232]: time=2026-09-30T15:08:48.036Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s485controller # [2274108.052640] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK486controller # [2274108.052640] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s487controller # [2274108.052781] controller data-mesher[232]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="push/pull successful" interval=5s488controller # [2274108.053217] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller489controller # [2274108.053391] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="received file request" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4490controller # [2274108.053761] controller data-mesher[232]: time=2026-09-30T15:08:48.039Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/controller491controller # [2274108.056102] controller data-mesher[232]: time=2026-09-30T15:08:48.041Z level=INFO msg="file transfer complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4492peer2 # [2274108.051687] peer2 data-mesher[222]: time=2026-09-30T15:08:48.037Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ493peer2 # [2274108.051687] peer2 data-mesher[222]: time=2026-09-30T15:08:48.037Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ494peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4495peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=DEBUG msg="new file detected" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller496peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4497peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller498peer2 # [2274108.052634] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ499peer2 # [2274108.052894] peer2 data-mesher[222]: time=2026-09-30T15:08:48.038Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ500peer2 # [2274108.058575] peer2 data-mesher[222]: time=2026-09-30T15:08:48.044Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-30 15:08:33.112 +0000 UTC" signed_by="DdAWC6KVow4OB6mpjNG1hnNj1L2IafSvLkKLWsnuRPk=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=5.952361ms501peer2 # [2274108.059892] peer2 data-mesher[222]: time=2026-09-30T15:08:48.045Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4 signed_at="2026-09-30 15:08:33.186 +0000 UTC" signed_by="bB9Kv45NKM8kzJX19k4dB2Sei0DX65f58ZDrXTwIeN4=" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ written=true elapsed=7.070576ms502peer2 # [2274108.060811] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...503peer2 # [2274108.234922] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.504peer2 # [2274108.235252] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.505peer1 # [2274108.045807] peer1 data-mesher[221]: time=2026-09-30T15:08:48.031Z level=DEBUG msg="attempting push/pull" peer_count=1506peer1 # [2274108.045807] peer1 data-mesher[221]: time=2026-09-30T15:08:48.031Z level=DEBUG msg="initiating state exchange" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s507peer1 # [2274108.047627] peer1 data-mesher[221]: time=2026-09-30T15:08:48.033Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ508peer1 # [2274108.048274] peer1 data-mesher[221]: time=2026-09-30T15:08:48.034Z level=INFO msg="state exchange complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ timeout=5s509peer1 # [2274108.048355] peer1 data-mesher[221]: time=2026-09-30T15:08:48.034Z level=DEBUG msg="push/pull successful" interval=5s510peer2: still waiting for container 'peer2' to reach ready state...511peer2 # [2274111.589512] peer2 data-mesher[222]: time=2026-09-30T15:08:51.575Z level=INFO msg="performing state exchange with peers on join" count=1512peer2 # [2274111.589512] peer2 data-mesher[222]: time=2026-09-30T15:08:51.575Z level=DEBUG msg="initiating state exchange" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s513peer2 # [2274111.591549] peer2 data-mesher[222]: time=2026-09-30T15:08:51.577Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf514peer2 # [2274111.592373] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="state exchange complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf timeout=5s515peer2 # [2274111.592453] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="server started"516peer2 # [2274111.592587] peer2 data-mesher[222]: time=2026-09-30T15:08:51.578Z level=INFO msg="starting expired-file sweeper" interval=1m0s517peer2 # [2274111.592774] peer2 systemd[1]: Started data mesher daemon.518peer2 # [2274111.595061] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...519peer2 # [2274111.757370] peer2 data-mesher[222]: time=2026-09-30T15:08:51.743Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY status=204520peer2 # [2274111.757821] peer2 dm-wg-star-publish[298]: Status: 204 No Content521peer2 # [2274111.759579] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...522peer2 # [2274111.762010] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.523peer2 # [2274111.762335] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.524peer2 # [2274111.763324] peer2 systemd[1]: Reached target Multi-User System.525peer1 # [2274111.590304] peer1 data-mesher[221]: time=2026-09-30T15:08:51.576Z level=INFO msg="received state sync from peer" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK526peer1 # [2274111.590304] peer1 data-mesher[221]: time=2026-09-30T15:08:51.576Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK527peer2: (finished: waiting for unit data-mesher.service, in 13.68 seconds)528??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.529 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39530controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1531??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.532 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39533peer2 # [2274111.919023] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.534peer2 # [2274111.919340] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.535peer2 # [2274111.919906] peer2 systemd[1]: Startup finished in 12.816s.536controller: (finished: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1, in 1.03 seconds)537controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1538controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)539peer2: waiting for success: wg show wg-star peers | grep -q .540peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)541peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64542peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::28bc:6cf0:1e15:8c64, in 0.01 seconds)543controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b544controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds)545peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b546peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c289:fe9d:a6bc:e45b, in 0.01 seconds)547peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1548peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::23fd:a719:7f48:87f1, in 0.01 seconds)549(finished: run the VM test script, in 33.60 seconds)550test script finished in 33.63s551cleanup552kill NspawnMachine (pid 50)553controller # [2274113.053296] controller data-mesher[232]: time=2026-09-30T15:08:53.039Z level=DEBUG msg="attempting push/pull" peer_count=1554controller # [2274113.054080] controller data-mesher[232]: time=2026-09-30T15:08:53.039Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s555controller # [2274113.056676] controller data-mesher[232]: time=2026-09-30T15:08:53.042Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK556controller # [2274113.057276] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=DEBUG msg="new file detected" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY557controller # [2274113.057435] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY558controller # [2274113.057528] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK559controller # [2274113.057873] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s560controller # [2274113.057934] controller data-mesher[232]: time=2026-09-30T15:08:53.043Z level=DEBUG msg="push/pull successful" interval=5s561controller # [2274113.061583] controller data-mesher[232]: time=2026-09-30T15:08:53.047Z level=INFO msg="download complete" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK written=true elapsed=4.098576ms562controller # [2274113.064621] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...563controller # [2274113.229648] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.564controller # [2274113.229792] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.565controller # [2274113.360473] controller systemd-networkd[223]: eth1: Link DOWN566peer2 # [2274113.050155] peer2 data-mesher[222]: time=2026-09-30T15:08:53.035Z level=INFO msg="received state sync from peer" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf567peer2 # [2274113.050155] peer2 data-mesher[222]: time=2026-09-30T15:08:53.035Z level=INFO msg="merging remote state" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf568peer2 # [2274113.052809] peer2 data-mesher[222]: time=2026-09-30T15:08:53.038Z level=INFO msg="received file request" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY569peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="received state sync from peer" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ570peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="merging remote state" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ571peer2 # [2274113.055016] peer2 data-mesher[222]: time=2026-09-30T15:08:53.040Z level=INFO msg="file transfer complete" peer=12D3KooWH6Rshcg8miQasumyMdtMBgzGDx8m2QpCazPZhrmcSCsf network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY572peer2 # [2274113.058147] peer2 data-mesher[222]: time=2026-09-30T15:08:53.043Z level=INFO msg="received file request" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY573peer2 # [2274113.059476] peer2 data-mesher[222]: time=2026-09-30T15:08:53.045Z level=INFO msg="file transfer complete" peer=12D3KooWRb7fY96LruvscwjABTE3L1vsgsVSwV8iKZTbMBsn4WHZ network="sFUEhrCVYv6MEvtAOK9EN1Nb4h7HkDcQN56oesCaO70=" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY574peer1 # [2274113.049347] peer1 data-mesher[221]: time=2026-09-30T15:08:53.035Z level=DEBUG msg="attempting push/pull" peer_count=1575peer1 # [2274113.049347] peer1 data-mesher[221]: time=2026-09-30T15:08:53.035Z level=DEBUG msg="initiating state exchange" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s576peer1 # [2274113.051292] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="merging remote state" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK577peer1 # [2274113.051871] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=DEBUG msg="new file detected" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY578peer1 # [2274113.052152] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY579peer1 # [2274113.052152] peer1 data-mesher[221]: time=2026-09-30T15:08:53.037Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK580peer1 # [2274113.052520] peer1 data-mesher[221]: time=2026-09-30T15:08:53.038Z level=INFO msg="state exchange complete" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK timeout=5s581peer1 # [2274113.052600] peer1 data-mesher[221]: time=2026-09-30T15:08:53.038Z level=DEBUG msg="push/pull successful" interval=5s582peer1 # [2274113.057328] peer1 data-mesher[221]: time=2026-09-30T15:08:53.043Z level=INFO msg="download complete" name=dm_wg_star_wg_star/-M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY signed_at="2026-09-30 15:08:51.739 +0000 UTC" signed_by="+M0QRtC0j82sjlNSgJeZap4jYFL3GKXvbfMdl7nwBjY=" peer=12D3KooWSZaduYTHJzakXPtkUZWcK4pmosp237jD7JnWjwG9JwjK written=true elapsed=5.208672ms583peer1 # [2274113.060331] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...584peer1 # [2274113.225322] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.585peer1 # [2274113.225645] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.586kill NspawnMachine (pid 53)587Container controller terminated by signal KILL.588kill NspawnMachine (pid 782)589Container peer1 terminated by signal KILL.590Container peer2 terminated by signal KILL.591(finished: cleanup, in 0.65 seconds)