container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #29
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 51)10agent: Waiting for journal at /build/vm-state-agent/var/log/journal...11client: systemd-nspawn running (pid 53)12relay: systemd-nspawn running (pid 56)13client: Waiting for journal at /build/vm-state-client/var/log/journal...14relay: Waiting for journal at /build/vm-state-relay/var/log/journal...15(finished: start all VMs, in 0.01 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.25░ Spawning container relay on /build/vm-state-relay.26░ Spawning container agent on /build/vm-state-agent.27Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.28░ Spawning container client on /build/vm-state-client.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31client # No journal files were found.32relay # No journal files were found.33client # No journal boot entry found for the specified boot (+0).34relay # No journal boot entry found for the specified boot (+0).35agent # [14999.781593] agent systemd-journald[57]: Journal started36agent # [14999.781635] agent systemd-journald[57]: Runtime Journal (/run/log/journal/2a89d6dbcb7f4a1f94a35d8ed7f32cc2) is 8M, max 4G, 3.9G free.37agent # [14999.796040] agent systemd[1]: Finished Apply Kernel Variables.38agent # [14999.809233] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [14999.840711] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [14999.841654] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [14999.849985] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/2a89d6dbcb7f4a1f94a35d8ed7f32cc2 is 1.305ms for 6 entries.42agent # [14999.849985] agent systemd-journald[57]: System Journal (/var/log/journal/2a89d6dbcb7f4a1f94a35d8ed7f32cc2) is 512B, max 4G, 3.9G free.43agent # [14999.862295] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [14999.863121] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [14999.863242] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [14999.874496] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [14999.947110] agent systemd[1]: Finished Firewall.48agent # [15000.804593] agent systemd[1]: Mounting /run/wrappers...49client # [14999.772201] client systemd-journald[57]: Journal started50client # [14999.772240] client systemd-journald[57]: Runtime Journal (/run/log/journal/0c8d0696facb4f17b87e4e0d1393b352) is 8M, max 4G, 3.9G free.51client # [14999.783517] client systemd[1]: Finished Apply Kernel Variables.52client # [14999.795929] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.53client # [14999.810827] client systemd[1]: Starting Flush Journal to Persistent Storage...54client # [14999.811566] client systemd[1]: Starting Create Static Device Nodes in /dev...55client # [14999.845967] client systemd-journald[57]: Time spent on flushing to /var/log/journal/0c8d0696facb4f17b87e4e0d1393b352 is 1.277ms for 6 entries.56client # [14999.845967] client systemd-journald[57]: System Journal (/var/log/journal/0c8d0696facb4f17b87e4e0d1393b352) is 512B, max 4G, 3.9G free.57client # [14999.856928] client systemd[1]: Finished Create Static Device Nodes in /dev.58client # [14999.857681] client systemd[1]: Reached target Preparation for Local File Systems.59client # [14999.857776] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys60client # [14999.868809] client systemd[1]: Finished Flush Journal to Persistent Storage.61client # [14999.935826] client systemd[1]: Finished Firewall.62client # [15000.772941] client systemd[1]: Mounting /run/wrappers...63relay # [14999.783158] relay systemd-journald[57]: Journal started64relay # [14999.783206] relay systemd-journald[57]: Runtime Journal (/run/log/journal/38b0b7f93ec7445699db5fb09cf5f2da) is 8M, max 4G, 3.9G free.65relay # [14999.796110] relay systemd[1]: Finished Apply Kernel Variables.66relay # [14999.809320] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.67relay # [14999.840563] relay systemd[1]: Starting Flush Journal to Persistent Storage...68relay # [14999.841299] relay systemd[1]: Starting Create Static Device Nodes in /dev...69relay # [14999.850026] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/38b0b7f93ec7445699db5fb09cf5f2da is 1.441ms for 6 entries.70relay # [14999.850026] relay systemd-journald[57]: System Journal (/var/log/journal/38b0b7f93ec7445699db5fb09cf5f2da) is 512B, max 4G, 3.9G free.71relay # [14999.860605] relay systemd[1]: Finished Create Static Device Nodes in /dev.72relay # [14999.861394] relay systemd[1]: Reached target Preparation for Local File Systems.73relay # [14999.861522] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys74relay # [14999.876124] relay systemd[1]: Finished Flush Journal to Persistent Storage.75relay # [14999.956312] relay systemd[1]: Finished Firewall.76relay # [15000.804700] relay systemd[1]: Mounting /run/wrappers...77client # [15000.824558] client systemd[1]: Mounted /run/wrappers.78client # [15000.825357] client systemd[1]: Reached target Local File Systems.79client # [15000.826158] client systemd[1]: Listening on Boot Loader Control Service Socket.80client # [15000.827460] client systemd[1]: Starting Create SUID/SGID Wrappers...81client # [15000.827492] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container82client # [15000.828501] client systemd[1]: Starting Save Transient machine-id to Disk...83client # [15000.829304] client systemd[1]: Starting Create System Files and Directories...84client # [15000.847156] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85client # [15000.847593] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted86client # [15000.847928] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/0c8d0696facb4f17b87e4e0d1393b352 failed: Operation not permitted87client # [15000.848370] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted88relay # [15000.825923] relay systemd[1]: Mounted /run/wrappers.89relay # [15000.826708] relay systemd[1]: Reached target Local File Systems.90relay # [15000.827498] relay systemd[1]: Listening on Boot Loader Control Service Socket.91relay # [15000.828702] relay systemd[1]: Starting Create SUID/SGID Wrappers...92relay # [15000.828761] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container93relay # [15000.829961] relay systemd[1]: Starting Save Transient machine-id to Disk...94relay # [15000.830934] relay systemd[1]: Starting Create System Files and Directories...95relay # [15000.849690] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted96relay # [15000.850149] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted97relay # [15000.850520] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/38b0b7f93ec7445699db5fb09cf5f2da failed: Operation not permitted98relay # [15000.850860] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted99agent # [15000.835921] agent systemd[1]: Mounted /run/wrappers.100agent # [15000.837097] agent systemd[1]: Reached target Local File Systems.101agent # [15000.838324] agent systemd[1]: Listening on Boot Loader Control Service Socket.102agent # [15000.839678] agent systemd[1]: Starting Create SUID/SGID Wrappers...103agent # [15000.839718] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104agent # [15000.840878] agent systemd[1]: Starting Save Transient machine-id to Disk...105agent # [15000.841808] agent systemd[1]: Starting Create System Files and Directories...106agent # [15000.859224] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted107agent # [15000.859738] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108agent # [15000.860066] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/2a89d6dbcb7f4a1f94a35d8ed7f32cc2 failed: Operation not permitted109agent # [15000.860419] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110relay # [15000.852817] relay systemd[1]: Finished Create System Files and Directories.111relay # [15000.853410] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.wc7Rx73yP5/chsh': Operation not permitted112relay # [15000.865610] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE113relay # [15000.865729] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.114relay # [15000.865769] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.115relay # [15000.868351] relay systemd[1]: Starting Rebuild Journal Catalog...116relay # [15000.869694] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...117relay # [15000.882330] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.118relay # [15000.888317] relay systemd[1]: Finished Rebuild Journal Catalog.119relay # [15000.889403] relay systemd[1]: Starting Update is Completed...120relay # [15000.900326] relay systemd[1]: Finished Update is Completed.121relay # [15000.900424] relay systemd[1]: Reached target System Initialization.122relay # [15000.900503] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123relay # [15000.900543] relay systemd[1]: Started Daily Cleanup of Temporary Directories.124relay # [15000.900559] relay systemd[1]: Reached target Timer Units.125relay # [15000.900658] relay systemd[1]: Listening on D-Bus System Message Bus Socket.126relay # [15000.900852] relay systemd[1]: Listening on Nix Daemon Socket.127relay # [15000.900947] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128relay # [15000.900961] relay systemd[1]: Reached target Socket Units.129relay # [15000.900991] relay systemd[1]: Reached target Basic System.130relay # [15000.902362] relay systemd[1]: Started device-mock.service.131relay # [15000.903330] relay systemd[1]: Starting Re-link flakelet services at boot...132relay # [15000.904017] relay systemd[1]: Starting Import lastlog data into lastlog2 database...133relay # [15000.905043] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...134relay # [15000.906081] relay systemd[1]: Starting resolvconf update...135relay # [15000.917918] relay systemd[1]: Finished Re-link flakelet services at boot.136relay # [15000.920475] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...137relay # [15000.929084] relay systemd[1]: Finished Import lastlog data into lastlog2 database.138relay # [15000.932956] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.139relay # [15000.976210] relay systemd[1]: Finished resolvconf update.140relay # [15000.976352] relay systemd[1]: Reached target Preparation for Network.141relay # [15000.977538] relay systemd[1]: Starting Address configuration of eth1...142relay # [15000.978307] relay systemd[1]: Starting Extra networking commands....143relay # [15000.998332] relay network-addresses-eth1-start[245]: adding address 192.168.1.3/24... done144relay # [15001.001723] relay network-addresses-eth1-start[245]: adding address 2001:db8:1::3/64... done145relay # [15001.006747] relay systemd[1]: Finished Address configuration of eth1.146client # [15000.851800] client systemd[1]: Finished Create System Files and Directories.147client # [15000.852459] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.hF4e3TOQgv/chsh': Operation not permitted148client # [15000.865461] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE149client # [15000.865561] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.150client # [15000.865731] client systemd[1]: Failed to start Create SUID/SGID Wrappers.151client # [15000.868166] client systemd[1]: Starting Rebuild Journal Catalog...152client # [15000.869642] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...153client # [15000.882307] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.154client # [15000.889526] client systemd[1]: Finished Rebuild Journal Catalog.155client # [15000.890643] client systemd[1]: Starting Update is Completed...156client # [15000.901902] client systemd[1]: Finished Update is Completed.157client # [15000.902017] client systemd[1]: Reached target System Initialization.158client # [15000.902087] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container159client # [15000.902114] client systemd[1]: Started Daily Cleanup of Temporary Directories.160client # [15000.902128] client systemd[1]: Reached target Timer Units.161client # [15000.902233] client systemd[1]: Listening on D-Bus System Message Bus Socket.162client # [15000.902453] client systemd[1]: Listening on Nix Daemon Socket.163client # [15000.902553] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.164client # [15000.902570] client systemd[1]: Reached target Socket Units.165client # [15000.902601] client systemd[1]: Reached target Basic System.166client # [15000.903949] client systemd[1]: Starting Import lastlog data into lastlog2 database...167client # [15000.905063] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...168client # [15000.906640] client systemd[1]: Starting resolvconf update...169client # [15000.925609] client systemd[1]: Finished Import lastlog data into lastlog2 database.170client # [15000.986729] client systemd[1]: Finished resolvconf update.171client # [15000.986875] client systemd[1]: Reached target Preparation for Network.172client # [15000.988129] client systemd[1]: Starting Address configuration of eth1...173client # [15000.989343] client systemd[1]: Starting Extra networking commands....174client # [15001.009873] client network-addresses-eth1-start[232]: adding address 192.168.1.2/24... done175client # [15001.012948] client network-addresses-eth1-start[232]: adding address 2001:db8:1::2/64... done176client # [15001.018470] client systemd[1]: Finished Address configuration of eth1.177agent # [15000.861218] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.MtoYG1fPiB/chsh': Operation not permitted178agent # [15000.867166] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE179agent # [15000.867204] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.180agent # [15000.867258] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.181agent # [15000.867843] agent systemd[1]: Finished Create System Files and Directories.182agent # [15000.881631] agent systemd[1]: Starting Rebuild Journal Catalog...183agent # [15000.882441] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...184agent # [15000.895304] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.185agent # [15000.899293] agent systemd[1]: Finished Rebuild Journal Catalog.186agent # [15000.900231] agent systemd[1]: Starting Update is Completed...187agent # [15000.910506] agent systemd[1]: Finished Update is Completed.188agent # [15000.910647] agent systemd[1]: Reached target System Initialization.189agent # [15000.910720] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container190agent # [15000.910744] agent systemd[1]: Started Daily Cleanup of Temporary Directories.191agent # [15000.910760] agent systemd[1]: Reached target Timer Units.192agent # [15000.910857] agent systemd[1]: Listening on D-Bus System Message Bus Socket.193agent # [15000.911050] agent systemd[1]: Listening on Nix Daemon Socket.194agent # [15000.911149] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.195agent # [15000.911162] agent systemd[1]: Reached target Socket Units.196agent # [15000.911193] agent systemd[1]: Reached target Basic System.197agent # [15000.912377] agent systemd[1]: Starting Re-link flakelet services at boot...198agent # [15000.912957] agent systemd[1]: Starting Import lastlog data into lastlog2 database...199agent # [15000.913896] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...200agent # [15000.914470] agent systemd[1]: Starting resolvconf update...201agent # [15000.927411] agent systemd[1]: Finished Re-link flakelet services at boot.202agent # [15000.928353] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...203agent # [15000.932332] agent systemd[1]: Finished Import lastlog data into lastlog2 database.204agent # [15000.940027] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.205agent # [15000.988278] agent systemd[1]: nscd.service: Deactivated successfully.206agent # [15000.988421] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).207agent # [15000.990513] agent systemd[1]: Finished resolvconf update.208agent # [15000.991998] agent systemd[1]: Reached target Preparation for Network.209agent # [15000.992974] agent systemd[1]: Starting Address configuration of eth1...210agent # [15000.993680] agent systemd[1]: Starting Extra networking commands....211agent # [15000.994518] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...212agent # [15001.012188] agent network-addresses-eth1-start[239]: adding address 192.168.1.1/24... done213agent # [15001.014931] agent network-addresses-eth1-start[239]: adding address 2001:db8:1::1/64... done214agent # [15001.022903] agent systemd[1]: Finished Address configuration of eth1.215client # [15001.064382] client systemd[1]: nscd.service: Deactivated successfully.216client # [15001.066808] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).217client # [15001.224150] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.218client # [15001.225395] client systemd[1]: Finished Save Transient machine-id to Disk.219client # [15001.241031] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...220client # [15001.244464] client systemd[1]: nscd.service: Deactivated successfully.221client # [15001.244642] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).222client # [15001.247881] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...223client # [15001.279271] client systemd[1]: Finished Extra networking commands..224client # [15001.279652] client systemd[1]: Reached target Network.225relay # [15001.066771] relay systemd[1]: Finished Extra networking commands..226relay # [15001.076622] relay systemd[1]: nscd.service: Deactivated successfully.227relay # [15001.077733] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).228relay # [15001.083496] relay systemd[1]: Reached target Network.229relay # [15001.085021] relay systemd[1]: Starting Dnsmasq Daemon...230relay # [15001.086141] relay systemd[1]: Starting Nginx Web Server...231relay # [15001.087395] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...232relay # [15001.088440] relay systemd[1]: Starting Update flakelet service flakelet-relay...233relay # [15001.125313] relay flakelet[309]: flakelet-relay: using prebuilt artifact /nix/store/bpb2mhfrqsvpql2mf2508y44zck75g5s-flakelet-flakelet-relay234relay # [15001.125961] relay flakelet[309]: flakelet-relay: activating generation 1235relay # [15001.128623] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.236relay # [15001.130099] relay systemd[1]: Finished Save Transient machine-id to Disk.237relay # [15001.132598] relay systemd[1]: Reload requested from client PID 315 ('systemctl') (unit flakelet-flakelet-relay.service)...238relay # [15001.132639] relay systemd[1]: Reloading...239agent # [15001.223037] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.240agent # [15001.224340] agent systemd[1]: Finished Save Transient machine-id to Disk.241agent # [15001.250244] agent systemd[1]: nscd.service: Deactivated successfully.242agent # [15001.250393] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).243agent # [15001.279487] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...244agent # [15001.279639] agent systemd[1]: Finished Extra networking commands..245agent # [15001.280419] agent systemd[1]: Reached target Network.246agent # [15001.281642] agent systemd[1]: Starting Update flakelet service app...247agent # [15001.282444] agent systemd[1]: Starting Update flakelet service flakelet-agent...248agent # [15001.283347] agent systemd[1]: Starting Update flakelet service other...249agent # [15001.293735] agent flakelet[308]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1250agent # [15001.294380] agent flakelet[308]: app: activating generation 1251agent # [15001.295151] agent flakelet[310]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1252agent # [15001.295675] agent flakelet[310]: other: activating generation 1253agent # [15001.296317] agent flakelet[309]: flakelet-agent: using prebuilt artifact /nix/store/y4sqgafd50j7yscbm9616bg2bini5d4v-flakelet-flakelet-agent254agent # [15001.297345] agent flakelet[309]: flakelet-agent: activating generation 1255agent # [15001.297606] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-app.service)...256agent # [15001.297640] agent systemd[1]: Reloading...257relay # [15001.455539] relay nsncd[308]: Sep 06 11:14:39.417 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"258relay # [15001.496121] relay systemd[1]: Reloading finished in 363 ms.259relay # [15001.588492] relay systemd[1]: Started Name Service Cache Daemon (nsncd).260relay # [15001.589518] relay systemd[1]: Reached target Host and Network Name Lookups.261relay # [15001.589609] relay systemd[1]: Reached target User and Group Name Lookups.262relay # [15001.590980] relay systemd[1]: Starting User Login Management...263relay # [15001.591987] relay systemd[1]: Starting Permit User Sessions...264relay # [15001.602262] relay systemd[1]: Finished Permit User Sessions.265relay # [15001.603211] relay systemd[1]: Reload requested from client PID 358 ('systemctl') (unit flakelet-flakelet-relay.service)...266relay # [15001.603252] relay systemd[1]: Reloading...267agent # [15001.543717] agent nsncd[306]: Sep 06 11:14:39.505 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"268agent # [15001.640494] agent systemd[1]: Reloading finished in 342 ms.269agent # [15001.726292] agent systemd[1]: Started Name Service Cache Daemon (nsncd).270agent # [15001.729398] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-other.service)...271agent # [15001.729445] agent systemd[1]: Reloading...272client # [15001.548647] client nsncd[293]: Sep 06 11:14:39.510 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"273client # [15001.548808] client systemd[1]: Started Name Service Cache Daemon (nsncd).274client # [15001.548866] client systemd[1]: Reached target Host and Network Name Lookups.275client # [15001.548932] client systemd[1]: Reached target User and Group Name Lookups.276client # [15001.550417] client systemd[1]: Starting User Login Management...277client # [15001.551215] client systemd[1]: Starting Permit User Sessions...278client # [15001.588734] client systemd[1]: Finished Permit User Sessions.279client # [15001.589986] client systemd[1]: Started Console Getty.280client # [15001.590020] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0281client # [15001.590031] client systemd[1]: Reached target Login Prompts.282relay # [15001.818058] relay dnsmasq-pre-start[395]: dnsmasq: syntax check OK.283relay # [15001.959520] relay systemd[1]: Reloading finished in 355 ms.284relay # [15002.040931] relay systemd[1]: Started Console Getty.285relay # [15002.040958] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0286relay # [15002.040971] relay systemd[1]: Reached target Login Prompts.287agent # [15002.076066] agent systemd[1]: Reloading finished in 346 ms.288agent # [15002.154580] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-flakelet-agent.service)...289agent # [15002.154631] agent systemd[1]: Reloading...290relay # [15002.069312] relay systemd[1]: Starting flakelet-relay...291agent # [15002.487851] agent systemd[1]: Reloading finished in 332 ms.292agent # [15002.573112] agent systemd[1]: Reached target Host and Network Name Lookups.293agent # [15002.573205] agent systemd[1]: Reached target User and Group Name Lookups.294agent # [15002.574316] agent systemd[1]: Starting User Login Management...295agent # [15002.575287] agent systemd[1]: Starting Permit User Sessions...296agent # [15002.578542] agent systemd[1]: Reload requested from client PID 405 ('systemctl') (unit flakelet-other.service)...297agent # [15002.578574] agent systemd[1]: Reloading...298relay # [15002.608082] relay systemd[1]: Starting D-Bus System Message Bus...299relay # [15003.021270] relay nginx-pre-start[404]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok300relay # [15003.021270] relay nginx-pre-start[404]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful301relay # [15003.037777] relay systemd[1]: Started Nginx Web Server.302relay # [15003.253172] relay dbus-broker-launch[403]: Looking up NSS user entry for 'systemd-timesync'...303relay # [15003.254491] relay dbus-broker-launch[403]: NSS returned no entry for 'systemd-timesync'304relay # [15003.254491] relay dbus-broker-launch[403]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"305relay # [15003.255540] relay systemd[1]: Started D-Bus System Message Bus.306relay # [15003.260434] relay dbus-broker-launch[403]: Ready307relay # [15003.263809] relay systemd[1]: Started Dnsmasq Daemon.308relay # [15003.265970] relay dnsmasq[396]: started, version 2.93 cachesize 150309relay # [15003.265980] relay dnsmasq[396]: 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 dumpfile310relay # [15003.265985] relay dnsmasq[396]: DBus support enabled: connected to system bus311relay # [15003.265991] relay dnsmasq[396]: no upstream servers configured - please set them from DBus312relay # [15003.266151] relay dnsmasq[396]: read /etc/hosts - 9 names313agent # [15002.963209] agent systemd[1]: Reloading finished in 384 ms.314agent # [15003.055572] agent systemd[1]: Finished Permit User Sessions.315agent # [15003.060787] agent systemd[1]: Reload requested from client PID 409 ('systemctl') (unit flakelet-app.service)...316agent # [15003.060825] agent systemd[1]: Reloading...317client # [15003.010147] client systemd-logind[313]: New seat seat0.318client # [15003.010548] client systemd[1]: Started User Login Management.319client # [15003.012414] client systemd[1]: Starting D-Bus System Message Bus...320client # [15003.014069] client systemd[1]: Starting linger-users.service...321client # [15003.046609] client systemd[1]: linger-users.service: Deactivated successfully.322client # [15003.046981] client systemd[1]: Finished linger-users.service.323client # [15003.047335] client systemd[1]: Reached target Multi-User System.324relay # [15003.286533] relay systemd-logind[354]: New seat seat0.325relay # [15003.286783] relay systemd[1]: Started User Login Management.326relay # [15003.289315] relay systemd[1]: Starting linger-users.service...327relay # [15003.337226] relay systemd[1]: linger-users.service: Deactivated successfully.328relay # [15003.337581] relay systemd[1]: Finished linger-users.service.329agent # [15003.416839] agent systemd[1]: Reloading finished in 355 ms.330agent # [15003.502820] agent systemd[1]: Started Console Getty.331agent # [15003.502934] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0332agent # [15003.503088] agent systemd[1]: Reached target Login Prompts.333agent # [15003.504013] agent systemd[1]: Starting other v1...334agent # [15003.506116] agent systemd[1]: Reload requested from client PID 444 ('systemctl') (unit flakelet-flakelet-agent.service)...335agent # [15003.506145] agent systemd[1]: Reloading...336client # [15003.508879] client dbus-broker-launch[323]: Looking up NSS user entry for 'systemd-timesync'...337client # [15003.510057] client dbus-broker-launch[323]: NSS returned no entry for 'systemd-timesync'338client # [15003.510057] client dbus-broker-launch[323]: Invalid user-name in /nix/store/l5kd2gsbxrgi6dcxkf32qp9f3s2fbcb8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"339client # [15003.510821] client systemd[1]: Started D-Bus System Message Bus.340client # [15003.511341] client systemd[1]: Startup finished in 4.180s.341client # [15003.516230] client dbus-broker-launch[323]: Ready342agent # [15003.842349] agent systemd[1]: Reloading finished in 335 ms.343agent # [15003.920908] agent systemd[1]: Started other v1.344agent # [15003.926680] agent systemd[1]: Starting app v1...345agent # [15003.930372] agent systemd-logind[407]: New seat seat0.346agent # [15003.930877] agent systemd[1]: Started User Login Management.347agent # [15003.959550] agent systemd[1]: Starting D-Bus System Message Bus...348agent # [15003.960990] agent systemd[1]: Starting flakelet-agent...349agent # [15003.962167] agent systemd[1]: Starting linger-users.service...350agent # [15003.963549] agent systemd[1]: Started app v1.351agent # [15003.966456] agent flakelet[310]: other: updated to generation 1352agent # [15003.968308] agent systemd[1]: Finished Update flakelet service other.353agent # [15003.979049] agent flakelet[308]: app: updated to generation 1354agent # [15003.981541] agent systemd[1]: Finished Update flakelet service app.355agent # [15003.985706] agent systemd[1]: linger-users.service: Deactivated successfully.356agent # [15003.985874] agent systemd[1]: Finished linger-users.service.357agent # [15004.078061] agent systemd[1]: Started flakelet-agent.358agent # [15004.081091] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:42.042833Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}359agent # [15004.092845] agent flakelet[309]: flakelet-agent: updated to generation 1360relay # [15004.115170] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:42.076776Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}361relay # [15004.116077] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:42.077327Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}362relay # [15004.115747] relay systemd[1]: Started flakelet-relay.363relay # [15004.125563] relay systemd[1]: Starting health for flakelet-relay...364agent # [15004.094676] agent systemd[1]: Finished Update flakelet service flakelet-agent.365agent # [15004.096053] agent systemd[1]: Reached target flakelet managed services.366agent # [15004.096144] agent systemd[1]: Reached target Multi-User System.367agent # [15004.429736] agent dbus-broker-launch[506]: Looking up NSS user entry for 'systemd-timesync'...368agent # [15004.431061] agent dbus-broker-launch[506]: NSS returned no entry for 'systemd-timesync'369agent # [15004.431061] agent dbus-broker-launch[506]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"370agent # [15004.431575] agent systemd[1]: Started D-Bus System Message Bus.371agent # [15004.431862] agent systemd[1]: Startup finished in 5.096s.372agent # [15004.437423] agent dbus-broker-launch[506]: Ready373relay # [15004.410870] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.374relay # [15004.411160] relay systemd[1]: Finished health for flakelet-relay.375relay # [15004.441655] relay flakelet[309]: flakelet-relay: updated to generation 1376relay # [15004.453175] relay systemd[1]: Finished Update flakelet service flakelet-relay.377relay # [15004.453467] relay systemd[1]: Reached target flakelet managed services.378relay # [15004.453555] relay systemd[1]: Reached target Multi-User System.379relay # [15004.455150] relay systemd[1]: Startup finished in 5.120s.380relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)381relay: waiting for unit nginx.service382relay: (finished: waiting for unit nginx.service, in 0.01 seconds)383agent: waiting for unit flakelet.target384agent: (finished: waiting for unit flakelet.target, in 0.01 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 # [15006.096134] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:44.057885Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}391relay # [15006.096281] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:44.058027Z","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.05 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.01 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 # [15007.114415] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:45.076191Z","level":"INFO","message":"start","id":"da426651919e3a648c678ca7c1ee0d20","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}400agent # [15007.115285] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:45.076618Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"da426651919e3a648c678ca7c1ee0d20\"]","target":"flakelet_relay::agent::jobs"}401agent # [15007.179570] agent systemd[1]: Starting flakelet update app (via relay)...402agent # [15007.209118] agent systemd[1]: Started flakelet update app (via relay).403agent # [15007.214209] agent flakelet[959]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2404agent # [15007.215507] agent flakelet[959]: app: activating generation 2405agent # [15007.224686] agent systemd[1]: Stopping app v1...406agent # [15007.225399] agent systemd[1]: app.service: Deactivated successfully.407agent # [15007.225531] agent systemd[1]: Stopped app v1.408agent # [15007.234780] agent systemd[1]: Reload requested from client PID 966 ('systemctl') (unit flakelet-relay-job-app.service)...409agent # [15007.234816] agent systemd[1]: Reloading...410relay # [15007.113828] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:45.075589Z","level":"INFO","message":"deploy accepted","job":"0af2fc6b6b2f9e17d70c64f51f21e800","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}411agent # [15007.568702] agent systemd[1]: Reloading finished in 333 ms.412agent # [15007.654418] agent systemd[1]: Reload requested from client PID 996 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [15007.654457] agent systemd[1]: Reloading...414agent # [15007.976637] agent systemd[1]: Reloading finished in 321 ms.415agent # [15008.063561] agent systemd[1]: Reload requested from client PID 1025 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [15008.063597] agent systemd[1]: Reloading...417agent # [15008.384158] agent systemd[1]: Reloading finished in 320 ms.418agent # [15008.474379] agent systemd[1]: Reload requested from client PID 1059 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [15008.474414] agent systemd[1]: Reloading...420agent # [15008.800264] agent systemd[1]: Reloading finished in 325 ms.421agent # [15008.893746] agent systemd[1]: Starting app v2...422agent # [15008.929764] agent systemd[1]: Started app v2.423agent # [15008.945223] agent flakelet[959]: app: updated to generation 2424agent # [15008.945767] 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.95 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 2.99 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU4OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMjg4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMT1VMRkpBSktWRDNDPT09IiwibmJmIjoxNzg4NjkzMjg4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ahC4q5hf2OqJdmKo0b1m05gHJO7U4YdEqi94H8zc04G8zWLuWtzyAwgB5dLWQG8CNLMXb80Q6v9i0GZVdo53AA' push --relay https://relay:7443 deploy agent/app 2>&1437relay # [15010.037037] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:47.998774Z","level":"INFO","message":"deploy finished","job":"0af2fc6b6b2f9e17d70c64f51f21e800","ok":true,"target":"flakelet_relay::relay::api"}438relay # [15010.166990] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:48.128784Z","level":"INFO","message":"deploy accepted","job":"d9f98daa689ebecd3633565eb84db433","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}439agent # [15010.035357] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:47.997106Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}440agent # [15010.167196] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:48.128992Z","level":"INFO","message":"start","id":"90a61e368153cc938ad8177e3a71c53f","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"}441agent # [15010.167435] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:48.129267Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"90a61e368153cc938ad8177e3a71c53f\"]","target":"flakelet_relay::agent::jobs"}442agent # [15010.210206] agent systemd[1]: Starting flakelet update app (via relay)...443agent # [15010.252503] agent systemd[1]: Started flakelet update app (via relay).444agent # [15010.256785] agent flakelet[1160]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1445agent # [15010.257466] agent flakelet[1160]: app: activating generation 3446agent # [15010.266072] agent systemd[1]: Stopping app v2...447agent # [15010.266772] agent systemd[1]: app.service: Deactivated successfully.448agent # [15010.266906] agent systemd[1]: Stopped app v2.449agent # [15010.277942] agent systemd[1]: Reload requested from client PID 1167 ('systemctl') (unit flakelet-relay-job-app.service)...450agent # [15010.277977] agent systemd[1]: Reloading...451agent # [15010.606203] agent systemd[1]: Reloading finished in 327 ms.452agent # [15010.697023] agent systemd[1]: Reload requested from client PID 1197 ('systemctl') (unit flakelet-relay-job-app.service)...453agent # [15010.697060] agent systemd[1]: Reloading...454agent # [15011.026489] agent systemd[1]: Reloading finished in 329 ms.455agent # [15011.108558] agent systemd[1]: Reload requested from client PID 1226 ('systemctl') (unit flakelet-relay-job-app.service)...456agent # [15011.108596] agent systemd[1]: Reloading...457agent # [15011.440524] agent systemd[1]: Reloading finished in 331 ms.458agent # [15011.534377] agent systemd[1]: Reload requested from client PID 1257 ('systemctl') (unit flakelet-relay-job-app.service)...459agent # [15011.534415] agent systemd[1]: Reloading...460agent # [15011.859692] agent systemd[1]: Reloading finished in 324 ms.461agent # [15011.940166] agent systemd[1]: Starting app v1...462agent # [15011.971848] agent systemd[1]: Started app v1.463agent # [15011.986435] agent flakelet[1160]: app: updated to generation 3464agent # [15011.988561] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.465client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU4OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMjg4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMT1VMRkpBSktWRDNDPT09IiwibmJmIjoxNzg4NjkzMjg4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ahC4q5hf2OqJdmKo0b1m05gHJO7U4YdEqi94H8zc04G8zWLuWtzyAwgB5dLWQG8CNLMXb80Q6v9i0GZVdo53AA' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.96 seconds)466(finished: subtest: deploy with OIDC token, sub principal, in 3.03 seconds)467subtest: policy denies uncovered target468client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU4OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMjg4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMT1VMRkpBSktWRDNDPT09IiwibmJmIjoxNzg4NjkzMjg4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ahC4q5hf2OqJdmKo0b1m05gHJO7U4YdEqi94H8zc04G8zWLuWtzyAwgB5dLWQG8CNLMXb80Q6v9i0GZVdo53AA' push --relay https://relay:7443 deploy agent/other 2>&1469client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU4OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMjg4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJMT1VMRkpBSktWRDNDPT09IiwibmJmIjoxNzg4NjkzMjg4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ahC4q5hf2OqJdmKo0b1m05gHJO7U4YdEqi94H8zc04G8zWLuWtzyAwgB5dLWQG8CNLMXb80Q6v9i0GZVdo53AA' 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.08 seconds)474client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU5MSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY5MzI5MSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiSEpLT1NSWDVEQzZEQz09PSIsIm5iZiI6MTc4ODY5MzI5MSwic3ViIjoic29tZW9uZSJ9.p5aBB7I8mfl1ty7JX9e26MgrXZfH714JLHk8z3fGU3p1BlvXJ-kfTNjlUSxSRr-z6smfZkELu1S7MqE-Ar56BQ' push --relay https://relay:7443 deploy agent/other 2>&1475agent # [15013.097483] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:51.059252Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}476agent # [15013.228547] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:51.190343Z","level":"INFO","message":"start","id":"b1c2a8f8b8dffc9680e9df943dfac74c","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"}477agent # [15013.228839] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:51.190669Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"b1c2a8f8b8dffc9680e9df943dfac74c\"]","target":"flakelet_relay::agent::jobs"}478agent # [15013.290673] agent systemd[1]: Starting flakelet update other (via relay)...479agent # [15013.330375] agent systemd[1]: Started flakelet update other (via relay).480agent # [15013.336310] agent flakelet[1338]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1481agent # [15013.337340] agent flakelet[1338]: other: up to date482agent # [15013.338449] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.483relay # [15013.098925] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:51.060648Z","level":"INFO","message":"deploy finished","job":"d9f98daa689ebecd3633565eb84db433","ok":true,"target":"flakelet_relay::relay::api"}484relay # [15013.228271] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:51.190061Z","level":"INFO","message":"deploy accepted","job":"c6c41040efb1b9ad80a0f685d900fec4","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}485client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzU5MSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY5MzI5MSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiSEpLT1NSWDVEQzZEQz09PSIsIm5iZiI6MTc4ODY5MzI5MSwic3ViIjoic29tZW9uZSJ9.p5aBB7I8mfl1ty7JX9e26MgrXZfH714JLHk8z3fGU3p1BlvXJ-kfTNjlUSxSRr-z6smfZkELu1S7MqE-Ar56BQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 1.71 seconds)486(finished: subtest: claim principal from groups, unchanged counts as success, in 1.79 seconds)487subtest: push login via device flow, cached token used afterwards488client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1489agent # [15014.914197] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:52.875954Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}490relay # [15014.915529] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:52.877279Z","level":"INFO","message":"deploy finished","job":"c6c41040efb1b9ad80a0f685d900fec4","ok":true,"target":"flakelet_relay::relay::api"}491relay # [15014.937991] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 11:14:52] "POST /device HTTP/1.1" 200 -492relay # [15015.944081] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 11:14:53] "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>&1497relay # [15016.996631] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 11:14:54] "POST /token HTTP/1.1" 200 -498relay # [15017.030193] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:54.991991Z","level":"INFO","message":"deploy accepted","job":"4048ca3efa85b3724f84dde67c67b4d4","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}499agent # [15017.030685] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:54.992453Z","level":"INFO","message":"start","id":"0a07f5e7b33d338cbfb14d29df558c41","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}500agent # [15017.031636] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:54.992994Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"0a07f5e7b33d338cbfb14d29df558c41\"]","target":"flakelet_relay::agent::jobs"}501agent # [15017.097659] agent systemd[1]: Starting flakelet update other (via relay)...502agent # [15017.131047] agent systemd[1]: Started flakelet update other (via relay).503agent # [15017.135255] agent flakelet[1403]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1504agent # [15017.135801] agent flakelet[1403]: other: up to date505agent # [15017.137754] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.506client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.70 seconds)507client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1508relay # [15017.705789] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:55.667539Z","level":"INFO","message":"deploy finished","job":"4048ca3efa85b3724f84dde67c67b4d4","ok":true,"target":"flakelet_relay::relay::api"}509relay # [15017.722754] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:55.684576Z","level":"INFO","message":"deploy accepted","job":"e8d7427a14e8b7c3322a070af17047a5","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}510agent # [15017.704878] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:55.666652Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}511agent # [15017.723104] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:55.684845Z","level":"INFO","message":"start","id":"291b6586239553eaab55020b31c443fd","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}512agent # [15017.723518] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:55.685340Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"291b6586239553eaab55020b31c443fd\"]","target":"flakelet_relay::agent::jobs"}513agent # [15017.769660] agent systemd[1]: Starting flakelet update other (via relay)...514agent # [15017.800092] agent systemd[1]: Started flakelet update other (via relay).515agent # [15017.805279] agent flakelet[1437]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1516agent # [15017.805762] agent flakelet[1437]: other: up to date517agent # [15017.806838] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.518client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds)519(finished: subtest: push login via device flow, cached token used afterwards, in 3.44 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>&1524agent # [15018.355270] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:56.317032Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}525agent # [15018.387048] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:56.348792Z","level":"INFO","message":"start","id":"6a0db58640ebc6551c78c12eda1ea93f","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}526agent # [15018.387433] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:14:56.349256Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6a0db58640ebc6551c78c12eda1ea93f\"]","target":"flakelet_relay::agent::jobs"}527agent # [15018.429606] agent systemd[1]: Starting flakelet update app (via relay)...528agent # [15018.458993] agent systemd[1]: Started flakelet update app (via relay).529agent # [15018.463400] agent flakelet[1492]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken530agent # [15018.464112] agent flakelet[1492]: app: activating generation 4531agent # [15018.473851] agent systemd[1]: Stopping app v1...532agent # [15018.475204] agent systemd[1]: app.service: Deactivated successfully.533agent # [15018.475424] agent systemd[1]: Stopped app v1.534agent # [15018.488644] agent systemd[1]: Reload requested from client PID 1499 ('systemctl') (unit flakelet-relay-job-app.service)...535agent # [15018.488698] agent systemd[1]: Reloading...536relay # [15018.356649] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:56.318382Z","level":"INFO","message":"deploy finished","job":"e8d7427a14e8b7c3322a070af17047a5","ok":true,"target":"flakelet_relay::relay::api"}537relay # [15018.386704] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:14:56.348503Z","level":"INFO","message":"deploy accepted","job":"63b9d9e8ab9fa669d4e32843169a6556","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}538agent # [15018.830978] agent systemd[1]: Reloading finished in 341 ms.539agent # [15018.926334] agent systemd[1]: Reload requested from client PID 1529 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [15018.926378] agent systemd[1]: Reloading...541agent # [15019.258677] agent systemd[1]: Reloading finished in 331 ms.542agent # [15019.341216] agent systemd[1]: Reload requested from client PID 1558 ('systemctl') (unit flakelet-relay-job-app.service)...543agent # [15019.341253] agent systemd[1]: Reloading...544agent # [15019.664807] agent systemd[1]: Reloading finished in 323 ms.545agent # [15019.741352] agent systemd[1]: Reload requested from client PID 1589 ('systemctl') (unit flakelet-relay-job-app.service)...546agent # [15019.741383] agent systemd[1]: Reloading...547agent # [15020.061793] agent systemd[1]: Reloading finished in 320 ms.548agent # [15020.151073] agent systemd[1]: Starting app broken...549agent # [15020.182172] agent (nonexistent)[1622]: app.service: Unable to locate executable '/nonexistent': No such file or directory550agent # [15020.182193] agent (nonexistent)[1622]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory551agent # [15020.184060] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC552agent # [15020.184153] agent systemd[1]: app.service: Failed with result 'exit-code'.553agent # [15020.184307] agent systemd[1]: Failed to start app broken.554agent # [15020.215462] agent systemd[1]: Reload requested from client PID 1639 ('systemctl') (unit flakelet-relay-job-app.service)...555agent # [15020.215501] agent systemd[1]: Reloading...556agent # [15020.535239] agent systemd[1]: Reloading finished in 319 ms.557agent # [15020.633760] agent systemd[1]: Reload requested from client PID 1670 ('systemctl') (unit flakelet-relay-job-app.service)...558agent # [15020.633798] agent systemd[1]: Reloading...559agent # [15020.955580] agent systemd[1]: Reloading finished in 321 ms.560agent # [15021.050025] agent systemd[1]: Reload requested from client PID 1700 ('systemctl') (unit flakelet-relay-job-app.service)...561agent # [15021.050062] agent systemd[1]: Reloading...562agent # [15021.385886] agent systemd[1]: Reloading finished in 335 ms.563agent # [15021.465021] agent systemd[1]: Reload requested from client PID 1730 ('systemctl') (unit flakelet-relay-job-app.service)...564agent # [15021.465062] agent systemd[1]: Reloading...565agent # [15021.797251] agent systemd[1]: Reloading finished in 331 ms.566agent # [15021.874092] agent systemd[1]: Starting app v1...567agent # [15021.906964] agent systemd[1]: Started app v1.568agent # [15021.907902] agent flakelet[1492]: app: deploy failed, rolled back: systemctl start app.service failed:569agent # [15021.907902] agent flakelet[1492]: failed units: app.service. See journalctl -u app.service570agent # [15021.910169] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE571agent # [15021.910268] 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.26 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.01 seconds)575(finished: subtest: waves: failing first wave skips the second, in 4.28 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 # [15022.622824] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:00.584576Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}581agent # [15022.675013] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:00.636808Z","level":"INFO","message":"start","id":"166ee89c378d8dc449ddb1ba2b9a6326","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}582agent # [15022.675595] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:00.637418Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"166ee89c378d8dc449ddb1ba2b9a6326\"]","target":"flakelet_relay::agent::jobs"}583agent # [15022.731730] agent systemd[1]: Starting flakelet update app (via relay)...584agent # [15022.763825] agent systemd[1]: Started flakelet update app (via relay).585agent # [15022.768364] agent flakelet[1816]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1586agent # [15022.768905] agent flakelet[1816]: app: up to date587agent # [15022.770759] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.588relay # [15022.624348] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:00.586080Z","level":"INFO","message":"deploy finished","job":"63b9d9e8ab9fa669d4e32843169a6556","ok":false,"target":"flakelet_relay::relay::api"}589relay # [15022.674727] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:00.636492Z","level":"INFO","message":"deploy accepted","job":"e96a65e0a8a031ddeec0e79db585b2ef","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.68 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 # [15023.333856] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:01.295606Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}593agent # [15023.357690] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:01.319495Z","level":"INFO","message":"start","id":"e3b9d2b131c39e2fd243eef0757f91f8","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}594agent # [15023.358090] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:01.319911Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e3b9d2b131c39e2fd243eef0757f91f8\"]","target":"flakelet_relay::agent::jobs"}595agent # [15023.409647] agent systemd[1]: Starting flakelet update app (via relay)...596agent # [15023.446116] agent systemd[1]: Started flakelet update app (via relay).597agent # [15023.450851] agent flakelet[1851]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1598agent # [15023.451436] agent flakelet[1851]: app: up to date599agent # [15023.451933] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.600relay # [15023.335198] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:01.296941Z","level":"INFO","message":"deploy finished","job":"e96a65e0a8a031ddeec0e79db585b2ef","ok":true,"target":"flakelet_relay::relay::api"}601relay # [15023.357369] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:01.319183Z","level":"INFO","message":"deploy accepted","job":"96cda8c2c2684d100031d85103b3beaa","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 1.70 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>&1604relay # [15025.031393] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:02.993101Z","level":"INFO","message":"deploy finished","job":"96cda8c2c2684d100031d85103b3beaa","ok":false,"target":"flakelet_relay::relay::api"}605relay # [15025.054546] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:03.016354Z","level":"INFO","message":"deploy accepted","job":"daaafb1313b31f9bf077569495af472e","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}606agent # [15025.029704] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:02.991489Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}607agent # [15025.054827] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:03.016632Z","level":"INFO","message":"start","id":"09017326608ccc7974977f6e5b7b8b9f","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}608agent # [15025.055268] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:03.017092Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"09017326608ccc7974977f6e5b7b8b9f\"]","target":"flakelet_relay::agent::jobs"}609agent # [15025.129038] agent systemd[1]: Starting flakelet update app (via relay)...610agent # [15025.164164] agent systemd[1]: Started flakelet update app (via relay).611agent # [15025.169419] agent flakelet[1903]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1612agent # [15025.170474] agent flakelet[1903]: app: up to date613agent # [15025.171929] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.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.71 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 3.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.service624relay # [15025.740519] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:03.702263Z","level":"INFO","message":"deploy finished","job":"daaafb1313b31f9bf077569495af472e","ok":false,"target":"flakelet_relay::relay::api"}625relay # [15025.797518] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:03.759281Z","level":"INFO","message":"deploy accepted","job":"61d6739c4a30b3e4dbc488e17ec13163","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}626agent # [15025.739277] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:03.701074Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}627agent # [15025.797816] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:03.759620Z","level":"INFO","message":"start","id":"3ef131740a620572edc95894771f5e20","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}628agent # [15025.798166] agent flakelet-agent[507]: {"timestamp":"2026-09-06T11:15:03.759999Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"3ef131740a620572edc95894771f5e20\"]","target":"flakelet_relay::agent::jobs"}629agent # [15025.842687] agent systemd[1]: Starting flakelet update app (via relay)...630agent # [15025.882981] agent systemd[1]: Started flakelet update app (via relay).631agent # [15025.888107] agent flakelet[1943]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2632agent # [15025.889415] agent flakelet[1943]: app: activating generation 4633agent # [15025.898360] agent systemd[1]: Stopping app v1...634agent # [15025.899069] agent systemd[1]: app.service: Deactivated successfully.635agent # [15025.899199] agent systemd[1]: Stopped app v1.636agent # [15025.908623] agent systemd[1]: Reload requested from client PID 1950 ('systemctl') (unit flakelet-relay-job-app.service)...637agent # [15025.908659] agent systemd[1]: Reloading...638agent # [15026.242940] agent systemd[1]: Reloading finished in 333 ms.639agent # [15026.342773] agent systemd[1]: Reload requested from client PID 1984 ('systemctl') (unit flakelet-relay-job-app.service)...640agent # [15026.342808] agent systemd[1]: Reloading...641agent # [15026.681382] agent systemd[1]: Reloading finished in 338 ms.642agent # [15026.800449] agent systemd[1]: Reload requested from client PID 2013 ('systemctl') (unit flakelet-relay-job-app.service)...643agent # [15026.800493] agent systemd[1]: Reloading...644agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.40 seconds)645??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.646 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39647agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service648??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.649 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39650agent # [15027.143321] agent systemd[1]: Reloading finished in 342 ms.651agent # [15027.204883] agent systemd[1]: Reload requested from client PID 2046 ('systemctl') (unit flakelet-relay-job-app.service)...652agent # [15027.204918] agent systemd[1]: Reloading...653agent # [15027.533220] agent systemd[1]: Reloading finished in 327 ms.654agent # [15027.585437] agent systemd[1]: Starting app slow2...655agent # [15033.647134] agent systemd[1]: Started app slow2.656agent # [15033.669343] agent flakelet[1943]: app: updated to generation 4657agent # [15033.672825] 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.48 seconds)659(finished: subtest: detach returns once the job is accepted, in 8.92 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.07 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.out670client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 0.01 seconds)671agent: must succeed: systemctl start flakelet-agent672agent # [15034.717147] agent systemd[1]: Stopping flakelet-agent...673agent # [15034.746144] agent systemd[1]: flakelet-agent.service: Deactivated successfully.674agent # [15034.746599] agent systemd[1]: Stopped flakelet-agent.675agent # [15034.747083] agent systemd[1]: flakelet-agent.service: Consumed 2.528s CPU time over 30.785s wall clock time.676agent: (finished: must succeed: systemctl start flakelet-agent, in 0.16 seconds)677agent # [15034.827511] agent systemd[1]: Starting flakelet-agent...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 39680agent # [15034.872212] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:12.833923Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"3ef131740a620572edc95894771f5e20\"]","target":"flakelet_relay::agent::jobs"}681client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out682agent # [15034.977748] agent systemd[1]: Started flakelet-agent.683relay # [15034.717100] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:12.678780Z","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"}684relay # [15034.988665] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:12.950314Z","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"}685agent # [15034.988471] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:12.950272Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}686agent # [15035.447640] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:13.409292Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}687agent # [15035.816358] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:13.778120Z","level":"INFO","message":"start","id":"4da65076f9530fc04715b524035451ee","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}688agent # [15035.816690] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:13.778515Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"4da65076f9530fc04715b524035451ee\"]","target":"flakelet_relay::agent::jobs"}689agent # [15035.881435] agent systemd[1]: Starting flakelet update other (via relay)...690agent # [15035.913016] agent systemd[1]: Started flakelet update other (via relay).691agent # [15035.918384] agent flakelet[2615]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1692agent # [15035.919401] agent flakelet[2615]: other: up to date693agent # [15035.920123] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.694relay # [15035.815959] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:13.777721Z","level":"INFO","message":"deploy accepted","job":"d918dc4e0aa0f78fb57b2544757f6a10","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}695relay # [15037.505167] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:15.466938Z","level":"INFO","message":"deploy finished","job":"d918dc4e0aa0f78fb57b2544757f6a10","ok":true,"target":"flakelet_relay::relay::api"}696agent # [15037.503128] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:15.464913Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzYxNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzE2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1Tkc0TU1OSDVJVDJXPT09IiwibmJmIjoxNzg4NjkzMzE2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gMurNKol2rIamQsQegCvX6bZKjW3-cgwdEGHuM1cHr5PrttOm9kaiVBb7-K-iWkQXTT1fDepmbmyZFV-QrIJBA' push --relay https://relay:7443 agents703client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzYxNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzE2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1Tkc0TU1OSDVJVDJXPT09IiwibmJmIjoxNzg4NjkzMzE2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gMurNKol2rIamQsQegCvX6bZKjW3-cgwdEGHuM1cHr5PrttOm9kaiVBb7-K-iWkQXTT1fDepmbmyZFV-QrIJBA' push --relay https://relay:7443 agents, in 0.02 seconds)704(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 3.43 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 # [15038.215836] agent systemd[1]: Stopping app slow2...716agent # [15038.216386] agent systemd[1]: app.service: Deactivated successfully.717agent # [15038.216653] agent systemd[1]: Stopped app slow2.718agent # [15038.233422] agent systemd[1]: Reload requested from client PID 2676 ('systemctl')...719agent # [15038.233488] agent systemd[1]: Reloading...720agent # [15038.582944] agent systemd[1]: Reloading finished in 348 ms.721agent # [15038.632651] agent systemd[1]: Reload requested from client PID 2705 ('systemctl')...722agent # [15038.632686] agent systemd[1]: Reloading...723agent # [15038.969538] agent systemd[1]: Reloading finished in 336 ms.724agent # [15039.069582] agent systemd[1]: Reload requested from client PID 2735 ('systemctl')...725agent # [15039.069627] agent systemd[1]: Reloading...726agent # [15039.403467] agent systemd[1]: Reloading finished in 333 ms.727agent # [15039.480876] agent systemd[1]: Reload requested from client PID 2767 ('systemctl')...728agent # [15039.480913] agent systemd[1]: Reloading...729agent: (finished: must succeed: flakelet update app, in 1.76 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 # [15039.810498] agent systemd[1]: Reloading finished in 329 ms.732agent # [15039.896735] agent systemd[1]: Starting app v2...733agent # [15039.939938] 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.06 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 # [15042.056210] agent systemd[1]: Stopping app v2...743agent # [15042.057303] agent systemd[1]: app.service: Deactivated successfully.744agent # [15042.057505] agent systemd[1]: Stopped app v2.745agent # [15042.067256] agent systemd[1]: Reload requested from client PID 2833 ('systemctl')...746agent # [15042.067292] agent systemd[1]: Reloading...747agent # [15042.405902] agent systemd[1]: Reloading finished in 338 ms.748agent # [15042.505431] agent systemd[1]: Reload requested from client PID 2862 ('systemctl')...749agent # [15042.505469] agent systemd[1]: Reloading...750agent # [15042.849190] agent systemd[1]: Reloading finished in 343 ms.751agent # [15042.896979] agent systemd[1]: Reload requested from client PID 2890 ('systemctl')...752agent # [15042.897020] agent systemd[1]: Reloading...753agent # [15043.233534] agent systemd[1]: Reloading finished in 336 ms.754agent # [15043.321333] agent systemd[1]: Reload requested from client PID 2922 ('systemctl')...755agent # [15043.321369] agent systemd[1]: Reloading...756agent # [15043.645068] agent systemd[1]: Reloading finished in 323 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 # [15043.691727] agent systemd[1]: Starting app v1...760agent # [15043.720733] 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.06 seconds)762(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.68 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.02 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.02 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=@1788693323 | grep -q 'app-slow'779agent # [15045.874735] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:23.836467Z","level":"INFO","message":"start","id":"6467bf1315622d7d31721829addef6ea","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}780agent # [15045.875679] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:23.837356Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6467bf1315622d7d31721829addef6ea\"]","target":"flakelet_relay::agent::jobs"}781agent # [15045.950437] agent systemd[1]: Starting flakelet update app (via relay)...782agent # [15045.978097] agent systemd[1]: Started flakelet update app (via relay).783agent # [15045.983553] agent flakelet[2996]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow784agent # [15045.984818] agent flakelet[2996]: app: activating generation 7785agent # [15045.994309] agent systemd[1]: Stopping app v1...786agent # [15045.995017] agent systemd[1]: app.service: Deactivated successfully.787agent # [15045.995143] agent systemd[1]: Stopped app v1.788agent # [15046.005856] agent systemd[1]: Reload requested from client PID 3003 ('systemctl') (unit flakelet-relay-job-app.service)...789agent # [15046.005892] agent systemd[1]: Reloading...790relay # [15045.818443] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:23.780185Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}791relay # [15045.874306] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:23.836067Z","level":"INFO","message":"deploy accepted","job":"cd23c78f1c6d5b1c8ca1a39948295a42","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}792agent # [15046.340535] agent systemd[1]: Reloading finished in 334 ms.793agent # [15046.406905] agent systemd[1]: Reload requested from client PID 3033 ('systemctl') (unit flakelet-relay-job-app.service)...794agent # [15046.406943] agent systemd[1]: Reloading...795agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788693323 | 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.07 seconds)800agent: must succeed: ss -K dport = 7443801agent # [15046.732981] agent systemd[1]: Reloading finished in 325 ms.802agent # [15046.809534] agent systemd[1]: Reload requested from client PID 3062 ('systemctl') (unit flakelet-relay-job-app.service)...803agent # [15046.809571] 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=@1788693323 | grep -q 'updated to generation'806relay # [15046.966860] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:24.928615Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}807agent # [15047.000069] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:24.961637Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}808agent # [15047.148696] agent systemd[1]: Reloading finished in 338 ms.809agent # [15047.246422] agent systemd[1]: Reload requested from client PID 3110 ('systemctl') (unit flakelet-relay-job-app.service)...810agent # [15047.246457] agent systemd[1]: Reloading...811agent # [15047.574134] agent systemd[1]: Reloading finished in 327 ms.812agent # [15047.645577] agent systemd[1]: Starting app slow...813agent # [15048.003798] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:25.965546Z","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 # [15050.005918] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:27.967661Z","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 # [15053.713120] agent systemd[1]: Started app slow.816agent # [15053.730749] agent flakelet[2996]: app: updated to generation 7817agent # [15053.733734] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.818agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788693323 | grep -q 'updated to generation', in 7.09 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 # [15054.009163] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:31.970740Z","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 # [15054.853698] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:32.815470Z","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.08 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'834agent # [15062.013792] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:39.975557Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}835agent # [15062.014319] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:39.975736Z","level":"INFO","message":"start","id":"6467bf1315622d7d31721829addef6ea","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}836agent # [15062.237128] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:40.198844Z","level":"INFO","message":"start","id":"832be432c4595e8d936405066ee829a6","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}837agent # [15062.237679] agent flakelet-agent[2166]: {"timestamp":"2026-09-06T11:15:40.199498Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"832be432c4595e8d936405066ee829a6\"]","target":"flakelet_relay::agent::jobs"}838relay # [15062.013866] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:39.975624Z","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"}839relay # [15062.014556] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:39.976341Z","level":"INFO","message":"deploy finished","job":"cd23c78f1c6d5b1c8ca1a39948295a42","ok":true,"target":"flakelet_relay::relay::api"}840relay # [15062.236664] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:40.198422Z","level":"INFO","message":"deploy accepted","job":"d0b2151d40c8ac20bd7002eb9cda5b02","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}841agent # [15062.283684] agent systemd[1]: Starting flakelet update app (via relay)...842agent # [15062.320256] agent systemd[1]: Started flakelet update app (via relay).843agent # [15062.324775] agent flakelet[3329]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2844agent # [15062.325475] agent flakelet[3329]: app: activating generation 8845agent # [15062.333682] agent systemd[1]: Stopping app slow...846agent # [15062.334386] agent systemd[1]: app.service: Deactivated successfully.847agent # [15062.334512] agent systemd[1]: Stopped app slow.848agent # [15062.344092] agent systemd[1]: Reload requested from client PID 3336 ('systemctl') (unit flakelet-relay-job-app.service)...849agent # [15062.344131] agent systemd[1]: Reloading...850agent # [15062.676990] agent systemd[1]: Reloading finished in 332 ms.851agent # [15062.772691] agent systemd[1]: Reload requested from client PID 3366 ('systemctl') (unit flakelet-relay-job-app.service)...852agent # [15062.772740] 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 # [15063.106991] agent systemd[1]: Reloading finished in 333 ms.856agent # [15063.198106] agent systemd[1]: Reload requested from client PID 3397 ('systemctl') (unit flakelet-relay-job-app.service)...857agent # [15063.198142] agent systemd[1]: Reloading...858agent # [15063.532571] agent systemd[1]: Reloading finished in 334 ms.859agent # [15063.630880] agent systemd[1]: Stopping flakelet-agent...860agent # [15063.632866] agent systemd[1]: Reload requested from client PID 3433 ('systemctl') (unit flakelet-relay-job-app.service)...861agent # [15063.632902] agent systemd[1]: Reloading...862relay # [15063.631330] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:41.593049Z","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 # [15063.969537] agent systemd[1]: Reloading finished in 335 ms.864agent # [15064.061403] agent systemd[1]: flakelet-agent.service: Deactivated successfully.865agent # [15064.061601] agent systemd[1]: Stopped flakelet-agent.866agent: (finished: must succeed: systemctl restart flakelet-agent, in 1.00 seconds)867agent # [15064.061615] agent systemd[1]: flakelet-agent.service: Consumed 1.832s CPU time over 29.233s wall clock time.868agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"869agent # [15064.080172] agent systemd[1]: Starting app slow2...870agent # [15064.081473] agent systemd[1]: Starting flakelet-agent...871agent # [15064.157230] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:42.119021Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"832be432c4595e8d936405066ee829a6\"]","target":"flakelet_relay::agent::jobs"}872agent # [15064.246245] agent systemd[1]: Started flakelet-agent.873agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)874client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out875relay # [15064.260717] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:42.222484Z","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"}876agent # [15064.260602] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:42.222402Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}877agent # [15064.261846] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:42.223669Z","level":"INFO","message":"start","id":"832be432c4595e8d936405066ee829a6","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}878agent # [15070.176018] agent systemd[1]: Started app slow2.879agent # [15070.196446] agent flakelet[3329]: app: updated to generation 8880agent # [15070.199480] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.881relay # [15070.771228] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:48.732982Z","level":"INFO","message":"deploy finished","job":"d0b2151d40c8ac20bd7002eb9cda5b02","ok":true,"target":"flakelet_relay::relay::api"}882agent # [15070.769660] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:48.731420Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}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.16 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=@1788693349 | grep -q 'app-slow'897agent # [15071.404807] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:49.366514Z","level":"INFO","message":"start","id":"c8aa90f824c00b3baf56b4eccf27ae96","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}898agent # [15071.405493] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:49.367312Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"c8aa90f824c00b3baf56b4eccf27ae96\"]","target":"flakelet_relay::agent::jobs"}899agent # [15071.471238] agent systemd[1]: Starting flakelet update app (via relay)...900agent # [15071.504999] agent systemd[1]: Started flakelet update app (via relay).901agent # [15071.509360] agent flakelet[3978]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow902agent # [15071.510023] agent flakelet[3978]: app: activating generation 9903agent # [15071.523154] agent systemd[1]: Stopping app slow2...904agent # [15071.523597] agent systemd[1]: app.service: Deactivated successfully.905agent # [15071.523853] agent systemd[1]: Stopped app slow2.906agent # [15071.541689] agent systemd[1]: Reload requested from client PID 3985 ('systemctl') (unit flakelet-relay-job-app.service)...907agent # [15071.541757] agent systemd[1]: Reloading...908relay # [15071.404271] relay flakelet-relay[401]: {"timestamp":"2026-09-06T11:15:49.366061Z","level":"INFO","message":"deploy accepted","job":"5c883a8b1f56858583b5e21e8d09fc8a","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}909agent # [15071.881080] agent systemd[1]: Reloading finished in 338 ms.910agent # [15071.974287] agent systemd[1]: Reload requested from client PID 4015 ('systemctl') (unit flakelet-relay-job-app.service)...911agent # [15071.974325] agent systemd[1]: Reloading...912agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788693349 | grep -q 'app-slow', in 1.02 seconds)913relay: must succeed: systemctl restart flakelet-relay914agent # [15072.305609] agent systemd[1]: Reloading finished in 330 ms.915agent # [15072.388379] agent systemd[1]: Reload requested from client PID 4046 ('systemctl') (unit flakelet-relay-job-app.service)...916agent # [15072.388414] agent systemd[1]: Reloading...917agent # [15072.427604] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:50.389394Z","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 # [15072.427186] relay systemd[1]: Stopping flakelet-relay...919relay # [15072.483665] relay systemd[1]: flakelet-relay.service: Deactivated successfully.920relay # [15072.483967] relay systemd[1]: Stopped flakelet-relay.921relay # [15072.483993] relay systemd[1]: flakelet-relay.service: Consumed 2.440s CPU time over 1min 10.414s wall clock time.922relay # [15072.502474] relay systemd[1]: Starting flakelet-relay...923agent # [15072.744580] agent systemd[1]: Reloading finished in 355 ms.924agent # [15072.844953] agent systemd[1]: Reload requested from client PID 4081 ('systemctl') (unit flakelet-relay-job-app.service)...925agent # [15072.844989] agent systemd[1]: Reloading...926agent # [15073.176836] agent systemd[1]: Reloading finished in 331 ms.927agent # [15073.273409] agent systemd[1]: Starting app slow...928agent # [15073.430351] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:51.392029Z","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.55 seconds)930client: waiting for success: grep -q '» ok' /tmp/resume.out931relay # [15073.960072] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:15:51.921830Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}932relay # [15073.960764] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:15:51.922351Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}933relay # [15073.960686] relay systemd[1]: Started flakelet-relay.934agent # [15075.444829] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:53.406599Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}935relay # [15075.445081] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:15:53.406808Z","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 # [15075.446813] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:15:53.408633Z","level":"INFO","message":"job reattached","job":"5c883a8b1f56858583b5e21e8d09fc8a","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}937agent # [15079.367350] agent systemd[1]: Started app slow.938agent # [15079.386703] agent flakelet[3978]: app: updated to generation 9939agent # [15079.390240] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.940agent # [15080.455156] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:58.416841Z","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.69 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>&1947agent # [15081.074803] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:59.036561Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}948agent # [15081.075226] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:15:59.037053Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}949agent # [15081.138007] agent systemd[1]: Starting flakelet update other (via relay)...950agent # [15081.176142] agent systemd[1]: Started flakelet update other (via relay).951agent # [15081.182529] agent flakelet[4223]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1952agent # [15081.183560] agent flakelet[4223]: other: up to date953agent # [15081.186015] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.954relay # [15081.074382] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:15:59.036132Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}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 1.71 seconds)956relay: must succeed: systemctl restart flakelet-relay957relay # [15082.758221] relay flakelet-relay[935]: {"timestamp":"2026-09-06T11:16:00.719990Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}958relay # [15082.772526] relay systemd[1]: Stopping flakelet-relay...959relay # [15082.829083] relay systemd[1]: flakelet-relay.service: Deactivated successfully.960relay # [15082.829488] relay systemd[1]: Stopped flakelet-relay.961relay # [15082.829527] relay systemd[1]: flakelet-relay.service: Consumed 1.970s CPU time over 10.326s wall clock time.962relay # [15082.866469] relay systemd[1]: Starting flakelet-relay...963agent # [15082.756470] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:00.718239Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}964agent # [15082.772937] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:00.734749Z","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"}965agent # [15083.776369] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:01.738105Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}966relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.51 seconds)967relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'968relay # [15084.265028] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:02.226819Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}969relay # [15084.265516] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:02.227335Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}970relay # [15084.265588] relay systemd[1]: Started flakelet-relay.971relay # [15085.788733] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:03.750479Z","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 # [15085.788644] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:03.750385Z","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.05 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzY2NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzY0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJPTFRWQ0JJWFdETkZHPT09IiwibmJmIjoxNzg4NjkzMzY0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.2Rm5dzm-FwU-9OOEhC5qnUglOpYv1b7HUflx_Ga63Ia1OJkYEezVfa0DYM6dNyyf8hiO0vF2uX6CPy5P07TiAA' 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 # [15086.407189] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:04.368936Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"}984agent # [15086.407506] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:04.369339Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}985agent # [15086.447921] agent systemd[1]: Starting flakelet update app (via relay)...986agent # [15086.478928] agent systemd[1]: Started flakelet update app (via relay).987agent/appagent # [15086.484544] agent flakelet[4302]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow988 | agent # [15086.485407] agent flakelet[4302]: app: up to date989app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slowagent # [15086.486021] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.990991agent/app | app: up to date992agent/app | flakelet-relay-job-app.service: Deactivated successfully.993relay # [15086.406832] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:04.368588Z","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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzY2NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzY0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJPTFRWQ0JJWFdETkZHPT09IiwibmJmIjoxNzg4NjkzMzY0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.2Rm5dzm-FwU-9OOEhC5qnUglOpYv1b7HUflx_Ga63Ia1OJkYEezVfa0DYM6dNyyf8hiO0vF2uX6CPy5P07TiAA' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.66 seconds)997client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzY2NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzY0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJPTFRWQ0JJWFdETkZHPT09IiwibmJmIjoxNzg4NjkzMzY0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.2Rm5dzm-FwU-9OOEhC5qnUglOpYv1b7HUflx_Ga63Ia1OJkYEezVfa0DYM6dNyyf8hiO0vF2uX6CPy5P07TiAA' push --relay https://relay:7443 jobs998client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MzY2NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkzMzY0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJPTFRWQ0JJWFdETkZHPT09IiwibmJmIjoxNzg4NjkzMzY0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.2Rm5dzm-FwU-9OOEhC5qnUglOpYv1b7HUflx_Ga63Ia1OJkYEezVfa0DYM6dNyyf8hiO0vF2uX6CPy5P07TiAA' 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 6.02 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/f3883cc97973af6ad92badeb32451fe1/events || true1016relay # [15087.049071] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:05.010795Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1017relay # [15087.125809] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 11:16:05] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=nxD29AMgZim17IelhqxT_MNg6_x3l9GhsbUoIuHJ_9Q&code_challenge=as7gdWWXYafptcYk3m0J6dOnX9g3SLRc5XHoZgYi5hU&code_challenge_method=S256 HTTP/1.1" 302 -1018relay # [15087.171572] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 11:16:05] "POST /token HTTP/1.1" 200 -1019relay # [15087.172611] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:05.134408Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1020relay # [15087.233731] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:05.195530Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1021relay # [15087.270703] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:05.232518Z","level":"INFO","message":"deploy accepted","job":"ab3d6a4cf6ec8ad9fbc83b781f745fd8","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1022relay # [15087.292180] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:05.253997Z","level":"INFO","message":"job reattached","job":"ab3d6a4cf6ec8ad9fbc83b781f745fd8","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1023agent # [15087.047616] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:05.009397Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}1024agent # [15087.270989] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:05.232768Z","level":"INFO","message":"start","id":"7cafe5b3d64a53dbf1f8bdee514391c2","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}1025agent # [15087.271362] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:05.233193Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"7cafe5b3d64a53dbf1f8bdee514391c2\"]","target":"flakelet_relay::agent::jobs"}1026agent # [15087.336677] agent systemd[1]: Starting flakelet update other (via relay)...1027agent # [15087.369855] agent systemd[1]: Started flakelet update other (via relay).1028agent # [15087.374391] agent flakelet[4338]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11029agent # [15087.374937] agent flakelet[4338]: other: up to date1030agent # [15087.376496] 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/f3883cc97973af6ad92badeb32451fe1/events || true, in 0.67 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/f3883cc97973af6ad92badeb32451fe11033client: (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/f3883cc97973af6ad92badeb32451fe1, 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=f3883cc97973af6ad92badeb32451fe1' | 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=f3883cc97973af6ad92badeb32451fe1' | 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/other | flakelet-relay-job-other.service: Deactivated successfully.1054agent # [15087.940935] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:05.902702Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1055agent # [15088.097769] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:06.059256Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}1056agent # [15088.098373] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:06.059834Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}1057agent # [15088.146096] agent systemd[1]: Starting flakelet update other (via relay)...1058agent # [15088.176983] agent systemd[1]: Started flakelet update other (via relay).1059agent # [15088.181446] agent flakelet[4374]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11060agent # [15088.181970] agent flakelet[4374]: other: up to date1061agent # [15088.184787] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1062relay # [15088.097082] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:06.058840Z","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.67 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.74 seconds)1073(finished: run the VM test script, in 90.01 seconds)1074relay # [15088.743306] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T11:16:06.705055Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}1075agent # [15088.742000] agent flakelet-agent[3466]: {"timestamp":"2026-09-06T11:16:06.703765Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1076test script finished in 92.81s1077cleanup1078kill NspawnMachine (pid 51)1079kill NspawnMachine (pid 53)1080Container agent terminated by signal KILL.1081kill NspawnMachine (pid 56)1082Container client terminated by signal KILL.1083Container relay terminated by signal KILL.1084(finished: cleanup, in 0.39 seconds)1085additionally exposed symbols:1086 agent, client, relay,1087 vlan1,1088 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_ssh1089» job 0af2fc6b6b2f9e17d70c64f51f21e800 via relay 0.1.0 (agents: agent 0.1.0)1090» wave 01091agent/app | Starting flakelet update app (via relay)...1092agent/app | Started flakelet update app (via relay).1093agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v21094agent/app | app: activating generation 21095agent/app | app: updated to generation 21096agent/app | flakelet-relay-job-app.service: Deactivated successfully.1097» agent/app: updated (generation 2)1098» ok10991100» job 63b9d9e8ab9fa669d4e32843169a6556 via relay 0.1.0 (agents: agent 0.1.0)1101» wave 01102agent/app | Starting flakelet update app (via relay)...1103agent/app | Started flakelet update app (via relay).1104agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1105agent/app | app: activating generation 41106agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1107agent/app | failed units: app.service. See journalctl -u app.service1108agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1109agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1110» agent/app: rolled-back (generation 3)1111agent/app │ Starting app v1...1112agent/app │ Started app v1.1113agent/app │ Stopping app v1...1114agent/app │ app.service: Deactivated successfully.1115agent/app │ Stopped app v1.1116agent/app │ Starting app v2...1117agent/app │ Started app v2.1118agent/app │ Stopping app v2...1119agent/app │ app.service: Deactivated successfully.1120agent/app │ Stopped app v2.1121agent/app │ Starting app v1...1122agent/app │ Started app v1.1123agent/app │ Stopping app v1...1124agent/app │ app.service: Deactivated successfully.1125agent/app │ Stopped app v1.1126agent/app │ Starting app broken...1127agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1128agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1129agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1130agent/app │ app.service: Failed with result 'exit-code'.1131agent/app │ Failed to start app broken.1132agent/app │ Starting app v1...1133agent/app │ Started app v1.1134» skipped: agent/other1135» failed11361137» job cd23c78f1c6d5b1c8ca1a39948295a42 via relay 0.1.0 (agents: agent 0.1.0)1138» wave 01139agent/app | Starting flakelet update app (via relay)...1140agent/app | Started flakelet update app (via relay).1141agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1142agent/app | app: activating generation 71143agent/app | app: updated to generation 71144agent/app | flakelet-relay-job-app.service: Deactivated successfully.1145» agent/app: updated (generation 7)1146» ok11471148» job d0b2151d40c8ac20bd7002eb9cda5b02 via relay 0.1.0 (agents: agent 0.1.0)1149» wave 01150agent/app | Starting flakelet update app (via relay)...1151agent/app | Started flakelet update app (via relay).1152agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21153agent/app | app: activating generation 81154agent/app | app: updated to generation 81155agent/app | flakelet-relay-job-app.service: Deactivated successfully.1156» agent/app: updated (generation 8)1157» ok11581159» job 5c883a8b1f56858583b5e21e8d09fc8a via relay 0.1.0 (agents: agent 0.1.0)1160» wave 01161agent/app | Starting flakelet update app (via relay)...1162agent/app | Started flakelet update app (via relay).1163agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1164agent/app | app: activating generation 91165flakelet-push: stream: error reading a body from connection, resuming job 92e839008eed504efa0451d0396c7e5f1166flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1167flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1168» job 5c883a8b1f56858583b5e21e8d09fc8a via relay 0.1.0 (agents: agent 0.1.0)1169» wave 01170agent/app | app: updated to generation 91171agent/app | flakelet-relay-job-app.service: Deactivated successfully.1172» agent/app: updated (generation 9)1173» ok117411751788693359 hist1 admin@example.org agent/other:unchanged11761788693349 92e839008eed504efa0451d0396c7e5f admin@example.org agent/app:updated11771788693340 4fe79655bd948a98b211915e32ec54be admin@example.org agent/app:updated11781788693323 bb7bc6750c818571bb0818f7d1112abb admin@example.org agent/app:updated11791788693313 485029a98a72f1003c092dd2ea586505 admin@example.org agent/other:unchanged11801788693303 9d5068b07d1fd8a4f67fc423410f8d53 admin@example.org agent/app:unchanged11811788693303 abc5f582b46be0d8ca4b341794621218 admin@example.org agent/app:updated11821788693301 75604609acb8f28c5c73e2d45291ce7f admin@example.org agent/app:unchanged11831788693300 bee893718114903fc8e39ed7557f24be admin@example.org agent/app:unchanged11841788693296 6b58b247a5aaab6b7f773424873fe280 admin@example.org agent/app:rolled-back11851788693295 20963a584d319e1706e22a4a628f26da dev@example.org agent/other:unchanged11861788693294 0fc0e6d2d531614e4749094257b450f8 dev@example.org agent/other:unchanged11871788693291 f0c65349b6192a5f1bb9f6f863b8d72f someone agent/other:unchanged11881788693288 63b42a4b8d2106d0674982f0369b5f27 repo:github:example/app:ref:refs/heads/main agent/app:updated11891788693285 5984162a4809d5f23f43028f00eacecd admin@example.org agent/app:updated1190