container-test-run-dm-dns
checks.aarch64-linux.dm-dns
· build #529
· 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 client, server,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_ssh11start all VMs12client: systemd-nspawn running (pid 52)13server: systemd-nspawn running (pid 53)14client: Waiting for journal at /build/vm-state-client/var/log/journal...15server: Waiting for journal at /build/vm-state-server/var/log/journal...16(finished: start all VMs, in 0.00 seconds)17server: waiting for unit unbound.service18nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE19nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.20nixos-nspawn(server): TAP vde-tap1 not found; container will be isolated from VDE21nixos-nspawn(server): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.22Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.23Note: 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.24░ Spawning container client on /build/vm-state-client.25░ Spawning container server on /build/vm-state-server.26client # [7072906.052286] client systemd-journald[87]: Journal started27client # [7072906.052335] client systemd-journald[87]: Runtime Journal (/run/log/journal/dd259819c0044f16a7c1438acb8cdcc6) is 8M, max 2.5G, 2.4G free.28client # [7072906.054464] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29client # [7072906.062145] client systemd[1]: Starting Flush Journal to Persistent Storage...30client # [7072906.062970] client systemd[1]: Starting Network Name Resolution...31client # [7072906.063679] client systemd[1]: Starting Create Static Device Nodes in /dev...32client # [7072906.073901] client systemd-journald[87]: Time spent on flushing to /var/log/journal/dd259819c0044f16a7c1438acb8cdcc6 is 1.555ms for 6 entries.33client # [7072906.073901] client systemd-journald[87]: System Journal (/var/log/journal/dd259819c0044f16a7c1438acb8cdcc6) is 8M, max 4G, 3.9G free.34client # [7072906.078721] client systemd[1]: Finished Create Static Device Nodes in /dev.35client # [7072906.078939] client systemd[1]: Reached target Preparation for Local File Systems.36client # [7072906.079021] client systemd[1]: Reached target Local File Systems.37client # [7072906.079734] client systemd[1]: Listening on Boot Loader Control Service Socket.38server # [7072906.061237] server systemd-journald[96]: Journal started39server # [7072906.061286] server systemd-journald[96]: Runtime Journal (/run/log/journal/a202345724aa460280cdcdb6e0049f50) is 8M, max 2.5G, 2.4G free.40server # [7072906.065698] server systemd[1]: Finished Create Static Device Nodes in /dev gracefully.41server # [7072906.075604] server systemd[1]: Starting Flush Journal to Persistent Storage...42server # [7072906.076394] server systemd[1]: Starting Network Name Resolution...43server # [7072906.077010] server systemd[1]: Starting Create Static Device Nodes in /dev...44server # [7072906.086629] server systemd-journald[96]: Time spent on flushing to /var/log/journal/a202345724aa460280cdcdb6e0049f50 is 1.792ms for 6 entries.45server # [7072906.086629] server systemd-journald[96]: System Journal (/var/log/journal/a202345724aa460280cdcdb6e0049f50) is 8M, max 4G, 3.9G free.46server # [7072906.089675] server systemd[1]: Finished Create Static Device Nodes in /dev.47server # [7072906.089899] server systemd[1]: Reached target Preparation for Local File Systems.48server # [7072906.089981] server systemd[1]: Reached target Local File Systems.49server # [7072906.090698] server systemd[1]: Listening on Boot Loader Control Service Socket.50server # [7072906.090740] server systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container51server # [7072906.091512] server systemd[1]: Starting Save Transient machine-id to Disk...52server # [7072906.091545] server systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys53server # [7072906.105191] server systemd[1]: Finished Flush Journal to Persistent Storage.54server # [7072906.106124] server systemd[1]: Starting Create System Files and Directories...55server # [7072906.119947] server systemd-tmpfiles[141]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted56server # [7072906.120122] server systemd-tmpfiles[141]: fchmod() of /var/log/journal failed: Operation not permitted57server # [7072906.120230] server systemd-tmpfiles[141]: fchmod() of /var/log/journal/a202345724aa460280cdcdb6e0049f50 failed: Operation not permitted58server # [7072906.120395] server systemd-tmpfiles[141]: fchmod() of /run/log/journal failed: Operation not permitted59server # [7072906.121798] server systemd[1]: Finished Create System Files and Directories.60server # [7072906.122784] server systemd[1]: Starting Rebuild Journal Catalog...61server # [7072906.123456] server systemd[1]: Starting Record System Boot/Shutdown in UTMP...62server # [7072906.136400] server systemd[1]: Finished Record System Boot/Shutdown in UTMP.63server # [7072906.141773] server systemd[1]: Finished Rebuild Journal Catalog.64server # [7072906.142755] server systemd[1]: Starting Update is Completed...65server # [7072906.152057] server systemd[1]: Finished Update is Completed.66server # [7072906.162298] server systemd[1]: Finished Save Transient machine-id to Disk.67client # [7072906.079774] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container68client # [7072906.080582] client systemd[1]: Starting Save Transient machine-id to Disk...69client # [7072906.080613] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys70client # [7072906.092862] client systemd[1]: Finished Flush Journal to Persistent Storage.71client # [7072906.094480] client systemd[1]: Starting Create System Files and Directories...72client # [7072906.110452] client systemd-tmpfiles[134]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted73client # [7072906.110616] client systemd-tmpfiles[134]: fchmod() of /var/log/journal failed: Operation not permitted74client # [7072906.110728] client systemd-tmpfiles[134]: fchmod() of /var/log/journal/dd259819c0044f16a7c1438acb8cdcc6 failed: Operation not permitted75client # [7072906.110897] client systemd-tmpfiles[134]: fchmod() of /run/log/journal failed: Operation not permitted76client # [7072906.112412] client systemd[1]: Finished Create System Files and Directories.77client # [7072906.113578] client systemd[1]: Starting Rebuild Journal Catalog...78client # [7072906.114291] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...79client # [7072906.127288] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.80client # [7072906.136252] client systemd[1]: Finished Rebuild Journal Catalog.81client # [7072906.138376] client systemd[1]: Starting Update is Completed...82client # [7072906.147995] client systemd[1]: Finished Update is Completed.83client # [7072906.162750] client systemd[1]: Finished Save Transient machine-id to Disk.84server # [7072906.268280] server systemd[1]: Finished Firewall.85server # [7072906.268460] server systemd[1]: Reached target Preparation for Network.86server # [7072906.268788] server systemd[1]: Listening on Network Management Resolve Hook Socket.87server # [7072906.269756] server systemd[1]: Starting Network Management...88client # [7072906.203677] client systemd[1]: Finished Firewall.89client # [7072906.203822] client systemd[1]: Reached target Preparation for Network.90client # [7072906.204113] client systemd[1]: Listening on Network Management Resolve Hook Socket.91client # [7072906.205110] client systemd[1]: Starting Network Management...92client # [7072906.647465] client systemd-networkd[205]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted93client # [7072906.647555] client systemd-networkd[205]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted94client # [7072906.654036] client systemd-networkd[205]: /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.95client # [7072906.654198] client systemd-networkd[205]: /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.96client # [7072906.654352] client systemd-networkd[205]: lo: Link UP97client # [7072906.654357] client systemd-networkd[205]: lo: Gained carrier98client # [7072906.654555] client systemd-networkd[205]: eth1: Configuring with /etc/systemd/network/40-eth1.network.99client # [7072906.654950] client systemd[1]: Started Network Management.100client # [7072906.655007] client systemd-networkd[205]: eth1: Link UP101client # [7072906.655260] client systemd-networkd[205]: eth1: Gained carrier102client # [7072906.656557] client systemd[1]: Starting Enable Persistent Storage in systemd-networkd...103client # [7072906.690363] client systemd[1]: Finished Enable Persistent Storage in systemd-networkd.104client # [7072906.719818] client systemd-resolved[109]: Positive Trust Anchors:105client # [7072906.719830] client systemd-resolved[109]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d106client # [7072906.719834] client systemd-resolved[109]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16107client # [7072906.719869] client systemd-resolved[109]: 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 test108client # [7072906.742735] client systemd-resolved[109]: Using system hostname 'client'.109client # [7072906.744294] client systemd[1]: Started Network Name Resolution.110client # [7072906.744384] client systemd[1]: Reached target Network.111client # [7072906.744463] client systemd[1]: Reached target System Initialization.112client # [7072906.744567] client systemd[1]: Started Watch for zone file changes.113client # [7072906.744601] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container114client # [7072906.744628] client systemd[1]: Started Daily Cleanup of Temporary Directories.115client # [7072906.744651] client systemd[1]: Reached target Path Units.116client # [7072906.744689] client systemd[1]: Reached target Timer Units.117client # [7072906.744834] client systemd[1]: Listening on D-Bus System Message Bus Socket.118client # [7072906.744958] client systemd[1]: Listening on Nix Daemon Socket.119client # [7072906.745080] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.120client # [7072906.745104] client systemd[1]: Reached target Socket Units.121client # [7072906.745143] client systemd[1]: Reached target Basic System.122client # [7072906.746560] client systemd[1]: Starting data mesher daemon...123client # [7072906.747782] client systemd[1]: Starting Import lastlog data into lastlog2 database...124client # [7072906.748702] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...125client # [7072906.750210] client systemd[1]: Starting D-Bus System Message Bus...126client # [7072906.766436] client systemd[1]: Finished Import lastlog data into lastlog2 database.127client # [7072906.855368] client nsncd[212]: Aug 29 20:05:32.908 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"128client # [7072906.855427] client systemd[1]: Started Name Service Cache Daemon (nsncd).129client # [7072906.855494] client systemd[1]: Reached target User and Group Name Lookups.130client # [7072906.856719] client systemd[1]: Starting User Login Management...131client # [7072906.857493] client systemd[1]: Starting Permit User Sessions...132client # [7072906.867503] client systemd[1]: Finished Permit User Sessions.133client # [7072906.868625] client systemd[1]: Started Console Getty.134client # [7072906.868667] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0135client # [7072906.868688] client systemd[1]: Reached target Login Prompts.136client # [7072906.944907] client dbus-broker-launch[213]: Looking up NSS user entry for 'systemd-timesync'...137client # [7072906.945616] client dbus-broker-launch[213]: NSS returned no entry for 'systemd-timesync'138client # [7072906.945616] client dbus-broker-launch[213]: Invalid user-name in /nix/store/giqgsa6vjp02ngnhasy010jgsrrlrx1x-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"139client # [7072906.946076] client systemd[1]: Started D-Bus System Message Bus.140server # [7072906.654317] server systemd-networkd[214]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted141server # [7072906.654405] server systemd-networkd[214]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted142server # [7072906.660939] server 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.143server # [7072906.661099] server 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.144server # [7072906.661253] server systemd-networkd[214]: lo: Link UP145server # [7072906.661255] server systemd-networkd[214]: lo: Gained carrier146server # [7072906.661431] server systemd-networkd[214]: eth1: Configuring with /etc/systemd/network/40-eth1.network.147server # [7072906.661794] server systemd[1]: Started Network Management.148server # [7072906.662054] server systemd-networkd[214]: eth1: Link UP149server # [7072906.662235] server systemd-networkd[214]: eth1: Gained carrier150server # [7072906.662960] server systemd[1]: Starting Enable Persistent Storage in systemd-networkd...151server # [7072906.690159] server systemd[1]: Finished Enable Persistent Storage in systemd-networkd.152server # [7072906.721183] server systemd-resolved[117]: Positive Trust Anchors:153server # [7072906.721193] server systemd-resolved[117]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d154server # [7072906.721198] server systemd-resolved[117]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16155server # [7072906.721233] server 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 test156server # [7072906.743187] server systemd-resolved[117]: Using system hostname 'server'.157server # [7072906.744562] server systemd[1]: Started Network Name Resolution.158server # [7072906.744644] server systemd[1]: Reached target Network.159server # [7072906.744716] server systemd[1]: Reached target System Initialization.160server # [7072906.744801] server systemd[1]: Started Watch for zone file changes.161server # [7072906.744828] server systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container162server # [7072906.744850] server systemd[1]: Started Daily Cleanup of Temporary Directories.163server # [7072906.744870] server systemd[1]: Reached target Path Units.164server # [7072906.744901] server systemd[1]: Reached target Timer Units.165server # [7072906.745027] server systemd[1]: Listening on D-Bus System Message Bus Socket.166server # [7072906.745133] server systemd[1]: Listening on Nix Daemon Socket.167server # [7072906.745234] server systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.168server # [7072906.745256] server systemd[1]: Reached target Socket Units.169server # [7072906.745290] server systemd[1]: Reached target Basic System.170server # [7072906.746638] server systemd[1]: Starting data mesher daemon...171server # [7072906.747720] server systemd[1]: Starting Import lastlog data into lastlog2 database...172server # [7072906.748923] server systemd[1]: Starting Name Service Cache Daemon (nsncd)...173server # [7072906.750183] server systemd[1]: Starting D-Bus System Message Bus...174server # [7072906.767064] server systemd[1]: Finished Import lastlog data into lastlog2 database.175server # [7072906.878684] server nsncd[221]: Aug 29 20:05:32.931 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"176server # [7072906.878758] server systemd[1]: Started Name Service Cache Daemon (nsncd).177server # [7072906.878830] server systemd[1]: Reached target User and Group Name Lookups.178server # [7072906.880205] server systemd[1]: Starting User Login Management...179server # [7072906.881116] server systemd[1]: Starting Permit User Sessions...180server # [7072906.890654] server systemd[1]: Finished Permit User Sessions.181server # [7072906.891595] server systemd[1]: Started Console Getty.182server # [7072906.891635] server systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0183server # [7072906.891652] server systemd[1]: Reached target Login Prompts.184server # [7072906.949802] server dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...185server # [7072906.950384] server dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'186server # [7072906.950384] server dbus-broker-launch[222]: Invalid user-name in /nix/store/8w5s9v175d1kxcvfs6lp43972ni20lqb-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"187client # [7072906.952871] client dbus-broker-launch[213]: Ready188server # [7072906.950852] server systemd[1]: Started D-Bus System Message Bus.189client # [7072907.040561] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.190server # [7072906.958033] server dbus-broker-launch[222]: Ready191client # [7072907.203376] client data-mesher[210]: time=2026-08-29T20:05:33.256Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]192server # [7072907.050626] server systemd[1]: etc-machine\x2did.mount: Deactivated successfully.193server # [7072907.203341] server data-mesher[219]: time=2026-08-29T20:05:33.256Z level=DEBUG msg="http config" listen_addresses="[[::1]:7331 127.0.0.1:7331]" port=7331 interfaces=[lo]194client # [7072907.204546] client data-mesher[210]: time=2026-08-29T20:05:33.257Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S: [/dns/client.test/tcp/7946]} {12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1: [/dns/server.test/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S195client # [7072907.204546] client data-mesher[210]: time=2026-08-29T20:05:33.257Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml196client # [7072907.267757] client data-mesher[210]: time=2026-08-29T20:05:33.320Z level=INFO msg="checking file integrity"197client # [7072907.267757] client data-mesher[210]: time=2026-08-29T20:05:33.320Z level=INFO msg="file integrity check complete"198client # [7072907.271668] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="libp2p host created" peer_id=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S 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]"199client # [7072907.271735] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="registered HTTP route" method=GET path=/files200client # [7072907.271735] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name201client # [7072907.271735] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name202client # [7072907.271735] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="starting server"203client # [7072907.271829] client data-mesher[210]: time=2026-08-29T20:05:33.324Z level=INFO msg="waiting for DHT to populate" delay=10s204client # [7072907.271926] client data-mesher[210]: time=2026-08-29T20:05:33.325Z level=INFO msg="HTTP server listening" address=[::1]:7331205client # [7072907.271962] client data-mesher[210]: time=2026-08-29T20:05:33.325Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331206client # [7072907.279449] client data-mesher[210]: time=2026-08-29T20:05:33.332Z level=INFO msg="peer connected" peer_id=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1 remote_addr=/ip4/192.168.1.2/tcp/7946207client # [7072907.305243] client data-mesher[210]: time=2026-08-29T20:05:33.358Z level=INFO msg="peer connected" peer_id=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1 remote_addr=/ip4/192.168.1.2/tcp/7946208client # [7072907.314472] client systemd-logind[230]: New seat seat0.209client # [7072907.314602] client systemd[1]: Started User Login Management.210client # [7072907.315911] client systemd[1]: Starting linger-users.service...211client # [7072907.326554] client systemd[1]: linger-users.service: Deactivated successfully.212client # [7072907.326730] client systemd[1]: Finished linger-users.service.213server # [7072907.204545] server data-mesher[219]: time=2026-08-29T20:05:33.257Z level=DEBUG msg="cluster config" port=7946 interfaces=[] bootstrap_peers="[{12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S: [/dns/client.test/tcp/7946]} {12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1: [/dns/server.test/tcp/7946]}]" push_pull_interval=5s peer_id=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1214server # [7072907.204545] server data-mesher[219]: time=2026-08-29T20:05:33.257Z level=INFO msg="config loaded" config_file=/etc/data-mesher/dm.toml215server # [7072907.267862] server data-mesher[219]: time=2026-08-29T20:05:33.320Z level=INFO msg="checking file integrity"216server # [7072907.267951] server data-mesher[219]: time=2026-08-29T20:05:33.321Z level=INFO msg="file integrity check complete"217server # [7072907.272341] server data-mesher[219]: time=2026-08-29T20:05:33.325Z level=INFO msg="libp2p host created" peer_id=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1 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]"218server # [7072907.273244] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="registered HTTP route" method=GET path=/files219server # [7072907.273306] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="registered HTTP route" method=PUT path=/files/:name220server # [7072907.273306] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="registered HTTP route" method=DELETE path=/files/:name221server # [7072907.273352] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="starting server"222server # [7072907.273465] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="HTTP server listening" address=[::1]:7331223server # [7072907.273495] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="HTTP server listening" address=127.0.0.1:7331224server # [7072907.273676] server data-mesher[219]: time=2026-08-29T20:05:33.326Z level=INFO msg="waiting for DHT to populate" delay=10s225server # [7072907.278437] server data-mesher[219]: time=2026-08-29T20:05:33.331Z level=INFO msg="peer connected" peer_id=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S remote_addr=/ip4/192.168.1.1/tcp/7946226server # [7072907.305921] server data-mesher[219]: time=2026-08-29T20:05:33.359Z level=INFO msg="peer connected" peer_id=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S remote_addr=/ip4/192.168.1.1/tcp/46142227server # [7072907.332161] server systemd-logind[234]: New seat seat0.228server # [7072907.332361] server systemd[1]: Started User Login Management.229server # [7072907.333604] server systemd[1]: Starting linger-users.service...230server # [7072907.344212] server systemd[1]: linger-users.service: Deactivated successfully.231server # [7072907.344409] server systemd[1]: Finished linger-users.service.232client # [7072907.840146] client systemd-networkd[205]: eth1: Gained IPv6LL233server # [7072908.352186] server systemd-networkd[214]: eth1: Gained IPv6LL234server: still waiting for container 'server' to reach ready state...235server # [7072917.273455] server data-mesher[219]: time=2026-08-29T20:05:43.326Z level=INFO msg="received state sync from peer" peer=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S236server # [7072917.273455] server data-mesher[219]: time=2026-08-29T20:05:43.326Z level=INFO msg="merging remote state" peer=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S237server # [7072917.274227] server data-mesher[219]: time=2026-08-29T20:05:43.327Z level=INFO msg="performing state exchange with peers on join" count=1238server # [7072917.274227] server data-mesher[219]: time=2026-08-29T20:05:43.327Z level=DEBUG msg="initiating state exchange" peer=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S timeout=5s239server # [7072917.274774] server data-mesher[219]: time=2026-08-29T20:05:43.327Z level=INFO msg="merging remote state" peer=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S240server # [7072917.274774] server data-mesher[219]: time=2026-08-29T20:05:43.327Z level=INFO msg="state exchange complete" peer=12D3KooWMBjdvg1RvEKmjMuedbQg7wabqhJSpVaB6hAc8pucRK9S timeout=5s241server # [7072917.274894] server data-mesher[219]: time=2026-08-29T20:05:43.327Z level=INFO msg="server started"242server # [7072917.275095] server systemd[1]: Started data mesher daemon.243server # [7072917.275658] server data-mesher[219]: time=2026-08-29T20:05:43.328Z level=INFO msg="starting expired-file sweeper" interval=1m0s244server # [7072917.277463] server systemd[1]: Starting Unbound recursive Domain Name Server...245client # [7072917.272630] client data-mesher[210]: time=2026-08-29T20:05:43.325Z level=INFO msg="performing state exchange with peers on join" count=1246client # [7072917.272630] client data-mesher[210]: time=2026-08-29T20:05:43.325Z level=DEBUG msg="initiating state exchange" peer=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1 timeout=5s247client # [7072917.273632] client data-mesher[210]: time=2026-08-29T20:05:43.326Z level=INFO msg="merging remote state" peer=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1248client # [7072917.273632] client data-mesher[210]: time=2026-08-29T20:05:43.326Z level=INFO msg="state exchange complete" peer=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1 timeout=5s249client # [7072917.273760] client data-mesher[210]: time=2026-08-29T20:05:43.326Z level=INFO msg="server started"250client # [7072917.273814] client data-mesher[210]: time=2026-08-29T20:05:43.326Z level=INFO msg="starting expired-file sweeper" interval=1m0s251client # [7072917.273988] client systemd[1]: Started data mesher daemon.252client # [7072917.274482] client data-mesher[210]: time=2026-08-29T20:05:43.327Z level=INFO msg="received state sync from peer" peer=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1253client # [7072917.274550] client data-mesher[210]: time=2026-08-29T20:05:43.327Z level=INFO msg="merging remote state" peer=12D3KooWKMCHbGV4FkNjkUWvJfMiZNiJXvjwtdmEiDgkW9cAUES1254client # [7072917.276360] client systemd[1]: Starting Unbound recursive Domain Name Server...255server # [7072917.793555] server unbound-pre-start[283]: Root anchor updated!256server # [7072917.806733] server unbound-pre-start[287]: setup in directory /var/lib/unbound257client # [7072917.792450] client unbound-pre-start[273]: Root anchor updated!258client # [7072917.805767] client unbound-pre-start[277]: setup in directory /var/lib/unbound259server # [7072918.567818] server unbound-pre-start[296]: Certificate request self-signature ok260server # [7072918.567818] server unbound-pre-start[296]: subject=CN=unbound-control261server # [7072918.586684] server unbound-pre-start[287]: removing artifacts262server # [7072918.588827] server unbound-pre-start[287]: Setup success. Certificates created. Enable in unbound.conf file to use263server: (finished: waiting for unit unbound.service, in 14.17 seconds)264client: waiting for unit unbound.service265server # [7072919.098675] server unbound[301]: [301:0] notice: init module 0: validator266server # [7072919.098788] server unbound[301]: [301:0] notice: init module 1: iterator267server # [7072919.104534] server unbound[301]: [301:0] info: start of service (unbound 1.26.0).268server # [7072919.104713] server systemd[1]: Started Unbound recursive Domain Name Server.269server # [7072919.105226] server systemd[1]: Reached target Multi-User System.270server # [7072919.105487] server systemd[1]: Reached target Host and Network Name Lookups.271server # [7072919.107239] server systemd[1]: Starting Reload unbound zone configuration...272server # [7072919.145713] server unbound[301]: [301:0] info: service stopped (unbound 1.26.0).273server # [7072919.146051] server unbound-control[304]: ok274server # [7072919.146037] server unbound[301]: [301:0] info: server stats for thread 0: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting275server # [7072919.146042] server unbound[301]: [301:0] info: server stats for thread 0: requestlist max 1 avg 1 exceeded 0 jostled 0276server # [7072919.147334] server systemd[1]: unbound-reload-zones.service: Deactivated successfully.277server # [7072919.147619] server systemd[1]: Finished Reload unbound zone configuration.278server # [7072919.147756] server unbound[301]: [301:0] notice: Restart of unbound 1.26.0.279server # [7072919.148143] server systemd[1]: Startup finished in 13.452s.280server # [7072919.148643] server unbound[301]: [301:0] notice: init module 0: validator281server # [7072919.148705] server unbound[301]: [301:0] notice: init module 1: iterator282server # [7072919.153228] server unbound[301]: [301:0] info: start of service (unbound 1.26.0).283client # [7072919.801741] client unbound-pre-start[286]: Certificate request self-signature ok284client # [7072919.801741] client unbound-pre-start[286]: subject=CN=unbound-control285client # [7072919.821212] client unbound-pre-start[277]: removing artifacts286client # [7072919.822753] client unbound-pre-start[277]: Setup success. Certificates created. Enable in unbound.conf file to use287client: (finished: waiting for unit unbound.service, in 1.15 seconds)288server: waiting for unit data-mesher.service289server: (finished: waiting for unit data-mesher.service, in 0.02 seconds)290server: waiting for success: dig +short @127.0.0.1 -p 5353 server.test A | grep 10.0.0.1291server: (finished: waiting for success: dig +short @127.0.0.1 -p 5353 server.test A | grep 10.0.0.1, in 0.03 seconds)292server: must succeed: data-mesher file update --network-id /nix/store/msmhl5dsf2vjmg34h0hwdmynk8vgn91h-shared-data-mesher-network_network.pub /nix/store/4g9kvmaqs34gisvxgf61p42p665lx8dx-shared-dm-dns_zone.conf --url http://localhost:7331 --key /run/secrets/shared/dm-dns-signing-key/signing.key --name dns/cnames293server: (finished: must succeed: data-mesher file update --network-id /nix/store/msmhl5dsf2vjmg34h0hwdmynk8vgn91h-shared-data-mesher-network_network.pub /nix/store/4g9kvmaqs34gisvxgf61p42p665lx8dx-shared-dm-dns_zone.conf --url http://localhost:7331 --key /run/secrets/shared/dm-dns-signing-key/signing.key --name dns/cnames, in 0.03 seconds)294??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.295 File "/nix/store/pg5lbaicpvf34wrdmfh8riwp8avk7lk6-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39296server: waiting for success: dig +short @127.0.0.1 -p 5353 myapp.test CNAME | grep server.test297??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.298 File "/nix/store/pg5lbaicpvf34wrdmfh8riwp8avk7lk6-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39299client # [7072920.327836] client unbound[290]: [290:0] notice: init module 0: validator300client # [7072920.327941] client unbound[290]: [290:0] notice: init module 1: iterator301client # [7072920.333178] client unbound[290]: [290:0] info: start of service (unbound 1.26.0).302client # [7072920.333349] client systemd[1]: Started Unbound recursive Domain Name Server.303client # [7072920.333874] client systemd[1]: Reached target Multi-User System.304client # [7072920.334136] client systemd[1]: Reached target Host and Network Name Lookups.305client # [7072920.335919] client systemd[1]: Starting Reload unbound zone configuration...306client # [7072920.393893] client unbound[290]: [290:0] info: service stopped (unbound 1.26.0).307client # [7072920.394239] client unbound-control[294]: ok308client # [7072920.394245] client unbound[290]: [290:0] info: server stats for thread 0: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting309client # [7072920.394251] client unbound[290]: [290:0] info: server stats for thread 0: requestlist max 1 avg 1 exceeded 0 jostled 0310client # [7072920.395504] client systemd[1]: unbound-reload-zones.service: Deactivated successfully.311client # [7072920.395794] client systemd[1]: Finished Reload unbound zone configuration.312client # [7072920.395930] client unbound[290]: [290:0] notice: Restart of unbound 1.26.0.313client # [7072920.396205] client systemd[1]: Startup finished in 14.724s.314client # [7072920.396814] client unbound[290]: [290:0] notice: init module 0: validator315client # [7072920.396873] client unbound[290]: [290:0] notice: init module 1: iterator316client # [7072920.401424] client unbound[290]: [290:0] info: start of service (unbound 1.26.0).317server # [7072920.598199] server data-mesher[219]: time=2026-08-29T20:05:46.651Z level=INFO msg=http_request uri=/files/dns/cnames status=204318server # [7072920.600375] server systemd[1]: Starting Reload unbound zone configuration...319server # [7072920.661775] server unbound-control[340]: ok320server # [7072920.661878] server unbound[301]: [301:0] info: service stopped (unbound 1.26.0).321server # [7072920.662423] server unbound[301]: [301:0] info: server stats for thread 0: 7 queries, 2 answers from cache, 5 recursions, 0 prefetch, 0 rejected by ip ratelimiting322server # [7072920.662431] server unbound[301]: [301:0] info: server stats for thread 0: requestlist max 2 avg 1.6 exceeded 0 jostled 0323server # [7072920.662939] server systemd[1]: unbound-reload-zones.service: Deactivated successfully.324server # [7072920.663228] server systemd[1]: Finished Reload unbound zone configuration.325server # [7072920.664279] server unbound[301]: [301:0] notice: Restart of unbound 1.26.0.326server # [7072920.665742] server unbound[301]: [301:0] notice: init module 0: validator327server # [7072920.665831] server unbound[301]: [301:0] notice: init module 1: iterator328server # [7072920.673936] server unbound[301]: [301:0] info: start of service (unbound 1.26.0).329server: (finished: waiting for success: dig +short @127.0.0.1 -p 5353 myapp.test CNAME | grep server.test, in 1.05 seconds)330(finished: run the VM test script, in 16.46 seconds)331test script finished in 16.92s332cleanup333kill NspawnMachine (pid 52)334kill NspawnMachine (pid 53)335Container client terminated by signal KILL.336(finished: cleanup, in 0.33 seconds)337Container server terminated by signal KILL.