container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #49
· 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 VMs9agent: systemd-nspawn running (pid 52)10client: systemd-nspawn running (pid 53)11agent: Waiting for journal at /build/vm-state-agent/var/log/journal...12client: Waiting for journal at /build/vm-state-client/var/log/journal...13relay: systemd-nspawn running (pid 56)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(client): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.21nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE22nixos-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.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 client on /build/vm-state-client.26Note: 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.27░ Spawning container agent on /build/vm-state-agent.28░ Spawning container relay on /build/vm-state-relay.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31relay # No journal files were found.32relay # No journal boot entry found for the specified boot (+0).33client # No journal files were found.34client # No journal boot entry found for the specified boot (+0).35relay # [95693.640551] relay systemd-journald[57]: Journal started36agent # [95693.639828] agent systemd-journald[57]: Journal started37relay # [95693.640597] relay systemd-journald[57]: Runtime Journal (/run/log/journal/57860d41eb284db4afdc98fcd7e210e7) is 8M, max 4G, 3.9G free.38agent # [95693.639875] agent systemd-journald[57]: Runtime Journal (/run/log/journal/ec4136b44bf04d3ca4712e2344fa22ad) is 8M, max 4G, 3.9G free.39relay # [95693.649627] relay systemd[1]: Finished Apply Kernel Variables.40agent # [95693.649884] agent systemd[1]: Finished Apply Kernel Variables.41relay # [95693.661598] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.42client # [95693.639521] client systemd-journald[57]: Journal started43relay # [95693.675296] relay systemd[1]: Starting Flush Journal to Persistent Storage...44client # [95693.639565] client systemd-journald[57]: Runtime Journal (/run/log/journal/223b5bb8942741b7ac7dbbbb053148a9) is 8M, max 4G, 3.9G free.45relay # [95693.676132] relay systemd[1]: Starting Create Static Device Nodes in /dev...46client # [95693.649748] client systemd[1]: Finished Apply Kernel Variables.47relay # [95693.684084] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/57860d41eb284db4afdc98fcd7e210e7 is 1.513ms for 6 entries.48agent # [95693.661649] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.49relay # [95693.684084] relay systemd-journald[57]: System Journal (/var/log/journal/57860d41eb284db4afdc98fcd7e210e7) is 512B, max 4G, 3.9G free.50agent # [95693.675278] agent systemd[1]: Starting Flush Journal to Persistent Storage...51relay # [95693.695508] relay systemd[1]: Finished Create Static Device Nodes in /dev.52agent # [95693.676410] agent systemd[1]: Starting Create Static Device Nodes in /dev...53relay # [95693.696324] relay systemd[1]: Reached target Preparation for Local File Systems.54agent # [95693.684280] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/ec4136b44bf04d3ca4712e2344fa22ad is 1.624ms for 6 entries.55relay # [95693.696439] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys56agent # [95693.684280] agent systemd-journald[57]: System Journal (/var/log/journal/ec4136b44bf04d3ca4712e2344fa22ad) is 512B, max 4G, 3.9G free.57client # [95693.661647] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.58relay # [95693.711435] relay systemd[1]: Finished Flush Journal to Persistent Storage.59client # [95693.675429] client systemd[1]: Starting Flush Journal to Persistent Storage...60agent # [95693.693360] agent systemd[1]: Finished Create Static Device Nodes in /dev.61client # [95693.676055] client systemd[1]: Starting Create Static Device Nodes in /dev...62agent # [95693.694260] agent systemd[1]: Reached target Preparation for Local File Systems.63client # [95693.684162] client systemd-journald[57]: Time spent on flushing to /var/log/journal/223b5bb8942741b7ac7dbbbb053148a9 is 1.399ms for 6 entries.64agent # [95693.694368] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys65relay # [95693.818170] relay systemd[1]: Finished Firewall.66client # [95693.684162] client systemd-journald[57]: System Journal (/var/log/journal/223b5bb8942741b7ac7dbbbb053148a9) is 512B, max 4G, 3.9G free.67relay # [95694.638557] relay systemd[1]: Mounting /run/wrappers...68client # [95693.692748] client systemd[1]: Finished Create Static Device Nodes in /dev.69agent # [95693.714203] agent systemd[1]: Finished Flush Journal to Persistent Storage.70client # [95693.693556] client systemd[1]: Reached target Preparation for Local File Systems.71agent # [95693.797102] agent systemd[1]: Finished Firewall.72client # [95693.693661] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys73agent # [95694.638623] agent systemd[1]: Mounting /run/wrappers...74client # [95693.710450] client systemd[1]: Finished Flush Journal to Persistent Storage.75client # [95693.795509] client systemd[1]: Finished Firewall.76client # [95694.638431] client systemd[1]: Mounting /run/wrappers...77agent # [95694.692365] agent systemd[1]: Mounted /run/wrappers.78agent # [95694.693533] agent systemd[1]: Reached target Local File Systems.79relay # [95694.692452] relay systemd[1]: Mounted /run/wrappers.80agent # [95694.694803] agent systemd[1]: Listening on Boot Loader Control Service Socket.81agent # [95694.696071] agent systemd[1]: Starting Create SUID/SGID Wrappers...82relay # [95694.693658] relay systemd[1]: Reached target Local File Systems.83relay # [95694.694990] relay systemd[1]: Listening on Boot Loader Control Service Socket.84agent # [95694.696118] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container85relay # [95694.696384] relay systemd[1]: Starting Create SUID/SGID Wrappers...86agent # [95694.697183] agent systemd[1]: Starting Save Transient machine-id to Disk...87agent # [95694.698423] agent systemd[1]: Starting Create System Files and Directories...88relay # [95694.696431] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container89relay # [95694.697654] relay systemd[1]: Starting Save Transient machine-id to Disk...90agent # [95694.738826] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted91relay # [95694.698884] relay systemd[1]: Starting Create System Files and Directories...92agent # [95694.739248] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted93agent # [95694.739546] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/ec4136b44bf04d3ca4712e2344fa22ad failed: Operation not permitted94relay # [95694.739000] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted95agent # [95694.739873] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted96relay # [95694.739448] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted97relay # [95694.739785] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/57860d41eb284db4afdc98fcd7e210e7 failed: Operation not permitted98client # [95694.691213] client systemd[1]: Mounted /run/wrappers.99relay # [95694.740123] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted100client # [95694.692381] client systemd[1]: Reached target Local File Systems.101client # [95694.693684] client systemd[1]: Listening on Boot Loader Control Service Socket.102client # [95694.695260] client systemd[1]: Starting Create SUID/SGID Wrappers...103client # [95694.695308] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104client # [95694.696801] client systemd[1]: Starting Save Transient machine-id to Disk...105client # [95694.697788] client systemd[1]: Starting Create System Files and Directories...106client # [95694.740332] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted107client # [95694.740745] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108client # [95694.741045] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/223b5bb8942741b7ac7dbbbb053148a9 failed: Operation not permitted109client # [95694.741363] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110agent # [95694.746560] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.Np7Wf1HAqG/chsh': Operation not permitted111agent # [95694.749076] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE112agent # [95694.749280] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.113agent # [95694.749641] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.114client # [95694.746078] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.S9GIxogNsE/chsh': Operation not permitted115agent # [95694.785544] agent systemd[1]: Finished Create System Files and Directories.116client # [95694.749646] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE117agent # [95694.817469] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.118client # [95694.749724] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.119agent # [95694.828827] agent systemd[1]: Finished Save Transient machine-id to Disk.120client # [95694.749820] client systemd[1]: Failed to start Create SUID/SGID Wrappers.121agent # [95694.846839] agent systemd[1]: Starting Rebuild Journal Catalog...122client # [95694.756889] client systemd[1]: Finished Create System Files and Directories.123agent # [95694.847624] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...124client # [95694.807871] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.125agent # [95694.860704] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.126client # [95694.819185] client systemd[1]: Finished Save Transient machine-id to Disk.127agent # [95694.867448] agent systemd[1]: Finished Rebuild Journal Catalog.128client # [95694.822355] client systemd[1]: Starting Rebuild Journal Catalog...129agent # [95694.868679] agent systemd[1]: Starting Update is Completed...130client # [95694.823405] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...131agent # [95694.877955] agent systemd[1]: Finished Update is Completed.132client # [95694.855245] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.133agent # [95694.878067] agent systemd[1]: Reached target System Initialization.134client # [95694.862628] client systemd[1]: Finished Rebuild Journal Catalog.135agent # [95694.878166] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container136client # [95694.863812] client systemd[1]: Starting Update is Completed...137agent # [95694.878193] agent systemd[1]: Started Daily Cleanup of Temporary Directories.138client # [95694.875437] client systemd[1]: Finished Update is Completed.139agent # [95694.878211] agent systemd[1]: Reached target Timer Units.140client # [95694.875585] client systemd[1]: Reached target System Initialization.141agent # [95694.878312] agent systemd[1]: Listening on D-Bus System Message Bus Socket.142client # [95694.875681] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container143agent # [95694.878717] agent systemd[1]: Listening on Nix Daemon Socket.144client # [95694.875718] client systemd[1]: Started Daily Cleanup of Temporary Directories.145agent # [95694.878815] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.146client # [95694.875738] client systemd[1]: Reached target Timer Units.147agent # [95694.878829] agent systemd[1]: Reached target Socket Units.148client # [95694.875897] client systemd[1]: Listening on D-Bus System Message Bus Socket.149agent # [95694.878855] agent systemd[1]: Reached target Basic System.150client # [95694.876206] client systemd[1]: Listening on Nix Daemon Socket.151agent # [95694.880080] agent systemd[1]: Starting Re-link flakelet services at boot...152client # [95694.876389] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.153agent # [95694.880739] agent systemd[1]: Starting Import lastlog data into lastlog2 database...154client # [95694.876414] client systemd[1]: Reached target Socket Units.155agent # [95694.881736] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...156client # [95694.876464] client systemd[1]: Reached target Basic System.157agent # [95694.882325] agent systemd[1]: Starting resolvconf update...158client # [95694.878139] client systemd[1]: Starting Import lastlog data into lastlog2 database...159client # [95694.879553] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...160client # [95694.880803] client systemd[1]: Starting resolvconf update...161relay # [95694.744801] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.29UTTjDnmn/chsh': Operation not permitted162relay # [95694.749079] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE163relay # [95694.749281] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.164relay # [95694.749656] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.165relay # [95694.785587] relay systemd[1]: Finished Create System Files and Directories.166relay # [95694.815273] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.167relay # [95694.826823] relay systemd[1]: Finished Save Transient machine-id to Disk.168relay # [95694.846761] relay systemd[1]: Starting Rebuild Journal Catalog...169relay # [95694.847633] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...170relay # [95694.860709] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.171relay # [95694.867440] relay systemd[1]: Finished Rebuild Journal Catalog.172relay # [95694.868566] relay systemd[1]: Starting Update is Completed...173relay # [95694.880077] relay systemd[1]: Finished Update is Completed.174relay # [95694.880214] relay systemd[1]: Reached target System Initialization.175relay # [95694.880281] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container176relay # [95694.880302] relay systemd[1]: Started Daily Cleanup of Temporary Directories.177relay # [95694.880315] relay systemd[1]: Reached target Timer Units.178relay # [95694.880414] relay systemd[1]: Listening on D-Bus System Message Bus Socket.179relay # [95694.880616] relay systemd[1]: Listening on Nix Daemon Socket.180relay # [95694.880717] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.181relay # [95694.880732] relay systemd[1]: Reached target Socket Units.182relay # [95694.880760] relay systemd[1]: Reached target Basic System.183relay # [95694.881856] relay systemd[1]: Started device-mock.service.184relay # [95694.882548] relay systemd[1]: Starting Re-link flakelet services at boot...185relay # [95694.883421] relay systemd[1]: Starting Import lastlog data into lastlog2 database...186relay # [95694.884237] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...187relay # [95694.884742] relay systemd[1]: Starting resolvconf update...188client # [95694.896151] client systemd[1]: Finished Import lastlog data into lastlog2 database.189client # [95694.970217] client systemd[1]: nscd.service: Deactivated successfully.190client # [95694.970425] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).191client # [95695.000060] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...192client # [95695.000289] client systemd[1]: Finished resolvconf update.193client # [95695.001437] client systemd[1]: Reached target Preparation for Network.194client # [95695.002746] client systemd[1]: Starting Address configuration of eth1...195client # [95695.004028] client systemd[1]: Starting Extra networking commands....196client # [95695.026232] client network-addresses-eth1-start[237]: adding address 192.168.1.2/24... done197client # [95695.029243] client network-addresses-eth1-start[237]: adding address 2001:db8:1::2/64... done198client # [95695.033543] client systemd[1]: Finished Address configuration of eth1.199client # [95695.085048] client systemd[1]: nscd.service: Deactivated successfully.200client # [95695.109159] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).201client # [95695.111075] client systemd[1]: Finished Extra networking commands..202client # [95695.112033] client systemd[1]: Reached target Network.203client # [95695.113219] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...204relay # [95694.895941] relay systemd[1]: Finished Re-link flakelet services at boot.205relay # [95694.897087] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...206relay # [95694.903483] relay systemd[1]: Finished Import lastlog data into lastlog2 database.207relay # [95694.909515] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.208relay # [95694.960446] relay systemd[1]: nscd.service: Deactivated successfully.209relay # [95694.965235] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).210relay # [95694.968572] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...211relay # [95694.999494] relay systemd[1]: Finished resolvconf update.212relay # [95694.999727] relay systemd[1]: Reached target Preparation for Network.213relay # [95695.000674] relay systemd[1]: Starting Address configuration of eth1...214relay # [95695.001756] relay systemd[1]: Starting Extra networking commands....215relay # [95695.020873] relay network-addresses-eth1-start[251]: adding address 192.168.1.3/24... done216relay # [95695.024163] relay network-addresses-eth1-start[251]: adding address 2001:db8:1::3/64... done217relay # [95695.027893] relay systemd[1]: Finished Address configuration of eth1.218relay # [95695.073221] relay systemd[1]: Finished Extra networking commands..219relay # [95695.073827] relay systemd[1]: Reached target Network.220relay # [95695.080585] relay systemd[1]: Starting Dnsmasq Daemon...221relay # [95695.081460] relay systemd[1]: Starting Nginx Web Server...222relay # [95695.082283] relay systemd[1]: Starting Update flakelet service flakelet-relay...223relay # [95695.117647] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/dmw24kck53hkbhzjp4k5hya5189hbkq0-flakelet-flakelet-relay224relay # [95695.118281] relay flakelet[311]: flakelet-relay: activating generation 1225relay # [95695.122415] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...226relay # [95695.122458] relay systemd[1]: Reloading...227agent # [95694.893292] agent systemd[1]: Finished Re-link flakelet services at boot.228agent # [95694.895191] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...229agent # [95694.901570] agent systemd[1]: Finished Import lastlog data into lastlog2 database.230agent # [95694.906705] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.231agent # [95694.970960] agent systemd[1]: nscd.service: Deactivated successfully.232agent # [95694.971088] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).233agent # [95694.972603] agent systemd[1]: Finished resolvconf update.234agent # [95694.973273] agent systemd[1]: Reached target Preparation for Network.235agent # [95695.000305] agent systemd[1]: Starting Address configuration of eth1...236agent # [95695.001648] agent systemd[1]: Starting Extra networking commands....237agent # [95695.002650] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...238agent # [95695.020668] agent network-addresses-eth1-start[240]: adding address 192.168.1.1/24... done239agent # [95695.025422] agent network-addresses-eth1-start[240]: adding address 2001:db8:1::1/64... done240agent # [95695.031244] agent systemd[1]: Finished Address configuration of eth1.241agent # [95695.080325] agent systemd[1]: nscd.service: Deactivated successfully.242agent # [95695.080464] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).243agent # [95695.083300] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...244agent # [95695.109240] agent systemd[1]: Finished Extra networking commands..245agent # [95695.109415] agent systemd[1]: Reached target Network.246agent # [95695.110551] agent systemd[1]: Starting Update flakelet service app...247agent # [95695.111379] agent systemd[1]: Starting Update flakelet service flakelet-agent...248agent # [95695.112244] agent systemd[1]: Starting Update flakelet service other...249agent # [95695.122052] agent flakelet[309]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1250agent # [95695.122618] agent flakelet[310]: flakelet-agent: using prebuilt artifact /nix/store/gn2q2am7xndcfsg15x75ady3rix35z5p-flakelet-flakelet-agent251agent # [95695.122819] agent flakelet[309]: app: activating generation 1252agent # [95695.123158] agent flakelet[310]: flakelet-agent: activating generation 1253agent # [95695.123237] agent flakelet[311]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1254agent # [95695.123747] agent flakelet[311]: other: activating generation 1255agent # [95695.128491] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-app.service)...256agent # [95695.128521] agent systemd[1]: Reloading...257relay # [95695.394730] relay nsncd[245]: Oct 15 11:58:08.205 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"258relay # [95695.529892] relay systemd[1]: Reloading finished in 407 ms.259client # [95695.432282] client systemd[1]: Started Name Service Cache Daemon (nsncd).260client # [95695.432347] client systemd[1]: Reached target Host and Network Name Lookups.261client # [95695.432561] client nsncd[303]: Oct 15 11:58:08.242 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"262client # [95695.432412] client systemd[1]: Reached target User and Group Name Lookups.263client # [95695.434358] client systemd[1]: Starting User Login Management...264client # [95695.435301] client systemd[1]: Starting Permit User Sessions...265client # [95695.465808] client systemd[1]: Finished Permit User Sessions.266client # [95695.466887] client systemd[1]: Started Console Getty.267client # [95695.466912] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0268client # [95695.466927] client systemd[1]: Reached target Login Prompts.269agent # [95695.461958] agent nsncd[305]: Oct 15 11:58:08.272 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"270agent # [95695.529455] agent systemd[1]: Reloading finished in 400 ms.271agent # [95695.666968] agent systemd[1]: Started Name Service Cache Daemon (nsncd).272agent # [95695.667535] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-other.service)...273agent # [95695.667580] agent systemd[1]: Reloading...274relay # [95695.662923] relay systemd[1]: Started Name Service Cache Daemon (nsncd).275relay # [95695.663392] relay systemd[1]: Reached target Host and Network Name Lookups.276relay # [95695.663479] relay systemd[1]: Reached target User and Group Name Lookups.277relay # [95695.664856] relay systemd[1]: Starting User Login Management...278relay # [95695.665883] relay systemd[1]: Starting Permit User Sessions...279relay # [95695.679875] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...280relay # [95695.679945] relay systemd[1]: Reloading...281relay # [95695.710537] relay dnsmasq-pre-start[366]: dnsmasq: syntax check OK.282relay # [95696.050686] relay systemd[1]: Reloading finished in 370 ms.283relay # [95696.177081] relay systemd[1]: Finished Permit User Sessions.284relay # [95696.181473] relay systemd[1]: Started Console Getty.285relay # [95696.181535] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0286relay # [95696.181616] relay systemd[1]: Reached target Login Prompts.287relay # [95696.205332] relay systemd[1]: Starting flakelet-relay...288agent # [95696.044982] agent systemd[1]: Reloading finished in 376 ms.289agent # [95696.179612] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-flakelet-agent.service)...290agent # [95696.179662] agent systemd[1]: Reloading...291relay # [95696.613337] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/jm9zi5xcg0k4gcww44kzxbjl3nggdc0x-nginx.conf syntax is ok292relay # [95696.614082] relay nginx-pre-start[402]: nginx: configuration file /nix/store/jm9zi5xcg0k4gcww44kzxbjl3nggdc0x-nginx.conf test is successful293relay # [95696.627775] relay systemd[1]: Started Nginx Web Server.294relay # [95696.792452] relay systemd[1]: Starting D-Bus System Message Bus...295agent # [95696.539682] agent systemd[1]: Reloading finished in 359 ms.296agent # [95696.628390] agent systemd[1]: Reached target Host and Network Name Lookups.297agent # [95696.628526] agent systemd[1]: Reached target User and Group Name Lookups.298agent # [95696.629703] agent systemd[1]: Starting User Login Management...299agent # [95696.630752] agent systemd[1]: Starting Permit User Sessions...300agent # [95696.635933] agent systemd[1]: Reload requested from client PID 405 ('systemctl') (unit flakelet-app.service)...301agent # [95696.635963] agent systemd[1]: Reloading...302client # [95696.745056] client systemd-logind[315]: New seat seat0.303client # [95696.745598] client systemd[1]: Started User Login Management.304client # [95696.747765] client systemd[1]: Starting D-Bus System Message Bus...305client # [95696.749395] client systemd[1]: Starting linger-users.service...306client # [95696.793670] client systemd[1]: linger-users.service: Deactivated successfully.307client # [95696.794052] client systemd[1]: Finished linger-users.service.308client # [95696.794410] client systemd[1]: Reached target Multi-User System.309relay # [95697.062964] relay systemd-logind[354]: New seat seat0.310relay # [95697.063252] relay systemd[1]: Started User Login Management.311relay # [95697.064738] relay systemd[1]: Starting linger-users.service...312relay # [95697.099254] relay systemd[1]: linger-users.service: Deactivated successfully.313relay # [95697.099502] relay systemd[1]: Finished linger-users.service.314relay # [95697.311427] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...315relay # [95697.312711] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'316relay # [95697.312711] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/vs0a8az17i3z78gq22l4n082lgvd42jj-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"317relay # [95697.313918] relay systemd[1]: Started D-Bus System Message Bus.318agent # [95697.089812] agent systemd[1]: Reloading finished in 453 ms.319agent # [95697.150702] agent systemd[1]: Finished Permit User Sessions.320agent # [95697.156256] agent systemd[1]: Started Console Getty.321agent # [95697.156348] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0322agent # [95697.156468] agent systemd[1]: Reached target Login Prompts.323agent # [95697.156803] agent systemd[1]: Reload requested from client PID 408 ('systemctl') (unit flakelet-other.service)...324agent # [95697.156832] agent systemd[1]: Reloading...325client # [95697.282508] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...326client # [95697.283847] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'327client # [95697.283847] client dbus-broker-launch[325]: Invalid user-name in /nix/store/bw3qfpk1dfh3rqrhglxb7ssyflsig0mc-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"328client # [95697.284607] client systemd[1]: Started D-Bus System Message Bus.329client # [95697.285149] client systemd[1]: Startup finished in 4.133s.330client # [95697.289827] client dbus-broker-launch[325]: Ready331relay # [95697.319146] relay dbus-broker-launch[408]: Ready332relay # [95697.322438] relay systemd[1]: Started Dnsmasq Daemon.333relay # [95697.324582] relay dnsmasq[394]: started, version 2.93 cachesize 150334relay # [95697.324591] 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 dumpfile335relay # [95697.324596] relay dnsmasq[394]: DBus support enabled: connected to system bus336relay # [95697.324604] relay dnsmasq[394]: no upstream servers configured - please set them from DBus337relay # [95697.324686] relay dnsmasq[394]: read /etc/hosts - 9 names338agent # [95697.499111] agent systemd[1]: Reloading finished in 341 ms.339agent # [95697.572885] agent systemd[1]: Starting app v1...340agent # [95697.575582] agent systemd[1]: Starting other v1...341agent # [95697.578067] agent systemd[1]: Reload requested from client PID 473 ('systemctl') (unit flakelet-flakelet-agent.service)...342agent # [95697.578106] agent systemd[1]: Reloading...343agent # [95697.911763] agent systemd[1]: Reloading finished in 333 ms.344agent # [95697.985361] agent systemd-logind[406]: New seat seat0.345agent # [95697.986107] agent systemd[1]: Started app v1.346agent # [95697.986258] agent systemd[1]: Started other v1.347agent # [95697.986545] agent systemd[1]: Started User Login Management.348agent # [95697.989642] agent systemd[1]: Starting D-Bus System Message Bus...349agent # [95697.990627] agent systemd[1]: Starting linger-users.service...350agent # [95697.994464] agent flakelet[309]: app: updated to generation 1351agent # [95697.994969] agent flakelet[311]: other: updated to generation 1352agent # [95698.024164] agent systemd[1]: Finished Update flakelet service app.353agent # [95698.024672] agent systemd[1]: Finished Update flakelet service other.354agent # [95698.027672] agent systemd[1]: Starting flakelet-agent...355agent # [95698.034435] agent systemd[1]: linger-users.service: Deactivated successfully.356agent # [95698.034635] agent systemd[1]: Finished linger-users.service.357agent # [95698.096678] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:10.907092Z","level":"INFO","message":"local change","flakelet":"app","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}358agent # [95698.097414] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:10.907287Z","level":"INFO","message":"local change","flakelet":"other","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}359agent # [95698.097154] agent systemd[1]: Started flakelet-agent.360agent # [95698.101196] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:10.911604Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}361agent # [95698.110354] agent flakelet[310]: flakelet-agent: updated to generation 1362agent # [95698.111875] agent systemd[1]: Finished Update flakelet service flakelet-agent.363agent # [95698.111989] agent systemd[1]: Reached target flakelet managed services.364agent # [95698.112041] agent systemd[1]: Reached target Multi-User System.365agent # [95698.129797] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:10.940242Z","level":"INFO","message":"local change","flakelet":"flakelet-agent","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}366relay # [95698.153380] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:10.963782Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}367relay # [95698.154308] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:10.964228Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}368relay # [95698.153828] relay systemd[1]: Started flakelet-relay.369relay # [95698.161535] relay systemd[1]: Starting health for flakelet-relay...370relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)371relay: waiting for unit nginx.service372relay: (finished: waiting for unit nginx.service, in 0.02 seconds)373agent: waiting for unit flakelet.target374agent: (finished: waiting for unit flakelet.target, in 0.01 seconds)375agent: waiting for unit flakelet-agent.service376agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)377client: waiting for unit multi-user.target378client: (finished: waiting for unit multi-user.target, in 0.02 seconds)379relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'380relay # [95698.414891] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.381relay # [95698.415287] relay systemd[1]: Finished health for flakelet-relay.382relay # [95698.423932] relay flakelet[311]: flakelet-relay: updated to generation 1383relay # [95698.425806] relay systemd[1]: Finished Update flakelet service flakelet-relay.384relay # [95698.426508] relay systemd[1]: Reached target flakelet managed services.385relay # [95698.426751] relay systemd[1]: Reached target Multi-User System.386relay # [95698.427053] relay systemd[1]: Startup finished in 5.272s.387agent # [95698.447042] agent dbus-broker-launch[506]: Looking up NSS user entry for 'systemd-timesync'...388agent # [95698.448370] agent dbus-broker-launch[506]: NSS returned no entry for 'systemd-timesync'389agent # [95698.448370] agent dbus-broker-launch[506]: Invalid user-name in /nix/store/si00m8lxg75ccl80rxnfdhrmm5ssvpwv-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"390agent # [95698.448951] agent systemd[1]: Started D-Bus System Message Bus.391agent # [95698.449339] agent systemd[1]: Startup finished in 5.288s.392agent # [95698.456198] agent dbus-broker-launch[506]: Ready393relay # [95700.115071] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:12.925454Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}394agent # [95700.114929] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:12.925355Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}395relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)396agent: must succeed: systemctl is-active app.service other.service397agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)398subtest: deploy with client certificate, relay found via SRV399agent: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json400agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)401client: must succeed: push --relay-srv test --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1402relay # [95700.967515] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:13.777906Z","level":"INFO","message":"deploy accepted","job":"3412571728039b4fa01e12d182524ba0","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}403agent # [95700.967950] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:13.778373Z","level":"INFO","message":"start","id":"358d9cd35d9ce9c255ea33543887b52d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}404agent # [95700.968843] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:13.779312Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"358d9cd35d9ce9c255ea33543887b52d\"]","target":"flakelet_relay::agent::jobs"}405agent # [95701.004816] agent systemd[1]: Starting flakelet update app (via relay)...406agent # [95701.026795] agent systemd[1]: Started flakelet update app (via relay).407agent # [95701.030420] agent flakelet[926]: app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2408agent # [95701.031072] agent flakelet[926]: app: activating generation 2409agent # [95701.049199] agent systemd[1]: Stopping app v1...410agent # [95701.049641] agent systemd[1]: app.service: Deactivated successfully.411agent # [95701.049894] agent systemd[1]: Stopped app v1.412agent # [95701.066704] agent systemd[1]: Reload requested from client PID 933 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [95701.066769] agent systemd[1]: Reloading...414agent # [95701.406438] agent systemd[1]: Reloading finished in 338 ms.415agent # [95701.492812] agent systemd[1]: Reload requested from client PID 963 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [95701.492856] agent systemd[1]: Reloading...417agent # [95701.815336] agent systemd[1]: Reloading finished in 322 ms.418agent # [95701.892642] agent systemd[1]: Reload requested from client PID 992 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [95701.892684] agent systemd[1]: Reloading...420agent # [95702.219388] agent systemd[1]: Reloading finished in 326 ms.421agent # [95702.307471] agent systemd[1]: Reload requested from client PID 1026 ('systemctl') (unit flakelet-relay-job-app.service)...422agent # [95702.307504] agent systemd[1]: Reloading...423agent # [95702.632475] agent systemd[1]: Reloading finished in 324 ms.424agent # [95702.700795] agent systemd[1]: Starting app v2...425agent # [95702.728786] agent systemd[1]: Started app v2.426agent # [95702.735223] agent flakelet[926]: app: updated to generation 2427agent # [95702.736303] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.428client: (finished: must succeed: push --relay-srv test --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.90 seconds)429agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'430agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.01 seconds)431agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'432agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)433agent: must succeed: flakelet status --json app | jq -c '.[0].changed.by'434agent: (finished: must succeed: flakelet status --json app | jq -c '.[0].changed.by', in 0.03 seconds)435(finished: subtest: deploy with client certificate, relay found via SRV, in 2.97 seconds)436subtest: deploy with OIDC token, sub principal437agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json438agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)439client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)440client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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.06 seconds)441client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1U0VZWVlCTktKS1hHPT09IiwibmJmIjoxNzkyMDY1NDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.NMhWaKo0-e_a1UvynnVB5oInCm4RZUdxlxwIFVJ3dRhC6b4WnqBqoYxRJMxPdpkstNX7g1PwVp3HNfIhQJcyDg' push --relay https://relay:7443 deploy agent/app 2>&1442agent # [95703.842959] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:16.653359Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}443agent # [95704.008714] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:16.819135Z","level":"INFO","message":"start","id":"767ad911901ce1d6ab1b7da7bdb61498","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"}444agent # [95704.009214] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:16.819689Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"767ad911901ce1d6ab1b7da7bdb61498\"]","target":"flakelet_relay::agent::jobs"}445agent # [95704.048922] agent systemd[1]: Starting flakelet update app (via relay)...446agent # [95704.078175] agent systemd[1]: Started flakelet update app (via relay).447agent # [95704.082289] agent flakelet[1092]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1448agent # [95704.082946] agent flakelet[1092]: app: activating generation 3449agent # [95704.096771] agent systemd[1]: Stopping app v2...450relay # [95703.844045] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:16.654432Z","level":"INFO","message":"deploy finished","job":"3412571728039b4fa01e12d182524ba0","ok":true,"target":"flakelet_relay::relay::api"}451relay # [95704.008437] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:16.818847Z","level":"INFO","message":"deploy accepted","job":"9488318adb2b10dad1c69cb6d17fe497","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}452agent # [95704.098498] agent systemd[1]: app.service: Deactivated successfully.453agent # [95704.098858] agent systemd[1]: Stopped app v2.454agent # [95704.118954] agent systemd[1]: Reload requested from client PID 1102 ('systemctl') (unit flakelet-relay-job-app.service)...455agent # [95704.119039] agent systemd[1]: Reloading...456agent # [95704.462498] agent systemd[1]: Reloading finished in 342 ms.457agent # [95704.552336] agent systemd[1]: Reload requested from client PID 1133 ('systemctl') (unit flakelet-relay-job-app.service)...458agent # [95704.552373] agent systemd[1]: Reloading...459agent # [95704.877920] agent systemd[1]: Reloading finished in 325 ms.460agent # [95704.942528] agent systemd[1]: Reload requested from client PID 1162 ('systemctl') (unit flakelet-relay-job-app.service)...461agent # [95704.942563] agent systemd[1]: Reloading...462agent # [95705.267596] agent systemd[1]: Reloading finished in 324 ms.463agent # [95705.350526] agent systemd[1]: Reload requested from client PID 1193 ('systemctl') (unit flakelet-relay-job-app.service)...464agent # [95705.350561] agent systemd[1]: Reloading...465agent # [95705.675325] agent systemd[1]: Reloading finished in 324 ms.466agent # [95705.756854] agent systemd[1]: Starting app v1...467agent # [95705.777706] agent systemd[1]: Started app v1.468agent # [95705.784161] agent flakelet[1092]: app: updated to generation 3469agent # [95705.785293] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.470client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1U0VZWVlCTktKS1hHPT09IiwibmJmIjoxNzkyMDY1NDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.NMhWaKo0-e_a1UvynnVB5oInCm4RZUdxlxwIFVJ3dRhC6b4WnqBqoYxRJMxPdpkstNX7g1PwVp3HNfIhQJcyDg' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.91 seconds)471(finished: subtest: deploy with OIDC token, sub principal, in 2.99 seconds)472subtest: policy denies uncovered target473client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1U0VZWVlCTktKS1hHPT09IiwibmJmIjoxNzkyMDY1NDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.NMhWaKo0-e_a1UvynnVB5oInCm4RZUdxlxwIFVJ3dRhC6b4WnqBqoYxRJMxPdpkstNX7g1PwVp3HNfIhQJcyDg' push --relay https://relay:7443 deploy agent/other 2>&1474client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1U0VZWVlCTktKS1hHPT09IiwibmJmIjoxNzkyMDY1NDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.NMhWaKo0-e_a1UvynnVB5oInCm4RZUdxlxwIFVJ3dRhC6b4WnqBqoYxRJMxPdpkstNX7g1PwVp3HNfIhQJcyDg' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)475(finished: subtest: policy denies uncovered target, in 0.02 seconds)476subtest: claim principal from groups, unchanged counts as success477client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)478client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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.07 seconds)479client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5OSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MjA2NTQ5OSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiR01BV1JFS0czUkFHSz09PSIsIm5iZiI6MTc5MjA2NTQ5OSwic3ViIjoic29tZW9uZSJ9.AVVpmNcrvCqlyNiINVYAQi3R2yNq_ceej4KJqO3AHm82VBCPGddcBemTKLjARTjNt2d3noNuonDu445XS-GKAw' push --relay https://relay:7443 deploy agent/other 2>&1480relay # [95706.880575] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:19.690958Z","level":"INFO","message":"deploy finished","job":"9488318adb2b10dad1c69cb6d17fe497","ok":true,"target":"flakelet_relay::relay::api"}481relay # [95706.995167] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:19.805582Z","level":"INFO","message":"deploy accepted","job":"baa7b5e5f5c4a4e56379911485834116","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}482agent # [95706.878771] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:19.689186Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}483agent # [95706.995658] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:19.806050Z","level":"INFO","message":"start","id":"75400317e3e548f99a817f764d3fc554","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"}484agent # [95706.996358] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:19.806824Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"75400317e3e548f99a817f764d3fc554\"]","target":"flakelet_relay::agent::jobs"}485agent # [95707.034927] agent systemd[1]: Starting flakelet update other (via relay)...486agent # [95707.064891] agent systemd[1]: Started flakelet update other (via relay).487agent # [95707.069060] agent flakelet[1247]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1488agent # [95707.069637] agent flakelet[1247]: other: up to date489agent # [95707.071460] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.490client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTc5OSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MjA2NTQ5OSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiR01BV1JFS0czUkFHSz09PSIsIm5iZiI6MTc5MjA2NTQ5OSwic3ViIjoic29tZW9uZSJ9.AVVpmNcrvCqlyNiINVYAQi3R2yNq_ceej4KJqO3AHm82VBCPGddcBemTKLjARTjNt2d3noNuonDu445XS-GKAw' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)491(finished: subtest: claim principal from groups, unchanged counts as success, in 0.71 seconds)492subtest: push login via device flow, cached token used afterwards493client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1494relay # [95707.614613] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:20.425017Z","level":"INFO","message":"deploy finished","job":"baa7b5e5f5c4a4e56379911485834116","ok":true,"target":"flakelet_relay::relay::api"}495relay # [95707.639939] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [15/Oct/2026 11:58:20] "POST /device HTTP/1.1" 200 -496agent # [95707.613297] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:20.423676Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}497relay # [95708.644884] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [15/Oct/2026 11:58:21] "POST /token HTTP/1.1" 400 -498client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)499client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600500client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)501client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1502relay # [95709.700341] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [15/Oct/2026 11:58:22] "POST /token HTTP/1.1" 200 -503relay # [95709.727564] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:22.538005Z","level":"INFO","message":"deploy accepted","job":"c7c10300a73aa8e41d347a138f0a1455","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}504agent # [95709.728066] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:22.538415Z","level":"INFO","message":"start","id":"e64426edf99c93fae9cce739b47ffb27","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}505agent # [95709.728929] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:22.539188Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"e64426edf99c93fae9cce739b47ffb27\"]","target":"flakelet_relay::agent::jobs"}506agent # [95709.765383] agent systemd[1]: Starting flakelet update other (via relay)...507agent # [95709.795822] agent systemd[1]: Started flakelet update other (via relay).508agent # [95709.799420] agent flakelet[1271]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1509agent # [95709.799982] agent flakelet[1271]: other: up to date510agent # [95709.801730] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.511client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.63 seconds)512client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1513relay # [95710.341928] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:23.152315Z","level":"INFO","message":"deploy finished","job":"c7c10300a73aa8e41d347a138f0a1455","ok":true,"target":"flakelet_relay::relay::api"}514relay # [95710.360054] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:23.170505Z","level":"INFO","message":"deploy accepted","job":"e43c6d6026afeda45ba0183182ef9181","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}515agent # [95710.340318] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.150703Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}516agent # [95710.360315] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.170764Z","level":"INFO","message":"start","id":"d445455317313548dea25275a4121230","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}517agent # [95710.360721] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.171188Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"d445455317313548dea25275a4121230\"]","target":"flakelet_relay::agent::jobs"}518agent # [95710.394627] agent systemd[1]: Starting flakelet update other (via relay)...519agent # [95710.420803] agent systemd[1]: Started flakelet update other (via relay).520agent # [95710.425012] agent flakelet[1295]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1521agent # [95710.425594] agent flakelet[1295]: other: up to date522agent # [95710.427702] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.523client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.62 seconds)524(finished: subtest: push login via device flow, cached token used afterwards, in 3.35 seconds)525subtest: waves: failing first wave skips the second526agent: must succeed: jq '.services.app.prebuilt="/nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json527agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)528client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1529relay # [95710.966615] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:23.776999Z","level":"INFO","message":"deploy finished","job":"e43c6d6026afeda45ba0183182ef9181","ok":true,"target":"flakelet_relay::relay::api"}530relay # [95710.998040] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:23.808473Z","level":"INFO","message":"deploy accepted","job":"66f9d2d59a97704f47ac8bb8b6f55b65","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}531agent # [95710.964873] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.775259Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}532agent # [95710.998284] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.808736Z","level":"INFO","message":"start","id":"2f125d7d30f0650336940d9320a73ebe","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}533agent # [95710.998712] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:23.809181Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2f125d7d30f0650336940d9320a73ebe\"]","target":"flakelet_relay::agent::jobs"}534agent # [95711.036651] agent systemd[1]: Starting flakelet update app (via relay)...535agent # [95711.069882] agent systemd[1]: Started flakelet update app (via relay).536agent # [95711.075338] agent flakelet[1318]: app: using prebuilt artifact /nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken537agent # [95711.076484] agent flakelet[1318]: app: activating generation 4538agent # [95711.093703] agent systemd[1]: Stopping app v1...539agent # [95711.094167] agent systemd[1]: app.service: Deactivated successfully.540agent # [95711.094430] agent systemd[1]: Stopped app v1.541agent # [95711.112976] agent systemd[1]: Reload requested from client PID 1325 ('systemctl') (unit flakelet-relay-job-app.service)...542agent # [95711.113056] agent systemd[1]: Reloading...543agent # [95711.449168] agent systemd[1]: Reloading finished in 335 ms.544agent # [95711.526482] agent systemd[1]: Reload requested from client PID 1355 ('systemctl') (unit flakelet-relay-job-app.service)...545agent # [95711.526521] agent systemd[1]: Reloading...546agent # [95711.849789] agent systemd[1]: Reloading finished in 322 ms.547agent # [95711.939655] agent systemd[1]: Reload requested from client PID 1384 ('systemctl') (unit flakelet-relay-job-app.service)...548agent # [95711.939693] agent systemd[1]: Reloading...549agent # [95712.262884] agent systemd[1]: Reloading finished in 322 ms.550agent # [95712.353897] agent systemd[1]: Reload requested from client PID 1418 ('systemctl') (unit flakelet-relay-job-app.service)...551agent # [95712.353934] agent systemd[1]: Reloading...552agent # [95712.677927] agent systemd[1]: Reloading finished in 323 ms.553agent # [95712.764712] agent systemd[1]: Starting app broken...554agent # [95712.798239] agent (nonexistent)[1449]: app.service: Unable to locate executable '/nonexistent': No such file or directory555agent # [95712.798264] agent (nonexistent)[1449]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory556agent # [95712.799630] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC557agent # [95712.799748] agent systemd[1]: app.service: Failed with result 'exit-code'.558agent # [95712.800108] agent systemd[1]: Failed to start app broken.559agent # [95712.829166] agent systemd[1]: Reload requested from client PID 1455 ('systemctl') (unit flakelet-relay-job-app.service)...560agent # [95712.829243] agent systemd[1]: Reloading...561agent # [95713.161934] agent systemd[1]: Reloading finished in 331 ms.562agent # [95713.241295] agent systemd[1]: Reload requested from client PID 1485 ('systemctl') (unit flakelet-relay-job-app.service)...563agent # [95713.241334] agent systemd[1]: Reloading...564agent # [95713.564346] agent systemd[1]: Reloading finished in 322 ms.565agent # [95713.648969] agent systemd[1]: Reload requested from client PID 1515 ('systemctl') (unit flakelet-relay-job-app.service)...566agent # [95713.649016] agent systemd[1]: Reloading...567agent # [95713.976843] agent systemd[1]: Reloading finished in 327 ms.568agent # [95714.063667] agent systemd[1]: Reload requested from client PID 1545 ('systemctl') (unit flakelet-relay-job-app.service)...569agent # [95714.063706] agent systemd[1]: Reloading...570agent # [95714.388010] agent systemd[1]: Reloading finished in 323 ms.571agent # [95714.471121] agent systemd[1]: Starting app v1...572agent # [95714.509979] agent systemd[1]: Started app v1.573agent # [95714.511186] agent flakelet[1318]: app: deploy failed, rolled back: systemctl start app.service failed:574agent # [95714.511186] agent flakelet[1318]: failed units: app.service. See journalctl -u app.service575agent # [95714.512553] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE576agent # [95714.512651] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.577client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.22 seconds)578agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'579agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.01 seconds)580(finished: subtest: waves: failing first wave skips the second, in 4.25 seconds)581subtest: host patterns expand on the relay582agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json583agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)584client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1585relay # [95715.197734] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:28.008120Z","level":"INFO","message":"deploy finished","job":"66f9d2d59a97704f47ac8bb8b6f55b65","ok":false,"target":"flakelet_relay::relay::api"}586relay # [95715.247928] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:28.058329Z","level":"INFO","message":"deploy accepted","job":"36f450ae6d40cd1328e5ffe2434391bf","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}587agent # [95715.196398] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.006777Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}588agent # [95715.248267] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.058672Z","level":"INFO","message":"start","id":"17e9ecb789af94f596945ce25831b5db","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}589agent # [95715.248740] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.059204Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"17e9ecb789af94f596945ce25831b5db\"]","target":"flakelet_relay::agent::jobs"}590agent # [95715.275608] agent systemd[1]: Starting flakelet update app (via relay)...591agent # [95715.306894] agent systemd[1]: Started flakelet update app (via relay).592agent # [95715.310499] agent flakelet[1605]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1593agent # [95715.311043] agent flakelet[1605]: app: up to date594agent # [95715.312125] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.595client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.62 seconds)596client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1597relay # [95715.846964] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:28.657349Z","level":"INFO","message":"deploy finished","job":"36f450ae6d40cd1328e5ffe2434391bf","ok":true,"target":"flakelet_relay::relay::api"}598relay # [95715.868089] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:28.678541Z","level":"INFO","message":"deploy accepted","job":"3b69f6c8af952f6bf141ce5d7c22eb9b","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}599agent # [95715.845702] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.656105Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}600agent # [95715.868386] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.678850Z","level":"INFO","message":"start","id":"e25022fc49210ab5027de9a850736402","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}601agent # [95715.868576] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:28.679053Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e25022fc49210ab5027de9a850736402\"]","target":"flakelet_relay::agent::jobs"}602agent # [95715.894359] agent systemd[1]: Starting flakelet update app (via relay)...603agent # [95715.928830] agent systemd[1]: Started flakelet update app (via relay).604agent # [95715.932851] agent flakelet[1625]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1605agent # [95715.933442] agent flakelet[1625]: app: up to date606agent # [95715.933963] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.607client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.63 seconds)608client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1609relay # [95716.477643] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:29.288020Z","level":"INFO","message":"deploy finished","job":"3b69f6c8af952f6bf141ce5d7c22eb9b","ok":false,"target":"flakelet_relay::relay::api"}610relay # [95716.500069] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:29.310522Z","level":"INFO","message":"deploy accepted","job":"0b7ab58fa89041c3a2c1590d0d356256","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}611agent # [95716.475921] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.286299Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}612agent # [95716.500381] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.310835Z","level":"INFO","message":"start","id":"84eaf38a482d0d40a818c288fa5142d5","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}613agent # [95716.500784] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.311253Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"84eaf38a482d0d40a818c288fa5142d5\"]","target":"flakelet_relay::agent::jobs"}614agent # [95716.528694] agent systemd[1]: Starting flakelet update app (via relay)...615agent # [95716.554849] agent systemd[1]: Started flakelet update app (via relay).616agent # [95716.559816] agent flakelet[1649]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1617agent # [95716.560699] agent flakelet[1649]: app: up to date618agent # [95716.563572] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.619client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.62 seconds)620client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1621client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)622(finished: subtest: host patterns expand on the relay, in 1.90 seconds)623subtest: detach returns once the job is accepted624agent: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json625agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)626client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1627client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)628agent: waiting for success: systemctl is-active flakelet-relay-job-app.service629relay # [95717.099511] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:29.909889Z","level":"INFO","message":"deploy finished","job":"0b7ab58fa89041c3a2c1590d0d356256","ok":false,"target":"flakelet_relay::relay::api"}630relay # [95717.153705] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:29.964113Z","level":"INFO","message":"deploy accepted","job":"bbc354866452ed623977bcb079ebc369","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}631agent # [95717.098063] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.908381Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}632agent # [95717.153955] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.964351Z","level":"INFO","message":"start","id":"d7bedcb32ad740890f158258cffa65eb","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}633agent # [95717.154426] agent flakelet-agent[511]: {"timestamp":"2026-10-15T11:58:29.964890Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"d7bedcb32ad740890f158258cffa65eb\"]","target":"flakelet_relay::agent::jobs"}634agent # [95717.194279] agent systemd[1]: Starting flakelet update app (via relay)...635agent # [95717.227246] agent systemd[1]: Started flakelet update app (via relay).636agent # [95717.233653] agent flakelet[1673]: app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2637agent # [95717.234804] agent flakelet[1673]: app: activating generation 4638agent # [95717.249606] agent systemd[1]: Stopping app v1...639agent # [95717.250098] agent systemd[1]: app.service: Deactivated successfully.640agent # [95717.250360] agent systemd[1]: Stopped app v1.641agent # [95717.267463] agent systemd[1]: Reload requested from client PID 1680 ('systemctl') (unit flakelet-relay-job-app.service)...642agent # [95717.267530] agent systemd[1]: Reloading...643agent # [95717.607564] agent systemd[1]: Reloading finished in 339 ms.644agent # [95717.689318] agent systemd[1]: Reload requested from client PID 1710 ('systemctl') (unit flakelet-relay-job-app.service)...645agent # [95717.689355] agent systemd[1]: Reloading...646agent # [95718.013771] agent systemd[1]: Reloading finished in 323 ms.647agent # [95718.082459] agent systemd[1]: Reload requested from client PID 1739 ('systemctl') (unit flakelet-relay-job-app.service)...648agent # [95718.082494] agent systemd[1]: Reloading...649agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.34 seconds)650??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.651 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39652agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service653??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.654 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39655agent # [95718.410444] agent systemd[1]: Reloading finished in 327 ms.656agent # [95718.498461] agent systemd[1]: Reload requested from client PID 1774 ('systemctl') (unit flakelet-relay-job-app.service)...657agent # [95718.498497] agent systemd[1]: Reloading...658agent # [95718.824881] agent systemd[1]: Reloading finished in 326 ms.659agent # [95718.898712] agent systemd[1]: Starting app slow2...660agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 6.48 seconds)661(finished: subtest: detach returns once the job is accepted, in 7.85 seconds)662subtest: unknown host is final, missing agent is retried, agents listing663client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1664client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)665agent: must succeed: systemctl stop flakelet-agent666agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.06 seconds)667relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'668relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)669client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &670client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)671client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out672relay # [95725.005733] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:37.816137Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}673agent # [95724.959849] agent systemd[1]: Started app slow2.674agent # [95724.968249] agent flakelet[1673]: app: updated to generation 4675agent # [95724.970692] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.676agent # [95725.005318] agent systemd[1]: Stopping flakelet-agent...677agent # [95725.036234] agent systemd[1]: flakelet-agent.service: Deactivated successfully.678agent # [95725.036515] agent systemd[1]: Stopped flakelet-agent.679agent # [95725.036822] agent systemd[1]: flakelet-agent.service: Consumed 1.644s CPU time over 27.008s wall clock time.680client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)681agent: must succeed: systemctl start flakelet-agent682agent: (finished: must succeed: systemctl start flakelet-agent, in 0.09 seconds)683??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.684 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39685client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out686agent # [95726.107544] agent systemd[1]: Starting flakelet-agent...687agent # [95726.163141] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:38.973583Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"d7bedcb32ad740890f158258cffa65eb\"]","target":"flakelet_relay::agent::jobs"}688agent # [95726.185822] agent systemd[1]: Started flakelet-agent.689agent # [95726.193067] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:39.003529Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}690relay # [95726.193174] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:39.003567Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}691agent # [95726.705165] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:39.515488Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}692relay # [95728.092666] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:40.903044Z","level":"INFO","message":"deploy accepted","job":"9cdd32f0c34c71be059ff78f95d203ae","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}693agent # [95728.093103] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:40.903457Z","level":"INFO","message":"start","id":"3d1333384bb8829ecc5e93b9839ace86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}694agent # [95728.093706] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:40.904174Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3d1333384bb8829ecc5e93b9839ace86\"]","target":"flakelet_relay::agent::jobs"}695agent # [95728.134313] agent systemd[1]: Starting flakelet update other (via relay)...696agent # [95728.161867] agent systemd[1]: Started flakelet update other (via relay).697agent # [95728.166512] agent flakelet[2251]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1698agent # [95728.167106] agent flakelet[2251]: other: up to date699agent # [95728.168900] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.700relay # [95728.712267] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:41.522651Z","level":"INFO","message":"deploy finished","job":"9cdd32f0c34c71be059ff78f95d203ae","ok":true,"target":"flakelet_relay::relay::api"}701agent # [95728.710545] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:41.520933Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}702client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)703client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents704client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)705client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)706client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)707client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTgyMiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTIyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJJN0hWNktCNUQ3N1VRPT09IiwibmJmIjoxNzkyMDY1NTIyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Mgo6RnzkBvqduWF1-KnntLSe6XVlzvak6BzsxdMqmL6vaq4MEGquF7SfiXHAk8gFbEiRfGcsb0SNf_VmzuhgDw' push --relay https://relay:7443 agents708client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTgyMiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTIyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJJN0hWNktCNUQ3N1VRPT09IiwibmJmIjoxNzkyMDY1NTIyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Mgo6RnzkBvqduWF1-KnntLSe6XVlzvak6BzsxdMqmL6vaq4MEGquF7SfiXHAk8gFbEiRfGcsb0SNf_VmzuhgDw' push --relay https://relay:7443 agents, in 0.02 seconds)709(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.35 seconds)710subtest: out-of-band flakelet update reaches the relay without reconnect711agent: must succeed: flakelet status --json app | jq '.[0].generation'712agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.03 seconds)713agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true714agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)715agent: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json716agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)717agent: must succeed: flakelet update app718app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2719app: activating generation 5720agent # [95729.397961] agent systemd[1]: Stopping app slow2...721agent # [95729.399739] agent systemd[1]: app.service: Deactivated successfully.722agent # [95729.400079] agent systemd[1]: Stopped app slow2.723agent # [95729.415152] agent systemd[1]: Reload requested from client PID 2285 ('systemctl')...724agent # [95729.415219] agent systemd[1]: Reloading...725agent # [95729.753197] agent systemd[1]: Reloading finished in 337 ms.726agent # [95729.819580] agent systemd[1]: Reload requested from client PID 2314 ('systemctl')...727agent # [95729.819617] agent systemd[1]: Reloading...728agent # [95730.143970] agent systemd[1]: Reloading finished in 323 ms.729agent # [95730.222482] agent systemd[1]: Reload requested from client PID 2344 ('systemctl')...730agent # [95730.222518] agent systemd[1]: Reloading...731agent # [95730.548149] agent systemd[1]: Reloading finished in 325 ms.732agent # [95730.633984] agent systemd[1]: Reload requested from client PID 2375 ('systemctl')...733agent # [95730.634026] agent systemd[1]: Reloading...734agent: (finished: must succeed: flakelet update app, in 1.71 seconds)735client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'736agent # [95730.958723] agent systemd[1]: Reloading finished in 324 ms.737agent # [95731.042377] agent systemd[1]: Starting app v2...738agent # [95731.071814] agent systemd[1]: Started app v2.739agent # [95732.212778] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:45.023172Z","level":"INFO","message":"local change","flakelet":"app","generation":5,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}740client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.07 seconds)741agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true742agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)743client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-744client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-, in 0.02 seconds)745client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-746client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-, in 0.02 seconds)747agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json748agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)749agent: must succeed: flakelet update app750app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1751app: activating generation 6752agent # [95733.239423] agent systemd[1]: Stopping app v2...753agent # [95733.241239] agent systemd[1]: app.service: Deactivated successfully.754agent # [95733.241566] agent systemd[1]: Stopped app v2.755agent # [95733.258223] agent systemd[1]: Reload requested from client PID 2421 ('systemctl')...756agent # [95733.258292] agent systemd[1]: Reloading...757agent # [95733.598889] agent systemd[1]: Reloading finished in 339 ms.758agent # [95733.679815] agent systemd[1]: Reload requested from client PID 2450 ('systemctl')...759agent # [95733.679853] agent systemd[1]: Reloading...760agent # [95734.004284] agent systemd[1]: Reloading finished in 323 ms.761agent # [95734.086270] agent systemd[1]: Reload requested from client PID 2478 ('systemctl')...762agent # [95734.086312] agent systemd[1]: Reloading...763agent # [95734.407654] agent systemd[1]: Reloading finished in 320 ms.764agent # [95734.490139] agent systemd[1]: Reload requested from client PID 2511 ('systemctl')...765agent # [95734.490177] agent systemd[1]: Reloading...766agent # [95734.813200] agent systemd[1]: Reloading finished in 322 ms.767agent: (finished: must succeed: flakelet update app, in 1.73 seconds)768client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'769agent # [95734.897979] agent systemd[1]: Starting app v1...770agent # [95734.929912] agent systemd[1]: Started app v1.771agent # [95736.215233] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:49.025625Z","level":"INFO","message":"local change","flakelet":"app","generation":6,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}772client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.07 seconds)773(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.68 seconds)774subtest: certificate not listed under agents cannot connect as agent775client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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/agent776client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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.03 seconds)777(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)778subtest: metrics779relay: must succeed: curl -sf http://127.0.0.1:7400/metrics780relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)781(finished: subtest: metrics, in 0.01 seconds)782subtest: agent link drop mid-run replays missed lines once783agent: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json784agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)785agent: must succeed: date +%s786agent: (finished: must succeed: date +%s, in 0.01 seconds)787client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &788client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)789agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065529 | grep -q 'app-slow'790relay # [95737.030653] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:49.841022Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}791relay # [95737.089167] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:49.899562Z","level":"INFO","message":"deploy accepted","job":"544b3b5f3125fd5df3af5a4c01095332","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}792agent # [95737.089513] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:49.899946Z","level":"INFO","message":"start","id":"ff806b393da2655286ee5b8b28ad4f54","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}793agent # [95737.089881] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:49.900359Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ff806b393da2655286ee5b8b28ad4f54\"]","target":"flakelet_relay::agent::jobs"}794agent # [95737.128045] agent systemd[1]: Starting flakelet update app (via relay)...795agent # [95737.157842] agent systemd[1]: Started flakelet update app (via relay).796agent # [95737.162104] agent flakelet[2560]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow797agent # [95737.162752] agent flakelet[2560]: app: activating generation 7798agent # [95737.182318] agent systemd[1]: Stopping app v1...799agent # [95737.182753] agent systemd[1]: app.service: Deactivated successfully.800agent # [95737.183028] agent systemd[1]: Stopped app v1.801agent # [95737.199751] agent systemd[1]: Reload requested from client PID 2567 ('systemctl') (unit flakelet-relay-job-app.service)...802agent # [95737.199816] agent systemd[1]: Reloading...803agent # [95737.536977] agent systemd[1]: Reloading finished in 336 ms.804agent # [95737.609535] agent systemd[1]: Reload requested from client PID 2597 ('systemctl') (unit flakelet-relay-job-app.service)...805agent # [95737.609569] agent systemd[1]: Reloading...806agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065529 | grep -q 'app-slow', in 1.02 seconds)807agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done808agent: (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)809relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done810relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)811agent: must succeed: ss -K dport = 7443812agent # [95737.932526] agent systemd[1]: Reloading finished in 322 ms.813agent # [95738.009406] agent systemd[1]: Reload requested from client PID 2626 ('systemctl') (unit flakelet-relay-job-app.service)...814agent # [95738.009446] agent systemd[1]: Reloading...815agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)816agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065529 | grep -q 'updated to generation'817relay # [95738.174681] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:58:50.985056Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}818agent # [95738.205652] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:51.015909Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}819agent # [95738.335772] agent systemd[1]: Reloading finished in 325 ms.820agent # [95738.407622] agent systemd[1]: Reload requested from client PID 2674 ('systemctl') (unit flakelet-relay-job-app.service)...821agent # [95738.407658] agent systemd[1]: Reloading...822agent # [95738.730253] agent systemd[1]: Reloading finished in 322 ms.823agent # [95738.799361] agent systemd[1]: Starting app slow...824agent # [95739.208261] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:52.018654Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}825agent # [95741.210919] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:54.021305Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}826agent # [95744.865809] agent systemd[1]: Started app slow.827agent # [95744.875758] agent flakelet[2560]: app: updated to generation 7828agent # [95744.877771] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.829agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065529 | grep -q 'updated to generation', in 7.10 seconds)830agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done831agent: (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)832client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out833agent # [95745.213333] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:58.023719Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}834agent # [95745.991066] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:58:58.801446Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}835client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.10 seconds)836client: must succeed: cat /tmp/slow.out837client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)838(finished: subtest: agent link drop mid-run replays missed lines once, in 16.40 seconds)839subtest: agent restart mid-run reattaches to the unit840agent: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json841agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)842client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &843client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)844agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'845relay # [95753.218049] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:06.028423Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}846relay # [95753.219665] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:06.030101Z","level":"INFO","message":"deploy finished","job":"544b3b5f3125fd5df3af5a4c01095332","ok":true,"target":"flakelet_relay::relay::api"}847agent # [95753.217947] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:59:06.028330Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}848relay # [95753.482617] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:06.292850Z","level":"INFO","message":"deploy accepted","job":"5ca34ffc7f343f4c36eee021f8a9486e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}849agent # [95753.219164] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:59:06.029630Z","level":"INFO","message":"start","id":"ff806b393da2655286ee5b8b28ad4f54","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}850agent # [95753.483175] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:59:06.293303Z","level":"INFO","message":"start","id":"2a5a458516fb1707bd9d2f598d109143","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}851agent # [95753.483672] agent flakelet-agent[1838]: {"timestamp":"2026-10-15T11:59:06.294132Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2a5a458516fb1707bd9d2f598d109143\"]","target":"flakelet_relay::agent::jobs"}852agent # [95753.523364] agent systemd[1]: Starting flakelet update app (via relay)...853agent # [95753.554840] agent systemd[1]: Started flakelet update app (via relay).854agent # [95753.559183] agent flakelet[2796]: app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2855agent # [95753.559897] agent flakelet[2796]: app: activating generation 8856agent # [95753.577103] agent systemd[1]: Stopping app slow...857agent # [95753.578746] agent systemd[1]: app.service: Deactivated successfully.858agent # [95753.579014] agent systemd[1]: Stopped app slow.859agent # [95753.594641] agent systemd[1]: Reload requested from client PID 2803 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [95753.594706] agent systemd[1]: Reloading...861agent # [95753.931584] agent systemd[1]: Reloading finished in 336 ms.862agent # [95754.020109] agent systemd[1]: Reload requested from client PID 2833 ('systemctl') (unit flakelet-relay-job-app.service)...863agent # [95754.020146] agent systemd[1]: Reloading...864agent # [95754.345417] agent systemd[1]: Reloading finished in 324 ms.865agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)866agent: must succeed: systemctl restart flakelet-agent867agent # [95754.421078] agent systemd[1]: Reload requested from client PID 2864 ('systemctl') (unit flakelet-relay-job-app.service)...868agent # [95754.421116] agent systemd[1]: Reloading...869relay # [95754.825244] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:07.635647Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}870agent # [95754.746812] agent systemd[1]: Reloading finished in 325 ms.871agent # [95754.824936] agent systemd[1]: Stopping flakelet-agent...872agent # [95754.832867] agent systemd[1]: Reload requested from client PID 2901 ('systemctl') (unit flakelet-relay-job-app.service)...873agent # [95754.832905] agent systemd[1]: Reloading...874agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.83 seconds)875agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"876agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)877client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out878relay # [95755.338543] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:08.148932Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}879agent # [95755.162242] agent systemd[1]: Reloading finished in 328 ms.880agent # [95755.227038] agent systemd[1]: flakelet-agent.service: Deactivated successfully.881agent # [95755.227234] agent systemd[1]: Stopped flakelet-agent.882agent # [95755.227252] agent systemd[1]: flakelet-agent.service: Consumed 1.398s CPU time over 29.119s wall clock time.883agent # [95755.245323] agent systemd[1]: Starting app slow2...884agent # [95755.246240] agent systemd[1]: Starting flakelet-agent...885agent # [95755.307634] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:08.118087Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"2a5a458516fb1707bd9d2f598d109143\"]","target":"flakelet_relay::agent::jobs"}886agent # [95755.327945] agent systemd[1]: Started flakelet-agent.887agent # [95755.338361] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:08.148817Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}888agent # [95755.339614] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:08.150093Z","level":"INFO","message":"start","id":"2a5a458516fb1707bd9d2f598d109143","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}889agent # [95761.316875] agent systemd[1]: Started app slow2.890agent # [95761.327537] agent flakelet[2796]: app: updated to generation 8891agent # [95761.329506] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.892relay # [95761.898373] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:14.708737Z","level":"INFO","message":"deploy finished","job":"5ca34ffc7f343f4c36eee021f8a9486e","ok":true,"target":"flakelet_relay::relay::api"}893agent # [95761.896635] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:14.707016Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}894client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)895client: must succeed: cat /tmp/restart.out896client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)897agent: must succeed: systemctl is-active app.service898agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)899(finished: subtest: agent restart mid-run reattaches to the unit, in 9.00 seconds)900subtest: relay restart mid-run, push resumes via /v1/jobs901agent: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json902agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)903agent: must succeed: date +%s904agent: (finished: must succeed: date +%s, in 0.01 seconds)905client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &906client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)907agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065555 | grep -q 'app-slow'908relay # [95762.491821] relay flakelet-relay[400]: {"timestamp":"2026-10-15T11:59:15.302200Z","level":"INFO","message":"deploy accepted","job":"42ab5f7004fc54b629f9b39b801005b6","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}909agent # [95762.492193] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:15.302620Z","level":"INFO","message":"start","id":"c93f39e6f43b885aeec377acaaea27b7","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}910agent # [95762.492780] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:15.303249Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"c93f39e6f43b885aeec377acaaea27b7\"]","target":"flakelet_relay::agent::jobs"}911agent # [95762.528669] agent systemd[1]: Starting flakelet update app (via relay)...912agent # [95762.557824] agent systemd[1]: Started flakelet update app (via relay).913agent # [95762.562062] agent flakelet[3378]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow914agent # [95762.562708] agent flakelet[3378]: app: activating generation 9915agent # [95762.581574] agent systemd[1]: Stopping app slow2...916agent # [95762.583283] agent systemd[1]: app.service: Deactivated successfully.917agent # [95762.583622] agent systemd[1]: Stopped app slow2.918agent # [95762.600176] agent systemd[1]: Reload requested from client PID 3385 ('systemctl') (unit flakelet-relay-job-app.service)...919agent # [95762.600243] agent systemd[1]: Reloading...920agent # [95762.940032] agent systemd[1]: Reloading finished in 339 ms.921agent # [95763.014823] agent systemd[1]: Reload requested from client PID 3415 ('systemctl') (unit flakelet-relay-job-app.service)...922agent # [95763.014858] agent systemd[1]: Reloading...923agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1792065555 | grep -q 'app-slow', in 1.02 seconds)924relay: must succeed: systemctl restart flakelet-relay925agent # [95763.337786] agent systemd[1]: Reloading finished in 322 ms.926agent # [95763.418329] agent systemd[1]: Reload requested from client PID 3446 ('systemctl') (unit flakelet-relay-job-app.service)...927agent # [95763.418366] agent systemd[1]: Reloading...928agent # [95763.514831] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:16.325236Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}929relay # [95763.513975] relay systemd[1]: Stopping flakelet-relay...930relay # [95763.547691] relay systemd[1]: flakelet-relay.service: Deactivated successfully.931relay # [95763.548103] relay systemd[1]: Stopped flakelet-relay.932relay # [95763.548148] relay systemd[1]: flakelet-relay.service: Consumed 2.287s CPU time over 1min 7.342s wall clock time.933relay # [95763.585125] relay systemd[1]: Starting flakelet-relay...934agent # [95763.753612] agent systemd[1]: Reloading finished in 334 ms.935agent # [95763.841634] agent systemd[1]: Reload requested from client PID 3482 ('systemctl') (unit flakelet-relay-job-app.service)...936agent # [95763.841670] agent systemd[1]: Reloading...937agent # [95764.171423] agent systemd[1]: Reloading finished in 329 ms.938agent # [95764.229673] agent systemd[1]: Starting app slow...939agent # [95764.518503] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:17.328705Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}940relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.47 seconds)941client: waiting for success: grep -q '» ok' /tmp/resume.out942relay # [95764.966242] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:17.776605Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}943relay # [95764.967203] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:17.777073Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}944relay # [95764.966809] relay systemd[1]: Started flakelet-relay.945relay # [95766.532693] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:19.343062Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}946agent # [95766.532529] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:19.342902Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}947agent # [95770.294888] agent systemd[1]: Started app slow.948agent # [95770.303934] agent flakelet[3378]: app: updated to generation 9949agent # [95770.305967] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.950relay # [95770.532391] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:23.342757Z","level":"INFO","message":"job reattached","job":"42ab5f7004fc54b629f9b39b801005b6","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}951agent # [95771.426966] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:24.237339Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}952client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.09 seconds)953client: must succeed: cat /tmp/resume.out954client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)955(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.62 seconds)956subtest: job history comes from the agents and survives a relay restart957client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1958relay # [95772.086805] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:24.897180Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}959agent # [95772.087333] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:24.897712Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}960agent # [95772.087984] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:24.898446Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}961agent # [95772.130815] agent systemd[1]: Starting flakelet update other (via relay)...962agent # [95772.161853] agent systemd[1]: Started flakelet update other (via relay).963agent # [95772.166786] agent flakelet[3556]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1964agent # [95772.167411] agent flakelet[3556]: other: up to date965agent # [95772.169631] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.966client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.65 seconds)967relay: must succeed: systemctl restart flakelet-relay968relay # [95772.709290] relay flakelet-relay[932]: {"timestamp":"2026-10-15T11:59:25.519687Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}969relay # [95772.726643] relay systemd[1]: Stopping flakelet-relay...970relay # [95772.764134] relay systemd[1]: flakelet-relay.service: Deactivated successfully.971relay # [95772.764625] relay systemd[1]: Stopped flakelet-relay.972relay # [95772.764671] relay systemd[1]: flakelet-relay.service: Consumed 2.372s CPU time over 9.179s wall clock time.973relay # [95772.800579] relay systemd[1]: Starting flakelet-relay...974agent # [95772.707396] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:25.517775Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}975agent # [95772.726736] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:25.537187Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}976agent # [95773.730156] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:26.540488Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}977relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.46 seconds)978relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'979relay # [95774.166598] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:26.976988Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}980relay # [95774.167500] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:26.977396Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}981relay # [95774.167160] relay systemd[1]: Started flakelet-relay.982relay # [95775.744676] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:28.555034Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}983agent # [95775.744510] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:28.554881Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}984relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds)985client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs986client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)987client: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)988client: (finished: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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.06 seconds)989client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTg2OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTY5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMUkRTRFlZUjJHSEhLPT09IiwibmJmIjoxNzkyMDY1NTY5LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.OXE3UETKmnvJriDn-qsi0-mf6uxTHsr3fNQ5Icgc4H8-Il8yj8J3qwg2UgV4eTJi1TVpYAiQlDnY_RoacU3IBQ' push --relay https://relay:7443 deploy --id hist2 agent/app990» job 6a239dbf87cfec796e49404c351d787f via relay 0.1.0 (agents: agent 0.1.0)991» wave 0992agent/app | Starting flakelet update app (via relay)...993agent/app | Started flakelet update app (via relay).994agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow995agent/app | app: up to date996agent/app | flakelet-relay-job-app.service: Deactivated successfully.997relay # [95776.325600] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:29.136002Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}998agent # [95776.326106] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:29.136467Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"}999agent # [95776.326735] agent flakelet-agent[2933]: {"timestamp":"2026-10-15T11:59:29.137196Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}1000agent # [95776.365901] agent systemd[1]: Starting flakelet update app (via relay)...1001agent # [95776.395926] agent systemd[1]: Started flakelet update app (via relay).1002agent # [95776.399676] agent flakelet[3584]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1003agent # [95776.400249] agent flakelet[3584]: app: up to date1004agent # [95776.402061] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.1005» agent/app: unchanged (generation 9)1006» ok1007client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTg2OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTY5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMUkRTRFlZUjJHSEhLPT09IiwibmJmIjoxNzkyMDY1NTY5LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.OXE3UETKmnvJriDn-qsi0-mf6uxTHsr3fNQ5Icgc4H8-Il8yj8J3qwg2UgV4eTJi1TVpYAiQlDnY_RoacU3IBQ' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.64 seconds)1008client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTg2OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTY5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMUkRTRFlZUjJHSEhLPT09IiwibmJmIjoxNzkyMDY1NTY5LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.OXE3UETKmnvJriDn-qsi0-mf6uxTHsr3fNQ5Icgc4H8-Il8yj8J3qwg2UgV4eTJi1TVpYAiQlDnY_RoacU3IBQ' push --relay https://relay:7443 jobs1009client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MjA2NTg2OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkyMDY1NTY5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMUkRTRFlZUjJHSEhLPT09IiwibmJmIjoxNzkyMDY1NTY5LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.OXE3UETKmnvJriDn-qsi0-mf6uxTHsr3fNQ5Icgc4H8-Il8yj8J3qwg2UgV4eTJi1TVpYAiQlDnY_RoacU3IBQ' push --relay https://relay:7443 jobs, in 0.02 seconds)1010(finished: subtest: job history comes from the agents and survives a relay restart, in 4.91 seconds)1011subtest: dashboard login via authorization code flow1012client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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'1013client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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)1014client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login1015client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds)1016client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs1017client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)1018!!! Test "dashboard login via authorization code flow" failed with error: ""1019cleanup1020kill NspawnMachine (pid 52)1021kill NspawnMachine (pid 53)1022Container agent terminated by signal KILL.1023kill NspawnMachine (pid 56)1024Container client terminated by signal KILL.1025relay # [95776.945821] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:29.756185Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1026relay # [95777.022502] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [15/Oct/2026 11:59:29] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=rOl6w7fIBliO_2kMBsLmvNvJHcORvvQsZvcGFCfkx54&code_challenge=YH3FG2IUAySpdvVN58RdDvUk7CzC_z58g5yfi9aGFBg&code_challenge_method=S256 HTTP/1.1" 302 -1027relay # [95777.072443] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [15/Oct/2026 11:59:29] "POST /token HTTP/1.1" 200 -1028relay # [95777.073299] relay flakelet-relay[1322]: {"timestamp":"2026-10-15T11:59:29.883741Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1029Container relay terminated by signal KILL.1030(finished: cleanup, in 0.39 seconds)1031additionally exposed symbols:1032 agent, client, relay,1033 vlan1,1034 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_ssh1035» job 3412571728039b4fa01e12d182524ba0 via relay 0.1.0 (agents: agent 0.1.0)1036» wave 01037agent/app | Starting flakelet update app (via relay)...1038agent/app | Started flakelet update app (via relay).1039agent/app | app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v21040agent/app | app: activating generation 21041agent/app | app: updated to generation 21042agent/app | flakelet-relay-job-app.service: Deactivated successfully.1043» agent/app: updated (generation 2)1044» ok10451046» job 66f9d2d59a97704f47ac8bb8b6f55b65 via relay 0.1.0 (agents: agent 0.1.0)1047» wave 01048agent/app | Starting flakelet update app (via relay)...1049agent/app | Started flakelet update app (via relay).1050agent/app | app: using prebuilt artifact /nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken1051agent/app | app: activating generation 41052agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1053agent/app | failed units: app.service. See journalctl -u app.service1054agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1055agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1056» agent/app: rolled-back (generation 3)1057agent/app │ Starting app v1...1058agent/app │ Started app v1.1059agent/app │ Stopping app v1...1060agent/app │ app.service: Deactivated successfully.1061agent/app │ Stopped app v1.1062agent/app │ Starting app v2...1063agent/app │ Started app v2.1064agent/app │ Stopping app v2...1065agent/app │ app.service: Deactivated successfully.1066agent/app │ Stopped app v2.1067agent/app │ Starting app v1...1068agent/app │ Started app v1.1069agent/app │ Stopping app v1...1070agent/app │ app.service: Deactivated successfully.1071agent/app │ Stopped app v1.1072agent/app │ Starting app broken...1073agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1074agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1075agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1076agent/app │ app.service: Failed with result 'exit-code'.1077agent/app │ Failed to start app broken.1078agent/app │ Starting app v1...1079agent/app │ Started app v1.1080» skipped: agent/other1081» failed10821083» job 544b3b5f3125fd5df3af5a4c01095332 via relay 0.1.0 (agents: agent 0.1.0)1084» wave 01085agent/app | Starting flakelet update app (via relay)...1086agent/app | Started flakelet update app (via relay).1087agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1088agent/app | app: activating generation 71089agent/app | app: updated to generation 71090agent/app | flakelet-relay-job-app.service: Deactivated successfully.1091» agent/app: updated (generation 7)1092» ok10931094» job 5ca34ffc7f343f4c36eee021f8a9486e via relay 0.1.0 (agents: agent 0.1.0)1095» wave 01096agent/app | Starting flakelet update app (via relay)...1097agent/app | Started flakelet update app (via relay).1098agent/app | app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow21099agent/app | app: activating generation 81100agent/app | app: updated to generation 81101agent/app | flakelet-relay-job-app.service: Deactivated successfully.1102» agent/app: updated (generation 8)1103» ok11041105» job 42ab5f7004fc54b629f9b39b801005b6 via relay 0.1.0 (agents: agent 0.1.0)1106» wave 01107agent/app | Starting flakelet update app (via relay)...1108agent/app | Started flakelet update app (via relay).1109agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1110agent/app | app: activating generation 91111flakelet-push: stream: error reading a body from connection, resuming job 9cef2760ec5344aaf3a98840165ab9ab1112flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1113flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1114flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1115» job 42ab5f7004fc54b629f9b39b801005b6 via relay 0.1.0 (agents: agent 0.1.0)1116» wave 01117agent/app | app: updated to generation 91118agent/app | flakelet-relay-job-app.service: Deactivated successfully.1119» agent/app: updated (generation 9)1120» ok112111221792065564 hist1 admin@example.org agent/other:unchanged11231792065555 9cef2760ec5344aaf3a98840165ab9ab admin@example.org agent/app:updated11241792065546 057c2fa4a37c2362f4df22761774c91f admin@example.org agent/app:updated11251792065529 929a12393a588c8e5e93657a6aec51a6 admin@example.org agent/app:updated11261792065527 local-app-6-1792065527 root (shell) agent/app:updated11271792065523 local-app-5-1792065523 root (shell) agent/app:updated11281792065520 b8d5b112762d47ca9202ed43f6a2719e admin@example.org agent/other:unchanged11291792065509 34a7cb7d3837ddbb3ded34e1fc47e740 admin@example.org agent/app:unchanged11301792065509 548c7362933277ef620bc2f81ca64d84 admin@example.org agent/app:updated11311792065508 b9d4183fbc3fd0b24a83872fd5225684 admin@example.org agent/app:unchanged11321792065508 bb573c472cd04ac274e54e1ee4523a48 admin@example.org agent/app:unchanged11331792065503 74d866c3ca872becaf99077cb0bf1c6e dev@example.org agent/other:unchanged11341792065503 f9aafa715e48fbd85a8bb9a24b075912 admin@example.org agent/app:rolled-back11351792065502 8615e71d27dd2ab00389bbc511e2777d dev@example.org agent/other:unchanged11361792065499 b8a109b38cc5c96d4c296f31b15a175a someone agent/other:unchanged11371792065496 1799ae85597ec8e4928957cedc8c2338 repo:github:example/app:ref:refs/heads/main agent/app:updated11381792065493 35b123532ca2d016db8f764251529554 admin@example.org agent/app:updated11391792065490 local-app-1-1792065490 host activation agent/app:updated11401792065490 local-flakelet-agent-1-1792065490 host activation agent/flakelet-agent:updated11411792065490 local-other-1-1792065490 host activation agent/other:updated11421143Traceback (most recent call last):1144 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/bin/.nixos-test-driver-wrapped", line 9, in <module>1145 sys.exit(main())1146 ~~~~^^1147 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/__init__.py", line 194, in main1148 driver.run_tests()1149 ~~~~~~~~~~~~~~~~^^1150 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 437, in run_tests1151 self.test_script()1152 ~~~~~~~~~~~~~~~~^^1153 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 395, in test_script1154 exec(self.tests, symbols, None)1155 ~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^1156 File "<string>", line 208, in <module>1157AssertionError