container-test-run-dm-wireguard-star
checks.x86_64-linux.dm-wireguard-star
· build #76
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.00 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 controller, peer1, peer2,9 vlan1,10 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh11controller: systemd-nspawn running (pid 50)12controller: Waiting for journal at /build/vm-state-controller/var/log/journal...13peer1: systemd-nspawn running (pid 53)14peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...15controller: waiting for unit data-mesher.service16nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE17nixos-nspawn(peer1): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.18nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE19nixos-nspawn(controller): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.20Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.21Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.22░ Spawning container peer1 on /build/vm-state-peer1.23░ Spawning container controller on /build/vm-state-controller.24controller # [7653794.890991] controller systemd-journald[105]: Journal started25peer1 # [7653794.891525] peer1 systemd-journald[96]: Journal started26controller # [7653794.891028] controller systemd-journald[105]: Runtime Journal (/run/log/journal/3469a64fed444bf1ae201938a17d3af4) is 8M, max 3.7G, 3.7G free.27peer1 # [7653794.891552] peer1 systemd-journald[96]: Runtime Journal (/run/log/journal/1cae326455294b868c4ab2faa43bd449) is 8M, max 3.7G, 3.7G free.28controller # [7653794.892988] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29peer1 # [7653794.895925] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...30controller # [7653794.897718] controller systemd[1]: Starting Flush Journal to Persistent Storage...31peer1 # [7653794.896337] peer1 systemd[1]: Starting Network Name Resolution...32controller # [7653794.898068] controller systemd[1]: Starting Network Name Resolution...33peer1 # [7653794.896662] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...34controller # [7653794.898370] controller systemd[1]: Starting Create Static Device Nodes in /dev...35peer1 # [7653794.901679] peer1 systemd-journald[96]: Time spent on flushing to /var/log/journal/1cae326455294b868c4ab2faa43bd449 is 1.366ms for 5 entries.36controller # [7653794.902692] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/3469a64fed444bf1ae201938a17d3af4 is 1.021ms for 6 entries.37peer1 # [7653794.901679] peer1 systemd-journald[96]: System Journal (/var/log/journal/1cae326455294b868c4ab2faa43bd449) is 8M, max 4G, 3.9G free.38controller # [7653794.902692] controller systemd-journald[105]: System Journal (/var/log/journal/3469a64fed444bf1ae201938a17d3af4) is 8M, max 4G, 3.9G free.39peer1 # [7653794.904981] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.40controller # [7653794.908778] controller systemd[1]: Finished Flush Journal to Persistent Storage.41peer1 # [7653794.905098] peer1 systemd[1]: Reached target Preparation for Local File Systems.42controller # [7653794.908988] controller systemd[1]: Finished Create Static Device Nodes in /dev.43peer1 # [7653794.905141] peer1 systemd[1]: Reached target Local File Systems.44controller # [7653794.909856] controller systemd[1]: Reached target Preparation for Local File Systems.45peer1 # [7653794.905542] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.46controller # [7653794.909910] controller systemd[1]: Reached target Local File Systems.47peer1 # [7653794.905567] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container48controller # [7653794.910336] controller systemd[1]: Listening on Boot Loader Control Service Socket.49peer1 # [7653794.905989] peer1 systemd[1]: Starting Save Transient machine-id to Disk...50controller # [7653794.910362] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container51peer1 # [7653794.906008] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys52controller # [7653794.910773] controller systemd[1]: Starting Save Transient machine-id to Disk...53peer1 # [7653794.907625] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.54controller # [7653794.911052] controller systemd[1]: Starting Create System Files and Directories...55peer1 # [7653794.908026] peer1 systemd[1]: Starting Create System Files and Directories...56controller # [7653794.911065] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys57peer1 # [7653794.919752] peer1 systemd-tmpfiles[136]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted58controller # [7653794.920538] controller systemd-tmpfiles[148]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted59peer1 # [7653794.919895] peer1 systemd-tmpfiles[136]: fchmod() of /var/log/journal failed: Operation not permitted60peer1 # [7653794.919996] peer1 systemd-tmpfiles[136]: fchmod() of /var/log/journal/1cae326455294b868c4ab2faa43bd449 failed: Operation not permitted61controller # [7653794.920683] controller systemd-tmpfiles[148]: fchmod() of /var/log/journal failed: Operation not permitted62peer1 # [7653794.920145] peer1 systemd-tmpfiles[136]: fchmod() of /run/log/journal failed: Operation not permitted63controller # [7653794.920782] controller systemd-tmpfiles[148]: fchmod() of /var/log/journal/3469a64fed444bf1ae201938a17d3af4 failed: Operation not permitted64peer1 # [7653794.921132] peer1 systemd[1]: Finished Create System Files and Directories.65controller # [7653794.920930] controller systemd-tmpfiles[148]: fchmod() of /run/log/journal failed: Operation not permitted66peer1 # [7653794.922010] peer1 systemd[1]: Starting Rebuild Journal Catalog...67controller # [7653794.922738] controller systemd[1]: Finished Create System Files and Directories.68peer1 # [7653794.922377] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...69controller # [7653794.923443] controller systemd[1]: Starting Rebuild Journal Catalog...70peer1 # [7653794.923720] peer1 systemd[1]: Finished Save Transient machine-id to Disk.71peer1 # [7653794.929227] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.72controller # [7653794.923847] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...73peer1 # [7653794.935731] peer1 systemd[1]: Finished Rebuild Journal Catalog.74controller # [7653794.924012] controller systemd[1]: Finished Save Transient machine-id to Disk.75peer1 # [7653794.936405] peer1 systemd[1]: Starting Update is Completed...76controller # [7653794.930677] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.77peer1 # [7653794.942312] peer1 systemd[1]: Finished Update is Completed.78controller # [7653794.936289] controller systemd[1]: Finished Rebuild Journal Catalog.79peer1 # [7653794.978628] peer1 systemd[1]: Finished Firewall.80controller # [7653794.936796] controller systemd[1]: Starting Update is Completed...81peer1 # [7653794.978705] peer1 systemd[1]: Reached target Preparation for Network.82controller # [7653794.941678] controller systemd[1]: Finished Update is Completed.83peer1 # [7653794.978867] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.84controller # [7653794.981237] controller systemd[1]: Finished Firewall.85peer1 # [7653794.979514] peer1 systemd[1]: Starting Network Management...86controller # [7653794.981323] controller systemd[1]: Reached target Preparation for Network.87peer1 # [7653795.238182] peer1 systemd-networkd[214]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted88controller # [7653794.981446] controller systemd[1]: Listening on Network Management Resolve Hook Socket.89peer1 # [7653795.238260] peer1 systemd-networkd[214]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted90controller # [7653794.981907] controller systemd[1]: Starting Network Management...91peer1 # [7653795.243753] peer1 systemd-networkd[214]: /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.92controller # [7653795.238140] controller systemd-networkd[225]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted93peer1 # [7653795.243906] peer1 systemd-networkd[214]: /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.94controller # [7653795.238234] controller systemd-networkd[225]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted95peer1 # [7653795.243972] peer1 systemd-networkd[214]: lo: Link UP96controller # [7653795.243752] controller systemd-networkd[225]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.97peer1 # [7653795.243975] peer1 systemd-networkd[214]: lo: Gained carrier98controller # [7653795.243913] controller systemd-networkd[225]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.99peer1 # [7653795.244105] peer1 systemd-networkd[214]: eth1: Configuring with /etc/systemd/network/40-eth1.network.100controller # [7653795.243985] controller systemd-networkd[225]: lo: Link UP101peer1 # [7653795.244340] peer1 systemd[1]: Started Network Management.102controller # [7653795.243988] controller systemd-networkd[225]: lo: Gained carrier103peer1 # [7653795.244891] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...104controller # [7653795.244136] controller systemd-networkd[225]: eth1: Configuring with /etc/systemd/network/40-eth1.network.105peer1 # [7653795.245110] peer1 systemd-networkd[214]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.106peer1 # [7653795.245295] peer1 systemd-networkd[214]: wg-star: netdev ready107controller # [7653795.244381] controller systemd[1]: Started Network Management.108peer1 # [7653795.245421] peer1 systemd-networkd[214]: eth1: Link UP109controller # [7653795.244926] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...110peer1 # [7653795.245423] peer1 systemd-networkd[214]: eth1: Gained carrier111controller # [7653795.245111] controller systemd-networkd[225]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.112peer1 # [7653795.266478] peer1 systemd-networkd[214]: wg-star: Link UP113controller # [7653795.245297] controller systemd-networkd[225]: wg-star: netdev ready114peer1 # [7653795.266483] peer1 systemd-networkd[214]: wg-star: Gained carrier115controller # [7653795.245585] controller systemd-networkd[225]: eth1: Link UP116peer1 # [7653795.269491] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.117controller # [7653795.245589] controller systemd-networkd[225]: eth1: Gained carrier118peer1 # [7653795.352768] peer1 systemd-resolved[118]: Positive Trust Anchors:119controller # [7653795.266414] controller systemd-networkd[225]: wg-star: Link UP120peer1 # [7653795.352777] peer1 systemd-resolved[118]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d121controller # [7653795.266418] controller systemd-networkd[225]: wg-star: Gained carrier122peer1 # [7653795.352779] peer1 systemd-resolved[118]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16123controller # [7653795.269683] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.124peer1 # [7653795.352795] peer1 systemd-resolved[118]: 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 test125controller # [7653795.343804] controller systemd-resolved[129]: Positive Trust Anchors:126peer1 # [7653795.363154] peer1 systemd-resolved[118]: Using system hostname 'peer1'.127controller # [7653795.343809] controller systemd-resolved[129]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d128controller # [7653795.343813] controller systemd-resolved[129]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16129peer1 # [7653795.364117] peer1 systemd[1]: Started Network Name Resolution.130controller # [7653795.343828] controller systemd-resolved[129]: 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 test131peer1 # [7653795.364170] peer1 systemd[1]: Reached target Network.132controller # [7653795.354912] controller systemd-resolved[129]: Using system hostname 'controller'.133peer1 # [7653795.364206] peer1 systemd[1]: Reached target System Initialization.134controller # [7653795.355970] controller systemd[1]: Started Network Name Resolution.135peer1 # [7653795.364258] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.136peer1 # [7653795.364276] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.137controller # [7653795.356039] controller systemd[1]: Reached target Network.138peer1 # [7653795.364293] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container139controller # [7653795.356085] controller systemd[1]: Reached target System Initialization.140controller # [7653795.356155] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.141peer1 # [7653795.364304] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.142controller # [7653795.356182] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container143peer1 # [7653795.364315] peer1 systemd[1]: Reached target Path Units.144controller # [7653795.356200] controller systemd[1]: Started Daily Cleanup of Temporary Directories.145peer1 # [7653795.364334] peer1 systemd[1]: Reached target Timer Units.146controller # [7653795.356212] controller systemd[1]: Reached target Path Units.147peer1 # [7653795.364403] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.148controller # [7653795.356236] controller systemd[1]: Reached target Timer Units.149peer1 # [7653795.364461] peer1 systemd[1]: Listening on Nix Daemon Socket.150controller # [7653795.356332] controller systemd[1]: Listening on D-Bus System Message Bus Socket.151peer1 # [7653795.364528] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.152controller # [7653795.356412] controller systemd[1]: Listening on Nix Daemon Socket.153peer1 # [7653795.364537] peer1 systemd[1]: Reached target Socket Units.154controller # [7653795.356496] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.155peer1 # [7653795.364556] peer1 systemd[1]: Reached target Basic System.156controller # [7653795.356512] controller systemd[1]: Reached target Socket Units.157peer1 # [7653795.378203] peer1 systemd[1]: Starting data mesher daemon...158controller # [7653795.356540] controller systemd[1]: Reached target Basic System.159peer1 # [7653795.378587] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...160controller # [7653795.357275] controller systemd[1]: Starting data mesher daemon...161peer1 # [7653795.378908] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...162controller # [7653795.357608] controller systemd[1]: Starting Import lastlog data into lastlog2 database...163peer1 # [7653795.379472] peer1 systemd[1]: Starting D-Bus System Message Bus...164peer1 # [7653795.388492] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.165controller # [7653795.357981] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...166controller # [7653795.358628] controller systemd[1]: Starting D-Bus System Message Bus...167controller # [7653795.387514] controller systemd[1]: Finished Import lastlog data into lastlog2 database.168controller # [7653795.443536] controller nsncd[232]: Aug 28 00:04:12.809 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"169peer1 # [7653795.444709] peer1 nsncd[221]: Aug 28 00:04:12.810 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"170controller # [7653795.443576] controller systemd[1]: Started Name Service Cache Daemon (nsncd).171peer1 # [7653795.444758] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).172peer1 # [7653795.444789] peer1 systemd[1]: Reached target Host and Network Name Lookups.173peer1 # [7653795.444817] peer1 systemd[1]: Reached target User and Group Name Lookups.174peer1 # [7653795.445398] peer1 systemd[1]: Starting User Login Management...175peer1 # [7653795.445724] peer1 systemd[1]: Starting Permit User Sessions...176peer1 # [7653795.474175] peer1 systemd[1]: Finished Permit User Sessions.177peer1 # [7653795.474752] peer1 systemd[1]: Started Console Getty.178peer1 # [7653795.474780] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0179peer1 # [7653795.474790] peer1 systemd[1]: Reached target Login Prompts.180controller # [7653795.443622] controller systemd[1]: Reached target Host and Network Name Lookups.181controller # [7653795.443656] controller systemd[1]: Reached target User and Group Name Lookups.182controller # [7653795.444348] controller systemd[1]: Starting User Login Management...183controller # [7653795.444686] controller systemd[1]: Starting Permit User Sessions...184controller # [7653795.474269] controller systemd[1]: Finished Permit User Sessions.185controller # [7653795.474836] controller systemd[1]: Started Console Getty.186controller # [7653795.474861] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0187controller # [7653795.474873] controller systemd[1]: Reached target Login Prompts.188controller # [7653795.497873] controller dbus-broker-launch[233]: Looking up NSS user entry for 'systemd-timesync'...189controller # [7653795.498378] controller dbus-broker-launch[233]: NSS returned no entry for 'systemd-timesync'190controller # [7653795.498378] controller dbus-broker-launch[233]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"191controller # [7653795.498638] controller systemd[1]: Started D-Bus System Message Bus.192controller # [7653795.503872] controller dbus-broker-launch[233]: Ready193controller # [7653795.662412] controller data-mesher[230]: time=2026-08-28T00:04:13.028Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]194controller # [7653795.663624] controller data-mesher[230]: time=2026-08-28T00:04:13.029Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q: [/dns/controller.clan/tcp/7946]} {12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk: [/dns/peer1.clan/tcp/7946]} {12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q195controller # [7653795.663624] controller data-mesher[230]: time=2026-08-28T00:04:13.029Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml196controller # [7653795.664535] controller data-mesher[230]: time=2026-08-28T00:04:13.030Z level=INFO msg="checking file integrity"197controller # [7653795.664601] controller data-mesher[230]: time=2026-08-28T00:04:13.030Z level=INFO msg="file integrity check complete"198controller # [7653795.666611] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="libp2p host created" peer_id=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q 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::563f:ed85:9046:f483/tcp/7946]"199controller # [7653795.666632] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=GET path=/files200controller # [7653795.666632] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name201controller # [7653795.666632] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name202controller # [7653795.666669] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="starting server"203controller # [7653795.666704] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="waiting for DHT to populate" delay=10s204controller # [7653795.666740] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="HTTP server listening" address=[::1]:7331205controller # [7653795.666759] controller data-mesher[230]: time=2026-08-28T00:04:13.032Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331206controller # [7653795.669116] controller data-mesher[230]: time=2026-08-28T00:04:13.034Z level=INFO msg="peer connected" peer_id=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk remote_addr=/ip4/192.168.1.2/tcp/7946207peer1 # [7653795.497960] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...208peer1 # [7653795.498441] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'209peer1 # [7653795.498441] peer1 dbus-broker-launch[222]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"210peer1 # [7653795.498680] peer1 systemd[1]: Started D-Bus System Message Bus.211peer1 # [7653795.504667] peer1 dbus-broker-launch[222]: Ready212peer1 # [7653795.663573] peer1 data-mesher[219]: time=2026-08-28T00:04:13.029Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]213peer1 # [7653795.663852] peer1 data-mesher[219]: time=2026-08-28T00:04:13.029Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q: [/dns/controller.clan/tcp/7946]} {12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk: [/dns/peer1.clan/tcp/7946]} {12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk214peer1 # [7653795.663873] peer1 data-mesher[219]: time=2026-08-28T00:04:13.029Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml215peer1 # [7653795.664583] peer1 data-mesher[219]: time=2026-08-28T00:04:13.030Z level=INFO msg="checking file integrity"216peer1 # [7653795.664655] peer1 data-mesher[219]: time=2026-08-28T00:04:13.030Z level=INFO msg="file integrity check complete"217peer1 # [7653795.667251] peer1 data-mesher[219]: time=2026-08-28T00:04:13.032Z level=INFO msg="libp2p host created" peer_id=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk 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::c6d9:8fc8:8659:506e/tcp/7946]"218peer1 # [7653795.667290] peer1 data-mesher[219]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=GET path=/files219peer1 # [7653795.667290] peer1 data-mesher[219]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name220peer1 # [7653795.667290] peer1 data-mesher[219]: time=2026-08-28T00:04:13.032Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name221peer1 # [7653795.667290] peer1 data-mesher[219]: time=2026-08-28T00:04:13.032Z level=INFO msg="starting server"222peer1 # [7653795.667347] peer1 data-mesher[219]: time=2026-08-28T00:04:13.033Z level=INFO msg="waiting for DHT to populate" delay=10s223peer1 # [7653795.667368] peer1 data-mesher[219]: time=2026-08-28T00:04:13.033Z level=INFO msg="HTTP server listening" address=[::1]:7331224peer1 # [7653795.667386] peer1 data-mesher[219]: time=2026-08-28T00:04:13.033Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331225peer1 # [7653795.669028] peer1 data-mesher[219]: time=2026-08-28T00:04:13.034Z level=INFO msg="peer connected" peer_id=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q remote_addr=/ip4/192.168.1.1/tcp/7946226controller # [7653795.760161] controller systemd-logind[249]: New seat seat0.227controller # [7653795.760316] controller systemd[1]: Started User Login Management.228controller # [7653795.761249] controller systemd[1]: Starting linger-users.service...229controller # [7653795.790036] controller systemd[1]: linger-users.service: Deactivated successfully.230controller # [7653795.790108] controller systemd[1]: Finished linger-users.service.231controller # [7653795.883908] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.232peer1 # [7653795.764289] peer1 systemd-logind[239]: New seat seat0.233peer1 # [7653795.764380] peer1 systemd[1]: Started User Login Management.234peer1 # [7653795.786206] peer1 systemd[1]: Starting linger-users.service...235peer1 # [7653795.793344] peer1 systemd[1]: linger-users.service: Deactivated successfully.236peer1 # [7653795.793398] peer1 systemd[1]: Finished linger-users.service.237peer1 # [7653795.883903] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.238peer1 # [7653796.349135] peer1 systemd-networkd[214]: eth1: Gained IPv6LL239controller # [7653797.181113] controller systemd-networkd[225]: eth1: Gained IPv6LL240controller: still waiting for container 'controller' to reach ready state...241controller: (finished: waiting for unit data-mesher.service, in 11.64 seconds)242peer1: waiting for unit data-mesher.service243peer1: (finished: waiting for unit data-mesher.service, in 0.01 seconds)244??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.245 File "/nix/store/y5iz7dc0kz6hbr148qpw2853k0hygs26-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39246controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller247??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.248 File "/nix/store/y5iz7dc0kz6hbr148qpw2853k0hygs26-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39249controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)250peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller251controller # [7653805.669651] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="performing state exchange with peers on join" count=1252controller # [7653805.669651] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s253controller # [7653805.669862] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="received state sync from peer" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk254controller # [7653805.669862] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk255controller # [7653805.669962] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk256controller # [7653805.669973] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="state exchange complete" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s257controller # [7653805.669986] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="server started"258controller # [7653805.670087] controller data-mesher[230]: time=2026-08-28T00:04:23.035Z level=INFO msg="starting expired-file sweeper" interval=1m0s259controller # [7653805.670238] controller systemd[1]: Started data mesher daemon.260controller # [7653805.671073] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...261controller # [7653805.710964] controller data-mesher[230]: time=2026-08-28T00:04:23.076Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204262controller # [7653805.711077] controller dm-wg-star-publish[283]: Status: 204 No Content263controller # [7653805.711990] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...264controller # [7653805.712832] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.265controller # [7653805.713095] controller systemd[1]: Reached target Multi-User System.266controller # [7653805.756356] controller dm-wg-star-reconfig[299]: No peer data available yet, skipping267controller # [7653805.757033] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.268controller # [7653805.757126] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.269controller # [7653805.757308] controller systemd[1]: Startup finished in 11.088s.270peer1 # [7653805.669734] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="performing state exchange with peers on join" count=1271peer1 # [7653805.669734] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s272peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="received state sync from peer" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q273peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q274peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q275peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="state exchange complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s276peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="server started"277peer1 # [7653805.670022] peer1 data-mesher[219]: time=2026-08-28T00:04:23.035Z level=INFO msg="starting expired-file sweeper" interval=1m0s278peer1 # [7653805.670098] peer1 systemd[1]: Started data mesher daemon.279peer1 # [7653805.670705] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...280peer1 # [7653805.746392] peer1 data-mesher[219]: time=2026-08-28T00:04:23.112Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs status=204281peer1 # [7653805.746457] peer1 dm-wg-star-publish[273]: Status: 204 No Content282peer1 # [7653805.747574] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...283peer1 # [7653805.747791] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.284peer1 # [7653805.747885] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.285peer1 # [7653805.748448] peer1 systemd[1]: Reached target Multi-User System.286peer1 # [7653805.789729] peer1 dm-wg-star-reconfig[281]: No controller data available yet, skipping287peer1 # [7653805.790408] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.288peer1 # [7653805.790474] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.289peer1 # [7653805.790680] peer1 systemd[1]: Startup finished in 11.130s.290peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.02 seconds)291controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .292controller: (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)293controller: waiting for success: wg show wg-star peers | grep -q .294controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)295peer1: waiting for success: wg show wg-star peers | grep -q .296peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.01 seconds)297peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::563f:ed85:9046:f483298peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::563f:ed85:9046:f483, in 0.00 seconds)299controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c6d9:8fc8:8659:506e300controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c6d9:8fc8:8659:506e, in 0.00 seconds)301controller: must succeed: wg show wg-star peers | wc -l302controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.01 seconds)303peer2: systemd-nspawn running (pid 722)304peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...305peer2: waiting for unit data-mesher.service306controller # [7653810.671228] controller data-mesher[230]: time=2026-08-28T00:04:28.036Z level=DEBUG msg="attempting push/pull" peer_count=1307controller # [7653810.671228] controller data-mesher[230]: time=2026-08-28T00:04:28.036Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s308controller # [7653810.671654] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="received state sync from peer" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk309controller # [7653810.671654] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk310controller # [7653810.671654] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="new file detected" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs311controller # [7653810.671697] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk312controller # [7653810.671697] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs313controller # [7653810.671697] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs signed_at="2026-08-28 00:04:23.11 +0000 UTC" signed_by="Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs=" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk314controller # [7653810.671752] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="new file detected" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs315controller # [7653810.671752] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="state exchange complete" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s316controller # [7653810.671752] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=INFO msg="received file request" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/controller317controller # [7653810.672215] controller data-mesher[230]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="push/pull successful" interval=5s318controller # [7653810.672869] controller data-mesher[230]: time=2026-08-28T00:04:28.038Z level=INFO msg="file transfer complete" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/controller319controller # [7653810.673722] controller data-mesher[230]: time=2026-08-28T00:04:28.039Z level=INFO msg="download complete" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs signed_at="2026-08-28 00:04:23.11 +0000 UTC" signed_by="Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs=" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk written=true elapsed=2.033189ms320controller # [7653810.674559] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...321controller # [7653810.753433] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.322controller # [7653810.753592] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.323nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE324nixos-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.325Note: 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.326░ Spawning container peer2 on /build/vm-state-peer2.327peer1 # [7653810.671329] peer1 data-mesher[219]: time=2026-08-28T00:04:28.036Z level=DEBUG msg="attempting push/pull" peer_count=1328peer1 # [7653810.671329] peer1 data-mesher[219]: time=2026-08-28T00:04:28.036Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s329peer1 # [7653810.671597] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="received state sync from peer" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q330peer1 # [7653810.671597] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q331peer1 # [7653810.671597] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="new file detected" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller332peer1 # [7653810.671597] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller333peer1 # [7653810.671597] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-08-28 00:04:23.074 +0000 UTC" signed_by="o7v4e5DaUKkTDKqI3eKwASfqqj0QZm007NCP9lE77Fs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q334peer1 # [7653810.671725] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q335peer1 # [7653810.671725] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="new file detected" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller336peer1 # [7653810.671797] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="state exchange complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s337peer1 # [7653810.671797] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=DEBUG msg="push/pull successful" interval=5s338peer1 # [7653810.671841] peer1 data-mesher[219]: time=2026-08-28T00:04:28.037Z level=INFO msg="received file request" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs339peer1 # [7653810.672781] peer1 data-mesher[219]: time=2026-08-28T00:04:28.038Z level=INFO msg="file transfer complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs340peer1 # [7653810.673768] peer1 data-mesher[219]: time=2026-08-28T00:04:28.039Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-08-28 00:04:23.074 +0000 UTC" signed_by="o7v4e5DaUKkTDKqI3eKwASfqqj0QZm007NCP9lE77Fs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q written=true elapsed=2.189203ms341peer1 # [7653810.674480] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...342peer1 # [7653810.753674] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.343peer1 # [7653810.753756] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.344peer2 # [7653811.577019] peer2 systemd-journald[95]: Journal started345peer2 # [7653811.577053] peer2 systemd-journald[95]: Runtime Journal (/run/log/journal/717aeb8b337c4b99b541d34f4a0bc58e) is 8M, max 3.7G, 3.7G free.346peer2 # [7653811.577802] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.347peer2 # [7653811.582095] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...348peer2 # [7653811.582443] peer2 systemd[1]: Starting Network Name Resolution...349peer2 # [7653811.582744] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...350peer2 # [7653811.587493] peer2 systemd-journald[95]: Time spent on flushing to /var/log/journal/717aeb8b337c4b99b541d34f4a0bc58e is 958us for 6 entries.351peer2 # [7653811.587493] peer2 systemd-journald[95]: System Journal (/var/log/journal/717aeb8b337c4b99b541d34f4a0bc58e) is 8M, max 4G, 3.9G free.352peer2 # [7653811.590546] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.353peer2 # [7653811.590661] peer2 systemd[1]: Reached target Preparation for Local File Systems.354peer2 # [7653811.590699] peer2 systemd[1]: Reached target Local File Systems.355peer2 # [7653811.591082] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.356peer2 # [7653811.591107] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container357peer2 # [7653811.591488] peer2 systemd[1]: Starting Save Transient machine-id to Disk...358peer2 # [7653811.591505] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys359peer2 # [7653811.591690] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.360peer2 # [7653811.592333] peer2 systemd[1]: Starting Create System Files and Directories...361peer2 # [7653811.601977] peer2 systemd-tmpfiles[133]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted362peer2 # [7653811.602117] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal failed: Operation not permitted363peer2 # [7653811.602214] peer2 systemd-tmpfiles[133]: fchmod() of /var/log/journal/717aeb8b337c4b99b541d34f4a0bc58e failed: Operation not permitted364peer2 # [7653811.602355] peer2 systemd-tmpfiles[133]: fchmod() of /run/log/journal failed: Operation not permitted365peer2 # [7653811.603245] peer2 systemd[1]: Finished Create System Files and Directories.366peer2 # [7653811.603684] peer2 systemd[1]: Starting Rebuild Journal Catalog...367peer2 # [7653811.603984] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...368peer2 # [7653811.610119] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.369peer2 # [7653811.610253] peer2 systemd[1]: Finished Save Transient machine-id to Disk.370peer2 # [7653811.615853] peer2 systemd[1]: Finished Rebuild Journal Catalog.371peer2 # [7653811.616362] peer2 systemd[1]: Starting Update is Completed...372peer2 # [7653811.622037] peer2 systemd[1]: Finished Update is Completed.373peer2 # [7653811.669581] peer2 systemd[1]: Finished Firewall.374peer2 # [7653811.670053] peer2 systemd[1]: Reached target Preparation for Network.375peer2 # [7653811.670293] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.376peer2 # [7653811.670917] peer2 systemd[1]: Starting Network Management...377peer2 # [7653811.922434] peer2 systemd-networkd[213]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted378peer2 # [7653811.922500] peer2 systemd-networkd[213]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted379peer2 # [7653811.927982] peer2 systemd-networkd[213]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.380peer2 # [7653811.928131] peer2 systemd-networkd[213]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.381peer2 # [7653811.928189] peer2 systemd-networkd[213]: lo: Link UP382peer2 # [7653811.928193] peer2 systemd-networkd[213]: lo: Gained carrier383peer2 # [7653811.928339] peer2 systemd-networkd[213]: eth1: Configuring with /etc/systemd/network/40-eth1.network.384peer2 # [7653811.928584] peer2 systemd[1]: Started Network Management.385peer2 # [7653811.928924] peer2 systemd-networkd[213]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.386peer2 # [7653811.929104] peer2 systemd-networkd[213]: wg-star: netdev ready387peer2 # [7653811.929149] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...388peer2 # [7653811.929223] peer2 systemd-networkd[213]: eth1: Link UP389peer2 # [7653811.929327] peer2 systemd-networkd[213]: eth1: Gained carrier390peer2 # [7653811.956262] peer2 systemd-networkd[213]: wg-star: Link UP391peer2 # [7653811.956266] peer2 systemd-networkd[213]: wg-star: Gained carrier392peer2 # [7653811.960594] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.393peer2 # [7653812.020176] peer2 systemd-resolved[117]: Positive Trust Anchors:394peer2 # [7653812.020183] peer2 systemd-resolved[117]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d395peer2 # [7653812.020186] peer2 systemd-resolved[117]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16396peer2 # [7653812.020202] peer2 systemd-resolved[117]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test397peer2 # [7653812.030377] peer2 systemd-resolved[117]: Using system hostname 'peer2'.398peer2 # [7653812.031640] peer2 systemd[1]: Started Network Name Resolution.399peer2 # [7653812.031715] peer2 systemd[1]: Reached target Network.400peer2 # [7653812.031761] peer2 systemd[1]: Reached target System Initialization.401peer2 # [7653812.031835] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.402peer2 # [7653812.031858] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.403peer2 # [7653812.031882] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container404peer2 # [7653812.031896] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.405peer2 # [7653812.031912] peer2 systemd[1]: Reached target Path Units.406peer2 # [7653812.031938] peer2 systemd[1]: Reached target Timer Units.407peer2 # [7653812.032048] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.408peer2 # [7653812.032139] peer2 systemd[1]: Listening on Nix Daemon Socket.409peer2 # [7653812.032238] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.410peer2 # [7653812.032251] peer2 systemd[1]: Reached target Socket Units.411peer2 # [7653812.032272] peer2 systemd[1]: Reached target Basic System.412peer2 # [7653812.032979] peer2 systemd[1]: Starting data mesher daemon...413peer2 # [7653812.033330] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...414peer2 # [7653812.033718] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...415peer2 # [7653812.034293] peer2 systemd[1]: Starting D-Bus System Message Bus...416peer2 # [7653812.063547] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.417peer2 # [7653812.113938] peer2 nsncd[220]: Aug 28 00:04:29.479 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"418peer2 # [7653812.113943] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).419peer2 # [7653812.113967] peer2 systemd[1]: Reached target Host and Network Name Lookups.420peer2 # [7653812.113991] peer2 systemd[1]: Reached target User and Group Name Lookups.421peer2 # [7653812.114449] peer2 systemd[1]: Starting User Login Management...422peer2 # [7653812.114757] peer2 systemd[1]: Starting Permit User Sessions...423peer2 # [7653812.132993] peer2 systemd[1]: Finished Permit User Sessions.424peer2 # [7653812.133396] peer2 systemd[1]: Started Console Getty.425peer2 # [7653812.133414] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0426peer2 # [7653812.133423] peer2 systemd[1]: Reached target Login Prompts.427peer2 # [7653812.159832] peer2 dbus-broker-launch[221]: Looking up NSS user entry for 'systemd-timesync'...428peer2 # [7653812.160354] peer2 dbus-broker-launch[221]: NSS returned no entry for 'systemd-timesync'429peer2 # [7653812.160354] peer2 dbus-broker-launch[221]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"430peer2 # [7653812.160654] peer2 systemd[1]: Started D-Bus System Message Bus.431peer2 # [7653812.164662] peer2 dbus-broker-launch[221]: Ready432peer2 # [7653812.313181] peer2 data-mesher[218]: time=2026-08-28T00:04:29.678Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]433peer2 # [7653812.313630] peer2 data-mesher[218]: time=2026-08-28T00:04:29.679Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q: [/dns/controller.clan/tcp/7946]} {12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk: [/dns/peer1.clan/tcp/7946]} {12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK434peer2 # [7653812.313630] peer2 data-mesher[218]: time=2026-08-28T00:04:29.679Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml435peer2 # [7653812.314225] peer2 data-mesher[218]: time=2026-08-28T00:04:29.679Z level=INFO msg="checking file integrity"436peer2 # [7653812.314299] peer2 data-mesher[218]: time=2026-08-28T00:04:29.679Z level=INFO msg="file integrity check complete"437peer2 # [7653812.316991] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="libp2p host created" peer_id=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK 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::9588:fd19:dcab:40d3/tcp/7946]"438peer2 # [7653812.317030] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="registered HTTP route" method=GET path=/files439peer2 # [7653812.317030] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name440peer2 # [7653812.317071] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name441peer2 # [7653812.317071] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="starting server"442peer2 # [7653812.317131] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="waiting for DHT to populate" delay=10s443peer2 # [7653812.317158] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="HTTP server listening" address=[::1]:7331444peer2 # [7653812.317172] peer2 data-mesher[218]: time=2026-08-28T00:04:29.682Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331445peer2 # [7653812.319178] peer2 data-mesher[218]: time=2026-08-28T00:04:29.684Z level=INFO msg="peer connected" peer_id=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q remote_addr=/ip4/192.168.1.1/tcp/7946446peer2 # [7653812.321721] peer2 data-mesher[218]: time=2026-08-28T00:04:29.687Z level=INFO msg="peer connected" peer_id=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk remote_addr=/ip4/192.168.1.2/tcp/7946447peer2 # [7653812.402169] peer2 systemd-logind[238]: New seat seat0.448peer2 # [7653812.402301] peer2 systemd[1]: Started User Login Management.449peer2 # [7653812.403184] peer2 systemd[1]: Starting linger-users.service...450peer2 # [7653812.432224] peer2 systemd[1]: linger-users.service: Deactivated successfully.451peer2 # [7653812.432350] peer2 systemd[1]: Finished linger-users.service.452peer2 # [7653812.570448] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.453controller # [7653812.319365] controller data-mesher[230]: time=2026-08-28T00:04:29.685Z level=INFO msg="peer connected" peer_id=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK remote_addr=/ip4/192.168.1.3/tcp/7946454peer1 # [7653812.322009] peer1 data-mesher[219]: time=2026-08-28T00:04:29.687Z level=INFO msg="peer connected" peer_id=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK remote_addr=/ip4/192.168.1.3/tcp/7946455peer2 # [7653813.437077] peer2 systemd-networkd[213]: eth1: Gained IPv6LL456peer1 # [7653815.671996] peer1 data-mesher[219]: time=2026-08-28T00:04:33.037Z level=DEBUG msg="attempting push/pull" peer_count=1457controller # [7653815.672334] controller data-mesher[230]: time=2026-08-28T00:04:33.037Z level=DEBUG msg="attempting push/pull" peer_count=1458peer1 # [7653815.671996] peer1 data-mesher[219]: time=2026-08-28T00:04:33.037Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s459controller # [7653815.672334] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s460peer1 # [7653815.672545] peer1 data-mesher[219]: time=2026-08-28T00:04:33.038Z level=INFO msg="received state sync from peer" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q461controller # [7653815.672770] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=INFO msg="received state sync from peer" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk462peer1 # [7653815.672545] peer1 data-mesher[219]: time=2026-08-28T00:04:33.038Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q463controller # [7653815.672770] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk464peer1 # [7653815.672652] peer1 data-mesher[219]: time=2026-08-28T00:04:33.038Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q465controller # [7653815.672770] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk466peer1 # [7653815.672686] peer1 data-mesher[219]: time=2026-08-28T00:04:33.038Z level=INFO msg="state exchange complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s467peer1 # [7653815.672701] peer1 data-mesher[219]: time=2026-08-28T00:04:33.038Z level=DEBUG msg="push/pull successful" interval=5s468controller # [7653815.672835] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=INFO msg="state exchange complete" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s469controller # [7653815.672835] controller data-mesher[230]: time=2026-08-28T00:04:33.038Z level=DEBUG msg="push/pull successful" interval=5s470peer2 # [7653820.673772] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="received state sync from peer" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q471peer2 # [7653820.673772] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q472peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=DEBUG msg="new file detected" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs473peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=DEBUG msg="new file detected" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller474peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs475peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller476peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-08-28 00:04:23.074 +0000 UTC" signed_by="o7v4e5DaUKkTDKqI3eKwASfqqj0QZm007NCP9lE77Fs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q477peer2 # [7653820.674182] peer2 data-mesher[218]: time=2026-08-28T00:04:38.039Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs signed_at="2026-08-28 00:04:23.11 +0000 UTC" signed_by="Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q478peer2 # [7653820.676524] peer2 data-mesher[218]: time=2026-08-28T00:04:38.042Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-08-28 00:04:23.074 +0000 UTC" signed_by="o7v4e5DaUKkTDKqI3eKwASfqqj0QZm007NCP9lE77Fs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q written=true elapsed=2.58048ms479peer2 # [7653820.676863] peer2 data-mesher[218]: time=2026-08-28T00:04:38.042Z level=INFO msg="download complete" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs signed_at="2026-08-28 00:04:23.11 +0000 UTC" signed_by="Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs=" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q written=true elapsed=2.92057ms480peer2 # [7653820.677326] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...481peer2 # [7653820.753408] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.482peer2 # [7653820.753526] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.483controller # [7653820.673299] controller data-mesher[230]: time=2026-08-28T00:04:38.038Z level=DEBUG msg="attempting push/pull" peer_count=1484controller # [7653820.673299] controller data-mesher[230]: time=2026-08-28T00:04:38.038Z level=DEBUG msg="initiating state exchange" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK timeout=5s485controller # [7653820.673645] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="received state sync from peer" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk486controller # [7653820.673645] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk487controller # [7653820.673931] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="merging remote state" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK488controller # [7653820.673931] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="state exchange complete" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK timeout=5s489controller # [7653820.673962] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=DEBUG msg="push/pull successful" interval=5s490controller # [7653820.674129] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="received file request" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/controller491controller # [7653820.674175] controller data-mesher[230]: time=2026-08-28T00:04:38.039Z level=INFO msg="received file request" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs492controller # [7653820.675520] controller data-mesher[230]: time=2026-08-28T00:04:38.041Z level=INFO msg="file transfer complete" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/controller493controller # [7653820.675574] controller data-mesher[230]: time=2026-08-28T00:04:38.041Z level=INFO msg="file transfer complete" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/Ntg3n5ebodGrfnWEZn9lIJ1m02B7orjiRLeRYzUAmgs494peer1 # [7653820.672996] peer1 data-mesher[219]: time=2026-08-28T00:04:38.038Z level=DEBUG msg="attempting push/pull" peer_count=1495peer1 # [7653820.672996] peer1 data-mesher[219]: time=2026-08-28T00:04:38.038Z level=DEBUG msg="initiating state exchange" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s496peer1 # [7653820.673567] peer1 data-mesher[219]: time=2026-08-28T00:04:38.039Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q497peer1 # [7653820.673631] peer1 data-mesher[219]: time=2026-08-28T00:04:38.039Z level=INFO msg="state exchange complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q timeout=5s498peer1 # [7653820.673667] peer1 data-mesher[219]: time=2026-08-28T00:04:38.039Z level=DEBUG msg="push/pull successful" interval=5s499peer2: still waiting for container 'peer2' to reach ready state...500peer1 # [7653822.317411] peer1 data-mesher[219]: time=2026-08-28T00:04:39.683Z level=INFO msg="received state sync from peer" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK501peer1 # [7653822.317411] peer1 data-mesher[219]: time=2026-08-28T00:04:39.683Z level=INFO msg="merging remote state" peer=12D3KooWLqGQbKxNNVoC3dAeT1uETiiPeJ5X69nW7XC1Z9RPD9dK502peer2: (finished: waiting for unit data-mesher.service, in 11.65 seconds)503??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.504 File "/nix/store/y5iz7dc0kz6hbr148qpw2853k0hygs26-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39505controller: waiting for success: test $(ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | wc -l) -gt 1506??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.507 File "/nix/store/y5iz7dc0kz6hbr148qpw2853k0hygs26-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39508peer2 # [7653822.317168] peer2 data-mesher[218]: time=2026-08-28T00:04:39.682Z level=INFO msg="performing state exchange with peers on join" count=1509peer2 # [7653822.317396] peer2 data-mesher[218]: time=2026-08-28T00:04:39.682Z level=DEBUG msg="initiating state exchange" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s510peer2 # [7653822.317591] peer2 data-mesher[218]: time=2026-08-28T00:04:39.683Z level=INFO msg="merging remote state" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk511peer2 # [7653822.317677] peer2 data-mesher[218]: time=2026-08-28T00:04:39.683Z level=INFO msg="state exchange complete" peer=12D3KooWDWTQdG3LfWYp1kC4oGeW9hfUCHwvnxkbawRz42vWyvPk timeout=5s512peer2 # [7653822.317695] peer2 data-mesher[218]: time=2026-08-28T00:04:39.683Z level=INFO msg="server started"513peer2 # [7653822.317763] peer2 data-mesher[218]: time=2026-08-28T00:04:39.683Z level=INFO msg="starting expired-file sweeper" interval=1m0s514peer2 # [7653822.317815] peer2 systemd[1]: Started data mesher daemon.515peer2 # [7653822.318393] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...516peer2 # [7653822.395034] peer2 data-mesher[218]: time=2026-08-28T00:04:39.760Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/o6ufbFKRT0tZWUPyUVuqPzSecrkFeHuJZwgHIRraaZo status=204517peer2 # [7653822.395106] peer2 dm-wg-star-publish[282]: Status: 204 No Content518peer2 # [7653822.395995] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...519peer2 # [7653822.396894] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.520peer2 # [7653822.397002] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.521peer2 # [7653822.397305] peer2 systemd[1]: Reached target Multi-User System.522peer2 # [7653822.472027] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.523peer2 # [7653822.472137] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.524peer2 # [7653822.472305] peer2 systemd[1]: Startup finished in 11.114s.525controller: (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.02 seconds)526controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1527controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.01 seconds)528peer2: waiting for success: wg show wg-star peers | grep -q .529peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)530peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::563f:ed85:9046:f483531peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::563f:ed85:9046:f483, in 0.00 seconds)532controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9588:fd19:dcab:40d3533controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9588:fd19:dcab:40d3, in 0.00 seconds)534peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9588:fd19:dcab:40d3535peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::9588:fd19:dcab:40d3, in 0.00 seconds)536peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c6d9:8fc8:8659:506e537peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::c6d9:8fc8:8659:506e, in 0.00 seconds)538(finished: run the VM test script, in 31.40 seconds)539test script finished in 31.42s540cleanup541kill NspawnMachine (pid 50)542kill NspawnMachine (pid 53)543Container controller terminated by signal KILL.544kill NspawnMachine (pid 722)545peer2 # [7653825.674656] peer2 data-mesher[218]: time=2026-08-28T00:04:43.040Z level=INFO msg="received state sync from peer" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q546peer2 # [7653825.674656] peer2 data-mesher[218]: time=2026-08-28T00:04:43.040Z level=INFO msg="merging remote state" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q547peer2 # [7653825.675281] peer2 data-mesher[218]: time=2026-08-28T00:04:43.040Z level=INFO msg="received file request" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/o6ufbFKRT0tZWUPyUVuqPzSecrkFeHuJZwgHIRraaZo548peer2 # [7653825.675798] peer2 data-mesher[218]: time=2026-08-28T00:04:43.041Z level=INFO msg="file transfer complete" peer=12D3KooWBzhhzWw52RZkWkB3nwAv1D4XC421fvjKUPBSnm2xdx8q network="r6o4Rclq/uBuFyuwgBs+/Ij24fDgwOfbrDUrAdAtH3g=" name=dm_wg_star_wg_star/o6ufbFKRT0tZWUPyUVuqPzSecrkFeHuJZwgHIRraaZo549Container peer1 terminated by signal KILL.550Container peer2 terminated by signal KILL.551(finished: cleanup, in 0.29 seconds)