container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #18
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9client: systemd-nspawn running (pid 53)10agent: systemd-nspawn running (pid 52)11client: Waiting for journal at /build/vm-state-client/var/log/journal...12relay: systemd-nspawn running (pid 54)13agent: Waiting for journal at /build/vm-state-agent/var/log/journal...14relay: Waiting for journal at /build/vm-state-relay/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE22nixos-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.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.24Note: 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.25░ Spawning container relay on /build/vm-state-relay.26░ Spawning container agent on /build/vm-state-agent.27Note: 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.28░ Spawning container client on /build/vm-state-client.29client # No journal files were found.30client # No journal boot entry found for the specified boot (+0).31relay # No journal files were found.32agent # No journal files were found.33agent # No journal boot entry found for the specified boot (+0).34relay # No journal boot entry found for the specified boot (+0).35client # [ 3743.809698] client systemd-journald[57]: Journal started36client # [ 3743.809743] client systemd-journald[57]: Runtime Journal (/run/log/journal/c4ba3fec4895401e9c3f374f828bae1e) is 8M, max 4G, 3.9G free.37client # [ 3743.831514] client systemd[1]: Listening on Journal Log Access Socket.38client # [ 3743.831783] client systemd[1]: Finished Apply Kernel Variables.39client # [ 3743.856021] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.40client # [ 3743.873094] client systemd[1]: Starting Flush Journal to Persistent Storage...41client # [ 3743.873872] client systemd[1]: Starting Create Static Device Nodes in /dev...42client # [ 3743.882927] client systemd-journald[57]: Time spent on flushing to /var/log/journal/c4ba3fec4895401e9c3f374f828bae1e is 1.365ms for 7 entries.43client # [ 3743.882927] client systemd-journald[57]: System Journal (/var/log/journal/c4ba3fec4895401e9c3f374f828bae1e) is 512B, max 4G, 3.9G free.44client # [ 3743.896633] client systemd[1]: Finished Create Static Device Nodes in /dev.45client # [ 3743.897366] client systemd[1]: Reached target Preparation for Local File Systems.46client # [ 3743.897473] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys47client # [ 3743.908380] client systemd[1]: Finished Flush Journal to Persistent Storage.48client # [ 3744.046159] client systemd[1]: Finished Firewall.49agent # [ 3743.809528] agent systemd-journald[57]: Journal started50agent # [ 3743.809575] agent systemd-journald[57]: Runtime Journal (/run/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd) is 8M, max 4G, 3.9G free.51agent # [ 3743.831110] agent systemd[1]: Listening on Journal Log Access Socket.52agent # [ 3743.831484] agent systemd[1]: Finished Apply Kernel Variables.53agent # [ 3743.853216] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.54agent # [ 3743.872162] agent systemd[1]: Starting Flush Journal to Persistent Storage...55agent # [ 3743.873039] agent systemd[1]: Starting Create Static Device Nodes in /dev...56agent # [ 3743.881371] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd is 1.684ms for 7 entries.57agent # [ 3743.881371] agent systemd-journald[57]: System Journal (/var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd) is 512B, max 4G, 3.9G free.58agent # [ 3743.896736] agent systemd[1]: Finished Create Static Device Nodes in /dev.59agent # [ 3743.897403] agent systemd[1]: Reached target Preparation for Local File Systems.60agent # [ 3743.897508] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys61agent # [ 3743.906961] agent systemd[1]: Finished Flush Journal to Persistent Storage.62agent # [ 3744.018789] agent systemd[1]: Finished Firewall.63relay # [ 3743.821016] relay systemd-journald[57]: Journal started64relay # [ 3743.821058] relay systemd-journald[57]: Runtime Journal (/run/log/journal/0c0eb96cc45e46c1a72a47abcc336c10) is 8M, max 4G, 3.9G free.65relay # [ 3743.865824] relay systemd[1]: Finished Apply Kernel Variables.66relay # [ 3743.884482] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.67relay # [ 3743.900359] relay systemd[1]: Starting Flush Journal to Persistent Storage...68relay # [ 3743.901219] relay systemd[1]: Starting Create Static Device Nodes in /dev...69relay # [ 3743.909921] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10 is 2.386ms for 6 entries.70relay # [ 3743.909921] relay systemd-journald[57]: System Journal (/var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10) is 512B, max 4G, 3.9G free.71relay # [ 3743.942842] relay systemd[1]: Finished Create Static Device Nodes in /dev.72relay # [ 3743.943094] relay systemd[1]: Finished Flush Journal to Persistent Storage.73relay # [ 3743.944353] relay systemd[1]: Reached target Preparation for Local File Systems.74relay # [ 3743.944460] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys75relay # [ 3744.047415] relay systemd[1]: Finished Firewall.76relay # [ 3744.821679] relay systemd[1]: Mounting /run/wrappers...77relay # [ 3744.845321] relay systemd[1]: Mounted /run/wrappers.78relay # [ 3744.846107] relay systemd[1]: Reached target Local File Systems.79relay # [ 3744.846923] relay systemd[1]: Listening on Boot Loader Control Service Socket.80relay # [ 3744.847853] relay systemd[1]: Starting Create SUID/SGID Wrappers...81relay # [ 3744.847881] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container82relay # [ 3744.848793] relay systemd[1]: Starting Save Transient machine-id to Disk...83relay # [ 3744.849714] relay systemd[1]: Starting Create System Files and Directories...84relay # [ 3744.869040] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85relay # [ 3744.869468] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted86relay # [ 3744.869795] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10 failed: Operation not permitted87relay # [ 3744.869862] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.xVJFhvaATa/chsh': Operation not permitted88relay # [ 3744.870148] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted89client # [ 3744.825805] client systemd[1]: Mounting /run/wrappers...90client # [ 3744.861941] client systemd[1]: Mounted /run/wrappers.91client # [ 3744.863035] client systemd[1]: Reached target Local File Systems.92agent # [ 3744.822724] agent systemd[1]: Mounting /run/wrappers...93client # [ 3744.864292] client systemd[1]: Listening on Boot Loader Control Service Socket.94agent # [ 3744.857096] agent systemd[1]: Mounted /run/wrappers.95client # [ 3744.865491] client systemd[1]: Starting Create SUID/SGID Wrappers...96agent # [ 3744.858104] agent systemd[1]: Reached target Local File Systems.97client # [ 3744.865539] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container98agent # [ 3744.859245] agent systemd[1]: Listening on Boot Loader Control Service Socket.99client # [ 3744.866756] client systemd[1]: Starting Save Transient machine-id to Disk...100agent # [ 3744.860310] agent systemd[1]: Starting Create SUID/SGID Wrappers...101client # [ 3744.867711] client systemd[1]: Starting Create System Files and Directories...102agent # [ 3744.860358] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container103client # [ 3744.889571] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.AjO7qj4Bwy/chsh': Operation not permitted104agent # [ 3744.861191] agent systemd[1]: Starting Save Transient machine-id to Disk...105client # [ 3744.896805] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted106agent # [ 3744.861844] agent systemd[1]: Starting Create System Files and Directories...107client # [ 3744.897251] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108agent # [ 3744.881491] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.SSEwFYwbZj/chsh': Operation not permitted109client # [ 3744.897560] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/c4ba3fec4895401e9c3f374f828bae1e failed: Operation not permitted110agent # [ 3744.894989] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE111agent # [ 3744.895091] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.112client # [ 3744.897912] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted113agent # [ 3744.895225] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.114agent # [ 3744.897095] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted115agent # [ 3744.897534] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted116agent # [ 3744.897848] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd failed: Operation not permitted117agent # [ 3744.898205] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted118relay # [ 3744.870494] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE119relay # [ 3744.870746] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.120relay # [ 3744.870934] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.121relay # [ 3744.885278] relay systemd[1]: Finished Create System Files and Directories.122relay # [ 3744.902215] relay systemd[1]: Starting Rebuild Journal Catalog...123relay # [ 3744.902958] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...124relay # [ 3744.915437] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.125relay # [ 3744.920950] relay systemd[1]: Finished Rebuild Journal Catalog.126relay # [ 3744.922551] relay systemd[1]: Starting Update is Completed...127relay # [ 3744.936288] relay systemd[1]: Finished Update is Completed.128relay # [ 3744.936442] relay systemd[1]: Reached target System Initialization.129relay # [ 3744.936516] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container130relay # [ 3744.936541] relay systemd[1]: Started Daily Cleanup of Temporary Directories.131relay # [ 3744.936557] relay systemd[1]: Reached target Timer Units.132relay # [ 3744.936650] relay systemd[1]: Listening on D-Bus System Message Bus Socket.133relay # [ 3744.936837] relay systemd[1]: Listening on Nix Daemon Socket.134relay # [ 3744.936934] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.135relay # [ 3744.936950] relay systemd[1]: Reached target Socket Units.136relay # [ 3744.936976] relay systemd[1]: Reached target Basic System.137relay # [ 3744.938381] relay systemd[1]: Started device-mock.service.138relay # [ 3744.939205] relay systemd[1]: Starting Re-link flakelet services at boot...139relay # [ 3744.940068] relay systemd[1]: Starting Import lastlog data into lastlog2 database...140relay # [ 3744.941482] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...141relay # [ 3744.942808] relay systemd[1]: Starting resolvconf update...142relay # [ 3744.950158] relay systemd[1]: Finished Re-link flakelet services at boot.143relay # [ 3744.951752] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...144relay # [ 3744.959054] relay systemd[1]: Finished Import lastlog data into lastlog2 database.145relay # [ 3744.962238] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.146relay # [ 3745.034503] relay systemd[1]: Finished resolvconf update.147relay # [ 3745.034666] relay systemd[1]: Reached target Preparation for Network.148relay # [ 3745.035890] relay systemd[1]: Starting Address configuration of eth1...149relay # [ 3745.037192] relay systemd[1]: Starting Extra networking commands....150relay # [ 3745.053563] relay network-addresses-eth1-start[245]: adding address 192.168.1.3/24... done151relay # [ 3745.056555] relay network-addresses-eth1-start[245]: adding address 2001:db8:1::3/64... done152agent # [ 3744.899900] agent systemd[1]: Finished Create System Files and Directories.153agent # [ 3744.913957] agent systemd[1]: Starting Rebuild Journal Catalog...154agent # [ 3744.914581] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...155agent # [ 3744.926167] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.156agent # [ 3744.937142] agent systemd[1]: Finished Rebuild Journal Catalog.157agent # [ 3744.939428] agent systemd[1]: Starting Update is Completed...158agent # [ 3744.950424] agent systemd[1]: Finished Update is Completed.159agent # [ 3744.950529] agent systemd[1]: Reached target System Initialization.160agent # [ 3744.950609] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container161agent # [ 3744.950636] agent systemd[1]: Started Daily Cleanup of Temporary Directories.162agent # [ 3744.950650] agent systemd[1]: Reached target Timer Units.163agent # [ 3744.950751] agent systemd[1]: Listening on D-Bus System Message Bus Socket.164agent # [ 3744.950936] agent systemd[1]: Listening on Nix Daemon Socket.165agent # [ 3744.951041] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.166agent # [ 3744.951056] agent systemd[1]: Reached target Socket Units.167agent # [ 3744.951084] agent systemd[1]: Reached target Basic System.168agent # [ 3744.952178] agent systemd[1]: Starting Re-link flakelet services at boot...169agent # [ 3744.952794] agent systemd[1]: Starting Import lastlog data into lastlog2 database...170agent # [ 3744.953568] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...171agent # [ 3744.954177] agent systemd[1]: Starting resolvconf update...172agent # [ 3744.963787] agent systemd[1]: Finished Re-link flakelet services at boot.173agent # [ 3744.965296] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...174agent # [ 3744.971635] agent systemd[1]: Finished Import lastlog data into lastlog2 database.175agent # [ 3744.986575] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.176agent # [ 3745.120011] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.177client # [ 3744.906023] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE178client # [ 3744.906061] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.179client # [ 3744.906111] client systemd[1]: Failed to start Create SUID/SGID Wrappers.180client # [ 3744.906754] client systemd[1]: Finished Create System Files and Directories.181client # [ 3744.922403] client systemd[1]: Starting Rebuild Journal Catalog...182client # [ 3744.923042] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...183client # [ 3744.939995] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.184client # [ 3744.947068] client systemd[1]: Finished Rebuild Journal Catalog.185client # [ 3744.948250] client systemd[1]: Starting Update is Completed...186client # [ 3744.958704] client systemd[1]: Finished Update is Completed.187client # [ 3744.958793] client systemd[1]: Reached target System Initialization.188client # [ 3744.958858] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container189client # [ 3744.958887] client systemd[1]: Started Daily Cleanup of Temporary Directories.190client # [ 3744.958903] client systemd[1]: Reached target Timer Units.191client # [ 3744.959010] client systemd[1]: Listening on D-Bus System Message Bus Socket.192client # [ 3744.959207] client systemd[1]: Listening on Nix Daemon Socket.193client # [ 3744.959307] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.194client # [ 3744.959320] client systemd[1]: Reached target Socket Units.195client # [ 3744.959349] client systemd[1]: Reached target Basic System.196client # [ 3744.960351] client systemd[1]: Starting Import lastlog data into lastlog2 database...197client # [ 3744.961520] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...198client # [ 3744.962130] client systemd[1]: Starting resolvconf update...199client # [ 3744.971619] client systemd[1]: lastlog2-import.service: Failed to spawn executor: No such file or directory200client # [ 3744.971729] client systemd[1]: lastlog2-import.service: Failed to spawn 'start-post' task: No such file or directory201client # [ 3744.971770] client systemd[1]: lastlog2-import.service: Failed with result 'resources'.202client # [ 3744.971812] client systemd[1]: Failed to start Import lastlog data into lastlog2 database.203client # [ 3745.134612] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.204agent # [ 3745.120941] agent systemd[1]: Finished Save Transient machine-id to Disk.205agent # [ 3745.153109] agent systemd[1]: nscd.service: Deactivated successfully.206agent # [ 3745.153230] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).207agent # [ 3745.175745] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...208agent # [ 3745.176338] agent systemd[1]: Finished resolvconf update.209agent # [ 3745.177100] agent systemd[1]: Reached target Preparation for Network.210agent # [ 3745.178259] agent systemd[1]: Starting Address configuration of eth1...211agent # [ 3745.179296] agent systemd[1]: Starting Extra networking commands....212agent # [ 3745.199071] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done213agent # [ 3745.201893] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done214agent # [ 3745.205716] agent systemd[1]: Finished Address configuration of eth1.215agent # [ 3745.250496] agent systemd[1]: Finished Extra networking commands..216agent # [ 3745.251984] agent systemd[1]: Reached target Network.217agent # [ 3745.254500] agent systemd[1]: Starting flakelet-agent...218agent # [ 3745.256190] agent systemd[1]: Starting Update flakelet service app...219agent # [ 3745.258641] agent systemd[1]: Starting Update flakelet service other...220agent # [ 3745.269284] agent flakelet[305]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1221agent # [ 3745.270871] agent flakelet[305]: app: activating generation 1222agent # [ 3745.275056] agent flakelet[306]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1223agent # [ 3745.275584] agent flakelet[306]: other: activating generation 1224agent # [ 3745.276197] agent systemd[1]: Reload requested from client PID 308 ('systemctl') (unit flakelet-app.service)...225agent # [ 3745.276267] agent systemd[1]: Reloading...226agent # [ 3745.338613] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:03.300333Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}227relay # [ 3745.135628] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.228relay # [ 3745.137304] relay systemd[1]: Finished Save Transient machine-id to Disk.229relay # [ 3745.137659] relay systemd[1]: nscd.service: Deactivated successfully.230relay # [ 3745.137854] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).231relay # [ 3745.141133] relay systemd[1]: Finished Address configuration of eth1.232relay # [ 3745.141507] relay systemd[1]: Finished Extra networking commands..233relay # [ 3745.153430] relay systemd[1]: Reached target Network.234relay # [ 3745.175713] relay systemd[1]: Starting Dnsmasq Daemon...235relay # [ 3745.177232] relay systemd[1]: Starting Nginx Web Server...236relay # [ 3745.177977] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...237relay # [ 3745.179209] relay systemd[1]: Starting Update flakelet service flakelet-relay...238relay # [ 3745.191263] relay flakelet[310]: flakelet-relay: using prebuilt artifact /nix/store/f1v78vfk8kx4d0k813cb79kbav5dag0q-flakelet-flakelet-relay239relay # [ 3745.191879] relay flakelet[310]: flakelet-relay: activating generation 1240relay # [ 3745.196941] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...241relay # [ 3745.197035] relay systemd[1]: Reloading...242client # [ 3745.136034] client systemd[1]: Finished Save Transient machine-id to Disk.243client # [ 3745.162382] client systemd[1]: nscd.service: Deactivated successfully.244client # [ 3745.175476] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).245client # [ 3745.177757] client systemd[1]: Finished resolvconf update.246client # [ 3745.178656] client systemd[1]: Reached target Preparation for Network.247client # [ 3745.179733] client systemd[1]: Starting Address configuration of eth1...248client # [ 3745.180484] client systemd[1]: Starting Extra networking commands....249client # [ 3745.181364] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...250client # [ 3745.200319] client network-addresses-eth1-start[235]: adding address 192.168.1.2/24... done251client # [ 3745.203340] client network-addresses-eth1-start[235]: adding address 2001:db8:1::2/64... done252client # [ 3745.207928] client systemd[1]: Finished Address configuration of eth1.253client # [ 3745.254470] client systemd[1]: Finished Extra networking commands..254client # [ 3745.255407] client systemd[1]: Reached target Network.255client # [ 3745.294497] client systemd[1]: nscd.service: Deactivated successfully.256client # [ 3745.294658] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).257client # [ 3745.297280] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...258relay # [ 3745.675734] relay nsncd[309]: Sep 06 08:07:03.637 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"259relay # [ 3745.760336] relay systemd[1]: Reloading finished in 562 ms.260relay # [ 3745.908063] relay systemd[1]: Started Name Service Cache Daemon (nsncd).261relay # [ 3745.909075] relay systemd[1]: Reached target Host and Network Name Lookups.262relay # [ 3745.909123] relay systemd[1]: Reached target User and Group Name Lookups.263relay # [ 3745.910133] relay systemd[1]: Starting User Login Management...264relay # [ 3745.910998] relay systemd[1]: Starting Permit User Sessions...265relay # [ 3745.918110] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...266relay # [ 3745.918145] relay systemd[1]: Reloading...267client # [ 3745.800184] client nsncd[302]: Sep 06 08:07:03.761 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"268client # [ 3745.800330] client systemd[1]: Started Name Service Cache Daemon (nsncd).269client # [ 3745.800415] client systemd[1]: Reached target Host and Network Name Lookups.270client # [ 3745.800504] client systemd[1]: Reached target User and Group Name Lookups.271client # [ 3745.802761] client systemd[1]: Starting User Login Management...272client # [ 3745.804184] client systemd[1]: Starting Permit User Sessions...273client # [ 3745.836406] client systemd[1]: Finished Permit User Sessions.274client # [ 3745.838192] client systemd[1]: Started Console Getty.275client # [ 3745.838243] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0276client # [ 3745.838274] client systemd[1]: Reached target Login Prompts.277agent # [ 3745.766963] agent systemd[1]: Reloading finished in 489 ms.278agent # [ 3745.907482] agent systemd[1]: Started flakelet-agent.279agent # [ 3745.907740] agent systemd[1]: nscd.service: Deactivated successfully.280agent # [ 3745.907851] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).281agent # [ 3745.913965] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...282agent # [ 3745.914144] agent systemd[1]: Reload requested from client PID 309 ('systemctl') (unit flakelet-other.service)...283agent # [ 3745.914185] agent systemd[1]: Reloading...284relay # [ 3746.298049] relay dnsmasq-pre-start[393]: dnsmasq: syntax check OK.285relay # [ 3746.372128] relay systemd[1]: Reloading finished in 453 ms.286relay # [ 3746.486243] relay systemd[1]: Finished Permit User Sessions.287relay # [ 3746.492506] relay systemd[1]: Started Console Getty.288relay # [ 3746.492571] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0289relay # [ 3746.492637] relay systemd[1]: Reached target Login Prompts.290relay # [ 3746.494292] relay systemd[1]: Starting flakelet-relay...291agent # [ 3746.308274] agent nsncd[724]: Sep 06 08:07:04.270 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"292agent # [ 3746.353145] agent systemd[1]: Reloading finished in 438 ms.293agent # [ 3746.485941] agent systemd[1]: Started Name Service Cache Daemon (nsncd).294agent # [ 3746.489837] agent systemd[1]: Reached target Host and Network Name Lookups.295agent # [ 3746.489889] agent systemd[1]: Reached target User and Group Name Lookups.296agent # [ 3746.490971] agent systemd[1]: Starting User Login Management...297agent # [ 3746.492768] agent systemd[1]: Starting Permit User Sessions...298agent # [ 3746.495705] agent systemd[1]: Reload requested from client PID 762 ('systemctl') (unit flakelet-app.service)...299agent # [ 3746.495741] agent systemd[1]: Reloading...300agent # [ 3746.890776] agent systemd[1]: Reloading finished in 394 ms.301agent # [ 3746.962648] agent systemd[1]: Finished Permit User Sessions.302agent # [ 3746.968056] agent systemd[1]: Started Console Getty.303agent # [ 3746.968147] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0304agent # [ 3746.968252] agent systemd[1]: Reached target Login Prompts.305agent # [ 3746.969908] agent systemd[1]: Reload requested from client PID 767 ('systemctl') (unit flakelet-other.service)...306agent # [ 3746.969935] agent systemd[1]: Reloading...307relay # [ 3747.258229] relay systemd[1]: Starting D-Bus System Message Bus...308agent # [ 3747.316682] agent systemd[1]: Reloading finished in 346 ms.309agent # [ 3747.395350] agent systemd[1]: Starting app v1...310agent # [ 3747.402761] agent systemd[1]: Started app v1.311agent # [ 3747.404800] agent systemd[1]: Starting other v1...312agent # [ 3747.412912] agent systemd[1]: Started other v1.313agent # [ 3747.415914] agent flakelet[305]: app: updated to generation 1314agent # [ 3747.418932] agent systemd[1]: Finished Update flakelet service app.315agent # [ 3747.426202] agent flakelet[306]: other: updated to generation 1316agent # [ 3747.427813] agent systemd[1]: Finished Update flakelet service other.317agent # [ 3747.427946] agent systemd[1]: Reached target flakelet managed services.318relay # [ 3748.151887] relay nginx-pre-start[403]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok319relay # [ 3748.152670] relay nginx-pre-start[403]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful320relay # [ 3748.165812] relay systemd[1]: Started Nginx Web Server.321relay # [ 3748.247097] relay dbus-broker-launch[402]: Looking up NSS user entry for 'systemd-timesync'...322relay # [ 3748.248025] relay dbus-broker-launch[402]: NSS returned no entry for 'systemd-timesync'323relay # [ 3748.248063] relay dbus-broker-launch[402]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"324relay # [ 3748.249071] relay systemd[1]: Started D-Bus System Message Bus.325relay # [ 3748.254198] relay dbus-broker-launch[402]: Ready326relay # [ 3748.256558] relay systemd[1]: Started Dnsmasq Daemon.327relay # [ 3748.258221] relay dnsmasq[394]: started, version 2.93 cachesize 150328relay # [ 3748.258228] relay dnsmasq[394]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth DNSSEC loop-detect inotify dumpfile329relay # [ 3748.258235] relay dnsmasq[394]: DBus support enabled: connected to system bus330relay # [ 3748.258241] relay dnsmasq[394]: no upstream servers configured - please set them from DBus331relay # [ 3748.258327] relay dnsmasq[394]: read /etc/hosts - 9 names332relay # [ 3748.264891] relay systemd-logind[355]: New seat seat0.333relay # [ 3748.265090] relay systemd[1]: Started User Login Management.334relay # [ 3748.279658] relay systemd[1]: Starting linger-users.service...335relay # [ 3748.330039] relay systemd[1]: linger-users.service: Deactivated successfully.336relay # [ 3748.330131] relay systemd[1]: Finished linger-users.service.337client # [ 3748.248155] client systemd-logind[314]: New seat seat0.338client # [ 3748.249300] client systemd[1]: Starting D-Bus System Message Bus...339client # [ 3748.249379] client systemd[1]: Started User Login Management.340client # [ 3748.251827] client systemd[1]: Starting linger-users.service...341client # [ 3748.287820] client systemd[1]: linger-users.service: Deactivated successfully.342client # [ 3748.288030] client systemd[1]: Finished linger-users.service.343client # [ 3748.288246] client systemd[1]: Reached target Multi-User System.344agent # [ 3748.796198] agent systemd-logind[764]: New seat seat0.345agent # [ 3748.799411] agent systemd[1]: Starting D-Bus System Message Bus...346agent # [ 3748.799482] agent systemd[1]: Started User Login Management.347agent # [ 3748.800281] agent systemd[1]: Starting linger-users.service...348agent # [ 3748.813871] agent systemd[1]: linger-users.service: Deactivated successfully.349agent # [ 3748.814041] agent systemd[1]: Finished linger-users.service.350agent # [ 3748.814184] agent systemd[1]: Reached target Multi-User System.351client # [ 3748.989479] client dbus-broker-launch[324]: Looking up NSS user entry for 'systemd-timesync'...352client # [ 3748.990427] client dbus-broker-launch[324]: NSS returned no entry for 'systemd-timesync'353client # [ 3748.990427] client dbus-broker-launch[324]: Invalid user-name in /nix/store/hw5jayq2v1cfs4spsqadln3i0wyayl63-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"354client # [ 3748.991230] client systemd[1]: Started D-Bus System Message Bus.355client # [ 3748.991517] client systemd[1]: Startup finished in 5.621s.356client # [ 3748.996166] client dbus-broker-launch[324]: Ready357agent # [ 3749.427217] agent dbus-broker-launch[839]: Looking up NSS user entry for 'systemd-timesync'...358agent # [ 3749.428187] agent dbus-broker-launch[839]: NSS returned no entry for 'systemd-timesync'359agent # [ 3749.428231] agent dbus-broker-launch[839]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"360agent # [ 3749.428839] agent systemd[1]: Started D-Bus System Message Bus.361agent # [ 3749.430081] agent systemd[1]: Startup finished in 6.052s.362agent # [ 3749.433961] agent dbus-broker-launch[839]: Ready363relay # [ 3749.590401] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:07.552103Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}364relay # [ 3749.591122] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:07.552924Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}365relay # [ 3749.591214] relay systemd[1]: Started flakelet-relay.366relay # [ 3749.597571] relay systemd[1]: Starting health for flakelet-relay...367relay # [ 3749.972963] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.368relay # [ 3749.973189] relay systemd[1]: Finished health for flakelet-relay.369relay # [ 3749.997611] relay flakelet[310]: flakelet-relay: updated to generation 1370relay # [ 3749.999491] relay systemd[1]: Finished Update flakelet service flakelet-relay.371relay # [ 3749.999756] relay systemd[1]: Reached target flakelet managed services.372relay # [ 3749.999837] relay systemd[1]: Reached target Multi-User System.373relay # [ 3749.999976] relay systemd[1]: Startup finished in 6.639s.374relay: (finished: waiting for unit flakelet-relay.service, in 7.66 seconds)375relay: waiting for unit nginx.service376relay: (finished: waiting for unit nginx.service, in 0.02 seconds)377agent: waiting for unit flakelet.target378agent: (finished: waiting for unit flakelet.target, in 0.01 seconds)379agent: waiting for unit flakelet-agent.service380agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)381client: waiting for unit multi-user.target382client: (finished: waiting for unit multi-user.target, in 0.01 seconds)383relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'384relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 0.01 seconds)385agent: must succeed: systemctl is-active app.service other.service386agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)387subtest: deploy with client certificate, relay found via SRV388agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json389agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)390client: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1391relay # [ 3750.431880] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:08.393613Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}392relay # [ 3750.561451] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:08.523245Z","level":"INFO","message":"deploy accepted","job":"7c688899f50c54534670dd507aceef9c","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}393agent # [ 3750.431495] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.393269Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}394agent # [ 3750.561987] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.523762Z","level":"INFO","message":"start","id":"58bc565a1d56a34acfac5475878adc6a","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}395agent # [ 3750.563011] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.524826Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"58bc565a1d56a34acfac5475878adc6a\"]","target":"flakelet_relay::agent::jobs"}396agent # [ 3750.622374] agent systemd[1]: Starting flakelet update app (via relay)...397agent # [ 3750.630247] agent systemd[1]: Started flakelet update app (via relay).398agent # [ 3750.634260] agent flakelet[868]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2399agent # [ 3750.634911] agent flakelet[868]: app: activating generation 2400agent # [ 3750.647976] agent systemd[1]: Stopping app v1...401agent # [ 3750.648456] agent systemd[1]: app.service: Deactivated successfully.402agent # [ 3750.648716] agent systemd[1]: Stopped app v1.403agent # [ 3750.671541] agent systemd[1]: Reload requested from client PID 875 ('systemctl') (unit flakelet-relay-job-app.service)...404agent # [ 3750.671607] agent systemd[1]: Reloading...405agent # [ 3751.031016] agent systemd[1]: Reloading finished in 358 ms.406agent # [ 3751.111158] agent systemd[1]: Reload requested from client PID 905 ('systemctl') (unit flakelet-relay-job-app.service)...407agent # [ 3751.111196] agent systemd[1]: Reloading...408agent # [ 3751.459109] agent systemd[1]: Reloading finished in 347 ms.409agent # [ 3751.547817] agent systemd[1]: Reload requested from client PID 934 ('systemctl') (unit flakelet-relay-job-app.service)...410agent # [ 3751.547859] agent systemd[1]: Reloading...411agent # [ 3751.930763] agent systemd[1]: Reloading finished in 382 ms.412agent # [ 3752.035829] agent systemd[1]: Reload requested from client PID 965 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [ 3752.035871] agent systemd[1]: Reloading...414agent # [ 3752.403539] agent systemd[1]: Reloading finished in 367 ms.415agent # [ 3752.465371] agent systemd[1]: Starting app v2...416agent # [ 3752.504597] agent systemd[1]: Started app v2.417agent # [ 3752.518062] agent flakelet[868]: app: updated to generation 2418agent # [ 3752.520321] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.419client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 3.06 seconds)420agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'421agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.01 seconds)422agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'423agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)424(finished: subtest: deploy with client certificate, relay found via SRV, in 3.10 seconds)425subtest: deploy with OIDC token, sub principal426agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json427agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)428client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)429client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)430client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/app 2>&1431agent # [ 3753.597303] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.559100Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}432agent # [ 3753.725607] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.687397Z","level":"INFO","message":"start","id":"d9cda3c4f0e6c78c5c401c1407920d75","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}433agent # [ 3753.726443] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.688263Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"d9cda3c4f0e6c78c5c401c1407920d75\"]","target":"flakelet_relay::agent::jobs"}434agent # [ 3753.785777] agent systemd[1]: Starting flakelet update app (via relay)...435agent # [ 3753.814075] agent systemd[1]: Started flakelet update app (via relay).436agent # [ 3753.817521] agent flakelet[1023]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1437agent # [ 3753.818140] agent flakelet[1023]: app: activating generation 3438agent # [ 3753.832187] agent systemd[1]: Stopping app v2...439agent # [ 3753.832645] agent systemd[1]: app.service: Deactivated successfully.440agent # [ 3753.832922] agent systemd[1]: Stopped app v2.441agent # [ 3753.852667] agent systemd[1]: Reload requested from client PID 1030 ('systemctl') (unit flakelet-relay-job-app.service)...442agent # [ 3753.852732] agent systemd[1]: Reloading...443relay # [ 3753.597940] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:11.559735Z","level":"INFO","message":"deploy finished","job":"7c688899f50c54534670dd507aceef9c","ok":true,"target":"flakelet_relay::relay::api"}444relay # [ 3753.725212] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:11.687022Z","level":"INFO","message":"deploy accepted","job":"4406421f3677d1bf43da05a5e71aa9ae","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}445agent # [ 3754.213895] agent systemd[1]: Reloading finished in 360 ms.446agent # [ 3754.306525] agent systemd[1]: Reload requested from client PID 1060 ('systemctl') (unit flakelet-relay-job-app.service)...447agent # [ 3754.306566] agent systemd[1]: Reloading...448agent # [ 3754.673009] agent systemd[1]: Reloading finished in 366 ms.449agent # [ 3754.759313] agent systemd[1]: Reload requested from client PID 1089 ('systemctl') (unit flakelet-relay-job-app.service)...450agent # [ 3754.759355] agent systemd[1]: Reloading...451agent # [ 3755.199125] agent systemd[1]: Reloading finished in 439 ms.452agent # [ 3755.284504] agent systemd[1]: Reload requested from client PID 1120 ('systemctl') (unit flakelet-relay-job-app.service)...453agent # [ 3755.284540] agent systemd[1]: Reloading...454agent # [ 3755.647334] agent systemd[1]: Reloading finished in 362 ms.455agent # [ 3755.745163] agent systemd[1]: Starting app v1...456agent # [ 3755.752206] agent systemd[1]: Started app v1.457agent # [ 3755.765721] agent flakelet[1023]: app: updated to generation 3458agent # [ 3755.767555] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.459client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/app 2>&1, in 3.15 seconds)460(finished: subtest: deploy with OIDC token, sub principal, in 3.22 seconds)461subtest: policy denies uncovered target462client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/other 2>&1463client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)464(finished: subtest: policy denies uncovered target, in 0.02 seconds)465subtest: claim principal from groups, unchanged counts as success466client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)467client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)468client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzNCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAzNCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVDM0TEtGMlFOSlRISz09PSIsIm5iZiI6MTc4ODY4MjAzNCwic3ViIjoic29tZW9uZSJ9.jlusJ4UCZzWGuXNbNFccZeVsr56DAZMRu9s754iXN67hDsRNwiVZB9_hYs58oILw0HkjYVWe3oPGEnB6e_4nBg' push --relay https://relay:7443 deploy agent/other 2>&1469agent # [ 3756.840044] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.801777Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}470agent # [ 3756.940716] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.902429Z","level":"INFO","message":"start","id":"f2b2879a34126884d5b4227259cd78bb","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}471agent # [ 3756.941346] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.903162Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f2b2879a34126884d5b4227259cd78bb\"]","target":"flakelet_relay::agent::jobs"}472agent # [ 3756.995474] agent systemd[1]: Starting flakelet update other (via relay)...473agent # [ 3757.028429] agent systemd[1]: Started flakelet update other (via relay).474agent # [ 3757.032192] agent flakelet[1169]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1475agent # [ 3757.032688] agent flakelet[1169]: other: up to date476agent # [ 3757.034941] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.477relay # [ 3756.841247] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:14.802992Z","level":"INFO","message":"deploy finished","job":"4406421f3677d1bf43da05a5e71aa9ae","ok":true,"target":"flakelet_relay::relay::api"}478relay # [ 3756.940179] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:14.901979Z","level":"INFO","message":"deploy accepted","job":"5e9352d3fc0a3133dcc1a2f1e52ba2bb","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}479client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzNCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAzNCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVDM0TEtGMlFOSlRISz09PSIsIm5iZiI6MTc4ODY4MjAzNCwic3ViIjoic29tZW9uZSJ9.jlusJ4UCZzWGuXNbNFccZeVsr56DAZMRu9s754iXN67hDsRNwiVZB9_hYs58oILw0HkjYVWe3oPGEnB6e_4nBg' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.67 seconds)480(finished: subtest: claim principal from groups, unchanged counts as success, in 0.72 seconds)481subtest: push login via device flow, cached token used afterwards482client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1483agent # [ 3757.585934] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:15.547695Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}484relay # [ 3757.586855] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:15.548617Z","level":"INFO","message":"deploy finished","job":"5e9352d3fc0a3133dcc1a2f1e52ba2bb","ok":true,"target":"flakelet_relay::relay::api"}485relay # [ 3757.607722] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:15] "POST /device HTTP/1.1" 200 -486relay # [ 3758.612980] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:16] "POST /token HTTP/1.1" 400 -487client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)488client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600489client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)490client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1491relay # [ 3759.662966] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:17] "POST /token HTTP/1.1" 200 -492relay # [ 3759.696440] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:17.658213Z","level":"INFO","message":"deploy accepted","job":"182f2c18e9f14519b24ac69b33adc951","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}493agent # [ 3759.696874] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:17.658629Z","level":"INFO","message":"start","id":"3993301ca6447c91a65ccaacb495413a","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}494agent # [ 3759.697636] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:17.659431Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3993301ca6447c91a65ccaacb495413a\"]","target":"flakelet_relay::agent::jobs"}495agent # [ 3759.741287] agent systemd[1]: Starting flakelet update other (via relay)...496agent # [ 3759.747747] agent systemd[1]: Started flakelet update other (via relay).497agent # [ 3759.752570] agent flakelet[1187]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1498agent # [ 3759.753061] agent flakelet[1187]: other: up to date499agent # [ 3759.754909] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.500client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 1.63 seconds)501client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1502agent # [ 3761.304892] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.266682Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}503agent # [ 3761.324705] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.286527Z","level":"INFO","message":"start","id":"f17c730293f26852e031868e720d3c9f","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}504agent # [ 3761.325735] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.287564Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f17c730293f26852e031868e720d3c9f\"]","target":"flakelet_relay::agent::jobs"}505agent # [ 3761.372872] agent systemd[1]: Starting flakelet update other (via relay)...506agent # [ 3761.382092] agent systemd[1]: Started flakelet update other (via relay).507agent # [ 3761.387788] agent flakelet[1206]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1508agent # [ 3761.388301] agent flakelet[1206]: other: up to date509agent # [ 3761.388915] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.510relay # [ 3761.305552] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.267323Z","level":"INFO","message":"deploy finished","job":"182f2c18e9f14519b24ac69b33adc951","ok":true,"target":"flakelet_relay::relay::api"}511relay # [ 3761.324403] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.286207Z","level":"INFO","message":"deploy accepted","job":"d22d70a5f872386985f2c47fe927d858","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}512client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.63 seconds)513(finished: subtest: push login via device flow, cached token used afterwards, in 4.34 seconds)514subtest: waves: failing first wave skips the second515agent: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json516agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)517client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1518relay # [ 3761.931729] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.893512Z","level":"INFO","message":"deploy finished","job":"d22d70a5f872386985f2c47fe927d858","ok":true,"target":"flakelet_relay::relay::api"}519agent # [ 3761.930784] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.892524Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}520relay # [ 3761.962438] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.924249Z","level":"INFO","message":"deploy accepted","job":"6c70740948a858850d4649517ab7ca16","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}521agent # [ 3761.962621] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.924418Z","level":"INFO","message":"start","id":"befecff353fb8d9f60ad1ccd94a20840","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}522agent # [ 3761.963045] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.924864Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"befecff353fb8d9f60ad1ccd94a20840\"]","target":"flakelet_relay::agent::jobs"}523agent # [ 3762.018994] agent systemd[1]: Starting flakelet update app (via relay)...524agent # [ 3762.046956] agent systemd[1]: Started flakelet update app (via relay).525agent # [ 3762.052572] agent flakelet[1227]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken526agent # [ 3762.053234] agent flakelet[1227]: app: activating generation 4527agent # [ 3762.061010] agent systemd[1]: Stopping app v1...528agent # [ 3762.061723] agent systemd[1]: app.service: Deactivated successfully.529agent # [ 3762.061925] agent systemd[1]: Stopped app v1.530agent # [ 3762.073495] agent systemd[1]: Reload requested from client PID 1234 ('systemctl') (unit flakelet-relay-job-app.service)...531agent # [ 3762.073530] agent systemd[1]: Reloading...532agent # [ 3762.412010] agent systemd[1]: Reloading finished in 338 ms.533agent # [ 3762.499330] agent systemd[1]: Reload requested from client PID 1264 ('systemctl') (unit flakelet-relay-job-app.service)...534agent # [ 3762.499372] agent systemd[1]: Reloading...535agent # [ 3762.857971] agent systemd[1]: Reloading finished in 358 ms.536agent # [ 3762.936464] agent systemd[1]: Reload requested from client PID 1293 ('systemctl') (unit flakelet-relay-job-app.service)...537agent # [ 3762.936506] agent systemd[1]: Reloading...538agent # [ 3763.325738] agent systemd[1]: Reloading finished in 388 ms.539agent # [ 3763.423901] agent systemd[1]: Reload requested from client PID 1324 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [ 3763.423938] agent systemd[1]: Reloading...541agent # [ 3763.778548] agent systemd[1]: Reloading finished in 354 ms.542agent # [ 3763.853840] agent systemd[1]: Starting app broken...543agent # [ 3763.860705] agent (nonexistent)[1354]: app.service: Unable to locate executable '/nonexistent': No such file or directory544agent # [ 3763.860727] agent (nonexistent)[1354]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory545agent # [ 3763.862180] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC546agent # [ 3763.862315] agent systemd[1]: app.service: Failed with result 'exit-code'.547agent # [ 3763.862662] agent systemd[1]: Failed to start app broken.548agent # [ 3763.897507] agent systemd[1]: Reload requested from client PID 1361 ('systemctl') (unit flakelet-relay-job-app.service)...549agent # [ 3763.897558] agent systemd[1]: Reloading...550agent # [ 3764.314619] agent systemd[1]: Reloading finished in 416 ms.551agent # [ 3764.426664] agent systemd[1]: Reload requested from client PID 1392 ('systemctl') (unit flakelet-relay-job-app.service)...552agent # [ 3764.426701] agent systemd[1]: Reloading...553agent # [ 3764.789486] agent systemd[1]: Reloading finished in 362 ms.554agent # [ 3764.870096] agent systemd[1]: Reload requested from client PID 1421 ('systemctl') (unit flakelet-relay-job-app.service)...555agent # [ 3764.870140] agent systemd[1]: Reloading...556agent # [ 3765.219428] agent systemd[1]: Reloading finished in 348 ms.557agent # [ 3765.315159] agent systemd[1]: Reload requested from client PID 1451 ('systemctl') (unit flakelet-relay-job-app.service)...558agent # [ 3765.315197] agent systemd[1]: Reloading...559agent # [ 3765.656905] agent systemd[1]: Reloading finished in 341 ms.560agent # [ 3765.746323] agent systemd[1]: Starting app v1...561agent # [ 3765.753379] agent systemd[1]: Started app v1.562agent # [ 3765.754412] agent flakelet[1227]: app: deploy failed, rolled back: systemctl start app.service failed:563agent # [ 3765.754412] agent flakelet[1227]: failed units: app.service. See journalctl -u app.service564agent # [ 3765.756519] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE565agent # [ 3765.756631] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.566client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 5.39 seconds)567agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'568agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.01 seconds)569(finished: subtest: waves: failing first wave skips the second, in 5.41 seconds)570subtest: host patterns expand on the relay571agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json572agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)573client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1574relay # [ 3767.331120] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.292919Z","level":"INFO","message":"deploy finished","job":"6c70740948a858850d4649517ab7ca16","ok":false,"target":"flakelet_relay::relay::api"}575agent # [ 3767.330315] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.292086Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}576relay # [ 3767.380995] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.342795Z","level":"INFO","message":"deploy accepted","job":"931b1963a1932ac92f57717607d7f2dc","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}577agent # [ 3767.381402] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.343190Z","level":"INFO","message":"start","id":"cbda194542977b6644e340cec3225c61","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}578agent # [ 3767.381896] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.343716Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cbda194542977b6644e340cec3225c61\"]","target":"flakelet_relay::agent::jobs"}579agent # [ 3767.441662] agent systemd[1]: Starting flakelet update app (via relay)...580agent # [ 3767.449460] agent systemd[1]: Started flakelet update app (via relay).581agent # [ 3767.453935] agent flakelet[1506]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1582agent # [ 3767.454452] agent flakelet[1506]: app: up to date583agent # [ 3767.456913] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.584client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.65 seconds)585client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1586relay # [ 3768.009253] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.971027Z","level":"INFO","message":"deploy finished","job":"931b1963a1932ac92f57717607d7f2dc","ok":true,"target":"flakelet_relay::relay::api"}587relay # [ 3768.034268] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.996063Z","level":"INFO","message":"deploy accepted","job":"51343228cba2fcdf38b2ee932146f68c","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}588agent # [ 3768.008375] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.970117Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}589agent # [ 3768.034557] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.996322Z","level":"INFO","message":"start","id":"e321a3293adff274198f74518a9ca5e8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}590agent # [ 3768.034914] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.996733Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e321a3293adff274198f74518a9ca5e8\"]","target":"flakelet_relay::agent::jobs"}591agent # [ 3768.111200] agent systemd[1]: Starting flakelet update app (via relay)...592agent # [ 3768.118747] agent systemd[1]: Started flakelet update app (via relay).593agent # [ 3768.123427] agent flakelet[1524]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1594agent # [ 3768.123972] agent flakelet[1524]: app: up to date595agent # [ 3768.126678] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.596client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.67 seconds)597client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1598relay # [ 3768.676913] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:26.638683Z","level":"INFO","message":"deploy finished","job":"51343228cba2fcdf38b2ee932146f68c","ok":false,"target":"flakelet_relay::relay::api"}599relay # [ 3768.698209] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:26.660028Z","level":"INFO","message":"deploy accepted","job":"dca13ad2193f05d9432a859f2f42f93f","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}600agent # [ 3768.676173] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.637846Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}601agent # [ 3768.698482] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.660288Z","level":"INFO","message":"start","id":"6e1e092362a0e6efc71bf980fc867dca","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}602agent # [ 3768.698834] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.660656Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6e1e092362a0e6efc71bf980fc867dca\"]","target":"flakelet_relay::agent::jobs"}603agent # [ 3768.750772] agent systemd[1]: Starting flakelet update app (via relay)...604agent # [ 3768.757592] agent systemd[1]: Started flakelet update app (via relay).605agent # [ 3768.761990] agent flakelet[1542]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1606agent # [ 3768.762492] agent flakelet[1542]: app: up to date607agent # [ 3768.762872] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.608client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.64 seconds)609client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1610client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)611(finished: subtest: host patterns expand on the relay, in 1.99 seconds)612subtest: detach returns once the job is accepted613agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json614agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)615client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1616client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)617agent: waiting for success: systemctl is-active flakelet-relay-job-app.service618agent # [ 3769.314079] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.275763Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}619agent # [ 3769.371692] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.333459Z","level":"INFO","message":"start","id":"9fd6f38666d05977f29e134860f0c787","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}620agent # [ 3769.371897] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.333726Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"9fd6f38666d05977f29e134860f0c787\"]","target":"flakelet_relay::agent::jobs"}621agent # [ 3769.427611] agent systemd[1]: Starting flakelet update app (via relay)...622agent # [ 3769.436650] agent systemd[1]: Started flakelet update app (via relay).623agent # [ 3769.440890] agent flakelet[1564]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2624agent # [ 3769.441562] agent flakelet[1564]: app: activating generation 4625agent # [ 3769.455401] agent systemd[1]: Stopping app v1...626agent # [ 3769.455871] agent systemd[1]: app.service: Deactivated successfully.627agent # [ 3769.456157] agent systemd[1]: Stopped app v1.628agent # [ 3769.473214] agent systemd[1]: Reload requested from client PID 1571 ('systemctl') (unit flakelet-relay-job-app.service)...629agent # [ 3769.473281] agent systemd[1]: Reloading...630relay # [ 3769.314805] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:27.276558Z","level":"INFO","message":"deploy finished","job":"dca13ad2193f05d9432a859f2f42f93f","ok":false,"target":"flakelet_relay::relay::api"}631relay # [ 3769.371423] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:27.333209Z","level":"INFO","message":"deploy accepted","job":"9c2aba91fb4cd62fb4fca17792527552","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}632agent # [ 3769.825546] agent systemd[1]: Reloading finished in 351 ms.633agent # [ 3769.921527] agent systemd[1]: Reload requested from client PID 1601 ('systemctl') (unit flakelet-relay-job-app.service)...634agent # [ 3769.921568] agent systemd[1]: Reloading...635agent # [ 3770.267452] agent systemd[1]: Reloading finished in 345 ms.636agent # [ 3770.352439] agent systemd[1]: Reload requested from client PID 1630 ('systemctl') (unit flakelet-relay-job-app.service)...637agent # [ 3770.352476] agent systemd[1]: Reloading...638agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.41 seconds)639??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.640 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39641agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service642??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.643 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39644agent # [ 3770.695549] agent systemd[1]: Reloading finished in 342 ms.645agent # [ 3770.788448] agent systemd[1]: Reload requested from client PID 1662 ('systemctl') (unit flakelet-relay-job-app.service)...646agent # [ 3770.788485] agent systemd[1]: Reloading...647agent # [ 3771.126298] agent systemd[1]: Reloading finished in 337 ms.648agent # [ 3771.208576] agent systemd[1]: Starting app slow2...649agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 6.49 seconds)650(finished: subtest: detach returns once the job is accepted, in 7.94 seconds)651subtest: unknown host is final, missing agent is retried, agents listing652client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1653client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)654agent: must succeed: systemctl stop flakelet-agent655agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.05 seconds)656relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'657relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.01 seconds)658client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &659client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)660client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out661agent # [ 3777.249072] agent systemd[1]: Started app slow2.662agent # [ 3777.272112] agent flakelet[1564]: app: updated to generation 4663agent # [ 3777.275109] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.664agent # [ 3777.309333] agent systemd[1]: Stopping flakelet-agent...665agent # [ 3777.340432] agent systemd[1]: flakelet-agent.service: Deactivated successfully.666agent # [ 3777.340829] agent systemd[1]: Stopped flakelet-agent.667agent # [ 3777.341386] agent systemd[1]: flakelet-agent.service: Consumed 1.544s CPU time over 32.086s wall clock time.668relay # [ 3777.310342] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:35.272106Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}669client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)670agent: must succeed: systemctl start flakelet-agent671agent: (finished: must succeed: systemctl start flakelet-agent, in 0.06 seconds)672??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.673 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39674client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out675relay # [ 3778.533632] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:36.495384Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}676agent # [ 3778.407609] agent systemd[1]: Starting flakelet-agent...677agent # [ 3778.440817] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.402623Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"9fd6f38666d05977f29e134860f0c787\"]","target":"flakelet_relay::agent::jobs"}678agent # [ 3778.440980] agent systemd[1]: Started flakelet-agent.679agent # [ 3778.533597] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.495319Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}680agent # [ 3779.000983] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.962763Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}681relay # [ 3780.384894] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:38.346672Z","level":"INFO","message":"deploy accepted","job":"efe873aaaa91f693354a5a999eae6d01","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}682agent # [ 3780.385339] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:38.347099Z","level":"INFO","message":"start","id":"4391afa6b9ee1ed547162380d3717185","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}683agent # [ 3780.387112] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:38.347772Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"4391afa6b9ee1ed547162380d3717185\"]","target":"flakelet_relay::agent::jobs"}684agent # [ 3780.453332] agent systemd[1]: Starting flakelet update other (via relay)...685agent # [ 3780.494174] agent systemd[1]: Started flakelet update other (via relay).686agent # [ 3780.498744] agent flakelet[2127]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1687agent # [ 3780.499319] agent flakelet[2127]: other: up to date688agent # [ 3780.501720] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.689relay # [ 3781.049800] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.011592Z","level":"INFO","message":"deploy finished","job":"efe873aaaa91f693354a5a999eae6d01","ok":true,"target":"flakelet_relay::relay::api"}690agent # [ 3781.049058] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.010819Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}691client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)692client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents693client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)694client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)695client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)696client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM1OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDU5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzWUxPUVZFVlMyNzdVPT09IiwibmJmIjoxNzg4NjgyMDU5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.nmaaHzYddW4DRKAi63aIkHDB2OW48MEWBXoufS74CMTkxfqP2nPeTy8GtcWrZBvNnmYGtwudB9EZC0HcUMDiCg' push --relay https://relay:7443 agents697client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM1OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDU5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzWUxPUVZFVlMyNzdVPT09IiwibmJmIjoxNzg4NjgyMDU5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.nmaaHzYddW4DRKAi63aIkHDB2OW48MEWBXoufS74CMTkxfqP2nPeTy8GtcWrZBvNnmYGtwudB9EZC0HcUMDiCg' push --relay https://relay:7443 agents, in 0.02 seconds)698(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.30 seconds)699subtest: certificate not listed under agents cannot connect as agent700client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent701client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.02 seconds)702(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)703subtest: metrics704relay: must succeed: curl -sf http://127.0.0.1:7400/metrics705relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.02 seconds)706(finished: subtest: metrics, in 0.02 seconds)707subtest: agent link drop mid-run replays missed lines once708agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json709agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)710agent: must succeed: date +%s711agent: (finished: must succeed: date +%s, in 0.01 seconds)712client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &713client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)714agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'app-slow'715relay # [ 3781.597885] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.559679Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}716relay # [ 3781.660577] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.622385Z","level":"INFO","message":"deploy accepted","job":"e85a1e72998985266f7693bf3126a7ce","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}717agent # [ 3781.660960] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.622729Z","level":"INFO","message":"start","id":"927eee0d36bffe1a2541d72efa0bd0cf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}718agent # [ 3781.661569] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.623393Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"927eee0d36bffe1a2541d72efa0bd0cf\"]","target":"flakelet_relay::agent::jobs"}719agent # [ 3781.696458] agent systemd[1]: Starting flakelet update app (via relay)...720agent # [ 3781.730132] agent systemd[1]: Started flakelet update app (via relay).721agent # [ 3781.734471] agent flakelet[2152]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow722agent # [ 3781.735128] agent flakelet[2152]: app: activating generation 5723agent # [ 3781.743021] agent systemd[1]: Stopping app slow2...724agent # [ 3781.743740] agent systemd[1]: app.service: Deactivated successfully.725agent # [ 3781.743877] agent systemd[1]: Stopped app slow2.726agent # [ 3781.752934] agent systemd[1]: Reload requested from client PID 2159 ('systemctl') (unit flakelet-relay-job-app.service)...727agent # [ 3781.752970] agent systemd[1]: Reloading...728agent # [ 3782.084038] agent systemd[1]: Reloading finished in 330 ms.729agent # [ 3782.175131] agent systemd[1]: Reload requested from client PID 2189 ('systemctl') (unit flakelet-relay-job-app.service)...730agent # [ 3782.175167] agent systemd[1]: Reloading...731agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'app-slow', in 1.02 seconds)732agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done733agent: (finished: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done, in 0.02 seconds)734relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done735relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)736agent: must succeed: ss -K dport = 7443737agent # [ 3782.511536] agent systemd[1]: Reloading finished in 335 ms.738agent # [ 3782.596846] agent systemd[1]: Reload requested from client PID 2218 ('systemctl') (unit flakelet-relay-job-app.service)...739agent # [ 3782.596891] agent systemd[1]: Reloading...740agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)741agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'updated to generation'742agent # [ 3782.769406] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:40.731061Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}743agent # [ 3782.939149] agent systemd[1]: Reloading finished in 341 ms.744relay # [ 3782.738057] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:40.699826Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}745agent # [ 3783.032204] agent systemd[1]: Reload requested from client PID 2263 ('systemctl') (unit flakelet-relay-job-app.service)...746agent # [ 3783.032241] agent systemd[1]: Reloading...747agent # [ 3783.367799] agent systemd[1]: Reloading finished in 335 ms.748agent # [ 3783.452131] agent systemd[1]: Starting app slow...749agent # [ 3783.859985] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:41.821786Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}750agent # [ 3785.950633] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:43.912432Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}751agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'updated to generation', in 7.10 seconds)752agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done753agent # [ 3789.520817] agent systemd[1]: Started app slow.754agent # [ 3789.544615] agent flakelet[2152]: app: updated to generation 5755agent # [ 3789.545437] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.756agent: (finished: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done, in 0.02 seconds)757client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out758relay # [ 3790.036990] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:47.998779Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}759agent # [ 3790.036950] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:47.998742Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}760agent # [ 3790.038049] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:47.999876Z","level":"INFO","message":"start","id":"927eee0d36bffe1a2541d72efa0bd0cf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}761client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 1.02 seconds)762client: must succeed: cat /tmp/slow.out763client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)764(finished: subtest: agent link drop mid-run replays missed lines once, in 9.30 seconds)765subtest: agent restart mid-run reattaches to the unit766agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json767agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)768client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &769client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)770agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'771relay # [ 3790.630954] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:48.592740Z","level":"INFO","message":"deploy finished","job":"e85a1e72998985266f7693bf3126a7ce","ok":true,"target":"flakelet_relay::relay::api"}772relay # [ 3790.955535] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:48.917258Z","level":"INFO","message":"deploy accepted","job":"012d36b9186571825180908984710eb8","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}773agent # [ 3790.629999] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.591780Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(5)","target":"flakelet_relay::agent::jobs"}774agent # [ 3790.955974] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.917635Z","level":"INFO","message":"start","id":"98c6067a4d342c1e9cb764dc3857f5ef","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}775agent # [ 3790.956301] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.918129Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"98c6067a4d342c1e9cb764dc3857f5ef\"]","target":"flakelet_relay::agent::jobs"}776agent # [ 3791.013103] agent systemd[1]: Starting flakelet update app (via relay)...777agent # [ 3791.040975] agent systemd[1]: Started flakelet update app (via relay).778agent # [ 3791.044203] agent flakelet[2384]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2779agent # [ 3791.044805] agent flakelet[2384]: app: activating generation 6780agent # [ 3791.059764] agent systemd[1]: Stopping app slow...781agent # [ 3791.061574] agent systemd[1]: app.service: Deactivated successfully.782agent # [ 3791.061906] agent systemd[1]: Stopped app slow.783agent # [ 3791.080379] agent systemd[1]: Reload requested from client PID 2391 ('systemctl') (unit flakelet-relay-job-app.service)...784agent # [ 3791.080450] agent systemd[1]: Reloading...785agent # [ 3791.443896] agent systemd[1]: Reloading finished in 362 ms.786agent # [ 3791.540933] agent systemd[1]: Reload requested from client PID 2421 ('systemctl') (unit flakelet-relay-job-app.service)...787agent # [ 3791.540974] agent systemd[1]: Reloading...788agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)789agent: must succeed: systemctl restart flakelet-agent790agent # [ 3791.888690] agent systemd[1]: Reloading finished in 347 ms.791agent # [ 3791.971222] agent systemd[1]: Reload requested from client PID 2453 ('systemctl') (unit flakelet-relay-job-app.service)...792agent # [ 3791.971264] agent systemd[1]: Reloading...793agent # [ 3792.302871] agent systemd[1]: Reloading finished in 331 ms.794agent # [ 3792.375922] agent systemd[1]: Stopping flakelet-agent...795agent # [ 3792.386475] agent systemd[1]: Reload requested from client PID 2485 ('systemctl') (unit flakelet-relay-job-app.service)...796agent # [ 3792.386513] agent systemd[1]: Reloading...797relay # [ 3792.376212] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:50.337952Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}798agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.90 seconds)799agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"800agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)801client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out802agent # [ 3792.727143] agent systemd[1]: Reloading finished in 340 ms.803agent # [ 3792.796730] agent systemd[1]: flakelet-agent.service: Deactivated successfully.804agent # [ 3792.796928] agent systemd[1]: Stopped flakelet-agent.805agent # [ 3792.796946] agent systemd[1]: flakelet-agent.service: Consumed 1.014s CPU time over 14.389s wall clock time.806agent # [ 3792.801252] agent systemd[1]: Starting flakelet-agent...807agent # [ 3792.803572] agent systemd[1]: Starting app slow2...808agent # [ 3792.862381] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.824189Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"98c6067a4d342c1e9cb764dc3857f5ef\"]","target":"flakelet_relay::agent::jobs"}809agent # [ 3792.862469] agent systemd[1]: Started flakelet-agent.810agent # [ 3792.930517] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.892306Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}811agent # [ 3792.931676] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.893498Z","level":"INFO","message":"start","id":"98c6067a4d342c1e9cb764dc3857f5ef","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}812relay # [ 3792.930551] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:50.892321Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}813agent # [ 3798.884052] agent systemd[1]: Started app slow2.814agent # [ 3798.902287] agent flakelet[2384]: app: updated to generation 6815agent # [ 3798.905451] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.816relay # [ 3799.463510] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:57.425256Z","level":"INFO","message":"deploy finished","job":"012d36b9186571825180908984710eb8","ok":true,"target":"flakelet_relay::relay::api"}817agent # [ 3799.462565] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.424317Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(6)","target":"flakelet_relay::agent::jobs"}818client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)819client: must succeed: cat /tmp/restart.out820client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)821agent: must succeed: systemctl is-active app.service822agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)823(finished: subtest: agent restart mid-run reattaches to the unit, in 9.05 seconds)824subtest: relay restart mid-run, push resumes via /v1/jobs825agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json826agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)827agent: must succeed: date +%s828agent: (finished: must succeed: date +%s, in 0.01 seconds)829client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &830client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)831agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682077 | grep -q 'app-slow'832relay # [ 3800.013550] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:57.975318Z","level":"INFO","message":"deploy accepted","job":"7ec8ea76b10475faaf72f0ea8b7fe5ae","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}833agent # [ 3800.013983] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.975746Z","level":"INFO","message":"start","id":"11c1679a0541c468bc55e7684cdfff1f","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}834agent # [ 3800.014841] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.976659Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"11c1679a0541c468bc55e7684cdfff1f\"]","target":"flakelet_relay::agent::jobs"}835agent # [ 3800.067729] agent systemd[1]: Starting flakelet update app (via relay)...836agent # [ 3800.098259] agent systemd[1]: Started flakelet update app (via relay).837agent # [ 3800.103166] agent flakelet[2951]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow838agent # [ 3800.104232] agent flakelet[2951]: app: activating generation 7839agent # [ 3800.117131] agent systemd[1]: Stopping app slow2...840agent # [ 3800.117599] agent systemd[1]: app.service: Deactivated successfully.841agent # [ 3800.117919] agent systemd[1]: Stopped app slow2.842agent # [ 3800.136855] agent systemd[1]: Reload requested from client PID 2958 ('systemctl') (unit flakelet-relay-job-app.service)...843agent # [ 3800.136933] agent systemd[1]: Reloading...844agent # [ 3800.487508] agent systemd[1]: Reloading finished in 349 ms.845agent # [ 3800.561093] agent systemd[1]: Reload requested from client PID 2988 ('systemctl') (unit flakelet-relay-job-app.service)...846agent # [ 3800.561132] agent systemd[1]: Reloading...847agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682077 | grep -q 'app-slow', in 1.02 seconds)848relay: must succeed: systemctl restart flakelet-relay849relay # [ 3801.042274] relay systemd[1]: Stopping flakelet-relay...850relay # [ 3801.077561] relay systemd[1]: flakelet-relay.service: Deactivated successfully.851relay # [ 3801.077847] relay systemd[1]: Stopped flakelet-relay.852relay # [ 3801.077873] relay systemd[1]: flakelet-relay.service: Consumed 2.657s CPU time over 54.583s wall clock time.853relay # [ 3801.096499] relay systemd[1]: Starting flakelet-relay...854agent # [ 3800.899852] agent systemd[1]: Reloading finished in 338 ms.855agent # [ 3800.986368] agent systemd[1]: Reload requested from client PID 3017 ('systemctl') (unit flakelet-relay-job-app.service)...856agent # [ 3800.986410] agent systemd[1]: Reloading...857agent # [ 3801.042724] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:59.004504Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}858agent # [ 3801.335720] agent systemd[1]: Reloading finished in 348 ms.859agent # [ 3801.430582] agent systemd[1]: Reload requested from client PID 3051 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [ 3801.430619] agent systemd[1]: Reloading...861agent # [ 3801.768962] agent systemd[1]: Reloading finished in 338 ms.862agent # [ 3801.858284] agent systemd[1]: Starting app slow...863agent # [ 3802.115670] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:00.077295Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}864relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.52 seconds)865client: waiting for success: grep -q '» ok' /tmp/resume.out866relay # [ 3802.546877] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:00.508665Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}867relay # [ 3802.547516] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:00.509183Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}868relay # [ 3802.547582] relay systemd[1]: Started flakelet-relay.869relay # [ 3804.194186] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:02.155934Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(6), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}870agent # [ 3804.194130] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:02.155819Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}871agent # [ 3807.925084] agent systemd[1]: Started app slow.872agent # [ 3807.942986] agent flakelet[2951]: app: updated to generation 7873agent # [ 3807.946459] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.874relay # [ 3808.061470] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:06.023250Z","level":"INFO","message":"job reattached","job":"7ec8ea76b10475faaf72f0ea8b7fe5ae","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}875agent # [ 3809.025645] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:06.987426Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}876client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)877client: must succeed: cat /tmp/resume.out878client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)879(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.66 seconds)880subtest: job history comes from the agents and survives a relay restart881client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1882relay # [ 3809.652906] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:07.614683Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}883agent # [ 3809.653356] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:07.615138Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}884agent # [ 3809.653865] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:07.615687Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}885agent # [ 3809.695682] agent systemd[1]: Starting flakelet update other (via relay)...886agent # [ 3809.727045] agent systemd[1]: Started flakelet update other (via relay).887agent # [ 3809.732276] agent flakelet[3128]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1888agent # [ 3809.732826] agent flakelet[3128]: other: up to date889agent # [ 3809.734516] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.890client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.64 seconds)891relay: must succeed: systemctl restart flakelet-relay892relay # [ 3810.277732] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:08.239479Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}893relay # [ 3810.290834] relay systemd[1]: Stopping flakelet-relay...894relay # [ 3810.321087] relay systemd[1]: flakelet-relay.service: Deactivated successfully.895relay # [ 3810.321354] relay systemd[1]: Stopped flakelet-relay.896relay # [ 3810.321382] relay systemd[1]: flakelet-relay.service: Consumed 2.322s CPU time over 9.224s wall clock time.897relay # [ 3810.338409] relay systemd[1]: Starting flakelet-relay...898agent # [ 3810.277141] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:08.238921Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}899agent # [ 3810.291174] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:08.252995Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}900agent # [ 3811.367986] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:09.329739Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}901relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.47 seconds)902relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'903relay # [ 3811.746630] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:09.708348Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}904relay # [ 3811.747634] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:09.708716Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}905relay # [ 3811.747109] relay systemd[1]: Started flakelet-relay.906relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)907client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs908relay # [ 3813.447331] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.409075Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}909client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)910client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)911client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)912client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM5MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDkxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI0TUY0Q0JSQVhJWkc0PT09IiwibmJmIjoxNzg4NjgyMDkxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.v02-ELbxgX1trFtP61qGGWw757G5NN9G456hpQw1fZomw9yxwmu5cGH5rtLXhkqVIZn76Nn7mwZxRyufoGgnAg' push --relay https://relay:7443 jobs913agent # [ 3813.447271] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:11.409015Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}914client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM5MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDkxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI0TUY0Q0JSQVhJWkc0PT09IiwibmJmIjoxNzg4NjgyMDkxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.v02-ELbxgX1trFtP61qGGWw757G5NN9G456hpQw1fZomw9yxwmu5cGH5rtLXhkqVIZn76Nn7mwZxRyufoGgnAg' push --relay https://relay:7443 jobs, in 0.02 seconds)915(finished: subtest: job history comes from the agents and survives a relay restart, in 4.25 seconds)916subtest: dashboard login via authorization code flow917client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login'918client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login', in 0.02 seconds)919client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login920client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.07 seconds)921client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs922client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)923client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1924client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1, in 0.02 seconds)925client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true926client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true, in 0.02 seconds)927client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403928client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403, in 0.02 seconds)929client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other'930client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other', in 0.02 seconds)931client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/4c8237dfd41d407bd078b97634ba27eb/events || true932relay # [ 3813.932329] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:11] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=Xa3zpcZvDxfAKZpBIZg7Zv8e48ayIlIdRYT8F6y9tng&code_challenge=F33_-EYEdqsIM0kTV_mSP6uky2IkvuBH8YoASLM7DVw&code_challenge_method=S256 HTTP/1.1" 302 -933relay # [ 3813.977319] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:11] "POST /token HTTP/1.1" 200 -934relay # [ 3813.978138] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.939946Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}935relay # [ 3814.035470] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.997264Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}936relay # [ 3814.074742] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.036527Z","level":"INFO","message":"deploy accepted","job":"c9e0f6181e1bb1cf4da2954b1c66fa7e","caller":"oidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}937relay # [ 3814.094035] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.055827Z","level":"INFO","message":"job reattached","job":"c9e0f6181e1bb1cf4da2954b1c66fa7e","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}938agent # [ 3814.075042] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.036823Z","level":"INFO","message":"start","id":"b5f453e8397a7ee21f389aa846be5180","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}939agent # [ 3814.075373] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.037207Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"b5f453e8397a7ee21f389aa846be5180\"]","target":"flakelet_relay::agent::jobs"}940agent # [ 3814.115210] agent systemd[1]: Starting flakelet update other (via relay)...941agent # [ 3814.157738] agent systemd[1]: Started flakelet update other (via relay).942agent # [ 3814.162219] agent flakelet[3166]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1943agent # [ 3814.162699] agent flakelet[3166]: other: up to date944agent # [ 3814.163655] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.945client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/4c8237dfd41d407bd078b97634ba27eb/events || true, in 0.64 seconds)946client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/4c8237dfd41d407bd078b97634ba27eb947client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/4c8237dfd41d407bd078b97634ba27eb, in 0.02 seconds)948client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js949client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js, in 0.02 seconds)950client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth'951client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth', in 0.02 seconds)952client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other953client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other, in 0.02 seconds)954client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected'955client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected', in 0.02 seconds)956client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=4c8237dfd41d407bd078b97634ba27eb' | grep -q 400957client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=4c8237dfd41d407bd078b97634ba27eb' | grep -q 400, in 0.02 seconds)958client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &959client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &, in 0.01 seconds)960client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other961» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)962» wave 0963agent/other | Starting flakelet update other (via relay)...964agent/other | Started flakelet update other (via relay).965agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1966agent/other | other: up to date967agent # [ 3814.711704] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.673425Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}968agent # [ 3814.865179] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.826824Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}969agent # [ 3814.865713] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.827531Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}970agent # [ 3814.905917] agent systemd[1]: Starting flakelet update other (via relay)...971agent/otheragent # [ 3814.939115] agent systemd[1]: Started flakelet update other (via relay).972 | agent # [ 3814.943916] agent flakelet[3184]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1973flakelet-relay-job-other.service: Deactivated successfully.974agent # [ 3814.944423] agent flakelet[3184]: other: up to date975agent # [ 3814.945896] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.976relay # [ 3814.864756] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.826499Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}977» agent/other: unchanged (generation 1)978» ok979client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 1.65 seconds)980client: waiting for success: grep -q live1 /tmp/ev.out981client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)982client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout983client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout, in 0.02 seconds)984client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303985client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303, in 0.02 seconds)986(finished: subtest: dashboard login via authorization code flow, in 2.66 seconds)987(finished: run the VM test script, in 73.77 seconds)988test script finished in 73.94s989cleanup990kill NspawnMachine (pid 52)991kill NspawnMachine (pid 53)992relay # [ 3816.498479] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:14.460273Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}993kill NspawnMachine (pid 54)994Container agent terminated by signal KILL.995Container client terminated by signal KILL.996Container relay terminated by signal KILL.997(finished: cleanup, in 0.34 seconds)998additionally exposed symbols:999 agent, client, relay,1000 vlan1,1001 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_ssh1002» job 7c688899f50c54534670dd507aceef9c via relay 0.1.0 (agents: agent 0.1.0)1003» wave 01004agent/app | Starting flakelet update app (via relay)...1005agent/app | Started flakelet update app (via relay).1006agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v21007agent/app | app: activating generation 21008agent/app | app: updated to generation 21009agent/app | flakelet-relay-job-app.service: Deactivated successfully.1010» agent/app: updated (generation 2)1011» ok10121013» job 6c70740948a858850d4649517ab7ca16 via relay 0.1.0 (agents: agent 0.1.0)1014» wave 01015agent/app | Starting flakelet update app (via relay)...1016agent/app | Started flakelet update app (via relay).1017agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1018agent/app | app: activating generation 41019agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1020agent/app | failed units: app.service. See journalctl -u app.service1021agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1022agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1023» agent/app: rolled-back (generation 3)1024agent/app │ Starting app v1...1025agent/app │ Started app v1.1026agent/app │ Stopping app v1...1027agent/app │ app.service: Deactivated successfully.1028agent/app │ Stopped app v1.1029agent/app │ Starting app v2...1030agent/app │ Started app v2.1031agent/app │ Stopping app v2...1032agent/app │ app.service: Deactivated successfully.1033agent/app │ Stopped app v2.1034agent/app │ Starting app v1...1035agent/app │ Started app v1.1036agent/app │ Stopping app v1...1037agent/app │ app.service: Deactivated successfully.1038agent/app │ Stopped app v1.1039agent/app │ Starting app broken...1040agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1041agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1042agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1043agent/app │ app.service: Failed with result 'exit-code'.1044agent/app │ Failed to start app broken.1045agent/app │ Starting app v1...1046agent/app │ Started app v1.1047» skipped: agent/other1048» failed10491050» job e85a1e72998985266f7693bf3126a7ce via relay 0.1.0 (agents: agent 0.1.0)1051» wave 01052agent/app | Starting flakelet update app (via relay)...1053agent/app | Started flakelet update app (via relay).1054agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1055agent/app | app: activating generation 51056agent/app | app: updated to generation 51057agent/app | flakelet-relay-job-app.service: Deactivated successfully.1058» agent/app: updated (generation 5)1059» ok10601061» job 012d36b9186571825180908984710eb8 via relay 0.1.0 (agents: agent 0.1.0)1062» wave 01063agent/app | Starting flakelet update app (via relay)...1064agent/app | Started flakelet update app (via relay).1065agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21066agent/app | app: activating generation 61067agent/app | app: updated to generation 61068agent/app | flakelet-relay-job-app.service: Deactivated successfully.1069» agent/app: updated (generation 6)1070» ok10711072» job 7ec8ea76b10475faaf72f0ea8b7fe5ae via relay 0.1.0 (agents: agent 0.1.0)1073» wave 01074agent/app | Starting flakelet update app (via relay)...1075agent/app | Started flakelet update app (via relay).1076agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1077agent/app | app: activating generation 71078flakelet-push: stream: error reading a body from connection, resuming job c5c29e4bc96eb35fa769432617e2a8371079flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1080flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1081flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1082» job 7ec8ea76b10475faaf72f0ea8b7fe5ae via relay 0.1.0 (agents: agent 0.1.0)1083» wave 01084agent/app | app: updated to generation 71085agent/app | flakelet-relay-job-app.service: Deactivated successfully.1086» agent/app: updated (generation 7)1087» ok108810891788682087 hist1 x509:email:admin@example.org agent/other:unchanged10901788682077 c5c29e4bc96eb35fa769432617e2a837 x509:email:admin@example.org agent/app:updated10911788682068 bab3f2e8a3cb4c3960692f9ef67203f1 x509:email:admin@example.org agent/app:updated10921788682059 a83454a80b61350a2f72ab7ddd86a01f x509:email:admin@example.org agent/app:updated10931788682058 83bd2bbe2cb487fffd24afb4363bc00e x509:email:admin@example.org agent/other:unchanged10941788682047 7c35fd6467d21f215c54f5bb5228d614 x509:email:admin@example.org agent/app:updated10951788682046 f880de0d3de4c5544110e91be18a057e x509:email:admin@example.org agent/app:unchanged10961788682045 084d281f1305a8789445510f9fdea61b x509:email:admin@example.org agent/app:unchanged10971788682045 5ff3958c58814053439e809bb2d814e0 x509:email:admin@example.org agent/app:unchanged10981788682039 1d9861a7eec93459c511b111ce0fff03 x509:email:admin@example.org agent/app:rolled-back10991788682039 6f0a33634dac65ab2b37cddc8a15ce1c oidc:mock:groups:wheel agent/other:unchanged11001788682037 f36fb5e34000c14e7c1aac2eae24837d oidc:mock:groups:wheel agent/other:unchanged11011788682034 9aed90bd01858acc6d3dd3cdba81df9b oidc:mock:groups:wheel agent/other:unchanged11021788682031 00fabb1fb0c04f844ed6e9a686dea144 oidc:mock:repo:github:example/app:ref:refs/heads/main agent/app:updated11031788682028 cb301dd1dad98892fc40883a6d78404c x509:email:admin@example.org agent/app:updated1104