container-test-run-dm-wireguard-star
checks.x86_64-linux.dm-wireguard-star
· build #197
· raw
1build-x86-01: building skr327lf9y0f4xbkxnj8dfx1wic8rl4i-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(peer1): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.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 peer1 on /build/vm-state-peer1.24░ Spawning container controller on /build/vm-state-controller.25controller # [2188007.528822] controller systemd-journald[108]: Journal started26controller # [2188007.528852] controller systemd-journald[108]: Runtime Journal (/run/log/journal/643ade56d75d401f8ffd5f08abcc0d65) is 8M, max 3.7G, 3.7G free.27controller # [2188007.533308] controller systemd[1]: Finished Apply Kernel Variables.28controller # [2188007.541377] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29controller # [2188007.549443] controller systemd[1]: Starting Flush Journal to Persistent Storage...30controller # [2188007.549763] controller systemd[1]: Starting Network Name Resolution...31controller # [2188007.550099] controller systemd[1]: Starting Create Static Device Nodes in /dev...32controller # [2188007.573136] controller systemd-journald[108]: Time spent on flushing to /var/log/journal/643ade56d75d401f8ffd5f08abcc0d65 is 1.103ms for 7 entries.33controller # [2188007.573136] controller systemd-journald[108]: System Journal (/var/log/journal/643ade56d75d401f8ffd5f08abcc0d65) is 8M, max 4G, 3.9G free.34controller # [2188007.585582] controller systemd[1]: Finished Flush Journal to Persistent Storage.35controller # [2188007.585838] controller systemd[1]: Finished Create Static Device Nodes in /dev.36controller # [2188007.586475] controller systemd[1]: Reached target Preparation for Local File Systems.37controller # [2188007.586527] controller systemd[1]: Reached target Local File Systems.38controller # [2188007.586948] controller systemd[1]: Listening on Boot Loader Control Service Socket.39controller # [2188007.586977] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container40controller # [2188007.587396] controller systemd[1]: Starting Save Transient machine-id to Disk...41controller # [2188007.587712] controller systemd[1]: Starting Create System Files and Directories...42controller # [2188007.587725] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys43controller # [2188007.598229] controller systemd-tmpfiles[186]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted44controller # [2188007.598368] controller systemd-tmpfiles[186]: fchmod() of /var/log/journal failed: Operation not permitted45controller # [2188007.598466] controller systemd-tmpfiles[186]: fchmod() of /var/log/journal/643ade56d75d401f8ffd5f08abcc0d65 failed: Operation not permitted46controller # [2188007.598611] controller systemd-tmpfiles[186]: fchmod() of /run/log/journal failed: Operation not permitted47controller # [2188007.599515] controller systemd[1]: Finished Create System Files and Directories.48controller # [2188007.600084] controller systemd[1]: Starting Rebuild Journal Catalog...49controller # [2188007.600461] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...50controller # [2188007.606959] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.51controller # [2188007.611756] controller systemd[1]: Finished Rebuild Journal Catalog.52controller # [2188007.612297] controller systemd[1]: Starting Update is Completed...53controller # [2188007.617441] controller systemd[1]: Finished Update is Completed.54controller # [2188007.621952] controller systemd[1]: Finished Firewall.55controller # [2188007.622047] controller systemd[1]: Reached target Preparation for Network.56controller # [2188007.622173] controller systemd[1]: Listening on Network Management Resolve Hook Socket.57controller # [2188007.622649] controller systemd[1]: Starting Network Management...58controller # [2188007.690216] controller systemd[1]: Finished Save Transient machine-id to Disk.59peer1 # [2188007.528826] peer1 systemd-journald[99]: Journal started60peer1 # [2188007.528852] peer1 systemd-journald[99]: Runtime Journal (/run/log/journal/9366e0d438a14f67b87e0ceb23dcbc17) is 8M, max 3.7G, 3.7G free.61peer1 # [2188007.533326] peer1 systemd[1]: Finished Apply Kernel Variables.62peer1 # [2188007.540019] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.63peer1 # [2188007.549011] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...64peer1 # [2188007.549372] peer1 systemd[1]: Starting Network Name Resolution...65peer1 # [2188007.549656] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...66peer1 # [2188007.573137] peer1 systemd-journald[99]: Time spent on flushing to /var/log/journal/9366e0d438a14f67b87e0ceb23dcbc17 is 1.018ms for 7 entries.67peer1 # [2188007.573137] peer1 systemd-journald[99]: System Journal (/var/log/journal/9366e0d438a14f67b87e0ceb23dcbc17) is 8M, max 4G, 3.9G free.68peer1 # [2188007.585064] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.69peer1 # [2188007.585271] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.70peer1 # [2188007.585875] peer1 systemd[1]: Reached target Preparation for Local File Systems.71peer1 # [2188007.585920] peer1 systemd[1]: Reached target Local File Systems.72peer1 # [2188007.586356] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.73peer1 # [2188007.586381] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container74peer1 # [2188007.586786] peer1 systemd[1]: Starting Save Transient machine-id to Disk...75peer1 # [2188007.587089] peer1 systemd[1]: Starting Create System Files and Directories...76peer1 # [2188007.587104] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys77peer1 # [2188007.596623] peer1 systemd-tmpfiles[178]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted78peer1 # [2188007.596769] peer1 systemd-tmpfiles[178]: fchmod() of /var/log/journal failed: Operation not permitted79peer1 # [2188007.596898] peer1 systemd-tmpfiles[178]: fchmod() of /var/log/journal/9366e0d438a14f67b87e0ceb23dcbc17 failed: Operation not permitted80peer1 # [2188007.597081] peer1 systemd-tmpfiles[178]: fchmod() of /run/log/journal failed: Operation not permitted81peer1 # [2188007.597878] peer1 systemd[1]: Finished Create System Files and Directories.82peer1 # [2188007.598561] peer1 systemd[1]: Starting Rebuild Journal Catalog...83peer1 # [2188007.598942] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...84peer1 # [2188007.605929] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.85peer1 # [2188007.611555] peer1 systemd[1]: Finished Rebuild Journal Catalog.86peer1 # [2188007.612132] peer1 systemd[1]: Starting Update is Completed...87peer1 # [2188007.617208] peer1 systemd[1]: Finished Firewall.88peer1 # [2188007.617350] peer1 systemd[1]: Finished Update is Completed.89peer1 # [2188007.618254] peer1 systemd[1]: Reached target Preparation for Network.90peer1 # [2188007.618408] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.91peer1 # [2188007.618966] peer1 systemd[1]: Starting Network Management...92peer1 # [2188007.690214] peer1 systemd[1]: Finished Save Transient machine-id to Disk.93peer1 # [2188008.078006] peer1 systemd-networkd[216]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted94peer1 # [2188008.078079] peer1 systemd-networkd[216]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted95peer1 # [2188008.085744] peer1 systemd-networkd[216]: /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.96peer1 # [2188008.085884] peer1 systemd-networkd[216]: /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.97peer1 # [2188008.085954] peer1 systemd-networkd[216]: lo: Link UP98peer1 # [2188008.085957] peer1 systemd-networkd[216]: lo: Gained carrier99peer1 # [2188008.086103] peer1 systemd-networkd[216]: eth1: Configuring with /etc/systemd/network/40-eth1.network.100peer1 # [2188008.086349] peer1 systemd[1]: Started Network Management.101peer1 # [2188008.086985] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...102peer1 # [2188008.087049] peer1 systemd-networkd[216]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.103peer1 # [2188008.087241] peer1 systemd-networkd[216]: wg-star: netdev ready104peer1 # [2188008.087384] peer1 systemd-networkd[216]: eth1: Link UP105peer1 # [2188008.087488] peer1 systemd-networkd[216]: eth1: Gained carrier106peer1 # [2188008.101323] peer1 systemd-networkd[216]: wg-star: Link UP107peer1 # [2188008.101328] peer1 systemd-networkd[216]: wg-star: Gained carrier108peer1 # [2188008.104605] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.109controller # [2188008.077527] controller systemd-networkd[227]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted110controller # [2188008.077594] controller systemd-networkd[227]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted111controller # [2188008.085803] controller systemd-networkd[227]: /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.112controller # [2188008.085946] controller systemd-networkd[227]: /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.113controller # [2188008.086009] controller systemd-networkd[227]: lo: Link UP114controller # [2188008.086012] controller systemd-networkd[227]: lo: Gained carrier115controller # [2188008.086140] controller systemd-networkd[227]: eth1: Configuring with /etc/systemd/network/40-eth1.network.116controller # [2188008.086366] controller systemd[1]: Started Network Management.117controller # [2188008.086985] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...118controller # [2188008.087052] controller systemd-networkd[227]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.119controller # [2188008.087232] controller systemd-networkd[227]: wg-star: netdev ready120controller # [2188008.087326] controller systemd-networkd[227]: eth1: Link UP121controller # [2188008.087431] controller systemd-networkd[227]: eth1: Gained carrier122controller # [2188008.110425] controller systemd-networkd[227]: wg-star: Link UP123controller # [2188008.110429] controller systemd-networkd[227]: wg-star: Gained carrier124controller # [2188008.111176] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.125controller # [2188008.423213] controller systemd-resolved[144]: Positive Trust Anchors:126controller # [2188008.423220] controller systemd-resolved[144]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d127controller # [2188008.423224] controller systemd-resolved[144]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16128controller # [2188008.423244] controller systemd-resolved[144]: 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 test129controller # [2188008.433659] controller systemd-resolved[144]: Using system hostname 'controller'.130controller # [2188008.434639] controller systemd[1]: Started Network Name Resolution.131controller # [2188008.434691] controller systemd[1]: Reached target Network.132controller # [2188008.434726] controller systemd[1]: Reached target System Initialization.133controller # [2188008.434782] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.134controller # [2188008.434800] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container135controller # [2188008.434812] controller systemd[1]: Started Daily Cleanup of Temporary Directories.136controller # [2188008.434824] controller systemd[1]: Reached target Path Units.137controller # [2188008.434843] controller systemd[1]: Reached target Timer Units.138controller # [2188008.434915] controller systemd[1]: Listening on D-Bus System Message Bus Socket.139controller # [2188008.434975] controller systemd[1]: Listening on Nix Daemon Socket.140controller # [2188008.435053] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.141controller # [2188008.435069] controller systemd[1]: Reached target Socket Units.142controller # [2188008.435093] controller systemd[1]: Reached target Basic System.143controller # [2188008.435790] controller systemd[1]: Starting data mesher daemon...144controller # [2188008.436171] controller systemd[1]: Starting Import lastlog data into lastlog2 database...145controller # [2188008.436561] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...146controller # [2188008.437207] controller systemd[1]: Starting D-Bus System Message Bus...147controller # [2188008.468484] controller systemd[1]: Finished Import lastlog data into lastlog2 database.148controller # [2188008.528025] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.149controller # [2188008.572780] controller nsncd[235]: Sep 29 15:03:42.996 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"150controller # [2188008.572794] controller systemd[1]: Started Name Service Cache Daemon (nsncd).151controller # [2188008.572835] controller systemd[1]: Reached target Host and Network Name Lookups.152controller # [2188008.572885] controller systemd[1]: Reached target User and Group Name Lookups.153controller # [2188008.573658] controller systemd[1]: Starting User Login Management...154controller # [2188008.574007] controller systemd[1]: Starting Permit User Sessions...155controller # [2188008.595137] controller systemd[1]: Finished Permit User Sessions.156controller # [2188008.595711] controller systemd[1]: Started Console Getty.157controller # [2188008.595738] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0158controller # [2188008.595751] controller systemd[1]: Reached target Login Prompts.159controller # [2188008.677038] controller dbus-broker-launch[236]: Looking up NSS user entry for 'systemd-timesync'...160peer1 # [2188008.430764] peer1 systemd-resolved[135]: Positive Trust Anchors:161peer1 # [2188008.430772] peer1 systemd-resolved[135]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d162peer1 # [2188008.430776] peer1 systemd-resolved[135]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16163peer1 # [2188008.430798] peer1 systemd-resolved[135]: 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 test164peer1 # [2188008.441564] peer1 systemd-resolved[135]: Using system hostname 'peer1'.165peer1 # [2188008.442494] peer1 systemd[1]: Started Network Name Resolution.166peer1 # [2188008.442543] peer1 systemd[1]: Reached target Network.167peer1 # [2188008.442577] peer1 systemd[1]: Reached target System Initialization.168peer1 # [2188008.442632] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.169peer1 # [2188008.442650] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.170peer1 # [2188008.442669] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container171peer1 # [2188008.442681] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.172peer1 # [2188008.442695] peer1 systemd[1]: Reached target Path Units.173peer1 # [2188008.442713] peer1 systemd[1]: Reached target Timer Units.174peer1 # [2188008.442780] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.175peer1 # [2188008.442837] peer1 systemd[1]: Listening on Nix Daemon Socket.176peer1 # [2188008.442900] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.177peer1 # [2188008.442909] peer1 systemd[1]: Reached target Socket Units.178peer1 # [2188008.442929] peer1 systemd[1]: Reached target Basic System.179peer1 # [2188008.460202] peer1 systemd[1]: Starting data mesher daemon...180peer1 # [2188008.460537] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...181peer1 # [2188008.460873] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...182peer1 # [2188008.461423] peer1 systemd[1]: Starting D-Bus System Message Bus...183peer1 # [2188008.471166] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.184peer1 # [2188008.528483] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.185peer1 # [2188008.574204] peer1 nsncd[224]: Sep 29 15:03:42.997 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"186peer1 # [2188008.574231] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).187peer1 # [2188008.574253] peer1 systemd[1]: Reached target Host and Network Name Lookups.188peer1 # [2188008.574280] peer1 systemd[1]: Reached target User and Group Name Lookups.189peer1 # [2188008.575083] peer1 systemd[1]: Starting User Login Management...190peer1 # [2188008.575345] peer1 systemd[1]: Starting Permit User Sessions...191peer1 # [2188008.595622] peer1 systemd[1]: Finished Permit User Sessions.192peer1 # [2188008.596040] peer1 systemd[1]: Started Console Getty.193peer1 # [2188008.596058] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0194peer1 # [2188008.596066] peer1 systemd[1]: Reached target Login Prompts.195peer1 # [2188008.672387] peer1 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'...196peer1 # [2188008.672847] peer1 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync'197peer1 # [2188008.672847] peer1 dbus-broker-launch[225]: Invalid user-name in /nix/store/1lr1srjvd1fgm10g9q2rzzqrxf3q9rfz-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"198peer1 # [2188008.673096] peer1 systemd[1]: Started D-Bus System Message Bus.199peer1 # [2188008.676967] peer1 dbus-broker-launch[225]: Ready200controller # [2188008.677441] controller dbus-broker-launch[236]: NSS returned no entry for 'systemd-timesync'201controller # [2188008.677441] controller dbus-broker-launch[236]: Invalid user-name in /nix/store/1lr1srjvd1fgm10g9q2rzzqrxf3q9rfz-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"202controller # [2188008.677690] controller systemd[1]: Started D-Bus System Message Bus.203controller # [2188008.681397] controller dbus-broker-launch[236]: Ready204controller # [2188008.967755] controller data-mesher[233]: time=2026-09-29T15:03:43.391Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]205controller # [2188008.968045] controller data-mesher[233]: time=2026-09-29T15:03:43.391Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ: [/dns/controller.clan/tcp/7946]} {12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV: [/dns/peer1.clan/tcp/7946]} {12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ206controller # [2188008.968079] controller data-mesher[233]: time=2026-09-29T15:03:43.391Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml207controller # [2188008.972199] controller data-mesher[233]: time=2026-09-29T15:03:43.395Z level=INFO msg="checking file integrity"208controller # [2188008.972286] controller data-mesher[233]: time=2026-09-29T15:03:43.395Z level=INFO msg="file integrity check complete"209controller # [2188008.975672] controller data-mesher[233]: time=2026-09-29T15:03:43.398Z level=INFO msg="libp2p host created" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ 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::da68:6425:5c0e:5f5a/tcp/7946]"210controller # [2188008.975705] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="registered HTTP route" method=GET path=/files211controller # [2188008.975705] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name212controller # [2188008.975705] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name213controller # [2188008.975705] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="starting server"214controller # [2188008.975774] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="waiting for DHT to populate" delay=10s215controller # [2188008.975805] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="HTTP server listening" address=[::1]:7331216controller # [2188008.975851] controller data-mesher[233]: time=2026-09-29T15:03:43.399Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331217controller # [2188009.119670] controller systemd-logind[253]: New seat seat0.218controller # [2188009.119796] controller systemd[1]: Started User Login Management.219controller # [2188009.120656] controller systemd[1]: Starting linger-users.service...220controller # [2188009.147218] controller systemd[1]: linger-users.service: Deactivated successfully.221controller # [2188009.147261] controller systemd[1]: Finished linger-users.service.222peer1 # [2188008.967737] peer1 data-mesher[222]: time=2026-09-29T15:03:43.391Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]223peer1 # [2188008.969164] peer1 data-mesher[222]: time=2026-09-29T15:03:43.392Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ: [/dns/controller.clan/tcp/7946]} {12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV: [/dns/peer1.clan/tcp/7946]} {12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV224peer1 # [2188008.969164] peer1 data-mesher[222]: time=2026-09-29T15:03:43.392Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml225peer1 # [2188008.972352] peer1 data-mesher[222]: time=2026-09-29T15:03:43.395Z level=INFO msg="checking file integrity"226peer1 # [2188008.972421] peer1 data-mesher[222]: time=2026-09-29T15:03:43.395Z level=INFO msg="file integrity check complete"227peer1 # [2188008.974797] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="libp2p host created" peer_id=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV 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::c56b:b714:f42c:e615/tcp/7946]"228peer1 # [2188008.974841] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="registered HTTP route" method=GET path=/files229peer1 # [2188008.974841] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name230peer1 # [2188008.974841] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name231peer1 # [2188008.974841] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="starting server"232peer1 # [2188008.974909] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="waiting for DHT to populate" delay=10s233peer1 # [2188008.974937] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="HTTP server listening" address=[::1]:7331234peer1 # [2188008.974953] peer1 data-mesher[222]: time=2026-09-29T15:03:43.398Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331235peer1 # [2188009.119994] peer1 systemd-logind[242]: New seat seat0.236peer1 # [2188009.120094] peer1 systemd[1]: Started User Login Management.237peer1 # [2188009.120896] peer1 systemd[1]: Starting linger-users.service...238peer1 # [2188009.146145] peer1 systemd[1]: linger-users.service: Deactivated successfully.239peer1 # [2188009.146223] peer1 systemd[1]: Finished linger-users.service.240controller # [2188009.408095] controller systemd-networkd[227]: eth1: Gained IPv6LL241peer1 # [2188009.920049] peer1 systemd-networkd[216]: eth1: Gained IPv6LL242controller # [2188013.978827] controller data-mesher[233]: time=2026-09-29T15:03:48.402Z level=INFO msg="peer connected" peer_id=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV remote_addr=/ip4/192.168.1.2/tcp/7946243controller # [2188013.979641] controller data-mesher[233]: time=2026-09-29T15:03:48.402Z level=INFO msg="peer connected" peer_id=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV remote_addr=/ip6/2001:db8:1::2/tcp/7946244peer1 # [2188013.978645] peer1 data-mesher[222]: time=2026-09-29T15:03:48.401Z level=INFO msg="peer connected" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ remote_addr=/ip4/192.168.1.1/tcp/7946245peer1 # [2188013.979829] peer1 data-mesher[222]: time=2026-09-29T15:03:48.403Z level=INFO msg="peer connected" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ remote_addr=/ip6/2001:db8:1::1/tcp/44658246peer1 # [2188013.980053] peer1 data-mesher[222]: time=2026-09-29T15:03:48.403Z level=INFO msg="peer connected" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ remote_addr=/ip4/192.168.1.1/tcp/44266247peer1 # [2188013.980105] peer1 data-mesher[222]: time=2026-09-29T15:03:48.403Z level=INFO msg="peer disconnected" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ remote_addr=/ip4/192.168.1.1/tcp/44266248controller: still waiting for container 'controller' to reach ready state...249controller: (finished: waiting for unit data-mesher.service, in 12.14 seconds)250peer1: waiting for unit data-mesher.service251peer1: (finished: waiting for unit data-mesher.service, in 0.01 seconds)252??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.253 File "/nix/store/ww1fp9ch7b86riwmzgb57p620cz6f717-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39254controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller255??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.256 File "/nix/store/ww1fp9ch7b86riwmzgb57p620cz6f717-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39257controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)258peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller259controller # [2188018.976675] controller data-mesher[233]: time=2026-09-29T15:03:53.399Z level=INFO msg="performing state exchange with peers on join" count=1260controller # [2188018.976675] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s261controller # [2188018.977098] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="received state sync from peer" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV262controller # [2188018.977098] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV263controller # [2188018.977226] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV264controller # [2188018.977226] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="state exchange complete" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s265controller # [2188018.977226] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="server started"266controller # [2188018.977323] controller data-mesher[233]: time=2026-09-29T15:03:53.400Z level=INFO msg="starting expired-file sweeper" interval=1m0s267controller # [2188018.977421] controller systemd[1]: Started data mesher daemon.268controller # [2188018.978305] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...269controller # [2188019.021948] controller data-mesher[233]: time=2026-09-29T15:03:53.445Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204270controller # [2188019.022024] controller dm-wg-star-publish[286]: Status: 204 No Content271controller # [2188019.022849] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...272controller # [2188019.023533] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.273controller # [2188019.023717] controller systemd[1]: Reached target Multi-User System.274controller # [2188019.071168] controller dm-wg-star-reconfig[301]: No peer data available yet, skipping275controller # [2188019.071764] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.276controller # [2188019.091090] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.277controller # [2188019.091264] controller systemd[1]: Startup finished in 11.796s.278peer1 # [2188018.976725] peer1 data-mesher[222]: time=2026-09-29T15:03:53.399Z level=INFO msg="performing state exchange with peers on join" count=1279peer1 # [2188018.976725] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=DEBUG msg="initiating state exchange" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s280peer1 # [2188018.977153] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="received state sync from peer" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ281peer1 # [2188018.977153] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ282peer1 # [2188018.977183] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ283peer1 # [2188018.977183] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="state exchange complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s284peer1 # [2188018.977183] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="server started"285peer1 # [2188018.977259] peer1 data-mesher[222]: time=2026-09-29T15:03:53.400Z level=INFO msg="starting expired-file sweeper" interval=1m0s286peer1 # [2188018.977414] peer1 systemd[1]: Started data mesher daemon.287peer1 # [2188018.978310] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...288peer1 # [2188019.060483] peer1 data-mesher[222]: time=2026-09-29T15:03:53.483Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 status=204289peer1 # [2188019.061093] peer1 dm-wg-star-publish[277]: Status: 204 No Content290peer1 # [2188019.061622] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...291peer1 # [2188019.062753] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.292peer1 # [2188019.062853] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.293peer1 # [2188019.063118] peer1 systemd[1]: Reached target Multi-User System.294peer1 # [2188019.133079] peer1 dm-wg-star-reconfig[290]: No controller data available yet, skipping295peer1 # [2188019.133715] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.296peer1 # [2188019.133779] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.297peer1 # [2188019.133993] peer1 systemd[1]: Startup finished in 11.846s.298peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.02 seconds)299controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .300controller: (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)301controller: waiting for success: wg show wg-star peers | grep -q .302controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)303peer1: waiting for success: wg show wg-star peers | grep -q .304peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)305peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::da68:6425:5c0e:5f5a306peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::da68:6425:5c0e:5f5a, in 0.00 seconds)307controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c56b:b714:f42c:e615308controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c56b:b714:f42c:e615, in 0.00 seconds)309controller: must succeed: wg show wg-star peers | wc -l310controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)311peer2: systemd-nspawn running (pid 736)312peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...313peer2: waiting for unit data-mesher.service314controller # [2188023.979397] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=DEBUG msg="attempting push/pull" peer_count=1315controller # [2188023.979397] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s316controller # [2188023.979714] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=INFO msg="received state sync from peer" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV317controller # [2188023.979714] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV318controller # [2188023.979714] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=DEBUG msg="new file detected" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04319controller # [2188023.979714] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04320controller # [2188023.979714] controller data-mesher[233]: time=2026-09-29T15:03:58.402Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 signed_at="2026-09-29 15:03:53.482 +0000 UTC" signed_by="bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04=" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV321controller # [2188023.979970] controller data-mesher[233]: time=2026-09-29T15:03:58.403Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV322controller # [2188023.980065] controller data-mesher[233]: time=2026-09-29T15:03:58.403Z level=INFO msg="received file request" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/controller323controller # [2188023.980128] controller data-mesher[233]: time=2026-09-29T15:03:58.403Z level=DEBUG msg="new file detected" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04324controller # [2188023.980128] controller data-mesher[233]: time=2026-09-29T15:03:58.403Z level=INFO msg="state exchange complete" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s325controller # [2188023.980194] controller data-mesher[233]: time=2026-09-29T15:03:58.403Z level=DEBUG msg="push/pull successful" interval=5s326controller # [2188023.980819] controller data-mesher[233]: time=2026-09-29T15:03:58.404Z level=INFO msg="file transfer complete" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/controller327controller # [2188023.982083] controller data-mesher[233]: time=2026-09-29T15:03:58.405Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 signed_at="2026-09-29 15:03:53.482 +0000 UTC" signed_by="bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04=" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV written=true elapsed=2.427012ms328controller # [2188023.983166] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...329controller # [2188024.047163] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.330controller # [2188024.047261] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.331nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE332nixos-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.333Note: 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.334░ Spawning container peer2 on /build/vm-state-peer2.335peer1 # [2188023.979108] peer1 data-mesher[222]: time=2026-09-29T15:03:58.402Z level=DEBUG msg="attempting push/pull" peer_count=1336peer1 # [2188023.979400] peer1 data-mesher[222]: time=2026-09-29T15:03:58.402Z level=DEBUG msg="initiating state exchange" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s337peer1 # [2188023.979676] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="received state sync from peer" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ338peer1 # [2188023.979676] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ339peer1 # [2188023.979724] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=DEBUG msg="new file detected" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller340peer1 # [2188023.979747] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller341peer1 # [2188023.979765] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-29 15:03:53.443 +0000 UTC" signed_by="NGCeffeLoGI8PtJvfqxjxSXjDEMAUFSsYrKG5fbvjT0=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ342peer1 # [2188023.980155] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ343peer1 # [2188023.980172] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=DEBUG msg="new file detected" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller344peer1 # [2188023.980172] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="state exchange complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s345peer1 # [2188023.980210] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=INFO msg="received file request" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04346peer1 # [2188023.980290] peer1 data-mesher[222]: time=2026-09-29T15:03:58.403Z level=DEBUG msg="push/pull successful" interval=5s347peer1 # [2188023.981111] peer1 data-mesher[222]: time=2026-09-29T15:03:58.404Z level=INFO msg="file transfer complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04348peer1 # [2188023.982021] peer1 data-mesher[222]: time=2026-09-29T15:03:58.405Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-29 15:03:53.443 +0000 UTC" signed_by="NGCeffeLoGI8PtJvfqxjxSXjDEMAUFSsYrKG5fbvjT0=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ written=true elapsed=2.251391ms349peer1 # [2188023.983109] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...350peer1 # [2188024.048876] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.351peer1 # [2188024.048922] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.352peer2 # [2188024.726194] peer2 systemd-journald[99]: Journal started353peer2 # [2188024.726222] peer2 systemd-journald[99]: Runtime Journal (/run/log/journal/5873c43471bf47f7bdb77556d72d026e) is 8M, max 3.7G, 3.7G free.354peer2 # [2188024.732606] peer2 systemd[1]: Finished Apply Kernel Variables.355peer2 # [2188024.739110] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.356peer2 # [2188024.746639] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...357peer2 # [2188024.746975] peer2 systemd[1]: Starting Network Name Resolution...358peer2 # [2188024.747274] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...359peer2 # [2188024.776539] peer2 systemd-journald[99]: Time spent on flushing to /var/log/journal/5873c43471bf47f7bdb77556d72d026e is 1.081ms for 7 entries.360peer2 # [2188024.776539] peer2 systemd-journald[99]: System Journal (/var/log/journal/5873c43471bf47f7bdb77556d72d026e) is 8M, max 4G, 3.9G free.361peer2 # [2188024.783715] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.362peer2 # [2188024.783889] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.363peer2 # [2188024.784622] peer2 systemd[1]: Reached target Preparation for Local File Systems.364peer2 # [2188024.784672] peer2 systemd[1]: Reached target Local File Systems.365peer2 # [2188024.785136] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.366peer2 # [2188024.785161] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container367peer2 # [2188024.785552] peer2 systemd[1]: Starting Save Transient machine-id to Disk...368peer2 # [2188024.785833] peer2 systemd[1]: Starting Create System Files and Directories...369peer2 # [2188024.785845] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys370peer2 # [2188024.795485] peer2 systemd-tmpfiles[181]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted371peer2 # [2188024.795619] peer2 systemd-tmpfiles[181]: fchmod() of /var/log/journal failed: Operation not permitted372peer2 # [2188024.795717] peer2 systemd-tmpfiles[181]: fchmod() of /var/log/journal/5873c43471bf47f7bdb77556d72d026e failed: Operation not permitted373peer2 # [2188024.795856] peer2 systemd-tmpfiles[181]: fchmod() of /run/log/journal failed: Operation not permitted374peer2 # [2188024.796653] peer2 systemd[1]: Finished Create System Files and Directories.375peer2 # [2188024.797096] peer2 systemd[1]: Starting Rebuild Journal Catalog...376peer2 # [2188024.797461] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...377peer2 # [2188024.803654] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.378peer2 # [2188024.809405] peer2 systemd[1]: Finished Save Transient machine-id to Disk.379peer2 # [2188024.811025] peer2 systemd[1]: Finished Rebuild Journal Catalog.380peer2 # [2188024.811493] peer2 systemd[1]: Starting Update is Completed...381peer2 # [2188024.811617] peer2 systemd[1]: Finished Firewall.382peer2 # [2188024.812091] peer2 systemd[1]: Reached target Preparation for Network.383peer2 # [2188024.812252] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.384peer2 # [2188024.812683] peer2 systemd[1]: Starting Network Management...385peer2 # [2188024.816206] peer2 systemd[1]: Finished Update is Completed.386peer2 # [2188025.251181] peer2 systemd-networkd[216]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted387peer2 # [2188025.251257] peer2 systemd-networkd[216]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted388peer2 # [2188025.258959] peer2 systemd-networkd[216]: /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.389peer2 # [2188025.259105] peer2 systemd-networkd[216]: /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.390peer2 # [2188025.259171] peer2 systemd-networkd[216]: lo: Link UP391peer2 # [2188025.259175] peer2 systemd-networkd[216]: lo: Gained carrier392peer2 # [2188025.259306] peer2 systemd-networkd[216]: eth1: Configuring with /etc/systemd/network/40-eth1.network.393peer2 # [2188025.259575] peer2 systemd[1]: Started Network Management.394peer2 # [2188025.259925] peer2 systemd-networkd[216]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.395peer2 # [2188025.260106] peer2 systemd-networkd[216]: wg-star: netdev ready396peer2 # [2188025.260212] peer2 systemd-networkd[216]: eth1: Link UP397peer2 # [2188025.260250] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...398peer2 # [2188025.260314] peer2 systemd-networkd[216]: eth1: Gained carrier399peer2 # [2188025.280298] peer2 systemd-networkd[216]: wg-star: Link UP400peer2 # [2188025.280303] peer2 systemd-networkd[216]: wg-star: Gained carrier401peer2 # [2188025.283631] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.402peer2 # [2188025.611039] peer2 systemd-resolved[135]: Positive Trust Anchors:403peer2 # [2188025.611046] peer2 systemd-resolved[135]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d404peer2 # [2188025.611049] peer2 systemd-resolved[135]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16405peer2 # [2188025.611065] peer2 systemd-resolved[135]: 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 test406peer2 # [2188025.621136] peer2 systemd-resolved[135]: Using system hostname 'peer2'.407peer2 # [2188025.622097] peer2 systemd[1]: Started Network Name Resolution.408peer2 # [2188025.622142] peer2 systemd[1]: Reached target Network.409peer2 # [2188025.622174] peer2 systemd[1]: Reached target System Initialization.410peer2 # [2188025.622222] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.411peer2 # [2188025.622240] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.412peer2 # [2188025.622257] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container413peer2 # [2188025.622269] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.414peer2 # [2188025.622280] peer2 systemd[1]: Reached target Path Units.415peer2 # [2188025.622298] peer2 systemd[1]: Reached target Timer Units.416peer2 # [2188025.622373] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.417peer2 # [2188025.622446] peer2 systemd[1]: Listening on Nix Daemon Socket.418peer2 # [2188025.622517] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.419peer2 # [2188025.622527] peer2 systemd[1]: Reached target Socket Units.420peer2 # [2188025.622545] peer2 systemd[1]: Reached target Basic System.421peer2 # [2188025.623197] peer2 systemd[1]: Starting data mesher daemon...422peer2 # [2188025.623544] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...423peer2 # [2188025.623899] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...424peer2 # [2188025.624439] peer2 systemd[1]: Starting D-Bus System Message Bus...425peer2 # [2188025.654641] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.426peer2 # [2188025.723539] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.427peer2 # [2188025.743980] peer2 nsncd[224]: Sep 29 15:04:00.167 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"428peer2 # [2188025.743985] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).429peer2 # [2188025.744040] peer2 systemd[1]: Reached target Host and Network Name Lookups.430peer2 # [2188025.744088] peer2 systemd[1]: Reached target User and Group Name Lookups.431peer2 # [2188025.744656] peer2 systemd[1]: Starting User Login Management...432peer2 # [2188025.744996] peer2 systemd[1]: Starting Permit User Sessions...433peer2 # [2188025.768538] peer2 systemd[1]: Finished Permit User Sessions.434peer2 # [2188025.769329] peer2 systemd[1]: Started Console Getty.435peer2 # [2188025.769349] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0436peer2 # [2188025.769357] peer2 systemd[1]: Reached target Login Prompts.437peer2 # [2188025.838625] peer2 dbus-broker-launch[225]: Looking up NSS user entry for 'systemd-timesync'...438peer2 # [2188025.839103] peer2 dbus-broker-launch[225]: NSS returned no entry for 'systemd-timesync'439peer2 # [2188025.839103] peer2 dbus-broker-launch[225]: Invalid user-name in /nix/store/1lr1srjvd1fgm10g9q2rzzqrxf3q9rfz-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"440peer2 # [2188025.839316] peer2 systemd[1]: Started D-Bus System Message Bus.441peer2 # [2188025.842536] peer2 dbus-broker-launch[225]: Ready442peer2 # [2188026.127237] peer2 data-mesher[222]: time=2026-09-29T15:04:00.550Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]443peer2 # [2188026.128399] peer2 data-mesher[222]: time=2026-09-29T15:04:00.551Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ: [/dns/controller.clan/tcp/7946]} {12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV: [/dns/peer1.clan/tcp/7946]} {12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv444peer2 # [2188026.128418] peer2 data-mesher[222]: time=2026-09-29T15:04:00.551Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml445peer2 # [2188026.129047] peer2 data-mesher[222]: time=2026-09-29T15:04:00.552Z level=INFO msg="checking file integrity"446peer2 # [2188026.129117] peer2 data-mesher[222]: time=2026-09-29T15:04:00.552Z level=INFO msg="file integrity check complete"447peer2 # [2188026.130983] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="libp2p host created" peer_id=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv 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::9438:7345:1b54:3bdc/tcp/7946]"448peer2 # [2188026.131017] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name449peer2 # [2188026.131017] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name450peer2 # [2188026.131017] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="registered HTTP route" method=GET path=/files451peer2 # [2188026.131017] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="starting server"452peer2 # [2188026.131097] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="waiting for DHT to populate" delay=10s453peer2 # [2188026.131162] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="HTTP server listening" address=[::1]:7331454peer2 # [2188026.131162] peer2 data-mesher[222]: time=2026-09-29T15:04:00.554Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331455peer2 # [2188026.133305] peer2 data-mesher[222]: time=2026-09-29T15:04:00.556Z level=INFO msg="peer connected" peer_id=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV remote_addr=/ip4/192.168.1.2/tcp/7946456peer2 # [2188026.134872] peer2 data-mesher[222]: time=2026-09-29T15:04:00.558Z level=INFO msg="peer connected" peer_id=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ remote_addr=/ip4/192.168.1.1/tcp/7946457peer2 # [2188026.277439] peer2 systemd-logind[242]: New seat seat0.458peer2 # [2188026.277564] peer2 systemd[1]: Started User Login Management.459peer2 # [2188026.278434] peer2 systemd[1]: Starting linger-users.service...460peer2 # [2188026.295871] peer2 systemd[1]: linger-users.service: Deactivated successfully.461peer2 # [2188026.295970] peer2 systemd[1]: Finished linger-users.service.462controller # [2188026.135078] controller data-mesher[233]: time=2026-09-29T15:04:00.558Z level=INFO msg="peer connected" peer_id=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv remote_addr=/ip4/192.168.1.3/tcp/7946463peer1 # [2188026.133480] peer1 data-mesher[222]: time=2026-09-29T15:04:00.556Z level=INFO msg="peer connected" peer_id=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv remote_addr=/ip4/192.168.1.3/tcp/7946464peer2 # [2188026.752364] peer2 systemd-networkd[216]: eth1: Gained IPv6LL465controller # [2188028.981041] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="attempting push/pull" peer_count=1466controller # [2188028.981041] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s467controller # [2188028.981404] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=INFO msg="received state sync from peer" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV468controller # [2188028.981404] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV469controller # [2188028.981502] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV470controller # [2188028.981612] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=INFO msg="state exchange complete" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s471controller # [2188028.981612] controller data-mesher[233]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="push/pull successful" interval=5s472peer1 # [2188028.980788] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="attempting push/pull" peer_count=1473peer1 # [2188028.980788] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="initiating state exchange" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s474peer1 # [2188028.981333] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=INFO msg="received state sync from peer" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ475peer1 # [2188028.981333] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ476peer1 # [2188028.981417] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ477peer1 # [2188028.981484] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=INFO msg="state exchange complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s478peer1 # [2188028.981484] peer1 data-mesher[222]: time=2026-09-29T15:04:03.404Z level=DEBUG msg="push/pull successful" interval=5s479controller # [2188033.982387] controller data-mesher[233]: time=2026-09-29T15:04:08.405Z level=DEBUG msg="attempting push/pull" peer_count=1480controller # [2188033.982387] controller data-mesher[233]: time=2026-09-29T15:04:08.405Z level=DEBUG msg="initiating state exchange" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv timeout=5s481controller # [2188033.982804] controller data-mesher[233]: time=2026-09-29T15:04:08.405Z level=INFO msg="received state sync from peer" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV482controller # [2188033.982804] controller data-mesher[233]: time=2026-09-29T15:04:08.405Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV483controller # [2188033.983045] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=INFO msg="merging remote state" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv484controller # [2188033.983045] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=INFO msg="state exchange complete" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv timeout=5s485controller # [2188033.983140] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=DEBUG msg="push/pull successful" interval=5s486controller # [2188033.983172] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=INFO msg="received file request" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04487controller # [2188033.983193] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=INFO msg="received file request" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/controller488controller # [2188033.983709] controller data-mesher[233]: time=2026-09-29T15:04:08.406Z level=INFO msg="file transfer complete" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/controller489controller # [2188033.984129] controller data-mesher[233]: time=2026-09-29T15:04:08.407Z level=INFO msg="file transfer complete" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04490peer1 # [2188033.982031] peer1 data-mesher[222]: time=2026-09-29T15:04:08.405Z level=DEBUG msg="attempting push/pull" peer_count=1491peer1 # [2188033.982031] peer1 data-mesher[222]: time=2026-09-29T15:04:08.405Z level=DEBUG msg="initiating state exchange" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s492peer1 # [2188033.982634] peer1 data-mesher[222]: time=2026-09-29T15:04:08.405Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ493peer1 # [2188033.982738] peer1 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="state exchange complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s494peer1 # [2188033.982762] peer1 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=DEBUG msg="push/pull successful" interval=5s495peer2: still waiting for container 'peer2' to reach ready state...496peer2 # [2188033.982844] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="received state sync from peer" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ497peer2 # [2188033.982844] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ498peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=DEBUG msg="new file detected" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04499peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=DEBUG msg="new file detected" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller500peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04501peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller502peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-29 15:03:53.443 +0000 UTC" signed_by="NGCeffeLoGI8PtJvfqxjxSXjDEMAUFSsYrKG5fbvjT0=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ503peer2 # [2188033.983214] peer2 data-mesher[222]: time=2026-09-29T15:04:08.406Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 signed_at="2026-09-29 15:03:53.482 +0000 UTC" signed_by="bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ504peer2 # [2188033.985405] peer2 data-mesher[222]: time=2026-09-29T15:04:08.408Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-29 15:03:53.443 +0000 UTC" signed_by="NGCeffeLoGI8PtJvfqxjxSXjDEMAUFSsYrKG5fbvjT0=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ written=true elapsed=2.417503ms505peer2 # [2188033.985718] peer2 data-mesher[222]: time=2026-09-29T15:04:08.409Z level=INFO msg="download complete" name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 signed_at="2026-09-29 15:03:53.482 +0000 UTC" signed_by="bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04=" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ written=true elapsed=2.728399ms506peer2 # [2188033.986362] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...507peer2 # [2188034.056418] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.508peer2 # [2188034.056548] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.509peer2: (finished: waiting for unit data-mesher.service, in 12.14 seconds)510??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.511 File "/nix/store/ww1fp9ch7b86riwmzgb57p620cz6f717-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39512controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1513??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.514 File "/nix/store/ww1fp9ch7b86riwmzgb57p620cz6f717-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39515peer2 # [2188036.131201] peer2 data-mesher[222]: time=2026-09-29T15:04:10.554Z level=INFO msg="performing state exchange with peers on join" count=1516peer2 # [2188036.131201] peer2 data-mesher[222]: time=2026-09-29T15:04:10.554Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s517peer2 # [2188036.131821] peer2 data-mesher[222]: time=2026-09-29T15:04:10.555Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV518peer2 # [2188036.131886] peer2 data-mesher[222]: time=2026-09-29T15:04:10.555Z level=INFO msg="state exchange complete" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV timeout=5s519peer2 # [2188036.131912] peer2 data-mesher[222]: time=2026-09-29T15:04:10.555Z level=INFO msg="server started"520peer2 # [2188036.132009] peer2 data-mesher[222]: time=2026-09-29T15:04:10.555Z level=INFO msg="starting expired-file sweeper" interval=1m0s521peer2 # [2188036.132064] peer2 systemd[1]: Started data mesher daemon.522peer2 # [2188036.132751] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...523peer2 # [2188036.211011] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...524peer2 # [2188036.214132] peer2 data-mesher[222]: time=2026-09-29T15:04:10.637Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE status=204525peer2 # [2188036.214203] peer2 dm-wg-star-publish[287]: Status: 204 No Content526peer2 # [2188036.215935] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.527peer2 # [2188036.235088] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.528peer2 # [2188036.235362] peer2 systemd[1]: Reached target Multi-User System.529peer2 # [2188036.288013] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.530peer2 # [2188036.288146] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.531peer2 # [2188036.288310] peer2 systemd[1]: Startup finished in 11.789s.532peer1 # [2188036.131604] peer1 data-mesher[222]: time=2026-09-29T15:04:10.554Z level=INFO msg="received state sync from peer" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv533peer1 # [2188036.131604] peer1 data-mesher[222]: time=2026-09-29T15:04:10.554Z level=INFO msg="merging remote state" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv534controller # [2188038.983814] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="attempting push/pull" peer_count=1535controller # [2188038.983814] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="initiating state exchange" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv timeout=5s536controller # [2188038.984218] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="received state sync from peer" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV537controller # [2188038.984218] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="merging remote state" peer=12D3KooWHBfYyix72xnsvjKxkwGuTYGcyCr4iwdGrMroLkzJjqEV538controller # [2188038.984278] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="merging remote state" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv539controller # [2188038.984405] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="new file detected" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv name=dm_wg_star_wg_star/bXapMEIksKMPm0v5hRTyuSpxkWUNtHQAnSDriLMQN04 name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE540controller # [2188038.984405] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="state exchange complete" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv timeout=5s541controller # [2188038.984462] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="push/pull successful" interval=5s542controller # [2188038.984462] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE543controller # [2188038.984462] controller data-mesher[233]: time=2026-09-29T15:04:13.407Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE signed_at="2026-09-29 15:04:10.631 +0000 UTC" signed_by="pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE=" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv544controller # [2188038.987161] controller data-mesher[233]: time=2026-09-29T15:04:13.410Z level=INFO msg="download complete" name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE signed_at="2026-09-29 15:04:10.631 +0000 UTC" signed_by="pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE=" peer=12D3KooWM4fCjoUD4pxKJERxq4JbjwmqXLrc3NUwzKugBjyjFuwv written=true elapsed=2.732287ms545controller # [2188038.987278] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...546controller # [2188039.068087] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.547controller # [2188039.068217] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.548peer1 # [2188038.983752] peer1 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="attempting push/pull" peer_count=1549peer1 # [2188038.983752] peer1 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="initiating state exchange" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s550peer1 # [2188038.984222] peer1 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ551peer1 # [2188038.984282] peer1 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=INFO msg="state exchange complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ timeout=5s552peer1 # [2188038.984295] peer1 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=DEBUG msg="push/pull successful" interval=5s553controller: (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 3.03 seconds)554controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1555controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)556peer2: waiting for success: wg show wg-star peers | grep -q .557peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)558peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::da68:6425:5c0e:5f5a559peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::da68:6425:5c0e:5f5a, in 0.01 seconds)560controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9438:7345:1b54:3bdc561controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9438:7345:1b54:3bdc, in 0.00 seconds)562peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9438:7345:1b54:3bdc563peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9438:7345:1b54:3bdc, in 0.00 seconds)564peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c56b:b714:f42c:e615565peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c56b:b714:f42c:e615, in 0.00 seconds)566(finished: run the VM test script, in 32.41 seconds)567peer2 # [2188038.984039] peer2 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=INFO msg="received state sync from peer" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ568peer2 # [2188038.984039] peer2 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=INFO msg="merging remote state" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ569peer2 # [2188038.984532] peer2 data-mesher[222]: time=2026-09-29T15:04:13.407Z level=INFO msg="received file request" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE570peer2 # [2188038.985486] peer2 data-mesher[222]: time=2026-09-29T15:04:13.408Z level=INFO msg="file transfer complete" peer=12D3KooWG3xKrtVL6JqWGNWPyUgv7nHWuPphMci5kW5TGgHU5BLZ network="dgz+zmwSgqfcwUOnLf/h/cPCcpDXk3LYCf9EZif9nrw=" name=dm_wg_star_wg_star/pxnyx4oUkGOno0CIFISsR8EAiXUl5vemWUMn2etgtBE571test script finished in 32.46s572cleanup573kill NspawnMachine (pid 50)574kill NspawnMachine (pid 53)575Container controller terminated by signal KILL.576kill NspawnMachine (pid 736)577Container peer1 terminated by signal KILL.578Container peer2 terminated by signal KILL.579(finished: cleanup, in 0.34 seconds)