container-test-run-dm-wireguard-star
checks.x86_64-linux.dm-wireguard-star
· build #109
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.00 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 controller, peer1, peer2,9 vlan1,10 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh11controller: systemd-nspawn running (pid 50)12controller: Waiting for journal at /build/vm-state-controller/var/log/journal...13peer1: systemd-nspawn running (pid 53)14peer1: Waiting for journal at /build/vm-state-peer1/var/log/journal...15controller: waiting for unit data-mesher.service16nixos-nspawn(controller): TAP vde-tap1 not found; container will be isolated from VDE17nixos-nspawn(controller): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.18nixos-nspawn(peer1): TAP vde-tap1 not found; container will be isolated from VDE19nixos-nspawn(peer1): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.20Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.21Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.22░ Spawning container controller on /build/vm-state-controller.23░ Spawning container peer1 on /build/vm-state-peer1.24controller # [8276732.601878] controller systemd-journald[105]: Journal started25controller # [8276732.601908] controller systemd-journald[105]: Runtime Journal (/run/log/journal/4d3dafe8194740c896edbc35a0ea1f74) is 8M, max 3.7G, 3.7G free.26controller # [8276732.606010] controller systemd[1]: Finished Create Static Device Nodes in /dev gracefully.27controller # [8276732.610770] controller systemd[1]: Starting Flush Journal to Persistent Storage...28controller # [8276732.611282] controller systemd[1]: Starting Network Name Resolution...29controller # [8276732.611622] controller systemd[1]: Starting Create Static Device Nodes in /dev...30controller # [8276732.615276] controller systemd-journald[105]: Time spent on flushing to /var/log/journal/4d3dafe8194740c896edbc35a0ea1f74 is 1.107ms for 6 entries.31controller # [8276732.615276] controller systemd-journald[105]: System Journal (/var/log/journal/4d3dafe8194740c896edbc35a0ea1f74) is 8M, max 4G, 3.9G free.32controller # [8276732.619840] controller systemd[1]: Finished Create Static Device Nodes in /dev.33controller # [8276732.619951] controller systemd[1]: Reached target Preparation for Local File Systems.34controller # [8276732.619995] controller systemd[1]: Reached target Local File Systems.35controller # [8276732.620405] controller systemd[1]: Listening on Boot Loader Control Service Socket.36controller # [8276732.620429] controller systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container37controller # [8276732.620840] controller systemd[1]: Starting Save Transient machine-id to Disk...38controller # [8276732.620855] controller systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys39controller # [8276732.647410] controller systemd[1]: Finished Flush Journal to Persistent Storage.40controller # [8276732.648289] controller systemd[1]: Starting Create System Files and Directories...41controller # [8276732.657401] controller systemd-tmpfiles[174]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted42controller # [8276732.657551] controller systemd-tmpfiles[174]: fchmod() of /var/log/journal failed: Operation not permitted43controller # [8276732.657653] controller systemd-tmpfiles[174]: fchmod() of /var/log/journal/4d3dafe8194740c896edbc35a0ea1f74 failed: Operation not permitted44controller # [8276732.657807] controller systemd-tmpfiles[174]: fchmod() of /run/log/journal failed: Operation not permitted45controller # [8276732.658813] controller systemd[1]: Finished Create System Files and Directories.46controller # [8276732.659387] controller systemd[1]: Starting Rebuild Journal Catalog...47controller # [8276732.659782] controller systemd[1]: Starting Record System Boot/Shutdown in UTMP...48controller # [8276732.666079] controller systemd[1]: Finished Record System Boot/Shutdown in UTMP.49controller # [8276732.671130] controller systemd[1]: Finished Rebuild Journal Catalog.50controller # [8276732.671666] controller systemd[1]: Starting Update is Completed...51controller # [8276732.677449] controller systemd[1]: Finished Update is Completed.52controller # [8276732.690010] controller systemd[1]: Finished Firewall.53controller # [8276732.690087] controller systemd[1]: Reached target Preparation for Network.54controller # [8276732.690241] controller systemd[1]: Listening on Network Management Resolve Hook Socket.55controller # [8276732.690735] controller systemd[1]: Starting Network Management...56controller # [8276732.724919] controller systemd[1]: Finished Save Transient machine-id to Disk.57controller # [8276732.980549] controller systemd-networkd[224]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted58controller # [8276732.980618] controller systemd-networkd[224]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted59controller # [8276732.986390] controller systemd-networkd[224]: /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.60controller # [8276732.986544] controller systemd-networkd[224]: /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.61controller # [8276732.986614] controller systemd-networkd[224]: lo: Link UP62controller # [8276732.986616] controller systemd-networkd[224]: lo: Gained carrier63controller # [8276732.986745] controller systemd-networkd[224]: eth1: Configuring with /etc/systemd/network/40-eth1.network.64controller # [8276732.986991] controller systemd[1]: Started Network Management.65controller # [8276732.987340] controller systemd-networkd[224]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.66controller # [8276732.987521] controller systemd-networkd[224]: wg-star: netdev ready67controller # [8276732.987619] controller systemd-networkd[224]: eth1: Link UP68controller # [8276732.987726] controller systemd-networkd[224]: eth1: Gained carrier69controller # [8276732.987799] controller systemd[1]: Starting Enable Persistent Storage in systemd-networkd...70controller # [8276733.010315] controller systemd-networkd[224]: wg-star: Link UP71controller # [8276733.010318] controller systemd-networkd[224]: wg-star: Gained carrier72controller # [8276733.010615] controller systemd[1]: Finished Enable Persistent Storage in systemd-networkd.73peer1 # [8276732.602194] peer1 systemd-journald[96]: Journal started74peer1 # [8276732.602220] peer1 systemd-journald[96]: Runtime Journal (/run/log/journal/6c72519c4f724e0285f6ac6aa25e5616) is 8M, max 3.7G, 3.7G free.75peer1 # [8276732.604482] peer1 systemd[1]: Finished Apply Kernel Variables.76peer1 # [8276732.608356] peer1 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.77peer1 # [8276732.613131] peer1 systemd[1]: Starting Flush Journal to Persistent Storage...78peer1 # [8276732.613539] peer1 systemd[1]: Starting Network Name Resolution...79peer1 # [8276732.613821] peer1 systemd[1]: Starting Create Static Device Nodes in /dev...80peer1 # [8276732.617395] peer1 systemd-journald[96]: Time spent on flushing to /var/log/journal/6c72519c4f724e0285f6ac6aa25e5616 is 1.028ms for 7 entries.81peer1 # [8276732.617395] peer1 systemd-journald[96]: System Journal (/var/log/journal/6c72519c4f724e0285f6ac6aa25e5616) is 8M, max 4G, 3.9G free.82peer1 # [8276732.623069] peer1 systemd[1]: Finished Create Static Device Nodes in /dev.83peer1 # [8276732.623183] peer1 systemd[1]: Reached target Preparation for Local File Systems.84peer1 # [8276732.623225] peer1 systemd[1]: Reached target Local File Systems.85peer1 # [8276732.623619] peer1 systemd[1]: Listening on Boot Loader Control Service Socket.86peer1 # [8276732.623642] peer1 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container87peer1 # [8276732.623936] peer1 systemd[1]: Starting Save Transient machine-id to Disk...88peer1 # [8276732.623951] peer1 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys89peer1 # [8276732.647931] peer1 systemd[1]: Finished Flush Journal to Persistent Storage.90peer1 # [8276732.648597] peer1 systemd[1]: Starting Create System Files and Directories...91peer1 # [8276732.658511] peer1 systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted92peer1 # [8276732.658658] peer1 systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted93peer1 # [8276732.658762] peer1 systemd-tmpfiles[161]: fchmod() of /var/log/journal/6c72519c4f724e0285f6ac6aa25e5616 failed: Operation not permitted94peer1 # [8276732.658914] peer1 systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted95peer1 # [8276732.659803] peer1 systemd[1]: Finished Create System Files and Directories.96peer1 # [8276732.660381] peer1 systemd[1]: Starting Rebuild Journal Catalog...97peer1 # [8276732.660744] peer1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...98peer1 # [8276732.666449] peer1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.99peer1 # [8276732.672304] peer1 systemd[1]: Finished Rebuild Journal Catalog.100peer1 # [8276732.672712] peer1 systemd[1]: Starting Update is Completed...101peer1 # [8276732.677621] peer1 systemd[1]: Finished Update is Completed.102peer1 # [8276732.710108] peer1 systemd[1]: Finished Firewall.103peer1 # [8276732.710210] peer1 systemd[1]: Reached target Preparation for Network.104peer1 # [8276732.710340] peer1 systemd[1]: Listening on Network Management Resolve Hook Socket.105peer1 # [8276732.710765] peer1 systemd[1]: Starting Network Management...106peer1 # [8276732.725434] peer1 systemd[1]: Finished Save Transient machine-id to Disk.107peer1 # [8276732.982982] peer1 systemd-networkd[213]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted108peer1 # [8276732.983054] peer1 systemd-networkd[213]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted109peer1 # [8276732.988998] peer1 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.110peer1 # [8276732.989158] peer1 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.111peer1 # [8276732.989243] peer1 systemd-networkd[213]: lo: Link UP112peer1 # [8276732.989247] peer1 systemd-networkd[213]: lo: Gained carrier113peer1 # [8276732.989386] peer1 systemd-networkd[213]: eth1: Configuring with /etc/systemd/network/40-eth1.network.114peer1 # [8276732.989669] peer1 systemd[1]: Started Network Management.115peer1 # [8276732.990088] peer1 systemd-networkd[213]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.116peer1 # [8276732.990328] peer1 systemd-networkd[213]: wg-star: netdev ready117peer1 # [8276732.990439] peer1 systemd-networkd[213]: eth1: Link UP118peer1 # [8276732.990501] peer1 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...119peer1 # [8276732.990575] peer1 systemd-networkd[213]: eth1: Gained carrier120peer1 # [8276733.014667] peer1 systemd-networkd[213]: wg-star: Link UP121peer1 # [8276733.014674] peer1 systemd-networkd[213]: wg-star: Gained carrier122peer1 # [8276733.015412] peer1 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.123peer1 # [8276733.110896] peer1 systemd-resolved[121]: Positive Trust Anchors:124peer1 # [8276733.110900] peer1 systemd-resolved[121]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d125peer1 # [8276733.110903] peer1 systemd-resolved[121]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16126peer1 # [8276733.110919] peer1 systemd-resolved[121]: 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 test127peer1 # [8276733.121022] peer1 systemd-resolved[121]: Using system hostname 'peer1'.128peer1 # [8276733.121967] peer1 systemd[1]: Started Network Name Resolution.129peer1 # [8276733.122039] peer1 systemd[1]: Reached target Network.130peer1 # [8276733.122079] peer1 systemd[1]: Reached target System Initialization.131peer1 # [8276733.122136] peer1 systemd[1]: Started Watch for WireGuard controller info from data-mesher.132peer1 # [8276733.122154] peer1 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.133peer1 # [8276733.122171] peer1 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container134peer1 # [8276733.122185] peer1 systemd[1]: Started Daily Cleanup of Temporary Directories.135peer1 # [8276733.122195] peer1 systemd[1]: Reached target Path Units.136peer1 # [8276733.122213] peer1 systemd[1]: Reached target Timer Units.137peer1 # [8276733.122281] peer1 systemd[1]: Listening on D-Bus System Message Bus Socket.138peer1 # [8276733.122341] peer1 systemd[1]: Listening on Nix Daemon Socket.139peer1 # [8276733.122408] peer1 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.140peer1 # [8276733.122418] peer1 systemd[1]: Reached target Socket Units.141peer1 # [8276733.122439] peer1 systemd[1]: Reached target Basic System.142peer1 # [8276733.132172] peer1 systemd[1]: Starting data mesher daemon...143peer1 # [8276733.132515] peer1 systemd[1]: Starting Import lastlog data into lastlog2 database...144peer1 # [8276733.132901] peer1 systemd[1]: Starting Name Service Cache Daemon (nsncd)...145peer1 # [8276733.133481] peer1 systemd[1]: Starting D-Bus System Message Bus...146peer1 # [8276733.142555] peer1 systemd[1]: Finished Import lastlog data into lastlog2 database.147peer1 # [8276733.204035] peer1 nsncd[221]: Sep 04 05:06:30.569 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"148peer1 # [8276733.204051] peer1 systemd[1]: Started Name Service Cache Daemon (nsncd).149peer1 # [8276733.204084] peer1 systemd[1]: Reached target Host and Network Name Lookups.150peer1 # [8276733.204117] peer1 systemd[1]: Reached target User and Group Name Lookups.151peer1 # [8276733.215348] peer1 systemd[1]: Starting User Login Management...152peer1 # [8276733.215722] peer1 systemd[1]: Starting Permit User Sessions...153peer1 # [8276733.220630] peer1 systemd[1]: Finished Permit User Sessions.154peer1 # [8276733.221020] peer1 systemd[1]: Started Console Getty.155peer1 # [8276733.221039] peer1 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0156peer1 # [8276733.221050] peer1 systemd[1]: Reached target Login Prompts.157peer1 # [8276733.253880] peer1 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...158peer1 # [8276733.254240] peer1 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'159peer1 # [8276733.254240] 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"160controller # [8276733.097299] controller systemd-resolved[132]: Positive Trust Anchors:161controller # [8276733.097308] controller systemd-resolved[132]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d162controller # [8276733.097310] controller systemd-resolved[132]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16163controller # [8276733.097331] controller systemd-resolved[132]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test164controller # [8276733.107639] controller systemd-resolved[132]: Using system hostname 'controller'.165controller # [8276733.108586] controller systemd[1]: Started Network Name Resolution.166controller # [8276733.108627] controller systemd[1]: Reached target Network.167controller # [8276733.108662] controller systemd[1]: Reached target System Initialization.168controller # [8276733.108717] controller systemd[1]: Started Watch for WireGuard peer changes from data-mesher.169controller # [8276733.108739] controller systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container170controller # [8276733.108754] controller systemd[1]: Started Daily Cleanup of Temporary Directories.171controller # [8276733.108766] controller systemd[1]: Reached target Path Units.172controller # [8276733.108784] controller systemd[1]: Reached target Timer Units.173controller # [8276733.108849] controller systemd[1]: Listening on D-Bus System Message Bus Socket.174controller # [8276733.108906] controller systemd[1]: Listening on Nix Daemon Socket.175controller # [8276733.108973] controller systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.176controller # [8276733.108982] controller systemd[1]: Reached target Socket Units.177controller # [8276733.109005] controller systemd[1]: Reached target Basic System.178controller # [8276733.109662] controller systemd[1]: Starting data mesher daemon...179controller # [8276733.110006] controller systemd[1]: Starting Import lastlog data into lastlog2 database...180controller # [8276733.110363] controller systemd[1]: Starting Name Service Cache Daemon (nsncd)...181controller # [8276733.110980] controller systemd[1]: Starting D-Bus System Message Bus...182controller # [8276733.141348] controller systemd[1]: Finished Import lastlog data into lastlog2 database.183controller # [8276733.197863] controller nsncd[232]: Sep 04 05:06:30.563 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"184controller # [8276733.197880] controller systemd[1]: Started Name Service Cache Daemon (nsncd).185controller # [8276733.197908] controller systemd[1]: Reached target Host and Network Name Lookups.186controller # [8276733.197934] controller systemd[1]: Reached target User and Group Name Lookups.187controller # [8276733.198461] controller systemd[1]: Starting User Login Management...188controller # [8276733.198767] controller systemd[1]: Starting Permit User Sessions...189controller # [8276733.219410] controller systemd[1]: Finished Permit User Sessions.190controller # [8276733.220201] controller systemd[1]: Started Console Getty.191controller # [8276733.220229] controller systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0192controller # [8276733.220243] controller systemd[1]: Reached target Login Prompts.193controller # [8276733.255750] controller dbus-broker-launch[233]: Looking up NSS user entry for 'systemd-timesync'...194controller # [8276733.256098] controller dbus-broker-launch[233]: NSS returned no entry for 'systemd-timesync'195controller # [8276733.256098] 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"196peer1 # [8276733.254483] peer1 systemd[1]: Started D-Bus System Message Bus.197peer1 # [8276733.257912] peer1 dbus-broker-launch[222]: Ready198peer1 # [8276733.421513] peer1 data-mesher[219]: time=2026-09-04T05:06:30.787Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]199peer1 # [8276733.421819] peer1 data-mesher[219]: time=2026-09-04T05:06:30.787Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS: [/dns/controller.clan/tcp/7946]} {12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt: [/dns/peer1.clan/tcp/7946]} {12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt200peer1 # [8276733.421839] peer1 data-mesher[219]: time=2026-09-04T05:06:30.787Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml201peer1 # [8276733.451184] peer1 data-mesher[219]: time=2026-09-04T05:06:30.816Z level=INFO msg="checking file integrity"202peer1 # [8276733.451254] peer1 data-mesher[219]: time=2026-09-04T05:06:30.816Z level=INFO msg="file integrity check complete"203peer1 # [8276733.454555] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="libp2p host created" peer_id=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt 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::11a6:255c:2ac:cbd6/tcp/7946]"204peer1 # [8276733.454600] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=GET path=/files205peer1 # [8276733.454600] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name206peer1 # [8276733.454600] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name207peer1 # [8276733.454600] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="starting server"208peer1 # [8276733.454673] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="waiting for DHT to populate" delay=10s209peer1 # [8276733.454729] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="HTTP server listening" address=[::1]:7331210peer1 # [8276733.454758] peer1 data-mesher[219]: time=2026-09-04T05:06:30.820Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331211peer1 # [8276733.456304] peer1 data-mesher[219]: time=2026-09-04T05:06:30.821Z level=INFO msg="peer connected" peer_id=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS remote_addr=/ip4/192.168.1.1/tcp/7946212controller # [8276733.256302] controller systemd[1]: Started D-Bus System Message Bus.213controller # [8276733.260806] controller dbus-broker-launch[233]: Ready214controller # [8276733.438201] controller data-mesher[230]: time=2026-09-04T05:06:30.803Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]215controller # [8276733.438527] controller data-mesher[230]: time=2026-09-04T05:06:30.804Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS: [/dns/controller.clan/tcp/7946]} {12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt: [/dns/peer1.clan/tcp/7946]} {12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS216controller # [8276733.438527] controller data-mesher[230]: time=2026-09-04T05:06:30.804Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml217controller # [8276733.451252] controller data-mesher[230]: time=2026-09-04T05:06:30.816Z level=INFO msg="checking file integrity"218controller # [8276733.451334] controller data-mesher[230]: time=2026-09-04T05:06:30.817Z level=INFO msg="file integrity check complete"219controller # [8276733.454388] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="libp2p host created" peer_id=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS 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::b2f2:452:9eab:1d9d/tcp/7946]"220controller # [8276733.454439] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name221controller # [8276733.454439] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=GET path=/files222controller # [8276733.454439] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name223controller # [8276733.454439] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="starting server"224controller # [8276733.454504] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="waiting for DHT to populate" delay=10s225controller # [8276733.454562] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="HTTP server listening" address=[::1]:7331226controller # [8276733.454580] controller data-mesher[230]: time=2026-09-04T05:06:30.820Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331227controller # [8276733.456523] controller data-mesher[230]: time=2026-09-04T05:06:30.822Z level=INFO msg="peer connected" peer_id=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt remote_addr=/ip4/192.168.1.2/tcp/7946228peer1 # [8276733.507538] peer1 systemd-logind[239]: New seat seat0.229peer1 # [8276733.507653] peer1 systemd[1]: Started User Login Management.230peer1 # [8276733.508576] peer1 systemd[1]: Starting linger-users.service...231peer1 # [8276733.530900] peer1 systemd[1]: linger-users.service: Deactivated successfully.232peer1 # [8276733.530971] peer1 systemd[1]: Finished linger-users.service.233peer1 # [8276733.596508] peer1 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.234controller # [8276733.511192] controller systemd-logind[250]: New seat seat0.235controller # [8276733.511304] controller systemd[1]: Started User Login Management.236controller # [8276733.527208] controller systemd[1]: Starting linger-users.service...237controller # [8276733.532352] controller systemd[1]: linger-users.service: Deactivated successfully.238controller # [8276733.532386] controller systemd[1]: Finished linger-users.service.239controller # [8276733.595833] controller systemd[1]: etc-machine\x2did.mount: Deactivated successfully.240peer1 # [8276734.014078] peer1 systemd-networkd[213]: eth1: Gained IPv6LL241controller # [8276734.590083] controller systemd-networkd[224]: eth1: Gained IPv6LL242controller: still waiting for container 'controller' to reach ready state...243controller: (finished: waiting for unit data-mesher.service, in 11.64 seconds)244peer1: waiting for unit data-mesher.service245peer1: (finished: waiting for unit data-mesher.service, in 0.01 seconds)246??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.247 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39248controller: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller249??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.250 File "/nix/store/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39251controller: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 0.00 seconds)252peer1: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller253peer1 # [8276743.454934] peer1 data-mesher[219]: time=2026-09-04T05:06:40.820Z level=INFO msg="performing state exchange with peers on join" count=1254peer1 # [8276743.454934] peer1 data-mesher[219]: time=2026-09-04T05:06:40.820Z level=DEBUG msg="initiating state exchange" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s255peer1 # [8276743.455399] peer1 data-mesher[219]: time=2026-09-04T05:06:40.820Z level=INFO msg="received state sync from peer" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS256peer1 # [8276743.455399] peer1 data-mesher[219]: time=2026-09-04T05:06:40.821Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS257peer1 # [8276743.455399] peer1 data-mesher[219]: time=2026-09-04T05:06:40.821Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS258peer1 # [8276743.455399] peer1 data-mesher[219]: time=2026-09-04T05:06:40.821Z level=INFO msg="state exchange complete" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s259peer1 # [8276743.455399] peer1 data-mesher[219]: time=2026-09-04T05:06:40.821Z level=INFO msg="server started"260peer1 # [8276743.455493] peer1 data-mesher[219]: time=2026-09-04T05:06:40.821Z level=INFO msg="starting expired-file sweeper" interval=1m0s261peer1 # [8276743.455515] peer1 systemd[1]: Started data mesher daemon.262peer1 # [8276743.456243] peer1 systemd[1]: Starting Publish WireGuard peer info to data-mesher...263peer1 # [8276743.532982] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...264peer1 # [8276743.577480] peer1 dm-wg-star-reconfig[278]: No controller data available yet, skipping265peer1 # [8276743.577959] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.266peer1 # [8276743.577998] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.267peer1 # [8276743.599562] peer1 data-mesher[219]: time=2026-09-04T05:06:40.965Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs status=204268peer1 # [8276743.600044] peer1 dm-wg-star-publish[271]: Status: 204 No Content269peer1 # [8276743.601628] peer1 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.270peer1 # [8276743.601745] peer1 systemd[1]: Finished Publish WireGuard peer info to data-mesher.271peer1 # [8276743.602033] peer1 systemd[1]: Reached target Multi-User System.272peer1 # [8276743.602141] peer1 systemd[1]: Startup finished in 11.279s.273controller # [8276743.455058] controller data-mesher[230]: time=2026-09-04T05:06:40.820Z level=INFO msg="performing state exchange with peers on join" count=1274controller # [8276743.455058] controller data-mesher[230]: time=2026-09-04T05:06:40.820Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s275controller # [8276743.455442] controller data-mesher[230]: time=2026-09-04T05:06:40.820Z level=INFO msg="received state sync from peer" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt276controller # [8276743.455442] controller data-mesher[230]: time=2026-09-04T05:06:40.820Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt277controller # [8276743.455442] controller data-mesher[230]: time=2026-09-04T05:06:40.821Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt278controller # [8276743.455442] controller data-mesher[230]: time=2026-09-04T05:06:40.821Z level=INFO msg="state exchange complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s279controller # [8276743.455442] controller data-mesher[230]: time=2026-09-04T05:06:40.821Z level=INFO msg="server started"280controller # [8276743.455544] controller data-mesher[230]: time=2026-09-04T05:06:40.821Z level=INFO msg="starting expired-file sweeper" interval=1m0s281controller # [8276743.455539] controller systemd[1]: Started data mesher daemon.282controller # [8276743.456245] controller systemd[1]: Starting Publish WireGuard controller info to data-mesher...283controller # [8276743.495424] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...284controller # [8276743.535650] controller dm-wg-star-reconfig[290]: No peer data available yet, skipping285controller # [8276743.536088] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.286controller # [8276743.536166] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.287controller # [8276743.590484] controller data-mesher[230]: time=2026-09-04T05:06:40.956Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/controller status=204288controller # [8276743.591126] controller dm-wg-star-publish[283]: Status: 204 No Content289controller # [8276743.592495] controller systemd[1]: Finished Publish WireGuard controller info to data-mesher.290controller # [8276743.592683] controller systemd[1]: Reached target Multi-User System.291controller # [8276743.592766] controller systemd[1]: Startup finished in 11.258s.292peer1 # [8276748.458579] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="attempting push/pull" peer_count=1293peer1 # [8276748.458579] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="initiating state exchange" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s294peer1 # [8276748.458982] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="received state sync from peer" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS295peer1 # [8276748.458982] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS296peer1 # [8276748.458982] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="new file detected" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller297peer1 # [8276748.458982] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller298peer1 # [8276748.458982] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-04 05:06:40.859 +0000 UTC" signed_by="aC1vW/nPfiNZAtWeZutFIF53z4QozIYTU6LlH7r+xQk=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS299peer1 # [8276748.459121] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS300peer1 # [8276748.459121] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="new file detected" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller301peer1 # [8276748.459121] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="state exchange complete" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s302peer1 # [8276748.459121] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="push/pull successful" interval=5s303peer1 # [8276748.459121] peer1 data-mesher[219]: time=2026-09-04T05:06:45.824Z level=INFO msg="received file request" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs304peer1 # [8276748.459860] peer1 data-mesher[219]: time=2026-09-04T05:06:45.825Z level=INFO msg="file transfer complete" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs305peer1 # [8276748.633274] peer1 data-mesher[219]: time=2026-09-04T05:06:45.998Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-04 05:06:40.859 +0000 UTC" signed_by="aC1vW/nPfiNZAtWeZutFIF53z4QozIYTU6LlH7r+xQk=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS written=true elapsed=174.513477ms306peer1 # [8276748.634175] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...307peer1 # [8276748.708491] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.308peer1 # [8276748.708563] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.309peer1: (finished: waiting for success: test -f /var/lib/data-mesher/files/home/dm_wg_star_wg_star/controller, in 5.02 seconds)310controller: waiting for success: ls /var/lib/data-mesher/files/home/dm_wg_star_wg_star/ | grep -v controller | grep -q .311controller: (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)312controller: waiting for success: wg show wg-star peers | grep -q .313controller: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)314peer1: waiting for success: wg show wg-star peers | grep -q .315peer1: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)316peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b2f2:0452:9eab:1d9d317peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b2f2:0452:9eab:1d9d, in 0.00 seconds)318controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::11a6:255c:02ac:cbd6319controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::11a6:255c:02ac:cbd6, in 0.00 seconds)320controller: must succeed: wg show wg-star peers | wc -l321controller: (finished: must succeed: wg show wg-star peers | wc -l, in 0.00 seconds)322peer2: systemd-nspawn running (pid 733)323peer2: Waiting for journal at /build/vm-state-peer2/var/log/journal...324peer2: waiting for unit data-mesher.service325nixos-nspawn(peer2): TAP vde-tap1 not found; container will be isolated from VDE326nixos-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.327Note: 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.328░ Spawning container peer2 on /build/vm-state-peer2.329controller # [8276748.458257] controller data-mesher[230]: time=2026-09-04T05:06:45.823Z level=DEBUG msg="attempting push/pull" peer_count=1330controller # [8276748.458510] controller data-mesher[230]: time=2026-09-04T05:06:45.823Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s331controller # [8276748.458800] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="received state sync from peer" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt332controller # [8276748.458823] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt333controller # [8276748.458823] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt334controller # [8276748.458891] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="new file detected" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs335controller # [8276748.458891] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="new file detected" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs336controller # [8276748.458914] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="state exchange complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s337controller # [8276748.458914] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs338controller # [8276748.458942] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs signed_at="2026-09-04 05:06:40.895 +0000 UTC" signed_by="deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW/VvqMs=" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt339controller # [8276748.458959] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=INFO msg="received file request" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/controller340controller # [8276748.459013] controller data-mesher[230]: time=2026-09-04T05:06:45.824Z level=DEBUG msg="push/pull successful" interval=5s341controller # [8276748.459918] controller data-mesher[230]: time=2026-09-04T05:06:45.825Z level=INFO msg="file transfer complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/controller342controller # [8276748.461820] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...343controller # [8276748.632855] controller data-mesher[230]: time=2026-09-04T05:06:45.998Z level=INFO msg="download complete" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs signed_at="2026-09-04 05:06:40.895 +0000 UTC" signed_by="deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW/VvqMs=" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt written=true elapsed=173.90985ms344controller # [8276748.645696] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.345controller # [8276748.658068] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.346peer2 # [8276749.291476] peer2 systemd-journald[97]: Journal started347peer2 # [8276749.291503] peer2 systemd-journald[97]: Runtime Journal (/run/log/journal/dbff6069eac84dd4abfc806a72eb45ef) is 8M, max 3.7G, 3.7G free.348peer2 # [8276749.292970] peer2 systemd[1]: Finished Create Static Device Nodes in /dev gracefully.349peer2 # [8276749.297767] peer2 systemd[1]: Starting Flush Journal to Persistent Storage...350peer2 # [8276749.298120] peer2 systemd[1]: Starting Network Name Resolution...351peer2 # [8276749.298429] peer2 systemd[1]: Starting Create Static Device Nodes in /dev...352peer2 # [8276749.302961] peer2 systemd-journald[97]: Time spent on flushing to /var/log/journal/dbff6069eac84dd4abfc806a72eb45ef is 1.645ms for 6 entries.353peer2 # [8276749.302961] peer2 systemd-journald[97]: System Journal (/var/log/journal/dbff6069eac84dd4abfc806a72eb45ef) is 8M, max 4G, 3.9G free.354peer2 # [8276749.306528] peer2 systemd[1]: Finished Create Static Device Nodes in /dev.355peer2 # [8276749.307108] peer2 systemd[1]: Reached target Preparation for Local File Systems.356peer2 # [8276749.307181] peer2 systemd[1]: Reached target Local File Systems.357peer2 # [8276749.307685] peer2 systemd[1]: Listening on Boot Loader Control Service Socket.358peer2 # [8276749.307711] peer2 systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container359peer2 # [8276749.308081] peer2 systemd[1]: Starting Save Transient machine-id to Disk...360peer2 # [8276749.308098] peer2 systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys361peer2 # [8276749.351443] peer2 systemd[1]: Finished Flush Journal to Persistent Storage.362peer2 # [8276749.352593] peer2 systemd[1]: Starting Create System Files and Directories...363peer2 # [8276749.375107] peer2 systemd[1]: Finished Firewall.364peer2 # [8276749.375265] peer2 systemd[1]: Reached target Preparation for Network.365peer2 # [8276749.375420] peer2 systemd[1]: Listening on Network Management Resolve Hook Socket.366peer2 # [8276749.375994] peer2 systemd[1]: Starting Network Management...367peer2 # [8276749.382645] peer2 systemd-tmpfiles[186]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted368peer2 # [8276749.382798] peer2 systemd-tmpfiles[186]: fchmod() of /var/log/journal failed: Operation not permitted369peer2 # [8276749.382904] peer2 systemd-tmpfiles[186]: fchmod() of /var/log/journal/dbff6069eac84dd4abfc806a72eb45ef failed: Operation not permitted370peer2 # [8276749.383073] peer2 systemd-tmpfiles[186]: fchmod() of /run/log/journal failed: Operation not permitted371peer2 # [8276749.383906] peer2 systemd[1]: Finished Create System Files and Directories.372peer2 # [8276749.384491] peer2 systemd[1]: Starting Rebuild Journal Catalog...373peer2 # [8276749.384813] peer2 systemd[1]: Starting Record System Boot/Shutdown in UTMP...374peer2 # [8276749.390369] peer2 systemd[1]: Finished Record System Boot/Shutdown in UTMP.375peer2 # [8276749.395799] peer2 systemd[1]: Finished Rebuild Journal Catalog.376peer2 # [8276749.396219] peer2 systemd[1]: Starting Update is Completed...377peer2 # [8276749.400731] peer2 systemd[1]: Finished Update is Completed.378peer2 # [8276749.620041] peer2 systemd-networkd[207]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted379peer2 # [8276749.620128] peer2 systemd-networkd[207]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted380peer2 # [8276749.626127] peer2 systemd-networkd[207]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.381peer2 # [8276749.626357] peer2 systemd-networkd[207]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.382peer2 # [8276749.626440] peer2 systemd-networkd[207]: lo: Link UP383peer2 # [8276749.626445] peer2 systemd-networkd[207]: lo: Gained carrier384peer2 # [8276749.626634] peer2 systemd-networkd[207]: eth1: Configuring with /etc/systemd/network/40-eth1.network.385peer2 # [8276749.626978] peer2 systemd[1]: Started Network Management.386peer2 # [8276749.627382] peer2 systemd-networkd[207]: wg-star: Configuring with /etc/systemd/network/40-wg-star.network.387peer2 # [8276749.627473] peer2 systemd[1]: Starting Enable Persistent Storage in systemd-networkd...388peer2 # [8276749.627566] peer2 systemd-networkd[207]: wg-star: netdev ready389peer2 # [8276749.627740] peer2 systemd-networkd[207]: eth1: Link UP390peer2 # [8276749.627844] peer2 systemd-networkd[207]: eth1: Gained carrier391peer2 # [8276749.640300] peer2 systemd-networkd[207]: wg-star: Link UP392peer2 # [8276749.640305] peer2 systemd-networkd[207]: wg-star: Gained carrier393peer2 # [8276749.651814] peer2 systemd[1]: Finished Enable Persistent Storage in systemd-networkd.394peer2 # [8276749.764361] peer2 systemd-resolved[120]: Positive Trust Anchors:395peer2 # [8276749.764369] peer2 systemd-resolved[120]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d396peer2 # [8276749.764373] peer2 systemd-resolved[120]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16397peer2 # [8276749.764388] peer2 systemd-resolved[120]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test398peer2 # [8276749.774752] peer2 systemd-resolved[120]: Using system hostname 'peer2'.399peer2 # [8276749.775676] peer2 systemd[1]: Started Network Name Resolution.400peer2 # [8276749.775721] peer2 systemd[1]: Reached target Network.401peer2 # [8276749.775755] peer2 systemd[1]: Reached target System Initialization.402peer2 # [8276749.775807] peer2 systemd[1]: Started Watch for WireGuard controller info from data-mesher.403peer2 # [8276749.775824] peer2 systemd[1]: Started Periodic heartbeat re-publish for dm-wireguard-star peer.404peer2 # [8276749.775840] peer2 systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container405peer2 # [8276749.775850] peer2 systemd[1]: Started Daily Cleanup of Temporary Directories.406peer2 # [8276749.775859] peer2 systemd[1]: Reached target Path Units.407peer2 # [8276749.775878] peer2 systemd[1]: Reached target Timer Units.408peer2 # [8276749.775941] peer2 systemd[1]: Listening on D-Bus System Message Bus Socket.409peer2 # [8276749.776008] peer2 systemd[1]: Listening on Nix Daemon Socket.410peer2 # [8276749.776077] peer2 systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.411peer2 # [8276749.776089] peer2 systemd[1]: Reached target Socket Units.412peer2 # [8276749.776117] peer2 systemd[1]: Reached target Basic System.413peer2 # [8276749.776648] peer2 systemd[1]: Starting data mesher daemon...414peer2 # [8276749.776945] peer2 systemd[1]: Starting Import lastlog data into lastlog2 database...415peer2 # [8276749.777275] peer2 systemd[1]: Starting Name Service Cache Daemon (nsncd)...416peer2 # [8276749.777804] peer2 systemd[1]: Starting D-Bus System Message Bus...417peer2 # [8276749.804588] peer2 systemd[1]: Finished Import lastlog data into lastlog2 database.418peer2 # [8276749.853030] peer2 nsncd[221]: Sep 04 05:06:47.218 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"419peer2 # [8276749.853027] peer2 systemd[1]: Started Name Service Cache Daemon (nsncd).420peer2 # [8276749.853050] peer2 systemd[1]: Reached target Host and Network Name Lookups.421peer2 # [8276749.853076] peer2 systemd[1]: Reached target User and Group Name Lookups.422peer2 # [8276749.853493] peer2 systemd[1]: Starting User Login Management...423peer2 # [8276749.853784] peer2 systemd[1]: Starting Permit User Sessions...424peer2 # [8276749.886578] peer2 systemd[1]: Finished Permit User Sessions.425peer2 # [8276749.887387] peer2 systemd[1]: Started Console Getty.426peer2 # [8276749.887416] peer2 systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0427peer2 # [8276749.887430] peer2 systemd[1]: Reached target Login Prompts.428peer2 # [8276749.903416] peer2 dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...429peer2 # [8276749.903815] peer2 dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'430peer2 # [8276749.903815] peer2 dbus-broker-launch[222]: Invalid user-name in /nix/store/37a9ydyl6jjxzyrg50w5rai4v2zhqhzk-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"431peer2 # [8276749.904053] peer2 systemd[1]: Started D-Bus System Message Bus.432peer2 # [8276749.907226] peer2 dbus-broker-launch[222]: Ready433peer2 # [8276749.955992] peer2 systemd[1]: Finished Save Transient machine-id to Disk.434peer2 # [8276750.068120] peer2 data-mesher[219]: time=2026-09-04T05:06:47.433Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]435peer2 # [8276750.068434] peer2 data-mesher[219]: time=2026-09-04T05:06:47.434Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS: [/dns/controller.clan/tcp/7946]} {12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt: [/dns/peer1.clan/tcp/7946]} {12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn: [/dns/peer2.clan/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn436peer2 # [8276750.068458] peer2 data-mesher[219]: time=2026-09-04T05:06:47.434Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml437peer2 # [8276750.074431] peer2 data-mesher[219]: time=2026-09-04T05:06:47.440Z level=INFO msg="checking file integrity"438peer2 # [8276750.074520] peer2 data-mesher[219]: time=2026-09-04T05:06:47.440Z level=INFO msg="file integrity check complete"439peer2 # [8276750.077306] peer2 data-mesher[219]: time=2026-09-04T05:06:47.442Z level=INFO msg="libp2p host created" peer_id=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn 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::bd0a:367b:9b0b:1713/tcp/7946]"440peer2 # [8276750.077332] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="registered HTTP route" method=GET path=/files441peer2 # [8276750.077332] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name442peer2 # [8276750.077332] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name443peer2 # [8276750.077332] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="starting server"444peer2 # [8276750.077409] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="waiting for DHT to populate" delay=10s445peer2 # [8276750.077422] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="HTTP server listening" address=[::1]:7331446peer2 # [8276750.077441] peer2 data-mesher[219]: time=2026-09-04T05:06:47.443Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331447peer2 # [8276750.078819] peer2 data-mesher[219]: time=2026-09-04T05:06:47.444Z level=INFO msg="peer connected" peer_id=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt remote_addr=/ip4/192.168.1.2/tcp/7946448peer2 # [8276750.081220] peer2 data-mesher[219]: time=2026-09-04T05:06:47.446Z level=INFO msg="peer connected" peer_id=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS remote_addr=/ip4/192.168.1.1/tcp/7946449controller # [8276750.081419] controller data-mesher[230]: time=2026-09-04T05:06:47.447Z level=INFO msg="peer connected" peer_id=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn remote_addr=/ip4/192.168.1.3/tcp/7946450peer2 # [8276750.166057] peer2 systemd-logind[239]: New seat seat0.451peer2 # [8276750.166187] peer2 systemd[1]: Started User Login Management.452peer2 # [8276750.167052] peer2 systemd[1]: Starting linger-users.service...453peer2 # [8276750.188986] peer2 systemd[1]: linger-users.service: Deactivated successfully.454peer2 # [8276750.189082] peer2 systemd[1]: Finished linger-users.service.455peer2 # [8276750.285029] peer2 systemd[1]: etc-machine\x2did.mount: Deactivated successfully.456peer1 # [8276750.079049] peer1 data-mesher[219]: time=2026-09-04T05:06:47.444Z level=INFO msg="peer connected" peer_id=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn remote_addr=/ip4/192.168.1.3/tcp/7946457peer2 # [8276751.550062] peer2 systemd-networkd[207]: eth1: Gained IPv6LL458peer1 # [8276753.459415] peer1 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="attempting push/pull" peer_count=1459peer1 # [8276753.459672] peer1 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="initiating state exchange" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s460peer1 # [8276753.459928] peer1 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS461peer1 # [8276753.460064] peer1 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="state exchange complete" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS timeout=5s462peer1 # [8276753.460094] peer1 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="push/pull successful" interval=5s463controller # [8276753.459704] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=INFO msg="received state sync from peer" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt464controller # [8276753.459704] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt465controller # [8276753.460001] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="attempting push/pull" peer_count=1466controller # [8276753.460001] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="initiating state exchange" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s467controller # [8276753.460278] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn468controller # [8276753.460278] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=INFO msg="state exchange complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s469controller # [8276753.460329] controller data-mesher[230]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="push/pull successful" interval=5s470controller # [8276753.460502] controller data-mesher[230]: time=2026-09-04T05:06:50.826Z level=INFO msg="received file request" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/controller471controller # [8276753.460562] controller data-mesher[230]: time=2026-09-04T05:06:50.826Z level=INFO msg="received file request" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs472controller # [8276753.461228] controller data-mesher[230]: time=2026-09-04T05:06:50.826Z level=INFO msg="file transfer complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/controller473controller # [8276753.461659] controller data-mesher[230]: time=2026-09-04T05:06:50.827Z level=INFO msg="file transfer complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs474peer2 # [8276753.460121] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="received state sync from peer" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS475peer2 # [8276753.460121] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS476peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="new file detected" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/controller477peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=DEBUG msg="new file detected" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs478peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/controller479peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs480peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/controller signed_at="2026-09-04 05:06:40.859 +0000 UTC" signed_by="aC1vW/nPfiNZAtWeZutFIF53z4QozIYTU6LlH7r+xQk=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS481peer2 # [8276753.460454] peer2 data-mesher[219]: time=2026-09-04T05:06:50.825Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs signed_at="2026-09-04 05:06:40.895 +0000 UTC" signed_by="deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW/VvqMs=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS482peer2 # [8276753.462676] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...483peer2 # [8276753.519972] peer2 data-mesher[219]: time=2026-09-04T05:06:50.885Z level=INFO msg="download complete" name=dm_wg_star_wg_star/controller signed_at="2026-09-04 05:06:40.859 +0000 UTC" signed_by="aC1vW/nPfiNZAtWeZutFIF53z4QozIYTU6LlH7r+xQk=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS written=true elapsed=59.685451ms484peer2 # [8276753.526943] peer2 data-mesher[219]: time=2026-09-04T05:06:50.892Z level=INFO msg="download complete" name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs signed_at="2026-09-04 05:06:40.895 +0000 UTC" signed_by="deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW/VvqMs=" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS written=true elapsed=66.66653ms485peer2 # [8276753.536946] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.486peer2 # [8276753.537104] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.487peer1 # [8276758.460653] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="attempting push/pull" peer_count=1488peer1 # [8276758.460653] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="initiating state exchange" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s489peer1 # [8276758.460975] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="received state sync from peer" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS490peer1 # [8276758.460975] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS491peer1 # [8276758.461152] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn492peer1 # [8276758.461213] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="state exchange complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s493peer1 # [8276758.461231] peer1 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="push/pull successful" interval=5s494peer2: still waiting for container 'peer2' to reach ready state...495peer2 # [8276758.460924] peer2 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="received state sync from peer" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt496peer2 # [8276758.460924] peer2 data-mesher[219]: time=2026-09-04T05:06:55.826Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt497controller # [8276758.460389] controller data-mesher[230]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="attempting push/pull" peer_count=1498controller # [8276758.460389] controller data-mesher[230]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s499controller # [8276758.460968] controller data-mesher[230]: time=2026-09-04T05:06:55.826Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt500controller # [8276758.461112] controller data-mesher[230]: time=2026-09-04T05:06:55.826Z level=INFO msg="state exchange complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s501controller # [8276758.461146] controller data-mesher[230]: time=2026-09-04T05:06:55.826Z level=DEBUG msg="push/pull successful" interval=5s502peer2: (finished: waiting for unit data-mesher.service, in 11.64 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/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-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/wsnxjqf86imlxfmxxxf02lp1kvcib7xs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39508peer2 # [8276760.077822] peer2 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=INFO msg="performing state exchange with peers on join" count=1509peer2 # [8276760.077822] peer2 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s510peer2 # [8276760.078234] peer2 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt511peer2 # [8276760.078301] peer2 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=INFO msg="state exchange complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s512peer2 # [8276760.078316] peer2 data-mesher[219]: time=2026-09-04T05:06:57.444Z level=INFO msg="server started"513peer2 # [8276760.078392] peer2 data-mesher[219]: time=2026-09-04T05:06:57.444Z level=INFO msg="starting expired-file sweeper" interval=1m0s514peer2 # [8276760.078470] peer2 systemd[1]: Started data mesher daemon.515peer2 # [8276760.079181] peer2 systemd[1]: Starting Publish WireGuard peer info to data-mesher...516peer2 # [8276760.159052] peer2 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...517peer2 # [8276760.225461] peer2 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.518peer2 # [8276760.225636] peer2 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.519peer2 # [8276760.288920] peer2 data-mesher[219]: time=2026-09-04T05:06:57.654Z level=INFO msg=http_request uri=/files/dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM status=204520peer2 # [8276760.288993] peer2 dm-wg-star-publish[283]: Status: 204 No Content521peer2 # [8276760.291723] peer2 systemd[1]: dm-wg-star-wg-star-publish.service: Deactivated successfully.522peer2 # [8276760.291847] peer2 systemd[1]: Finished Publish WireGuard peer info to data-mesher.523peer2 # [8276760.292152] peer2 systemd[1]: Reached target Multi-User System.524peer2 # [8276760.292247] peer2 systemd[1]: Startup finished in 11.264s.525peer1 # [8276760.078056] peer1 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=INFO msg="received state sync from peer" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn526peer1 # [8276760.078056] peer1 data-mesher[219]: time=2026-09-04T05:06:57.443Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn527peer1 # [8276763.461816] peer1 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=DEBUG msg="attempting push/pull" peer_count=1528peer1 # [8276763.461816] peer1 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=DEBUG msg="initiating state exchange" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s529peer1 # [8276763.462213] peer1 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn530peer1 # [8276763.462349] peer1 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=DEBUG msg="new file detected" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM531peer1 # [8276763.462349] peer1 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="state exchange complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s532peer1 # [8276763.462407] peer1 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=DEBUG msg="push/pull successful" interval=5s533peer1 # [8276763.462407] peer1 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM534peer1 # [8276763.462407] peer1 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM signed_at="2026-09-04 05:06:57.522 +0000 UTC" signed_by="xwaz3GVybQ+jLwA605RI4wg20cUd8dkFoR3MmzunQkM=" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn535peer1 # [8276763.465290] peer1 systemd[1]: Starting Reconfigure WireGuard with controller from data-mesher...536peer1 # [8276763.469056] peer1 data-mesher[219]: time=2026-09-04T05:07:00.834Z level=INFO msg="download complete" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM signed_at="2026-09-04 05:06:57.522 +0000 UTC" signed_by="xwaz3GVybQ+jLwA605RI4wg20cUd8dkFoR3MmzunQkM=" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn written=true elapsed=6.670453ms537peer1 # [8276763.541129] peer1 systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.538peer1 # [8276763.541237] peer1 systemd[1]: Finished Reconfigure WireGuard with controller from data-mesher.539controller # [8276763.461747] controller data-mesher[230]: time=2026-09-04T05:07:00.827Z level=DEBUG msg="attempting push/pull" peer_count=1540controller # [8276763.461747] controller data-mesher[230]: time=2026-09-04T05:07:00.827Z level=DEBUG msg="initiating state exchange" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s541controller # [8276763.462209] controller data-mesher[230]: time=2026-09-04T05:07:00.827Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn542controller # [8276763.462375] controller data-mesher[230]: time=2026-09-04T05:07:00.828Z level=DEBUG msg="new file detected" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn name=dm_wg_star_wg_star/controller name=dm_wg_star_wg_star/deOgFalTg90fJJF3e6uXZYaTWkhHJ4ASgQFQW_VvqMs name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM543controller # [8276763.462396] controller data-mesher[230]: time=2026-09-04T05:07:00.828Z level=INFO msg="state exchange complete" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn timeout=5s544controller # [8276763.462420] controller data-mesher[230]: time=2026-09-04T05:07:00.828Z level=DEBUG msg="push/pull successful" interval=5s545controller # [8276763.462420] controller data-mesher[230]: time=2026-09-04T05:07:00.828Z level=INFO msg="scheduling file download" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM546controller # [8276763.462458] controller data-mesher[230]: time=2026-09-04T05:07:00.828Z level=INFO msg="downloading file" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM signed_at="2026-09-04 05:06:57.522 +0000 UTC" signed_by="xwaz3GVybQ+jLwA605RI4wg20cUd8dkFoR3MmzunQkM=" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn547controller # [8276763.465289] controller systemd[1]: Starting Reconfigure WireGuard peers from data-mesher...548controller # [8276763.469080] controller data-mesher[230]: time=2026-09-04T05:07:00.834Z level=INFO msg="download complete" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM signed_at="2026-09-04 05:06:57.522 +0000 UTC" signed_by="xwaz3GVybQ+jLwA605RI4wg20cUd8dkFoR3MmzunQkM=" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn written=true elapsed=6.660154ms549controller # [8276763.542598] controller systemd[1]: dm-wg-star-wg-star-reconfig.service: Deactivated successfully.550controller # [8276763.542642] controller systemd[1]: Finished Reconfigure WireGuard peers from data-mesher.551peer2 # [8276763.461992] peer2 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=INFO msg="received state sync from peer" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt552peer2 # [8276763.461992] peer2 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt553peer2 # [8276763.462251] peer2 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=INFO msg="received state sync from peer" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS554peer2 # [8276763.462251] peer2 data-mesher[219]: time=2026-09-04T05:07:00.827Z level=INFO msg="merging remote state" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS555peer2 # [8276763.462533] peer2 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="received file request" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM556peer2 # [8276763.462533] peer2 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="received file request" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM557peer2 # [8276763.463142] peer2 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="file transfer complete" peer=12D3KooWC1evpbqxibXcXwpWRitrK6UUUxGGCg2hwUxM3t5ocTPS network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM558peer2 # [8276763.463205] peer2 data-mesher[219]: time=2026-09-04T05:07:00.828Z level=INFO msg="file transfer complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt network="JI1GY9Zc6pr9xMmERz1NnBaAIyPFxi2zh59AP55yBEU=" name=dm_wg_star_wg_star/xwaz3GVybQ-jLwA605RI4wg20cUd8dkFoR3MmzunQkM559controller: (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 4.03 seconds)560controller: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1561controller: (finished: waiting for success: test $(wg show wg-star peers | wc -l) -gt 1, in 0.00 seconds)562peer2: waiting for success: wg show wg-star peers | grep -q .563peer2: (finished: waiting for success: wg show wg-star peers | grep -q ., in 0.00 seconds)564peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b2f2:0452:9eab:1d9d565peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::b2f2:0452:9eab:1d9d, in 0.00 seconds)566controller: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bd0a:367b:9b0b:1713567controller: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bd0a:367b:9b0b:1713, in 0.00 seconds)568peer1: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bd0a:367b:9b0b:1713569peer1: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::bd0a:367b:9b0b:1713, in 0.00 seconds)570peer2: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::11a6:255c:02ac:cbd6571peer2: (finished: waiting for success: ping -6 -c1 -W5 fda1:05c8:00::11a6:255c:02ac:cbd6, in 0.00 seconds)572(finished: run the VM test script, in 32.39 seconds)573peer2 # [8276765.079167] peer2 data-mesher[219]: time=2026-09-04T05:07:02.444Z level=DEBUG msg="attempting push/pull" peer_count=2574peer2 # [8276765.079167] peer2 data-mesher[219]: time=2026-09-04T05:07:02.444Z level=DEBUG msg="initiating state exchange" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s575peer2 # [8276765.079846] peer2 data-mesher[219]: time=2026-09-04T05:07:02.445Z level=INFO msg="merging remote state" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt576peer2 # [8276765.079963] peer2 data-mesher[219]: time=2026-09-04T05:07:02.445Z level=INFO msg="state exchange complete" peer=12D3KooWHkZBXzoFcX9FSu77Ld33XDLTM6iY5SZ98SLyABTVisdt timeout=5s577peer2 # [8276765.079989] peer2 data-mesher[219]: time=2026-09-04T05:07:02.445Z level=DEBUG msg="push/pull successful" interval=5s578peer1 # [8276765.079535] peer1 data-mesher[219]: time=2026-09-04T05:07:02.445Z level=INFO msg="received state sync from peer" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn579peer1 # [8276765.079535] peer1 data-mesher[219]: time=2026-09-04T05:07:02.445Z level=INFO msg="merging remote state" peer=12D3KooWPDHECoMV7ZTA9DCnK3fffyzP2X2rbfScGBCEPmK1mGJn580test script finished in 33.93s581cleanup582kill NspawnMachine (pid 50)583kill NspawnMachine (pid 53)584kill NspawnMachine (pid 733)585Container controller terminated by signal KILL.586Container peer1 terminated by signal KILL.587Container peer2 terminated by signal KILL.588(finished: cleanup, in 0.31 seconds)