container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #27
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9client: systemd-nspawn running (pid 53)10relay: systemd-nspawn running (pid 54)11agent: systemd-nspawn running (pid 52)12client: Waiting for journal at /build/vm-state-client/var/log/journal...13relay: Waiting for journal at /build/vm-state-relay/var/log/journal...14agent: Waiting for journal at /build/vm-state-agent/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(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE22nixos-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.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24░ Spawning container client on /build/vm-state-client.25Note: 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.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 relay on /build/vm-state-relay.28░ Spawning container agent on /build/vm-state-agent.29client # No journal files were found.30client # No journal boot entry found for the specified boot (+0).31agent # No journal files were found.32relay # No journal files were found.33agent # No journal boot entry found for the specified boot (+0).34relay # No journal boot entry found for the specified boot (+0).35client # [10466.394812] client systemd-journald[57]: Journal started36client # [10466.394852] client systemd-journald[57]: Runtime Journal (/run/log/journal/26754fe738a54154966b27186544edcc) is 8M, max 4G, 3.9G free.37client # [10466.402945] client systemd[1]: Finished Apply Kernel Variables.38client # [10466.414527] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39client # [10466.428225] client systemd[1]: Starting Flush Journal to Persistent Storage...40client # [10466.428929] client systemd[1]: Starting Create Static Device Nodes in /dev...41client # [10466.464832] client systemd-journald[57]: Time spent on flushing to /var/log/journal/26754fe738a54154966b27186544edcc is 1.375ms for 6 entries.42client # [10466.464832] client systemd-journald[57]: System Journal (/var/log/journal/26754fe738a54154966b27186544edcc) is 512B, max 4G, 3.9G free.43client # [10466.473840] client systemd[1]: Finished Create Static Device Nodes in /dev.44client # [10466.474524] client systemd[1]: Reached target Preparation for Local File Systems.45client # [10466.474637] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46client # [10466.486512] client systemd[1]: Finished Flush Journal to Persistent Storage.47client # [10466.539989] client systemd[1]: Finished Firewall.48client # [10467.426749] client systemd[1]: Mounting /run/wrappers...49client # [10467.447872] client systemd[1]: Mounted /run/wrappers.50client # [10467.448554] client systemd[1]: Reached target Local File Systems.51client # [10467.449286] client systemd[1]: Listening on Boot Loader Control Service Socket.52client # [10467.450326] client systemd[1]: Starting Create SUID/SGID Wrappers...53client # [10467.450351] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container54client # [10467.451379] client systemd[1]: Starting Save Transient machine-id to Disk...55client # [10467.452200] client systemd[1]: Starting Create System Files and Directories...56relay # [10466.398082] relay systemd-journald[57]: Journal started57agent # [10466.401076] agent systemd-journald[57]: Journal started58relay # [10466.398123] relay systemd-journald[57]: Runtime Journal (/run/log/journal/157625e1091a4b659b2f7e7dab3aa2e6) is 8M, max 4G, 3.9G free.59agent # [10466.401119] agent systemd-journald[57]: Runtime Journal (/run/log/journal/799cd12fd6b34bd392800e8f47ad56cd) is 8M, max 4G, 3.9G free.60relay # [10466.407381] relay systemd[1]: Finished Apply Kernel Variables.61agent # [10466.411983] agent systemd[1]: Finished Apply Kernel Variables.62relay # [10466.418759] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.63agent # [10466.423835] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.64relay # [10466.459441] relay systemd[1]: Starting Flush Journal to Persistent Storage...65agent # [10466.459736] agent systemd[1]: Starting Flush Journal to Persistent Storage...66relay # [10466.460086] relay systemd[1]: Starting Create Static Device Nodes in /dev...67agent # [10466.460403] agent systemd[1]: Starting Create Static Device Nodes in /dev...68relay # [10466.468439] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/157625e1091a4b659b2f7e7dab3aa2e6 is 1.383ms for 6 entries.69agent # [10466.468465] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/799cd12fd6b34bd392800e8f47ad56cd is 1.371ms for 6 entries.70relay # [10466.468439] relay systemd-journald[57]: System Journal (/var/log/journal/157625e1091a4b659b2f7e7dab3aa2e6) is 512B, max 4G, 3.9G free.71agent # [10466.468465] agent systemd-journald[57]: System Journal (/var/log/journal/799cd12fd6b34bd392800e8f47ad56cd) is 512B, max 4G, 3.9G free.72relay # [10466.477731] relay systemd[1]: Finished Flush Journal to Persistent Storage.73agent # [10466.477679] agent systemd[1]: Finished Create Static Device Nodes in /dev.74relay # [10466.478072] relay systemd[1]: Finished Create Static Device Nodes in /dev.75agent # [10466.478444] agent systemd[1]: Reached target Preparation for Local File Systems.76relay # [10466.479339] relay systemd[1]: Reached target Preparation for Local File Systems.77agent # [10466.478571] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys78relay # [10466.479455] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys79agent # [10466.490867] agent systemd[1]: Finished Flush Journal to Persistent Storage.80relay # [10466.566433] relay systemd[1]: Finished Firewall.81agent # [10466.552314] agent systemd[1]: Finished Firewall.82relay # [10467.397132] relay systemd[1]: Mounting /run/wrappers...83agent # [10467.426772] agent systemd[1]: Mounting /run/wrappers...84relay # [10467.457901] relay systemd[1]: Mounted /run/wrappers.85agent # [10467.458263] agent systemd[1]: Mounted /run/wrappers.86relay # [10467.458962] relay systemd[1]: Reached target Local File Systems.87agent # [10467.459320] agent systemd[1]: Reached target Local File Systems.88relay # [10467.460339] relay systemd[1]: Listening on Boot Loader Control Service Socket.89agent # [10467.460653] agent systemd[1]: Listening on Boot Loader Control Service Socket.90relay # [10467.461700] relay systemd[1]: Starting Create SUID/SGID Wrappers...91relay # [10467.461751] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container92agent # [10467.461871] agent systemd[1]: Starting Create SUID/SGID Wrappers...93agent # [10467.461914] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container94client # [10467.469748] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted95client # [10467.470171] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted96client # [10467.470478] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/26754fe738a54154966b27186544edcc failed: Operation not permitted97client # [10467.470815] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted98relay # [10467.462835] relay systemd[1]: Starting Save Transient machine-id to Disk...99relay # [10467.464026] relay systemd[1]: Starting Create System Files and Directories...100relay # [10467.482426] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted101relay # [10467.482856] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted102agent # [10467.463025] agent systemd[1]: Starting Save Transient machine-id to Disk...103agent # [10467.464104] agent systemd[1]: Starting Create System Files and Directories...104agent # [10467.483152] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted105relay # [10467.483209] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/157625e1091a4b659b2f7e7dab3aa2e6 failed: Operation not permitted106agent # [10467.483564] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted107relay # [10467.483545] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted108agent # [10467.483891] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/799cd12fd6b34bd392800e8f47ad56cd failed: Operation not permitted109agent # [10467.484240] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110relay # [10467.485196] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.VgxeinNkOq/chsh': Operation not permitted111relay # [10467.491220] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE112relay # [10467.491259] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.113relay # [10467.491314] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.114relay # [10467.491642] relay systemd[1]: Finished Create System Files and Directories.115relay # [10467.505763] relay systemd[1]: Starting Rebuild Journal Catalog...116relay # [10467.506532] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...117relay # [10467.517872] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.118relay # [10467.523064] relay systemd[1]: Finished Rebuild Journal Catalog.119relay # [10467.524052] relay systemd[1]: Starting Update is Completed...120relay # [10467.532019] relay systemd[1]: Finished Update is Completed.121relay # [10467.532089] relay systemd[1]: Reached target System Initialization.122relay # [10467.532150] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123relay # [10467.532173] relay systemd[1]: Started Daily Cleanup of Temporary Directories.124relay # [10467.532187] relay systemd[1]: Reached target Timer Units.125relay # [10467.532277] relay systemd[1]: Listening on D-Bus System Message Bus Socket.126relay # [10467.532448] relay systemd[1]: Listening on Nix Daemon Socket.127relay # [10467.532542] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128relay # [10467.532553] relay systemd[1]: Reached target Socket Units.129relay # [10467.532581] relay systemd[1]: Reached target Basic System.130relay # [10467.533649] relay systemd[1]: Started device-mock.service.131relay # [10467.534329] relay systemd[1]: Starting Re-link flakelet services at boot...132relay # [10467.535019] relay systemd[1]: Starting Import lastlog data into lastlog2 database...133relay # [10467.535857] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...134relay # [10467.536587] relay systemd[1]: Starting resolvconf update...135relay # [10467.543639] relay systemd[1]: Finished Re-link flakelet services at boot.136relay # [10467.545570] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...137relay # [10467.550959] relay systemd[1]: Finished Import lastlog data into lastlog2 database.138relay # [10467.663666] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.139client # [10467.472969] client systemd[1]: Finished Create System Files and Directories.140client # [10467.475591] client suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.kGfFVRbs50/chsh': Operation not permitted141client # [10467.485722] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE142client # [10467.485814] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.143client # [10467.485950] client systemd[1]: Failed to start Create SUID/SGID Wrappers.144client # [10467.487577] client systemd[1]: Starting Rebuild Journal Catalog...145client # [10467.488282] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...146client # [10467.499648] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.147client # [10467.505255] client systemd[1]: Finished Rebuild Journal Catalog.148client # [10467.506632] client systemd[1]: Starting Update is Completed...149client # [10467.517509] client systemd[1]: Finished Update is Completed.150client # [10467.517575] client systemd[1]: Reached target System Initialization.151client # [10467.517635] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container152client # [10467.517657] client systemd[1]: Started Daily Cleanup of Temporary Directories.153client # [10467.517671] client systemd[1]: Reached target Timer Units.154client # [10467.517766] client systemd[1]: Listening on D-Bus System Message Bus Socket.155client # [10467.517941] client systemd[1]: Listening on Nix Daemon Socket.156client # [10467.518049] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.157client # [10467.518062] client systemd[1]: Reached target Socket Units.158client # [10467.518089] client systemd[1]: Reached target Basic System.159client # [10467.519233] client systemd[1]: Starting Import lastlog data into lastlog2 database...160client # [10467.520167] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...161client # [10467.520994] client systemd[1]: Starting resolvconf update...162client # [10467.538510] client systemd[1]: Finished Import lastlog data into lastlog2 database.163client # [10467.601913] client systemd[1]: Finished resolvconf update.164client # [10467.602060] client systemd[1]: Reached target Preparation for Network.165client # [10467.605035] client systemd[1]: Starting Address configuration of eth1...166client # [10467.606836] client systemd[1]: Starting Extra networking commands....167client # [10467.612497] client systemd[1]: nscd.service: Deactivated successfully.168client # [10467.639258] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).169client # [10467.656318] client network-addresses-eth1-start[232]: adding address 192.168.1.2/24... done170client # [10467.659608] client network-addresses-eth1-start[232]: adding address 2001:db8:1::2/64... done171client # [10467.664423] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.172client # [10467.665324] client systemd[1]: Finished Save Transient machine-id to Disk.173agent # [10467.485151] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.QHofuk2NeO/chsh': Operation not permitted174client # [10467.665528] client systemd[1]: Finished Address configuration of eth1.175agent # [10467.490620] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE176client # [10467.667800] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...177agent # [10467.490658] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.178agent # [10467.490704] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.179agent # [10467.491261] agent systemd[1]: Finished Create System Files and Directories.180agent # [10467.505384] agent systemd[1]: Starting Rebuild Journal Catalog...181agent # [10467.506434] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...182agent # [10467.516581] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.183agent # [10467.524065] agent systemd[1]: Finished Rebuild Journal Catalog.184agent # [10467.524943] agent systemd[1]: Starting Update is Completed...185agent # [10467.534236] agent systemd[1]: Finished Update is Completed.186agent # [10467.534363] agent systemd[1]: Reached target System Initialization.187agent # [10467.534421] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container188agent # [10467.534444] agent systemd[1]: Started Daily Cleanup of Temporary Directories.189agent # [10467.534458] agent systemd[1]: Reached target Timer Units.190agent # [10467.534552] agent systemd[1]: Listening on D-Bus System Message Bus Socket.191agent # [10467.534748] agent systemd[1]: Listening on Nix Daemon Socket.192agent # [10467.534841] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.193agent # [10467.534853] agent systemd[1]: Reached target Socket Units.194agent # [10467.534881] agent systemd[1]: Reached target Basic System.195agent # [10467.535748] agent systemd[1]: Starting Re-link flakelet services at boot...196agent # [10467.536520] agent systemd[1]: Starting Import lastlog data into lastlog2 database...197agent # [10467.537372] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...198agent # [10467.538022] agent systemd[1]: Starting resolvconf update...199agent # [10467.545719] agent systemd[1]: Finished Re-link flakelet services at boot.200agent # [10467.547727] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...201agent # [10467.568398] agent systemd[1]: Finished Import lastlog data into lastlog2 database.202agent # [10467.664523] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.203agent # [10467.665246] agent systemd[1]: Finished Save Transient machine-id to Disk.204agent # [10467.665379] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.205relay # [10467.664586] relay systemd[1]: Finished Save Transient machine-id to Disk.206relay # [10467.664784] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.207relay # [10467.690892] relay systemd[1]: nscd.service: Deactivated successfully.208relay # [10467.691082] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).209relay # [10467.693345] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...210relay # [10467.709243] relay systemd[1]: Finished resolvconf update.211relay # [10467.709787] relay systemd[1]: Reached target Preparation for Network.212relay # [10467.710759] relay systemd[1]: Starting Address configuration of eth1...213relay # [10467.711401] relay systemd[1]: Starting Extra networking commands....214relay # [10467.734482] relay network-addresses-eth1-start[251]: adding address 192.168.1.3/24... done215relay # [10467.737621] relay network-addresses-eth1-start[251]: adding address 2001:db8:1::3/64... done216relay # [10467.742848] relay systemd[1]: Finished Address configuration of eth1.217relay # [10467.774869] relay systemd[1]: Finished Extra networking commands..218relay # [10467.775434] relay systemd[1]: Reached target Network.219relay # [10467.776714] relay systemd[1]: Starting Dnsmasq Daemon...220relay # [10467.777571] relay systemd[1]: Starting Nginx Web Server...221relay # [10467.778358] relay systemd[1]: Starting Update flakelet service flakelet-relay...222relay # [10467.825371] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/cpk5hkdzplfs93i15agmvg22qdwmlgjg-flakelet-flakelet-relay223relay # [10467.826093] relay flakelet[311]: flakelet-relay: activating generation 1224relay # [10467.829596] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...225relay # [10467.829636] relay systemd[1]: Reloading...226client # [10467.722274] client systemd[1]: nscd.service: Deactivated successfully.227client # [10467.722473] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).228client # [10467.724699] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...229client # [10467.726565] client systemd[1]: Finished Extra networking commands..230client # [10467.726681] client systemd[1]: Reached target Network.231agent # [10467.700168] agent systemd[1]: nscd.service: Deactivated successfully.232agent # [10467.700344] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).233agent # [10467.702615] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...234agent # [10467.711237] agent systemd[1]: Finished resolvconf update.235agent # [10467.711364] agent systemd[1]: Reached target Preparation for Network.236agent # [10467.712040] agent systemd[1]: Starting Address configuration of eth1...237agent # [10467.717219] agent systemd[1]: Starting Extra networking commands....238agent # [10467.733768] agent network-addresses-eth1-start[242]: adding address 192.168.1.1/24... done239agent # [10467.738209] agent network-addresses-eth1-start[242]: adding address 2001:db8:1::1/64... done240agent # [10467.742784] agent systemd[1]: Finished Address configuration of eth1.241agent # [10467.817283] agent systemd[1]: Finished Extra networking commands..242agent # [10467.817432] agent systemd[1]: Reached target Network.243agent # [10467.818637] agent systemd[1]: Starting Update flakelet service app...244agent # [10467.819413] agent systemd[1]: Starting Update flakelet service flakelet-agent...245agent # [10467.820174] agent systemd[1]: Starting Update flakelet service other...246agent # [10467.823751] agent systemd[1]: nscd.service: Deactivated successfully.247agent # [10467.823940] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).248agent # [10467.826461] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...249agent # [10467.830623] agent flakelet[305]: flakelet-agent: using prebuilt artifact /nix/store/3l4q9wb09sz99aw86z6ybrswza7dxk92-flakelet-flakelet-agent250agent # [10467.831200] agent flakelet[305]: flakelet-agent: activating generation 1251agent # [10467.831451] agent flakelet[304]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1252agent # [10467.831644] agent flakelet[306]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1253agent # [10467.832055] agent flakelet[304]: app: activating generation 1254agent # [10467.832140] agent flakelet[306]: other: activating generation 1255agent # [10467.834237] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-flakelet-agent.service)...256agent # [10467.834269] agent systemd[1]: Reloading...257relay # [10468.153526] relay nsncd[240]: Sep 06 09:59:06.115 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"258relay # [10468.229882] relay systemd[1]: Reloading finished in 399 ms.259relay # [10468.365738] relay systemd[1]: Started Name Service Cache Daemon (nsncd).260relay # [10468.366197] relay systemd[1]: Reached target Host and Network Name Lookups.261relay # [10468.366285] relay systemd[1]: Reached target User and Group Name Lookups.262relay # [10468.367720] relay systemd[1]: Starting User Login Management...263relay # [10468.368714] relay systemd[1]: Starting Permit User Sessions...264relay # [10468.387383] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...265relay # [10468.387446] relay systemd[1]: Reloading...266client # [10468.135103] client nsncd[302]: Sep 06 09:59:06.096 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"267client # [10468.135110] client systemd[1]: Started Name Service Cache Daemon (nsncd).268client # [10468.135208] client systemd[1]: Reached target Host and Network Name Lookups.269client # [10468.135318] client systemd[1]: Reached target User and Group Name Lookups.270client # [10468.137882] client systemd[1]: Starting User Login Management...271client # [10468.145132] client systemd[1]: Starting Permit User Sessions...272client # [10468.183335] client systemd[1]: Finished Permit User Sessions.273client # [10468.185691] client systemd[1]: Started Console Getty.274client # [10468.185757] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0275client # [10468.185787] client systemd[1]: Reached target Login Prompts.276agent # [10468.145814] agent nsncd[310]: Sep 06 09:59:06.107 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"277agent # [10468.223974] agent systemd[1]: Reloading finished in 389 ms.278agent # [10468.365087] agent systemd[1]: Started Name Service Cache Daemon (nsncd).279agent # [10468.368451] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-other.service)...280agent # [10468.368498] agent systemd[1]: Reloading...281relay # [10468.422158] relay dnsmasq-pre-start[367]: dnsmasq: syntax check OK.282relay # [10468.746327] relay systemd[1]: Reloading finished in 358 ms.283relay # [10468.888964] relay systemd[1]: Finished Permit User Sessions.284relay # [10468.893043] relay systemd[1]: Started Console Getty.285relay # [10468.893107] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0286relay # [10468.893168] relay systemd[1]: Reached target Login Prompts.287relay # [10468.915659] relay systemd[1]: Starting flakelet-relay...288agent # [10468.751107] agent systemd[1]: Reloading finished in 382 ms.289agent # [10468.893284] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-app.service)...290agent # [10468.893340] agent systemd[1]: Reloading...291agent # [10469.255134] agent systemd[1]: Reloading finished in 361 ms.292agent # [10469.329870] agent systemd[1]: Reached target Host and Network Name Lookups.293agent # [10469.329925] agent systemd[1]: Reached target User and Group Name Lookups.294agent # [10469.331169] agent systemd[1]: Starting User Login Management...295agent # [10469.332126] agent systemd[1]: Starting Permit User Sessions...296agent # [10469.342655] agent systemd[1]: Reload requested from client PID 406 ('systemctl') (unit flakelet-flakelet-agent.service)...297agent # [10469.342689] agent systemd[1]: Reloading...298relay # [10469.334677] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok299relay # [10469.335409] relay nginx-pre-start[402]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful300relay # [10469.359701] relay systemd[1]: Started Nginx Web Server.301relay # [10469.537245] relay systemd[1]: Starting D-Bus System Message Bus...302client # [10469.611129] client systemd-logind[315]: New seat seat0.303client # [10469.612684] client systemd[1]: Starting D-Bus System Message Bus...304client # [10469.612748] client systemd[1]: Started User Login Management.305client # [10469.613847] client systemd[1]: Starting linger-users.service...306client # [10469.647186] client systemd[1]: linger-users.service: Deactivated successfully.307client # [10469.647399] client systemd[1]: Finished linger-users.service.308client # [10469.647524] client systemd[1]: Reached target Multi-User System.309agent # [10469.728120] agent systemd[1]: Reloading finished in 385 ms.310agent # [10469.800623] agent systemd[1]: Finished Permit User Sessions.311agent # [10469.801790] agent systemd[1]: Reload requested from client PID 407 ('systemctl') (unit flakelet-other.service)...312agent # [10469.801836] agent systemd[1]: Reloading...313agent # [10470.157070] agent systemd[1]: Reloading finished in 354 ms.314relay # [10469.901497] relay systemd-logind[354]: New seat seat0.315relay # [10469.901915] relay systemd[1]: Started User Login Management.316relay # [10469.904606] relay systemd[1]: Starting linger-users.service...317relay # [10469.940833] relay systemd[1]: linger-users.service: Deactivated successfully.318relay # [10469.941206] relay systemd[1]: Finished linger-users.service.319relay # [10470.096905] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...320relay # [10470.097958] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'321relay # [10470.097958] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"322relay # [10470.103298] relay systemd[1]: Started D-Bus System Message Bus.323relay # [10470.109273] relay dbus-broker-launch[408]: Ready324relay # [10470.112592] relay systemd[1]: Started Dnsmasq Daemon.325relay # [10470.115358] relay dnsmasq[394]: started, version 2.93 cachesize 150326relay # [10470.115377] 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 dumpfile327relay # [10470.115392] relay dnsmasq[394]: DBus support enabled: connected to system bus328relay # [10470.115408] relay dnsmasq[394]: no upstream servers configured - please set them from DBus329relay # [10470.115556] relay dnsmasq[394]: read /etc/hosts - 9 names330client # [10470.112394] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...331client # [10470.113589] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'332client # [10470.113589] client dbus-broker-launch[325]: Invalid user-name in /nix/store/is9gm7ra4rcq24krd7wzlkcajhnlc3y6-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"333client # [10470.114320] client systemd[1]: Started D-Bus System Message Bus.334client # [10470.114638] client systemd[1]: Startup finished in 4.164s.335client # [10470.121282] client dbus-broker-launch[325]: Ready336agent # [10470.232429] agent systemd[1]: Started Console Getty.337agent # [10470.232551] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0338agent # [10470.232702] agent systemd[1]: Reached target Login Prompts.339agent # [10470.233119] agent systemd[1]: Reload requested from client PID 410 ('systemctl') (unit flakelet-app.service)...340agent # [10470.233143] agent systemd[1]: Reloading...341agent # [10470.573904] agent systemd[1]: Reloading finished in 340 ms.342agent # [10470.637542] agent systemd[1]: Starting flakelet-agent...343agent # [10470.641593] agent systemd[1]: Starting app v1...344agent # [10470.666236] agent systemd[1]: Starting other v1...345agent # [10470.680957] agent systemd-logind[408]: New seat seat0.346agent # [10470.681147] agent systemd[1]: Started other v1.347agent # [10470.681356] agent systemd[1]: Started app v1.348agent # [10470.681604] agent systemd[1]: Started User Login Management.349agent # [10470.684157] agent systemd[1]: Starting D-Bus System Message Bus...350agent # [10470.685378] agent systemd[1]: Starting linger-users.service...351agent # [10470.696601] agent systemd[1]: linger-users.service: Deactivated successfully.352agent # [10470.696722] agent systemd[1]: Finished linger-users.service.353agent # [10470.700442] agent flakelet[304]: app: updated to generation 1354agent # [10470.701864] agent systemd[1]: Finished Update flakelet service app.355agent # [10470.703012] agent flakelet[306]: other: updated to generation 1356agent # [10470.703819] agent systemd[1]: Finished Update flakelet service other.357agent # [10470.745878] agent systemd[1]: Started flakelet-agent.358agent # [10470.749752] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:08.711482Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}359agent # [10470.760531] agent flakelet[305]: flakelet-agent: updated to generation 1360agent # [10470.761464] agent systemd[1]: Finished Update flakelet service flakelet-agent.361agent # [10470.763585] agent systemd[1]: Reached target flakelet managed services.362agent # [10470.763629] agent systemd[1]: Reached target Multi-User System.363relay # [10470.876863] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:08.838489Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}364relay # [10470.877726] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:08.839263Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}365relay # [10470.877518] relay systemd[1]: Started flakelet-relay.366relay # [10470.887684] relay systemd[1]: Starting health for flakelet-relay...367agent # [10471.099088] agent dbus-broker-launch[692]: Looking up NSS user entry for 'systemd-timesync'...368agent # [10471.100361] agent dbus-broker-launch[692]: NSS returned no entry for 'systemd-timesync'369agent # [10471.100361] agent dbus-broker-launch[692]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"370agent # [10471.100886] agent systemd[1]: Started D-Bus System Message Bus.371agent # [10471.101272] agent systemd[1]: Startup finished in 5.141s.372agent # [10471.107082] agent dbus-broker-launch[692]: Ready373relay # [10471.153770] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.374relay # [10471.154148] relay systemd[1]: Finished health for flakelet-relay.375relay # [10471.197129] relay flakelet[311]: flakelet-relay: updated to generation 1376relay # [10471.199843] relay systemd[1]: Finished Update flakelet service flakelet-relay.377relay # [10471.200412] relay systemd[1]: Reached target flakelet managed services.378relay # [10471.200590] relay systemd[1]: Reached target Multi-User System.379relay # [10471.200849] relay systemd[1]: Startup finished in 5.247s.380relay: (finished: waiting for unit flakelet-relay.service, in 6.15 seconds)381relay: waiting for unit nginx.service382relay: (finished: waiting for unit nginx.service, in 0.02 seconds)383agent: waiting for unit flakelet.target384agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)385agent: waiting for unit flakelet-agent.service386agent: (finished: waiting for unit flakelet-agent.service, in 0.01 seconds)387client: waiting for unit multi-user.target388client: (finished: waiting for unit multi-user.target, in 0.02 seconds)389relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'390agent # [10472.769858] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:10.731609Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}391relay # [10472.770307] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:10.731991Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}392relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds)393agent: must succeed: systemctl is-active app.service other.service394agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)395subtest: deploy with client certificate, relay found via SRV396agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json397agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)398client: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1399agent # [10473.790502] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:11.752226Z","level":"INFO","message":"start","id":"18db2e280600fb627e2842598423d6f1","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}400agent # [10473.791412] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:11.753139Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"18db2e280600fb627e2842598423d6f1\"]","target":"flakelet_relay::agent::jobs"}401agent # [10473.857359] agent systemd[1]: Starting flakelet update app (via relay)...402agent # [10473.889155] agent systemd[1]: Started flakelet update app (via relay).403agent # [10473.893108] agent flakelet[960]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2404agent # [10473.893751] agent flakelet[960]: app: activating generation 2405agent # [10473.906807] agent systemd[1]: Stopping app v1...406agent # [10473.907271] agent systemd[1]: app.service: Deactivated successfully.407agent # [10473.907535] agent systemd[1]: Stopped app v1.408agent # [10473.924224] agent systemd[1]: Reload requested from client PID 967 ('systemctl') (unit flakelet-relay-job-app.service)...409agent # [10473.924293] agent systemd[1]: Reloading...410relay # [10473.789461] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:11.751208Z","level":"INFO","message":"deploy accepted","job":"9f22de804f08d23f8d319356581a8471","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}411agent # [10474.270300] agent systemd[1]: Reloading finished in 345 ms.412agent # [10474.350019] agent systemd[1]: Reload requested from client PID 997 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [10474.350060] agent systemd[1]: Reloading...414agent # [10474.678982] agent systemd[1]: Reloading finished in 328 ms.415agent # [10474.744512] agent systemd[1]: Reload requested from client PID 1026 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [10474.744551] agent systemd[1]: Reloading...417agent # [10475.077756] agent systemd[1]: Reloading finished in 332 ms.418agent # [10475.157878] agent systemd[1]: Reload requested from client PID 1060 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [10475.157920] agent systemd[1]: Reloading...420agent # [10475.487066] agent systemd[1]: Reloading finished in 328 ms.421agent # [10475.555500] agent systemd[1]: Starting app v2...422agent # [10475.585150] agent systemd[1]: Started app v2.423agent # [10475.599857] agent flakelet[960]: app: updated to generation 2424agent # [10475.602055] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.425client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.96 seconds)426agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'427agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)428agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'429agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)430(finished: subtest: deploy with client certificate, relay found via SRV, in 3.01 seconds)431subtest: deploy with OIDC token, sub principal432agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json433agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)434client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)435client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)436client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzU0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJGSEJPTU5CUlpGRFFZPT09IiwibmJmIjoxNzg4Njg4NzU0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.49Fd10yV_HD9pxLN_VnTyib2_18EKsn9VkCQdBxQgfYdDSnWlE4lWpvLxDrcdUnIeNwN6_l3TiOojim1NPy-BA' push --relay https://relay:7443 deploy agent/app 2>&1437relay # [10476.720715] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:14.682436Z","level":"INFO","message":"deploy finished","job":"9f22de804f08d23f8d319356581a8471","ok":true,"target":"flakelet_relay::relay::api"}438relay # [10476.855921] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:14.817666Z","level":"INFO","message":"deploy accepted","job":"2257c75f9a3ebf99b9f9a74d9f0ce9e6","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}439agent # [10476.719235] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:14.680990Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}440agent # [10476.856241] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:14.818039Z","level":"INFO","message":"start","id":"3db54972b3abbc118d2856f3590b1d4f","flakelet":"app","rule":"ci","relay":"relay","caller_name":"Some(\"repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}441agent # [10476.856498] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:14.818331Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"3db54972b3abbc118d2856f3590b1d4f\"]","target":"flakelet_relay::agent::jobs"}442agent # [10476.901016] agent systemd[1]: Starting flakelet update app (via relay)...443agent # [10476.934148] agent systemd[1]: Started flakelet update app (via relay).444agent # [10476.937705] agent flakelet[1161]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1445agent # [10476.938379] agent flakelet[1161]: app: activating generation 3446agent # [10476.951711] agent systemd[1]: Stopping app v2...447agent # [10476.952203] agent systemd[1]: app.service: Deactivated successfully.448agent # [10476.952463] agent systemd[1]: Stopped app v2.449agent # [10476.967244] agent systemd[1]: Reload requested from client PID 1168 ('systemctl') (unit flakelet-relay-job-app.service)...450agent # [10476.967300] agent systemd[1]: Reloading...451agent # [10477.302442] agent systemd[1]: Reloading finished in 334 ms.452agent # [10477.374261] agent systemd[1]: Reload requested from client PID 1198 ('systemctl') (unit flakelet-relay-job-app.service)...453agent # [10477.374298] agent systemd[1]: Reloading...454agent # [10477.705402] agent systemd[1]: Reloading finished in 330 ms.455agent # [10477.763784] agent systemd[1]: Reload requested from client PID 1227 ('systemctl') (unit flakelet-relay-job-app.service)...456agent # [10477.763819] agent systemd[1]: Reloading...457agent # [10478.094861] agent systemd[1]: Reloading finished in 330 ms.458agent # [10478.169997] agent systemd[1]: Reload requested from client PID 1258 ('systemctl') (unit flakelet-relay-job-app.service)...459agent # [10478.170041] agent systemd[1]: Reloading...460agent # [10478.501368] agent systemd[1]: Reloading finished in 330 ms.461agent # [10478.567789] agent systemd[1]: Starting app v1...462agent # [10478.596140] agent systemd[1]: Started app v1.463agent # [10478.609204] agent flakelet[1161]: app: updated to generation 3464agent # [10478.611154] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.465client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzU0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJGSEJPTU5CUlpGRFFZPT09IiwibmJmIjoxNzg4Njg4NzU0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.49Fd10yV_HD9pxLN_VnTyib2_18EKsn9VkCQdBxQgfYdDSnWlE4lWpvLxDrcdUnIeNwN6_l3TiOojim1NPy-BA' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.89 seconds)466(finished: subtest: deploy with OIDC token, sub principal, in 2.96 seconds)467subtest: policy denies uncovered target468client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzU0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJGSEJPTU5CUlpGRFFZPT09IiwibmJmIjoxNzg4Njg4NzU0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.49Fd10yV_HD9pxLN_VnTyib2_18EKsn9VkCQdBxQgfYdDSnWlE4lWpvLxDrcdUnIeNwN6_l3TiOojim1NPy-BA' push --relay https://relay:7443 deploy agent/other 2>&1469client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzU0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJGSEJPTU5CUlpGRFFZPT09IiwibmJmIjoxNzg4Njg4NzU0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.49Fd10yV_HD9pxLN_VnTyib2_18EKsn9VkCQdBxQgfYdDSnWlE4lWpvLxDrcdUnIeNwN6_l3TiOojim1NPy-BA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)470(finished: subtest: policy denies uncovered target, in 0.02 seconds)471subtest: claim principal from groups, unchanged counts as success472client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)473client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)474client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4ODc1NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiQ0daUlA2SjJYTVdCNj09PSIsIm5iZiI6MTc4ODY4ODc1Nywic3ViIjoic29tZW9uZSJ9.u1h56eEowdTGA_olEkuj-xLf8X_Q4b-wZCa5tc5j04TGh0OaXiUtSc41jfSAFKrjBlq7GDXM5QGmm9PWtB8pCQ' push --relay https://relay:7443 deploy agent/other 2>&1475relay # [10479.715292] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:17.677005Z","level":"INFO","message":"deploy finished","job":"2257c75f9a3ebf99b9f9a74d9f0ce9e6","ok":true,"target":"flakelet_relay::relay::api"}476relay # [10479.811250] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:17.773006Z","level":"INFO","message":"deploy accepted","job":"073f637ef5197160c2a995388d2bbfcf","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}477agent # [10479.713831] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:17.675585Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}478agent # [10479.811569] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:17.773301Z","level":"INFO","message":"start","id":"5b814053a359d20416fc827bc7aca459","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"someone\")","target":"flakelet_relay::agent::conn"}479agent # [10479.811971] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:17.773789Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5b814053a359d20416fc827bc7aca459\"]","target":"flakelet_relay::agent::jobs"}480agent # [10479.883334] agent systemd[1]: Starting flakelet update other (via relay)...481agent # [10479.915043] agent systemd[1]: Started flakelet update other (via relay).482agent # [10479.920359] agent flakelet[1339]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1483agent # [10479.921356] agent flakelet[1339]: other: up to date484agent # [10479.922940] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.485client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA1NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4ODc1NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiQ0daUlA2SjJYTVdCNj09PSIsIm5iZiI6MTc4ODY4ODc1Nywic3ViIjoic29tZW9uZSJ9.u1h56eEowdTGA_olEkuj-xLf8X_Q4b-wZCa5tc5j04TGh0OaXiUtSc41jfSAFKrjBlq7GDXM5QGmm9PWtB8pCQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.70 seconds)486(finished: subtest: claim principal from groups, unchanged counts as success, in 0.76 seconds)487subtest: push login via device flow, cached token used afterwards488client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1489relay # [10480.492348] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:18.454080Z","level":"INFO","message":"deploy finished","job":"073f637ef5197160c2a995388d2bbfcf","ok":true,"target":"flakelet_relay::relay::api"}490relay # [10480.516799] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 09:59:18] "POST /device HTTP/1.1" 200 -491agent # [10480.491042] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:18.452794Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}492relay # [10481.521288] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 09:59:19] "POST /token HTTP/1.1" 400 -493client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)494client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600495client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)496client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1497agent # [10482.600909] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:20.562667Z","level":"INFO","message":"start","id":"d40441117dda09846dc54e0d27ec8d51","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}498agent # [10482.601741] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:20.563077Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"d40441117dda09846dc54e0d27ec8d51\"]","target":"flakelet_relay::agent::jobs"}499agent # [10482.666828] agent systemd[1]: Starting flakelet update other (via relay)...500agent # [10482.698074] agent systemd[1]: Started flakelet update other (via relay).501agent # [10482.702204] agent flakelet[1389]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1502agent # [10482.702718] agent flakelet[1389]: other: up to date503agent # [10482.706141] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.504relay # [10482.571206] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 09:59:20] "POST /token HTTP/1.1" 200 -505relay # [10482.600467] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:20.562250Z","level":"INFO","message":"deploy accepted","job":"ce98f188488353c0814052e96bea208c","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}506client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.69 seconds)507client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1508agent # [10483.271222] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.232956Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}509agent # [10483.291803] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.253608Z","level":"INFO","message":"start","id":"6d230633f1fc6fe9e5284375ce8b6698","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}510agent # [10483.292183] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.254005Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"6d230633f1fc6fe9e5284375ce8b6698\"]","target":"flakelet_relay::agent::jobs"}511agent # [10483.350572] agent systemd[1]: Starting flakelet update other (via relay)...512agent # [10483.384064] agent systemd[1]: Started flakelet update other (via relay).513agent # [10483.388249] agent flakelet[1436]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1514agent # [10483.388803] agent flakelet[1436]: other: up to date515agent # [10483.389178] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.516relay # [10483.272427] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:21.234161Z","level":"INFO","message":"deploy finished","job":"ce98f188488353c0814052e96bea208c","ok":true,"target":"flakelet_relay::relay::api"}517relay # [10483.291481] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:21.253281Z","level":"INFO","message":"deploy accepted","job":"00acc6c3e473ecb06deab3dbd48b8b74","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}518client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.68 seconds)519(finished: subtest: push login via device flow, cached token used afterwards, in 3.46 seconds)520subtest: waves: failing first wave skips the second521agent: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json522agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)523client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1524relay # [10483.956473] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:21.918191Z","level":"INFO","message":"deploy finished","job":"00acc6c3e473ecb06deab3dbd48b8b74","ok":true,"target":"flakelet_relay::relay::api"}525relay # [10483.993218] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:21.955013Z","level":"INFO","message":"deploy accepted","job":"a8a0c87420c2181b5ba7cad86aa90385","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}526agent # [10483.955282] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.917045Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}527agent # [10483.993614] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.955387Z","level":"INFO","message":"start","id":"83dcde5e76d859ce05cf915f36342111","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}528agent # [10483.993807] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:21.955619Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"83dcde5e76d859ce05cf915f36342111\"]","target":"flakelet_relay::agent::jobs"}529agent # [10484.054556] agent systemd[1]: Starting flakelet update app (via relay)...530agent # [10484.092139] agent systemd[1]: Started flakelet update app (via relay).531agent # [10484.096331] agent flakelet[1478]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken532agent # [10484.096950] agent flakelet[1478]: app: activating generation 4533agent # [10484.106160] agent systemd[1]: Stopping app v1...534agent # [10484.107133] agent systemd[1]: app.service: Deactivated successfully.535agent # [10484.107330] agent systemd[1]: Stopped app v1.536agent # [10484.116269] agent systemd[1]: Reload requested from client PID 1485 ('systemctl') (unit flakelet-relay-job-app.service)...537agent # [10484.116306] agent systemd[1]: Reloading...538agent # [10484.448088] agent systemd[1]: Reloading finished in 331 ms.539agent # [10484.511084] agent systemd[1]: Reload requested from client PID 1515 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [10484.511120] agent systemd[1]: Reloading...541agent # [10484.841591] agent systemd[1]: Reloading finished in 330 ms.542agent # [10484.907661] agent systemd[1]: Reload requested from client PID 1546 ('systemctl') (unit flakelet-relay-job-app.service)...543agent # [10484.907696] agent systemd[1]: Reloading...544agent # [10485.241216] agent systemd[1]: Reloading finished in 333 ms.545agent # [10485.315878] agent systemd[1]: Reload requested from client PID 1579 ('systemctl') (unit flakelet-relay-job-app.service)...546agent # [10485.315915] agent systemd[1]: Reloading...547agent # [10485.646730] agent systemd[1]: Reloading finished in 330 ms.548agent # [10485.707802] agent systemd[1]: Starting app broken...549agent # [10485.736475] agent (nonexistent)[1611]: app.service: Unable to locate executable '/nonexistent': No such file or directory550agent # [10485.736498] agent (nonexistent)[1611]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory551agent # [10485.738489] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC552agent # [10485.738587] agent systemd[1]: app.service: Failed with result 'exit-code'.553agent # [10485.738748] agent systemd[1]: Failed to start app broken.554agent # [10485.779725] agent systemd[1]: Reload requested from client PID 1626 ('systemctl') (unit flakelet-relay-job-app.service)...555agent # [10485.779765] agent systemd[1]: Reloading...556agent # [10486.115339] agent systemd[1]: Reloading finished in 335 ms.557agent # [10486.187737] agent systemd[1]: Reload requested from client PID 1656 ('systemctl') (unit flakelet-relay-job-app.service)...558agent # [10486.187776] agent systemd[1]: Reloading...559agent # [10486.520251] agent systemd[1]: Reloading finished in 332 ms.560agent # [10486.593885] agent systemd[1]: Reload requested from client PID 1686 ('systemctl') (unit flakelet-relay-job-app.service)...561agent # [10486.593925] agent systemd[1]: Reloading...562agent # [10486.926029] agent systemd[1]: Reloading finished in 331 ms.563agent # [10487.002323] agent systemd[1]: Reload requested from client PID 1719 ('systemctl') (unit flakelet-relay-job-app.service)...564agent # [10487.002358] agent systemd[1]: Reloading...565agent # [10487.335058] agent systemd[1]: Reloading finished in 332 ms.566agent # [10487.398490] agent systemd[1]: Starting app v1...567agent # [10487.426562] agent systemd[1]: Started app v1.568agent # [10487.427653] agent flakelet[1478]: app: deploy failed, rolled back: systemctl start app.service failed:569agent # [10487.427653] agent flakelet[1478]: failed units: app.service. See journalctl -u app.service570agent # [10487.430133] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE571agent # [10487.430224] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.572client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.19 seconds)573agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'574agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds)575(finished: subtest: waves: failing first wave skips the second, in 4.23 seconds)576subtest: host patterns expand on the relay577agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json578agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)579client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1580agent # [10488.159512] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.121277Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}581agent # [10488.216793] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.178554Z","level":"INFO","message":"start","id":"bd61896370379d02ea013addee299c76","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}582agent # [10488.217101] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.178825Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"bd61896370379d02ea013addee299c76\"]","target":"flakelet_relay::agent::jobs"}583agent # [10488.277049] agent systemd[1]: Starting flakelet update app (via relay)...584agent # [10488.309051] agent systemd[1]: Started flakelet update app (via relay).585agent # [10488.313265] agent flakelet[1802]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1586agent # [10488.313771] agent flakelet[1802]: app: up to date587agent # [10488.316376] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.588relay # [10488.160442] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:26.122177Z","level":"INFO","message":"deploy finished","job":"a8a0c87420c2181b5ba7cad86aa90385","ok":false,"target":"flakelet_relay::relay::api"}589relay # [10488.216466] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:26.178213Z","level":"INFO","message":"deploy accepted","job":"863fc87dc00017f4455bff3a69c5ba95","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}590client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.69 seconds)591client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1592agent # [10488.883698] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.845472Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}593agent # [10488.906195] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.868017Z","level":"INFO","message":"start","id":"4bffcc6efa6c9a1dc6d88345c46b3eab","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}594agent # [10488.906363] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:26.868200Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"4bffcc6efa6c9a1dc6d88345c46b3eab\"]","target":"flakelet_relay::agent::jobs"}595agent # [10488.964272] agent systemd[1]: Starting flakelet update app (via relay)...596agent # [10489.004215] agent systemd[1]: Started flakelet update app (via relay).597agent # [10489.008273] agent flakelet[1852]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1598agent # [10489.008771] agent flakelet[1852]: app: up to date599agent # [10489.009412] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.600relay # [10488.885086] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:26.846737Z","level":"INFO","message":"deploy finished","job":"863fc87dc00017f4455bff3a69c5ba95","ok":true,"target":"flakelet_relay::relay::api"}601relay # [10488.905990] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:26.867780Z","level":"INFO","message":"deploy accepted","job":"5cabb6b1eae96658c8e37561f0d1d9cd","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}602client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.69 seconds)603client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1604agent # [10489.575149] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:27.536936Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}605agent # [10489.598277] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:27.560086Z","level":"INFO","message":"start","id":"24f4cd26de504bcd7578d05885551c2e","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}606agent # [10489.598454] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:27.560285Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"24f4cd26de504bcd7578d05885551c2e\"]","target":"flakelet_relay::agent::jobs"}607agent # [10489.669458] agent systemd[1]: Starting flakelet update app (via relay)...608agent # [10489.704169] agent systemd[1]: Started flakelet update app (via relay).609agent # [10489.708626] agent flakelet[1886]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1610agent # [10489.709159] agent flakelet[1886]: app: up to date611agent # [10489.710185] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.612relay # [10489.576401] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:27.538143Z","level":"INFO","message":"deploy finished","job":"5cabb6b1eae96658c8e37561f0d1d9cd","ok":false,"target":"flakelet_relay::relay::api"}613relay # [10489.597967] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:27.559772Z","level":"INFO","message":"deploy accepted","job":"9d9e80941c71ff347ec4649b50529631","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}614client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.70 seconds)615client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1616client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)617(finished: subtest: host patterns expand on the relay, in 2.12 seconds)618subtest: detach returns once the job is accepted619agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json620agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)621client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1622client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)623agent: waiting for success: systemctl is-active flakelet-relay-job-app.service624agent # [10490.279471] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:28.241245Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}625agent # [10490.332270] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:28.294060Z","level":"INFO","message":"start","id":"91bf7eea01bec8697029c6852d16a037","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}626agent # [10490.332702] agent flakelet-agent[502]: {"timestamp":"2026-09-06T09:59:28.294525Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"91bf7eea01bec8697029c6852d16a037\"]","target":"flakelet_relay::agent::jobs"}627agent # [10490.402422] agent systemd[1]: Starting flakelet update app (via relay)...628agent # [10490.442172] agent systemd[1]: Started flakelet update app (via relay).629agent # [10490.446534] agent flakelet[1928]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2630agent # [10490.447181] agent flakelet[1928]: app: activating generation 4631agent # [10490.460302] agent systemd[1]: Stopping app v1...632agent # [10490.460742] agent systemd[1]: app.service: Deactivated successfully.633agent # [10490.460983] agent systemd[1]: Stopped app v1.634agent # [10490.475996] agent systemd[1]: Reload requested from client PID 1935 ('systemctl') (unit flakelet-relay-job-app.service)...635agent # [10490.476073] agent systemd[1]: Reloading...636relay # [10490.280857] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:28.242601Z","level":"INFO","message":"deploy finished","job":"9d9e80941c71ff347ec4649b50529631","ok":false,"target":"flakelet_relay::relay::api"}637relay # [10490.331977] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:28.293732Z","level":"INFO","message":"deploy accepted","job":"045af8361fef53a222fe5e7c22661af8","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}638agent # [10490.815519] agent systemd[1]: Reloading finished in 338 ms.639agent # [10490.893895] agent systemd[1]: Reload requested from client PID 1968 ('systemctl') (unit flakelet-relay-job-app.service)...640agent # [10490.893934] agent systemd[1]: Reloading...641agent # [10491.220776] agent systemd[1]: Reloading finished in 326 ms.642agent # [10491.291892] agent systemd[1]: Reload requested from client PID 1998 ('systemctl') (unit flakelet-relay-job-app.service)...643agent # [10491.291931] agent systemd[1]: Reloading...644agent # [10491.622609] agent systemd[1]: Reloading finished in 330 ms.645agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.37 seconds)646??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.647 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39648agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service649??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.650 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39651agent # [10491.706331] agent systemd[1]: Reload requested from client PID 2032 ('systemctl') (unit flakelet-relay-job-app.service)...652agent # [10491.706367] agent systemd[1]: Reloading...653agent # [10492.036788] agent systemd[1]: Reloading finished in 330 ms.654agent # [10492.103553] agent systemd[1]: Starting app slow2...655agent # [10498.182126] agent systemd[1]: Started app slow2.656agent # [10498.200412] agent flakelet[1928]: app: updated to generation 4657agent # [10498.203377] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.658agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.50 seconds)659(finished: subtest: detach returns once the job is accepted, in 8.90 seconds)660subtest: unknown host is final, missing agent is retried, agents listing661client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1662client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)663agent: must succeed: systemctl stop flakelet-agent664agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.08 seconds)665relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'666relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)667client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &668client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)669client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out670relay # [10499.236929] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:37.198663Z","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"}671agent # [10499.236890] agent systemd[1]: Stopping flakelet-agent...672agent # [10499.271755] agent systemd[1]: flakelet-agent.service: Deactivated successfully.673agent # [10499.272189] agent systemd[1]: Stopped flakelet-agent.674agent # [10499.272610] agent systemd[1]: flakelet-agent.service: Consumed 2.482s CPU time over 28.634s wall clock time.675client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)676agent: must succeed: systemctl start flakelet-agent677agent: (finished: must succeed: systemctl start flakelet-agent, in 0.16 seconds)678??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.679 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39680client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out681agent # [10500.365070] agent systemd[1]: Starting flakelet-agent...682agent # [10500.423201] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:38.385001Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"91bf7eea01bec8697029c6852d16a037\"]","target":"flakelet_relay::agent::jobs"}683agent # [10500.511032] agent systemd[1]: Started flakelet-agent.684agent # [10500.525280] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:38.487081Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}685relay # [10500.525423] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:38.487153Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}686agent # [10500.991863] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:38.953610Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}687agent # [10502.351524] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:40.313263Z","level":"INFO","message":"start","id":"287fb483c3daec7936a65521f488cd7f","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}688agent # [10502.352404] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:40.314053Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"287fb483c3daec7936a65521f488cd7f\"]","target":"flakelet_relay::agent::jobs"}689agent # [10502.421722] agent systemd[1]: Starting flakelet update other (via relay)...690agent # [10502.455168] agent systemd[1]: Started flakelet update other (via relay).691agent # [10502.459626] agent flakelet[2600]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1692agent # [10502.460163] agent flakelet[2600]: other: up to date693agent # [10502.463317] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.694relay # [10502.351096] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:40.312764Z","level":"INFO","message":"deploy accepted","job":"12310f129f7c13ea8b77336cd5ab7eea","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}695agent # [10503.032252] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:40.994000Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}696relay # [10503.033743] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:40.995474Z","level":"INFO","message":"deploy finished","job":"12310f129f7c13ea8b77336cd5ab7eea","ok":true,"target":"flakelet_relay::relay::api"}697client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)698client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents699client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)700client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)701client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)702client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA4MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzgxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWSkxWSFpQNlgzM0ZHPT09IiwibmJmIjoxNzg4Njg4NzgxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.WHRQDdVMgn1C-Y-bQYuDybJ5Vq-qWPpS9K0FjEWfBDh_4XgbkeeFHxSIZvjg-vVPQNT42dk2nDxq0QTGnLS9Dg' push --relay https://relay:7443 agents703client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTA4MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4NzgxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWSkxWSFpQNlgzM0ZHPT09IiwibmJmIjoxNzg4Njg4NzgxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.WHRQDdVMgn1C-Y-bQYuDybJ5Vq-qWPpS9K0FjEWfBDh_4XgbkeeFHxSIZvjg-vVPQNT42dk2nDxq0QTGnLS9Dg' push --relay https://relay:7443 agents, in 0.02 seconds)704(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.45 seconds)705subtest: out-of-band flakelet update reaches the relay without reconnect706agent: must succeed: flakelet status --json app | jq '.[0].generation'707agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.06 seconds)708agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true709agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)710agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json711agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)712agent: must succeed: flakelet update app713app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2714app: activating generation 5715agent # [10503.760758] agent systemd[1]: Stopping app slow2...716agent # [10503.761249] agent systemd[1]: app.service: Deactivated successfully.717agent # [10503.761519] agent systemd[1]: Stopped app slow2.718agent # [10503.779159] agent systemd[1]: Reload requested from client PID 2660 ('systemctl')...719agent # [10503.779228] agent systemd[1]: Reloading...720agent # [10504.120361] agent systemd[1]: Reloading finished in 340 ms.721agent # [10504.184652] agent systemd[1]: Reload requested from client PID 2689 ('systemctl')...722agent # [10504.184689] agent systemd[1]: Reloading...723agent # [10504.515896] agent systemd[1]: Reloading finished in 330 ms.724agent # [10504.597689] agent systemd[1]: Reload requested from client PID 2719 ('systemctl')...725agent # [10504.597724] agent systemd[1]: Reloading...726agent # [10504.928715] agent systemd[1]: Reloading finished in 330 ms.727agent # [10505.000285] agent systemd[1]: Reload requested from client PID 2751 ('systemctl')...728agent # [10505.000321] agent systemd[1]: Reloading...729agent: (finished: must succeed: flakelet update app, in 1.70 seconds)730client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'731agent # [10505.329461] agent systemd[1]: Reloading finished in 328 ms.732agent # [10505.397812] agent systemd[1]: Starting app v2...733agent # [10505.424052] agent systemd[1]: Started app v2.734client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.07 seconds)735agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true736agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)737agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json738agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)739agent: must succeed: flakelet update app740app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1741app: activating generation 6742agent # [10507.549748] agent systemd[1]: Stopping app v2...743agent # [10507.550228] agent systemd[1]: app.service: Deactivated successfully.744agent # [10507.550495] agent systemd[1]: Stopped app v2.745agent # [10507.567471] agent systemd[1]: Reload requested from client PID 2817 ('systemctl')...746agent # [10507.567540] agent systemd[1]: Reloading...747agent # [10507.921070] agent systemd[1]: Reloading finished in 352 ms.748agent # [10507.988429] agent systemd[1]: Reload requested from client PID 2846 ('systemctl')...749agent # [10507.988468] agent systemd[1]: Reloading...750agent # [10508.316218] agent systemd[1]: Reloading finished in 327 ms.751agent # [10508.383770] agent systemd[1]: Reload requested from client PID 2874 ('systemctl')...752agent # [10508.383808] agent systemd[1]: Reloading...753agent # [10508.712644] agent systemd[1]: Reloading finished in 328 ms.754agent # [10508.779449] agent systemd[1]: Reload requested from client PID 2906 ('systemctl')...755agent # [10508.779487] agent systemd[1]: Reloading...756agent # [10509.111148] agent systemd[1]: Reloading finished in 331 ms.757agent: (finished: must succeed: flakelet update app, in 1.70 seconds)758client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'759agent # [10509.179035] agent systemd[1]: Starting app v1...760agent # [10509.219108] agent systemd[1]: Started app v1.761client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.07 seconds)762(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.65 seconds)763subtest: certificate not listed under agents cannot connect as agent764client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent765client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.03 seconds)766(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)767subtest: metrics768relay: must succeed: curl -sf http://127.0.0.1:7400/metrics769relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)770(finished: subtest: metrics, in 0.01 seconds)771subtest: agent link drop mid-run replays missed lines once772agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json773agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)774agent: must succeed: date +%s775agent: (finished: must succeed: date +%s, in 0.01 seconds)776client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &777client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)778agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688789 | grep -q 'app-slow'779agent # [10511.379073] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:49.340788Z","level":"INFO","message":"start","id":"629c1244b01b32018c837680e90268de","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}780agent # [10511.379859] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:49.341522Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"629c1244b01b32018c837680e90268de\"]","target":"flakelet_relay::agent::jobs"}781agent # [10511.426119] agent systemd[1]: Starting flakelet update app (via relay)...782agent # [10511.454061] agent systemd[1]: Started flakelet update app (via relay).783agent # [10511.457998] agent flakelet[2980]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow784agent # [10511.458643] agent flakelet[2980]: app: activating generation 7785agent # [10511.468072] agent systemd[1]: Stopping app v1...786agent # [10511.468752] agent systemd[1]: app.service: Deactivated successfully.787agent # [10511.468879] agent systemd[1]: Stopped app v1.788agent # [10511.481059] agent systemd[1]: Reload requested from client PID 2987 ('systemctl') (unit flakelet-relay-job-app.service)...789agent # [10511.481115] agent systemd[1]: Reloading...790relay # [10511.323306] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:49.285054Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}791relay # [10511.378600] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:49.340353Z","level":"INFO","message":"deploy accepted","job":"099931305f5821596bb26525b513269f","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}792agent # [10511.818297] agent systemd[1]: Reloading finished in 336 ms.793agent # [10511.890911] agent systemd[1]: Reload requested from client PID 3017 ('systemctl') (unit flakelet-relay-job-app.service)...794agent # [10511.890948] agent systemd[1]: Reloading...795agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688789 | grep -q 'app-slow', in 1.02 seconds)796agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done797agent: (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)798relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done799relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)800agent: must succeed: ss -K dport = 7443801agent # [10512.225487] agent systemd[1]: Reloading finished in 334 ms.802agent # [10512.290379] agent systemd[1]: Reload requested from client PID 3046 ('systemctl') (unit flakelet-relay-job-app.service)...803agent # [10512.290418] agent systemd[1]: Reloading...804agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)805agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688789 | grep -q 'updated to generation'806relay # [10512.460959] relay flakelet-relay[400]: {"timestamp":"2026-09-06T09:59:50.422719Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}807agent # [10512.492795] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:50.454425Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}808agent # [10512.627032] agent systemd[1]: Reloading finished in 336 ms.809agent # [10512.699420] agent systemd[1]: Reload requested from client PID 3094 ('systemctl') (unit flakelet-relay-job-app.service)...810agent # [10512.699459] agent systemd[1]: Reloading...811agent # [10513.030647] agent systemd[1]: Reloading finished in 330 ms.812agent # [10513.107194] agent systemd[1]: Starting app slow...813agent # [10513.495083] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:51.456826Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}814agent # [10515.497524] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:53.459268Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}815agent # [10519.183023] agent systemd[1]: Started app slow.816agent # [10519.200892] agent flakelet[2980]: app: updated to generation 7817agent # [10519.203683] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.818agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688789 | grep -q 'updated to generation', in 7.10 seconds)819agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done820agent: (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)821client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out822agent # [10519.500645] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:57.462258Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}823agent # [10520.305404] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T09:59:58.267146Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}824client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.09 seconds)825client: must succeed: cat /tmp/slow.out826client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)827(finished: subtest: agent link drop mid-run replays missed lines once, in 16.37 seconds)828subtest: agent restart mid-run reattaches to the unit829agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json830agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)831client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &832client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)833agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'834relay # [10527.505544] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:05.467236Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}835relay # [10527.507172] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:05.468967Z","level":"INFO","message":"deploy finished","job":"099931305f5821596bb26525b513269f","ok":true,"target":"flakelet_relay::relay::api"}836relay # [10527.742811] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:05.704554Z","level":"INFO","message":"deploy accepted","job":"f1e1c707d6646eaa3dd70f67aba40f18","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}837agent # [10527.505416] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T10:00:05.467151Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}838agent # [10527.506615] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T10:00:05.468435Z","level":"INFO","message":"start","id":"629c1244b01b32018c837680e90268de","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}839agent # [10527.743261] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T10:00:05.705012Z","level":"INFO","message":"start","id":"2ee85cd16541e733a1509b835c237e9b","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}840agent # [10527.743822] agent flakelet-agent[2151]: {"timestamp":"2026-09-06T10:00:05.705641Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2ee85cd16541e733a1509b835c237e9b\"]","target":"flakelet_relay::agent::jobs"}841agent # [10527.789083] agent systemd[1]: Starting flakelet update app (via relay)...842agent # [10527.820154] agent systemd[1]: Started flakelet update app (via relay).843agent # [10527.824145] agent flakelet[3313]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2844agent # [10527.824814] agent flakelet[3313]: app: activating generation 8845agent # [10527.838058] agent systemd[1]: Stopping app slow...846agent # [10527.838470] agent systemd[1]: app.service: Deactivated successfully.847agent # [10527.838740] agent systemd[1]: Stopped app slow.848agent # [10527.855227] agent systemd[1]: Reload requested from client PID 3320 ('systemctl') (unit flakelet-relay-job-app.service)...849agent # [10527.855296] agent systemd[1]: Reloading...850agent # [10528.199144] agent systemd[1]: Reloading finished in 343 ms.851agent # [10528.286086] agent systemd[1]: Reload requested from client PID 3350 ('systemctl') (unit flakelet-relay-job-app.service)...852agent # [10528.286123] agent systemd[1]: Reloading...853agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)854agent: must succeed: systemctl restart flakelet-agent855agent # [10528.621702] agent systemd[1]: Reloading finished in 335 ms.856agent # [10528.713664] agent systemd[1]: Reload requested from client PID 3381 ('systemctl') (unit flakelet-relay-job-app.service)...857agent # [10528.713704] agent systemd[1]: Reloading...858agent # [10529.051321] agent systemd[1]: Reloading finished in 337 ms.859agent # [10529.141568] agent systemd[1]: Stopping flakelet-agent...860agent # [10529.146192] agent systemd[1]: Reload requested from client PID 3418 ('systemctl') (unit flakelet-relay-job-app.service)...861agent # [10529.146235] agent systemd[1]: Reloading...862relay # [10529.141894] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:07.103583Z","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"}863agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.97 seconds)864agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"865agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)866client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out867agent # [10529.484594] agent systemd[1]: Reloading finished in 338 ms.868agent # [10529.561399] agent systemd[1]: flakelet-agent.service: Deactivated successfully.869agent # [10529.561602] agent systemd[1]: Stopped flakelet-agent.870agent # [10529.561617] agent systemd[1]: flakelet-agent.service: Consumed 2.006s CPU time over 29.196s wall clock time.871agent # [10529.580205] agent systemd[1]: Starting app slow2...872agent # [10529.581271] agent systemd[1]: Starting flakelet-agent...873agent # [10529.637551] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:07.599343Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"2ee85cd16541e733a1509b835c237e9b\"]","target":"flakelet_relay::agent::jobs"}874agent # [10529.718668] agent systemd[1]: Started flakelet-agent.875agent # [10529.731898] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:07.693702Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}876agent # [10529.733166] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:07.694990Z","level":"INFO","message":"start","id":"2ee85cd16541e733a1509b835c237e9b","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}877relay # [10529.732046] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:07.693782Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}878agent # [10535.652051] agent systemd[1]: Started app slow2.879agent # [10535.672015] agent flakelet[3313]: app: updated to generation 8880agent # [10535.675519] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.881agent # [10536.257490] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:14.219237Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}882relay # [10536.259032] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:14.220752Z","level":"INFO","message":"deploy finished","job":"f1e1c707d6646eaa3dd70f67aba40f18","ok":true,"target":"flakelet_relay::relay::api"}883client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)884client: must succeed: cat /tmp/restart.out885client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)886agent: must succeed: systemctl is-active app.service887agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)888(finished: subtest: agent restart mid-run reattaches to the unit, in 9.12 seconds)889subtest: relay restart mid-run, push resumes via /v1/jobs890agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json891agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)892agent: must succeed: date +%s893agent: (finished: must succeed: date +%s, in 0.01 seconds)894client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &895client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)896agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688814 | grep -q 'app-slow'897agent # [10536.870944] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:14.832721Z","level":"INFO","message":"start","id":"6b7be39087f608ed8fa727124d98a956","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}898agent # [10536.871526] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:14.833351Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6b7be39087f608ed8fa727124d98a956\"]","target":"flakelet_relay::agent::jobs"}899agent # [10536.936633] agent systemd[1]: Starting flakelet update app (via relay)...900agent # [10536.964036] agent systemd[1]: Started flakelet update app (via relay).901agent # [10536.968190] agent flakelet[3962]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow902agent # [10536.968846] agent flakelet[3962]: app: activating generation 9903agent # [10536.981260] agent systemd[1]: Stopping app slow2...904agent # [10536.981719] agent systemd[1]: app.service: Deactivated successfully.905agent # [10536.981978] agent systemd[1]: Stopped app slow2.906agent # [10536.998929] agent systemd[1]: Reload requested from client PID 3969 ('systemctl') (unit flakelet-relay-job-app.service)...907agent # [10536.998996] agent systemd[1]: Reloading...908relay # [10536.870596] relay flakelet-relay[400]: {"timestamp":"2026-09-06T10:00:14.832346Z","level":"INFO","message":"deploy accepted","job":"7115753d344731557ff8531cd3a9b170","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}909agent # [10537.342765] agent systemd[1]: Reloading finished in 343 ms.910agent # [10537.410663] agent systemd[1]: Reload requested from client PID 3999 ('systemctl') (unit flakelet-relay-job-app.service)...911agent # [10537.410700] agent systemd[1]: Reloading...912agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788688814 | grep -q 'app-slow', in 1.02 seconds)913relay: must succeed: systemctl restart flakelet-relay914agent # [10537.742519] agent systemd[1]: Reloading finished in 331 ms.915agent # [10537.816704] agent systemd[1]: Reload requested from client PID 4030 ('systemctl') (unit flakelet-relay-job-app.service)...916agent # [10537.816741] agent systemd[1]: Reloading...917agent # [10537.890358] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:15.852131Z","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"}918relay # [10537.889735] relay systemd[1]: Stopping flakelet-relay...919relay # [10537.942894] relay systemd[1]: flakelet-relay.service: Deactivated successfully.920relay # [10537.943223] relay systemd[1]: Stopped flakelet-relay.921relay # [10537.943257] relay systemd[1]: flakelet-relay.service: Consumed 3.355s CPU time over 1min 9.027s wall clock time.922relay # [10537.961667] relay systemd[1]: Starting flakelet-relay...923agent # [10538.165177] agent systemd[1]: Reloading finished in 348 ms.924agent # [10538.253682] agent systemd[1]: Reload requested from client PID 4067 ('systemctl') (unit flakelet-relay-job-app.service)...925agent # [10538.253720] agent systemd[1]: Reloading...926agent # [10538.589558] agent systemd[1]: Reloading finished in 335 ms.927agent # [10538.668986] agent systemd[1]: Starting app slow...928agent # [10538.893128] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:16.854687Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}929relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.51 seconds)930client: waiting for success: grep -q '» ok' /tmp/resume.out931relay # [10539.382395] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:17.344140Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}932relay # [10539.383265] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:17.344577Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}933relay # [10539.382939] relay systemd[1]: Started flakelet-relay.934agent # [10540.904454] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:18.866220Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}935relay # [10540.904643] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:18.866376Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}936relay # [10540.908482] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:18.870268Z","level":"INFO","message":"job reattached","job":"7115753d344731557ff8531cd3a9b170","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}937agent # [10544.739228] agent systemd[1]: Started app slow.938agent # [10544.756657] agent flakelet[3962]: app: updated to generation 9939agent # [10544.758550] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.940agent # [10545.868084] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:23.829792Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}941client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)942client: must succeed: cat /tmp/resume.out943client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)944(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.65 seconds)945subtest: job history comes from the agents and survives a relay restart946client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1947relay # [10546.498597] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:24.460352Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}948agent # [10546.498887] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:24.460673Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}949agent # [10546.499593] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:24.461416Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}950agent # [10546.562725] agent systemd[1]: Starting flakelet update other (via relay)...951agent # [10546.596161] agent systemd[1]: Started flakelet update other (via relay).952agent # [10546.600965] agent flakelet[4207]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1953agent # [10546.601463] agent flakelet[4207]: other: up to date954agent # [10546.603385] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.955client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.69 seconds)956relay: must succeed: systemctl restart flakelet-relay957agent # [10547.168588] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:25.130350Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}958agent # [10547.187441] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:25.149253Z","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"}959relay # [10547.170065] relay flakelet-relay[933]: {"timestamp":"2026-09-06T10:00:25.131736Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}960relay # [10547.187220] relay systemd[1]: Stopping flakelet-relay...961relay # [10547.220492] relay systemd[1]: flakelet-relay.service: Deactivated successfully.962relay # [10547.220928] relay systemd[1]: Stopped flakelet-relay.963relay # [10547.220968] relay systemd[1]: flakelet-relay.service: Consumed 2.411s CPU time over 9.258s wall clock time.964relay # [10547.257598] relay systemd[1]: Starting flakelet-relay...965relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.49 seconds)966relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'967agent # [10548.191238] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:26.153023Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}968relay # [10548.661331] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:26.623082Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}969relay # [10548.662122] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:26.623498Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}970relay # [10548.661897] relay systemd[1]: Started flakelet-relay.971relay # [10550.205180] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:28.166940Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}972agent # [10550.205097] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:28.166795Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}973relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds)974client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs975client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)976client: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)977client: (finished: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)978client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTEyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4ODI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSWEJYWVdNQVFEM1k0PT09IiwibmJmIjoxNzg4Njg4ODI4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.murbX291LgEf80NqtYcnG2JYDGj_ZUDLoQqzbiqXYGsS-v-sWTnlDe3utDhY6EfWPuRG3gT0hj523iIteAUoDw' push --relay https://relay:7443 deploy --id hist2 agent/app979» job 6a239dbf87cfec796e49404c351d787f via relay 0.1.0 (agents: agent 0.1.0)980» wave 0981agent/app | Starting flakelet update app (via relay)...982agent/app | Started flakelet update app (via relay).983agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow984agent/app | app: up to date985agent # [10550.812481] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:28.774263Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"Some(\"example/app\")","target":"flakelet_relay::agent::conn"}986agent # [10550.813160] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:28.774983Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}987agent # [10550.883153] agent systemd[1]: Starting flakelet update app (via relay)...988agent # [10550.915139] agent systemd[1]: Started flakelet update app (via relay).989agent # [10550.919582] agent flakelet[4271]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow990agent # [10550.920183] agent flakelet[4271]: app: up to date991agent # [10550.923681] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.992agent/app | flakelet-relay-job-app.service: Deactivated successfully.993relay # [10550.812091] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:28.773869Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}994» agent/app: unchanged (generation 9)995» ok996client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTEyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4ODI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSWEJYWVdNQVFEM1k0PT09IiwibmJmIjoxNzg4Njg4ODI4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.murbX291LgEf80NqtYcnG2JYDGj_ZUDLoQqzbiqXYGsS-v-sWTnlDe3utDhY6EfWPuRG3gT0hj523iIteAUoDw' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.70 seconds)997client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTEyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4ODI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSWEJYWVdNQVFEM1k0PT09IiwibmJmIjoxNzg4Njg4ODI4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.murbX291LgEf80NqtYcnG2JYDGj_ZUDLoQqzbiqXYGsS-v-sWTnlDe3utDhY6EfWPuRG3gT0hj523iIteAUoDw' push --relay https://relay:7443 jobs998client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4OTEyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njg4ODI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSWEJYWVdNQVFEM1k0PT09IiwibmJmIjoxNzg4Njg4ODI4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.murbX291LgEf80NqtYcnG2JYDGj_ZUDLoQqzbiqXYGsS-v-sWTnlDe3utDhY6EfWPuRG3gT0hj523iIteAUoDw' push --relay https://relay:7443 jobs, in 0.02 seconds)999(finished: subtest: job history comes from the agents and survives a relay restart, in 5.04 seconds)1000subtest: dashboard login via authorization code flow1001client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login'1002client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login', in 0.02 seconds)1003client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login1004client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds)1005client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs1006client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)1007client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist11008client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1, in 0.02 seconds)1009client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true1010client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true, in 0.02 seconds)1011client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 4031012client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403, in 0.02 seconds)1013client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other'1014client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other', in 0.02 seconds)1015client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/baae8de8922b1ca1a82da27fb2d271db/events || true1016relay # [10551.492346] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:29.454088Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1017relay # [10551.566380] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:00:29] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=Kf5kkZvQlNWMkO_BzwQpau3T0tOCneYp-qYaCuCb9AI&code_challenge=Hrchsz5mDtueB3AoG2xKAvAY-ZY_wBNgHHFx-PKrY2Y&code_challenge_method=S256 HTTP/1.1" 302 -1018relay # [10551.614902] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:00:29] "POST /token HTTP/1.1" 200 -1019relay # [10551.615923] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:29.577720Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1020relay # [10551.677107] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:29.638866Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1021relay # [10551.717427] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:29.679180Z","level":"INFO","message":"deploy accepted","job":"7285566a2c07bd24d6d48763a315f0e8","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1022relay # [10551.738959] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:29.700765Z","level":"INFO","message":"job reattached","job":"7285566a2c07bd24d6d48763a315f0e8","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1023agent # [10551.491092] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:29.452769Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}1024agent # [10551.717716] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:29.679444Z","level":"INFO","message":"start","id":"9dbce296f5fc74f02115e6f0b5ae6625","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}1025agent # [10551.718130] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:29.679953Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"9dbce296f5fc74f02115e6f0b5ae6625\"]","target":"flakelet_relay::agent::jobs"}1026agent # [10551.799302] agent systemd[1]: Starting flakelet update other (via relay)...1027agent # [10551.836181] agent systemd[1]: Started flakelet update other (via relay).1028agent # [10551.839925] agent flakelet[4317]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11029agent # [10551.840512] agent flakelet[4317]: other: up to date1030agent # [10551.841206] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1031client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/baae8de8922b1ca1a82da27fb2d271db/events || true, in 0.69 seconds)1032client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/baae8de8922b1ca1a82da27fb2d271db1033client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/baae8de8922b1ca1a82da27fb2d271db, in 0.02 seconds)1034client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js1035client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js, in 0.02 seconds)1036client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth'1037client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth', in 0.02 seconds)1038client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other1039client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other, in 0.02 seconds)1040client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected'1041client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected', in 0.02 seconds)1042client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=baae8de8922b1ca1a82da27fb2d271db' | grep -q 4001043client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=baae8de8922b1ca1a82da27fb2d271db' | grep -q 400, in 0.02 seconds)1044client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &1045client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &, in 0.01 seconds)1046client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other1047» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)1048» wave 01049agent/other | Starting flakelet update other (via relay)...1050agent/other | Started flakelet update other (via relay).1051agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11052agent/other | other: up to date1053agent # [10552.403849] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:30.365586Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1054agent/otheragent # [10552.544864] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:30.506618Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}1055 | agent # [10552.545657] agent flakelet-agent[3450]: {"timestamp":"2026-09-06T10:00:30.507115Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}1056flakelet-relay-job-other.service: Deactivated successfully.agent # [10552.611774] agent systemd[1]: Starting flakelet update other (via relay)...10571058agent # [10552.641109] agent systemd[1]: Started flakelet update other (via relay).1059agent # [10552.645187] agent flakelet[4357]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11060agent # [10552.645692] agent flakelet[4357]: other: up to date1061agent # [10552.649186] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1062relay # [10552.544610] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:30.506355Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1063» agent/other: unchanged (generation 1)1064» ok1065client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 0.69 seconds)1066client: waiting for success: grep -q live1 /tmp/ev.out1067client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)1068client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout1069client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout, in 0.02 seconds)1070client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 3031071client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303, in 0.02 seconds)1072(finished: subtest: dashboard login via authorization code flow, in 1.75 seconds)1073(finished: run the VM test script, in 87.82 seconds)1074relay # [10553.217616] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T10:00:31.179355Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}1075test script finished in 88.15s1076cleanup1077kill NspawnMachine (pid 52)1078kill NspawnMachine (pid 53)1079Container agent terminated by signal KILL.1080kill NspawnMachine (pid 54)1081Container client terminated by signal KILL.1082Container relay terminated by signal KILL.1083(finished: cleanup, in 0.39 seconds)1084additionally exposed symbols:1085 agent, client, relay,1086 vlan1,1087 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_ssh1088» job 9f22de804f08d23f8d319356581a8471 via relay 0.1.0 (agents: agent 0.1.0)1089» wave 01090agent/app | Starting flakelet update app (via relay)...1091agent/app | Started flakelet update app (via relay).1092agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v21093agent/app | app: activating generation 21094agent/app | app: updated to generation 21095agent/app | flakelet-relay-job-app.service: Deactivated successfully.1096» agent/app: updated (generation 2)1097» ok10981099» job a8a0c87420c2181b5ba7cad86aa90385 via relay 0.1.0 (agents: agent 0.1.0)1100» wave 01101agent/app | Starting flakelet update app (via relay)...1102agent/app | Started flakelet update app (via relay).1103agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1104agent/app | app: activating generation 41105agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1106agent/app | failed units: app.service. See journalctl -u app.service1107agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1108agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1109» agent/app: rolled-back (generation 3)1110agent/app │ Starting app v1...1111agent/app │ Started app v1.1112agent/app │ Stopping app v1...1113agent/app │ app.service: Deactivated successfully.1114agent/app │ Stopped app v1.1115agent/app │ Starting app v2...1116agent/app │ Started app v2.1117agent/app │ Stopping app v2...1118agent/app │ app.service: Deactivated successfully.1119agent/app │ Stopped app v2.1120agent/app │ Starting app v1...1121agent/app │ Started app v1.1122agent/app │ Stopping app v1...1123agent/app │ app.service: Deactivated successfully.1124agent/app │ Stopped app v1.1125agent/app │ Starting app broken...1126agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1127agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1128agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1129agent/app │ app.service: Failed with result 'exit-code'.1130agent/app │ Failed to start app broken.1131agent/app │ Starting app v1...1132agent/app │ Started app v1.1133» skipped: agent/other1134» failed11351136» job 099931305f5821596bb26525b513269f via relay 0.1.0 (agents: agent 0.1.0)1137» wave 01138agent/app | Starting flakelet update app (via relay)...1139agent/app | Started flakelet update app (via relay).1140agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1141agent/app | app: activating generation 71142agent/app | app: updated to generation 71143agent/app | flakelet-relay-job-app.service: Deactivated successfully.1144» agent/app: updated (generation 7)1145» ok11461147» job f1e1c707d6646eaa3dd70f67aba40f18 via relay 0.1.0 (agents: agent 0.1.0)1148» wave 01149agent/app | Starting flakelet update app (via relay)...1150agent/app | Started flakelet update app (via relay).1151agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21152agent/app | app: activating generation 81153agent/app | app: updated to generation 81154agent/app | flakelet-relay-job-app.service: Deactivated successfully.1155» agent/app: updated (generation 8)1156» ok11571158» job 7115753d344731557ff8531cd3a9b170 via relay 0.1.0 (agents: agent 0.1.0)1159» wave 01160agent/app | Starting flakelet update app (via relay)...1161agent/app | Started flakelet update app (via relay).1162agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1163agent/app | app: activating generation 91164flakelet-push: stream: error reading a body from connection, resuming job 7fd76dbeaf4a1eaab775b97e3e4540f01165flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1166flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1167» job 7115753d344731557ff8531cd3a9b170 via relay 0.1.0 (agents: agent 0.1.0)1168» wave 01169agent/app | app: updated to generation 91170agent/app | flakelet-relay-job-app.service: Deactivated successfully.1171» agent/app: updated (generation 9)1172» ok117311741788688824 hist1 admin@example.org agent/other:unchanged11751788688814 7fd76dbeaf4a1eaab775b97e3e4540f0 admin@example.org agent/app:updated11761788688805 0e67255806096c8f57d252c28203eea1 admin@example.org agent/app:updated11771788688789 0d9456b9378d5ab46b821056301aa8a4 admin@example.org agent/app:updated11781788688780 21faef6220ece44001aca9837cea7ea3 admin@example.org agent/other:unchanged11791788688768 284f34dbe36e16d132f31d902756eae1 admin@example.org agent/app:updated11801788688767 259fa2076919a28c31ec47c9d353d401 admin@example.org agent/app:unchanged11811788688766 54da4dbb623fa6ef43cb2ff9ae24d9ec admin@example.org agent/app:unchanged11821788688766 f885dec345e86d1d52c4af554e8832a1 admin@example.org agent/app:unchanged11831788688761 08451866f69ba51ac80761775b3ae582 dev@example.org agent/other:unchanged11841788688761 5abbcd0234c3f5267203d8d73abc867f admin@example.org agent/app:rolled-back11851788688760 1fd2aae6404967fdcde13b1364b4195d dev@example.org agent/other:unchanged11861788688757 a4b30748dc1c9fc73ebc211bcd494fc4 someone agent/other:unchanged11871788688754 e94dbe11e9c7ce6b0b721dfdae215945 repo:github:example/app:ref:refs/heads/main agent/app:updated11881788688751 8b7ab91a84d920bacf7149a29b0187fe admin@example.org agent/app:updated1189