nixbot

builds

succeeded container-test-run-flakelet-relay checks.x86_64-linux.nixos-test · build #20 · 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)10client: systemd-nspawn running (pid 53)11agent: Waiting for journal at /build/vm-state-agent/var/log/journal...12relay: systemd-nspawn running (pid 55)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.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.25░ Spawning container client on /build/vm-state-client.26░ Spawning container relay on /build/vm-state-relay.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 agent on /build/vm-state-agent.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31client # No journal files were found.32client # No journal boot entry found for the specified boot (+0).33relay # No journal files were found.34relay # No journal boot entry found for the specified boot (+0).35agent # [ 4267.426784] agent systemd-journald[57]: Journal started36agent # [ 4267.426824] agent systemd-journald[57]: Runtime Journal (/run/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db) is 8M, max 4G, 3.9G free.37agent # [ 4267.437808] agent systemd[1]: Finished Apply Kernel Variables.38agent # [ 4267.449695] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [ 4267.463774] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [ 4267.464491] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [ 4267.494688] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db is 1.631ms for 6 entries.42agent # [ 4267.494688] agent systemd-journald[57]: System Journal (/var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db) is 512B, max 4G, 3.9G free.43agent # [ 4267.504351] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [ 4267.505031] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [ 4267.505152] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [ 4267.517663] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [ 4267.579965] agent systemd[1]: Finished Firewall.48client # [ 4267.427257] client systemd-journald[57]: Journal started49client # [ 4267.427297] client systemd-journald[57]: Runtime Journal (/run/log/journal/feb4e24c6a0e4855b5669cee0f098a4e) is 8M, max 4G, 3.9G free.50client # [ 4267.438687] client systemd[1]: Finished Apply Kernel Variables.51client # [ 4267.450966] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.52client # [ 4267.465224] client systemd[1]: Starting Flush Journal to Persistent Storage...53client # [ 4267.465775] client systemd[1]: Starting Create Static Device Nodes in /dev...54client # [ 4267.495249] client systemd-journald[57]: Time spent on flushing to /var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e is 1.398ms for 6 entries.55client # [ 4267.495249] client systemd-journald[57]: System Journal (/var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e) is 512B, max 4G, 3.9G free.56client # [ 4267.504152] client systemd[1]: Finished Create Static Device Nodes in /dev.57client # [ 4267.504857] client systemd[1]: Reached target Preparation for Local File Systems.58client # [ 4267.504979] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys59client # [ 4267.519974] client systemd[1]: Finished Flush Journal to Persistent Storage.60client # [ 4267.584362] client systemd[1]: Finished Firewall.61relay # [ 4267.434405] relay systemd-journald[57]: Journal started62relay # [ 4267.434447] relay systemd-journald[57]: Runtime Journal (/run/log/journal/b251195dba4843849f56bd16da8cc57a) is 8M, max 4G, 3.9G free.63relay # [ 4267.443527] relay systemd[1]: Finished Apply Kernel Variables.64relay # [ 4267.454811] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.65relay # [ 4267.489551] relay systemd[1]: Starting Flush Journal to Persistent Storage...66relay # [ 4267.490184] relay systemd[1]: Starting Create Static Device Nodes in /dev...67relay # [ 4267.498449] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/b251195dba4843849f56bd16da8cc57a is 1.650ms for 6 entries.68relay # [ 4267.498449] relay systemd-journald[57]: System Journal (/var/log/journal/b251195dba4843849f56bd16da8cc57a) is 512B, max 4G, 3.9G free.69relay # [ 4267.507176] relay systemd[1]: Finished Create Static Device Nodes in /dev.70relay # [ 4267.507847] relay systemd[1]: Reached target Preparation for Local File Systems.71relay # [ 4267.507941] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys72relay # [ 4267.522923] relay systemd[1]: Finished Flush Journal to Persistent Storage.73relay # [ 4267.602278] relay systemd[1]: Finished Firewall.74relay # [ 4268.434409] relay systemd[1]: Mounting /run/wrappers...75agent # [ 4268.437228] agent systemd[1]: Mounting /run/wrappers...76agent # [ 4268.500815] agent systemd[1]: Mounted /run/wrappers.77agent # [ 4268.501952] agent systemd[1]: Reached target Local File Systems.78agent # [ 4268.503287] agent systemd[1]: Listening on Boot Loader Control Service Socket.79agent # [ 4268.504710] agent systemd[1]: Starting Create SUID/SGID Wrappers...80agent # [ 4268.504754] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container81agent # [ 4268.505697] agent systemd[1]: Starting Save Transient machine-id to Disk...82agent # [ 4268.506836] agent systemd[1]: Starting Create System Files and Directories...83agent # [ 4268.525239] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted84agent # [ 4268.525645] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted85agent # [ 4268.525970] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db failed: Operation not permitted86agent # [ 4268.526330] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted87client # [ 4268.437699] client systemd[1]: Mounting /run/wrappers...88client # [ 4268.500827] client systemd[1]: Mounted /run/wrappers.89client # [ 4268.501883] client systemd[1]: Reached target Local File Systems.90client # [ 4268.503191] client systemd[1]: Listening on Boot Loader Control Service Socket.91client # [ 4268.504565] client systemd[1]: Starting Create SUID/SGID Wrappers...92client # [ 4268.504635] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container93client # [ 4268.506087] client systemd[1]: Starting Save Transient machine-id to Disk...94client # [ 4268.507286] client systemd[1]: Starting Create System Files and Directories...95client # [ 4268.526375] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted96client # [ 4268.526769] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted97client # [ 4268.527074] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e failed: Operation not permitted98client # [ 4268.527182] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.gpk2Bu8h3K/chsh': Operation not permitted99client # [ 4268.527404] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted100relay # [ 4268.499730] relay systemd[1]: Mounted /run/wrappers.101relay # [ 4268.500791] relay systemd[1]: Reached target Local File Systems.102relay # [ 4268.502171] relay systemd[1]: Listening on Boot Loader Control Service Socket.103relay # [ 4268.503763] relay systemd[1]: Starting Create SUID/SGID Wrappers...104relay # [ 4268.503802] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container105relay # [ 4268.504908] relay systemd[1]: Starting Save Transient machine-id to Disk...106relay # [ 4268.506101] relay systemd[1]: Starting Create System Files and Directories...107relay # [ 4268.527793] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted108relay # [ 4268.528204] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted109relay # [ 4268.528511] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/b251195dba4843849f56bd16da8cc57a failed: Operation not permitted110relay # [ 4268.528839] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted111relay # [ 4268.529962] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.ZfGkMZzrPJ/chsh': Operation not permitted112relay # [ 4268.584171] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.113relay # [ 4268.595663] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE114relay # [ 4268.595755] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.115relay # [ 4268.595937] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.116relay # [ 4268.596184] relay systemd[1]: Finished Save Transient machine-id to Disk.117relay # [ 4268.596726] relay systemd[1]: Finished Create System Files and Directories.118relay # [ 4268.611588] relay systemd[1]: Starting Rebuild Journal Catalog...119relay # [ 4268.612493] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...120relay # [ 4268.645649] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.121relay # [ 4268.651984] relay systemd[1]: Finished Rebuild Journal Catalog.122relay # [ 4268.652956] relay systemd[1]: Starting Update is Completed...123relay # [ 4268.660984] relay systemd[1]: Finished Update is Completed.124relay # [ 4268.661074] relay systemd[1]: Reached target System Initialization.125relay # [ 4268.661147] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container126relay # [ 4268.661167] relay systemd[1]: Started Daily Cleanup of Temporary Directories.127relay # [ 4268.661179] relay systemd[1]: Reached target Timer Units.128relay # [ 4268.661276] relay systemd[1]: Listening on D-Bus System Message Bus Socket.129relay # [ 4268.661441] relay systemd[1]: Listening on Nix Daemon Socket.130relay # [ 4268.661540] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.131relay # [ 4268.661556] relay systemd[1]: Reached target Socket Units.132relay # [ 4268.661581] relay systemd[1]: Reached target Basic System.133relay # [ 4268.663464] relay systemd[1]: Started device-mock.service.134relay # [ 4268.664199] relay systemd[1]: Starting Re-link flakelet services at boot...135relay # [ 4268.665082] relay systemd[1]: Starting Import lastlog data into lastlog2 database...136relay # [ 4268.666060] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...137relay # [ 4268.666678] relay systemd[1]: Starting resolvconf update...138relay # [ 4268.680063] relay systemd[1]: Finished Re-link flakelet services at boot.139relay # [ 4268.681037] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...140client # [ 4268.591159] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.141agent # [ 4268.530051] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.QoDBIPEiI7/chsh': Operation not permitted142client # [ 4268.604736] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE143agent # [ 4268.612009] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.144client # [ 4268.604771] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.145client # [ 4268.604824] client systemd[1]: Failed to start Create SUID/SGID Wrappers.146agent # [ 4268.612650] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE147agent # [ 4268.612686] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.148client # [ 4268.604969] client systemd[1]: Finished Save Transient machine-id to Disk.149client # [ 4268.605453] client systemd[1]: Finished Create System Files and Directories.150client # [ 4268.636528] client systemd[1]: Starting Rebuild Journal Catalog...151client # [ 4268.637492] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...152client # [ 4268.650920] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.153client # [ 4268.656109] client systemd[1]: Finished Rebuild Journal Catalog.154client # [ 4268.657468] client systemd[1]: Starting Update is Completed...155client # [ 4268.665448] client systemd[1]: Finished Update is Completed.156client # [ 4268.666264] client systemd[1]: Reached target System Initialization.157client # [ 4268.666427] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container158client # [ 4268.666493] client systemd[1]: Started Daily Cleanup of Temporary Directories.159client # [ 4268.666520] client systemd[1]: Reached target Timer Units.160client # [ 4268.666712] client systemd[1]: Listening on D-Bus System Message Bus Socket.161agent # [ 4268.612740] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.162client # [ 4268.666995] client systemd[1]: Listening on Nix Daemon Socket.163agent # [ 4268.612885] agent systemd[1]: Finished Save Transient machine-id to Disk.164client # [ 4268.667184] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.165agent # [ 4268.613381] agent systemd[1]: Finished Create System Files and Directories.166client # [ 4268.667210] client systemd[1]: Reached target Socket Units.167agent # [ 4268.636652] agent systemd[1]: Starting Rebuild Journal Catalog...168client # [ 4268.667256] client systemd[1]: Reached target Basic System.169agent # [ 4268.637533] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...170client # [ 4268.668985] client systemd[1]: Starting Import lastlog data into lastlog2 database...171agent # [ 4268.650171] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.172client # [ 4268.670172] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...173agent # [ 4268.657723] agent systemd[1]: Finished Rebuild Journal Catalog.174client # [ 4268.671276] client systemd[1]: Starting resolvconf update...175agent # [ 4268.658618] agent systemd[1]: Starting Update is Completed...176client # [ 4268.688178] client systemd[1]: Finished Import lastlog data into lastlog2 database.177agent # [ 4268.667254] agent systemd[1]: Finished Update is Completed.178agent # [ 4268.667326] agent systemd[1]: Reached target System Initialization.179agent # [ 4268.667390] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container180agent # [ 4268.667412] agent systemd[1]: Started Daily Cleanup of Temporary Directories.181agent # [ 4268.667424] agent systemd[1]: Reached target Timer Units.182agent # [ 4268.667513] agent systemd[1]: Listening on D-Bus System Message Bus Socket.183agent # [ 4268.667699] agent systemd[1]: Listening on Nix Daemon Socket.184agent # [ 4268.667791] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.185agent # [ 4268.667803] agent systemd[1]: Reached target Socket Units.186agent # [ 4268.667830] agent systemd[1]: Reached target Basic System.187agent # [ 4268.668894] agent systemd[1]: Starting Re-link flakelet services at boot...188agent # [ 4268.669606] agent systemd[1]: Starting Import lastlog data into lastlog2 database...189agent # [ 4268.670315] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...190agent # [ 4268.671010] agent systemd[1]: Starting resolvconf update...191agent # [ 4268.683141] agent systemd[1]: Finished Re-link flakelet services at boot.192agent # [ 4268.684645] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...193agent # [ 4268.688149] agent systemd[1]: Finished Import lastlog data into lastlog2 database.194agent # [ 4268.697046] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.195agent # [ 4268.740898] agent systemd[1]: Finished resolvconf update.196agent # [ 4268.741526] agent systemd[1]: Reached target Preparation for Network.197agent # [ 4268.742497] agent systemd[1]: Starting Address configuration of eth1...198agent # [ 4268.743099] agent systemd[1]: Starting Extra networking commands....199agent # [ 4268.781330] agent systemd[1]: nscd.service: Deactivated successfully.200agent # [ 4268.781394] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).201agent # [ 4268.784311] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...202agent # [ 4268.798915] agent network-addresses-eth1-start[237]: adding address 192.168.1.1/24... done203agent # [ 4268.802405] agent network-addresses-eth1-start[237]: adding address 2001:db8:1::1/64... done204agent # [ 4268.806994] agent systemd[1]: Finished Address configuration of eth1.205agent # [ 4268.850070] agent systemd[1]: Finished Extra networking commands..206agent # [ 4268.850196] agent systemd[1]: Reached target Network.207agent # [ 4268.851248] agent systemd[1]: Starting flakelet-agent...208agent # [ 4268.883801] agent systemd[1]: Starting Update flakelet service app...209agent # [ 4268.885661] agent systemd[1]: Starting Update flakelet service other...210agent # [ 4268.886283] agent systemd[1]: nscd.service: Deactivated successfully.211agent # [ 4268.886501] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).212agent # [ 4268.892100] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...213agent # [ 4268.895500] agent flakelet[305]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1214agent # [ 4268.896057] agent flakelet[305]: app: activating generation 1215agent # [ 4268.896919] agent flakelet[307]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1216agent # [ 4268.897437] agent flakelet[307]: other: activating generation 1217agent # [ 4268.899359] agent systemd[1]: Reload requested from client PID 391 ('systemctl') (unit flakelet-app.service)...218agent # [ 4268.899399] agent systemd[1]: Reloading...219agent # [ 4268.922173] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:46.883741Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}220relay # [ 4268.686952] relay systemd[1]: Finished Import lastlog data into lastlog2 database.221relay # [ 4268.692230] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.222relay # [ 4268.740225] relay systemd[1]: Finished resolvconf update.223relay # [ 4268.740353] relay systemd[1]: Reached target Preparation for Network.224relay # [ 4268.741371] relay systemd[1]: Starting Address configuration of eth1...225relay # [ 4268.742306] relay systemd[1]: Starting Extra networking commands....226relay # [ 4268.768561] relay systemd[1]: nscd.service: Deactivated successfully.227relay # [ 4268.781344] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).228relay # [ 4268.784245] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...229relay # [ 4268.797859] relay network-addresses-eth1-start[246]: adding address 192.168.1.3/24... done230relay # [ 4268.802103] relay network-addresses-eth1-start[246]: adding address 2001:db8:1::3/64... done231relay # [ 4268.806376] relay systemd[1]: Finished Address configuration of eth1.232relay # [ 4268.846216] relay systemd[1]: Finished Extra networking commands..233relay # [ 4268.846313] relay systemd[1]: Reached target Network.234relay # [ 4268.847709] relay systemd[1]: Starting Dnsmasq Daemon...235relay # [ 4268.848642] relay systemd[1]: Starting Nginx Web Server...236relay # [ 4268.849453] relay systemd[1]: Starting Update flakelet service flakelet-relay...237relay # [ 4268.891988] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/zhnlcnggdn7ymdlwkz9j9s4dkxd6v5g7-flakelet-flakelet-relay238relay # [ 4268.892629] relay flakelet[311]: flakelet-relay: activating generation 1239relay # [ 4268.896804] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...240relay # [ 4268.896847] relay systemd[1]: Reloading...241client # [ 4268.743989] client systemd[1]: Finished resolvconf update.242client # [ 4268.744125] client systemd[1]: Reached target Preparation for Network.243client # [ 4268.781627] client systemd[1]: Starting Address configuration of eth1...244client # [ 4268.782532] client systemd[1]: Starting Extra networking commands....245client # [ 4268.782665] client systemd[1]: nscd.service: Deactivated successfully.246client # [ 4268.782717] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).247client # [ 4268.786601] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...248client # [ 4268.803924] client network-addresses-eth1-start[233]: adding address 192.168.1.2/24... done249client # [ 4268.807443] client network-addresses-eth1-start[233]: adding address 2001:db8:1::2/64... done250client # [ 4268.812401] client systemd[1]: Finished Address configuration of eth1.251client # [ 4268.883550] client systemd[1]: Finished Extra networking commands..252client # [ 4268.883960] client systemd[1]: nscd.service: Deactivated successfully.253client # [ 4268.884199] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).254client # [ 4268.887767] client systemd[1]: Reached target Network.255client # [ 4268.889604] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...256relay # [ 4269.219986] relay nsncd[251]: Sep 06 08:15:47.181 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"257relay # [ 4269.314795] relay systemd[1]: Reloading finished in 417 ms.258relay # [ 4269.441523] relay systemd[1]: Started Name Service Cache Daemon (nsncd).259relay # [ 4269.442545] relay systemd[1]: Reached target Host and Network Name Lookups.260relay # [ 4269.442631] relay systemd[1]: Reached target User and Group Name Lookups.261relay # [ 4269.444015] relay systemd[1]: Starting User Login Management...262relay # [ 4269.444896] relay systemd[1]: Starting Permit User Sessions...263relay # [ 4269.459626] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...264relay # [ 4269.459660] relay systemd[1]: Reloading...265agent # [ 4269.230762] agent nsncd[311]: Sep 06 08:15:47.192 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"266agent # [ 4269.307136] agent systemd[1]: Reloading finished in 407 ms.267agent # [ 4269.440787] agent systemd[1]: Started flakelet-agent.268agent # [ 4269.440901] agent systemd[1]: Started Name Service Cache Daemon (nsncd).269agent # [ 4269.443033] agent systemd[1]: Reached target Host and Network Name Lookups.270agent # [ 4269.443146] agent systemd[1]: Reached target User and Group Name Lookups.271agent # [ 4269.444498] agent systemd[1]: Starting User Login Management...272agent # [ 4269.445304] agent systemd[1]: Starting Permit User Sessions...273agent # [ 4269.445587] agent systemd[1]: Reload requested from client PID 421 ('systemctl') (unit flakelet-other.service)...274agent # [ 4269.445616] agent systemd[1]: Reloading...275client # [ 4269.212236] client systemd[1]: Started Name Service Cache Daemon (nsncd).276client # [ 4269.212530] client nsncd[303]: Sep 06 08:15:47.174 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"277client # [ 4269.212332] client systemd[1]: Reached target Host and Network Name Lookups.278client # [ 4269.212429] client systemd[1]: Reached target User and Group Name Lookups.279client # [ 4269.214920] client systemd[1]: Starting User Login Management...280client # [ 4269.219009] client systemd[1]: Starting Permit User Sessions...281client # [ 4269.250106] client systemd[1]: Finished Permit User Sessions.282client # [ 4269.251944] client systemd[1]: Started Console Getty.283client # [ 4269.251997] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0284client # [ 4269.252044] client systemd[1]: Reached target Login Prompts.285relay # [ 4269.503541] relay dnsmasq-pre-start[375]: dnsmasq: syntax check OK.286agent # [ 4269.863561] agent systemd[1]: Reloading finished in 417 ms.287agent # [ 4269.998197] agent systemd[1]: Finished Permit User Sessions.288agent # [ 4270.004535] agent systemd[1]: Started Console Getty.289agent # [ 4270.004561] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0290agent # [ 4270.004572] agent systemd[1]: Reached target Login Prompts.291agent # [ 4270.010471] agent systemd[1]: Reload requested from client PID 778 ('systemctl') (unit flakelet-app.service)...292agent # [ 4270.010502] agent systemd[1]: Reloading...293relay # [ 4269.856397] relay systemd[1]: Reloading finished in 396 ms.294relay # [ 4270.001542] relay systemd[1]: Finished Permit User Sessions.295relay # [ 4270.043653] relay systemd[1]: Started Console Getty.296relay # [ 4270.043709] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0297relay # [ 4270.043732] relay systemd[1]: Reached target Login Prompts.298relay # [ 4270.048537] relay systemd[1]: Starting flakelet-relay...299agent # [ 4270.390469] agent systemd[1]: Reloading finished in 379 ms.300agent # [ 4270.468940] agent systemd[1]: Reload requested from client PID 779 ('systemctl') (unit flakelet-other.service)...301agent # [ 4270.468980] agent systemd[1]: Reloading...302relay # [ 4270.504057] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok303relay # [ 4270.504748] relay nginx-pre-start[402]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful304relay # [ 4270.521587] relay systemd[1]: Started Nginx Web Server.305relay # [ 4270.665290] relay systemd[1]: Starting D-Bus System Message Bus...306client # [ 4270.614986] client systemd-logind[315]: New seat seat0.307client # [ 4270.615459] client systemd[1]: Started User Login Management.308client # [ 4270.617646] client systemd[1]: Starting D-Bus System Message Bus...309client # [ 4270.618920] client systemd[1]: Starting linger-users.service...310client # [ 4270.650888] client systemd[1]: linger-users.service: Deactivated successfully.311client # [ 4270.651230] client systemd[1]: Finished linger-users.service.312client # [ 4270.651564] client systemd[1]: Reached target Multi-User System.313agent # [ 4270.842883] agent systemd[1]: Reloading finished in 373 ms.314agent # [ 4270.924266] agent systemd[1]: Starting other v1...315agent # [ 4270.926902] agent systemd[1]: Starting app v1...316agent # [ 4270.953858] agent systemd[1]: Started other v1.317agent # [ 4270.954443] agent systemd[1]: Started app v1.318agent # [ 4270.972094] agent flakelet[307]: other: updated to generation 1319agent # [ 4270.973040] agent systemd[1]: Finished Update flakelet service other.320agent # [ 4270.974112] agent systemd-logind[740]: New seat seat0.321agent # [ 4270.974906] agent systemd[1]: Started User Login Management.322agent # [ 4270.975875] agent flakelet[305]: app: updated to generation 1323agent # [ 4270.976360] agent systemd[1]: Finished Update flakelet service app.324agent # [ 4270.976981] agent systemd[1]: Reached target flakelet managed services.325agent # [ 4270.978155] agent systemd[1]: Starting D-Bus System Message Bus...326agent # [ 4270.979243] agent systemd[1]: Starting linger-users.service...327agent # [ 4270.991741] agent systemd[1]: linger-users.service: Deactivated successfully.328agent # [ 4270.991943] agent systemd[1]: Finished linger-users.service.329agent # [ 4270.992088] agent systemd[1]: Reached target Multi-User System.330relay # [ 4271.063373] relay systemd-logind[354]: New seat seat0.331relay # [ 4271.063783] relay systemd[1]: Started User Login Management.332relay # [ 4271.066123] relay systemd[1]: Starting linger-users.service...333relay # [ 4271.105786] relay systemd[1]: linger-users.service: Deactivated successfully.334relay # [ 4271.106165] relay systemd[1]: Finished linger-users.service.335relay # [ 4271.184980] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...336relay # [ 4271.186417] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'337relay # [ 4271.186417] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"338relay # [ 4271.187615] relay systemd[1]: Started D-Bus System Message Bus.339relay # [ 4271.194700] relay dbus-broker-launch[408]: Ready340relay # [ 4271.198113] relay systemd[1]: Started Dnsmasq Daemon.341relay # [ 4271.199597] relay dnsmasq[394]: started, version 2.93 cachesize 150342relay # [ 4271.199614] relay dnsmasq[394]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth DNSSEC loop-detect inotify dumpfile343relay # [ 4271.199628] relay dnsmasq[394]: DBus support enabled: connected to system bus344relay # [ 4271.199645] relay dnsmasq[394]: no upstream servers configured - please set them from DBus345relay # [ 4271.199791] relay dnsmasq[394]: read /etc/hosts - 9 names346client # [ 4271.156345] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...347client # [ 4271.157806] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'348client # [ 4271.157806] client dbus-broker-launch[325]: Invalid user-name in /nix/store/kl0xf3n3ac6xk287l1j4isggl96cyhax-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"349client # [ 4271.158757] client systemd[1]: Started D-Bus System Message Bus.350client # [ 4271.159230] client systemd[1]: Startup finished in 4.201s.351client # [ 4271.164362] client dbus-broker-launch[325]: Ready352agent # [ 4271.399072] agent dbus-broker-launch[846]: Looking up NSS user entry for 'systemd-timesync'...353agent # [ 4271.400682] agent dbus-broker-launch[846]: NSS returned no entry for 'systemd-timesync'354agent # [ 4271.400682] agent dbus-broker-launch[846]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"355agent # [ 4271.401672] agent systemd[1]: Started D-Bus System Message Bus.356agent # [ 4271.402143] agent systemd[1]: Startup finished in 4.453s.357agent # [ 4271.406731] agent dbus-broker-launch[846]: Ready358relay # [ 4271.958749] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:49.920360Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}359relay # [ 4271.959636] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:49.921027Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}360relay # [ 4271.959429] relay systemd[1]: Started flakelet-relay.361relay # [ 4271.970174] relay systemd[1]: Starting health for flakelet-relay...362relay # [ 4272.213411] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.363relay # [ 4272.213758] relay systemd[1]: Finished health for flakelet-relay.364relay # [ 4272.255128] relay flakelet[311]: flakelet-relay: updated to generation 1365relay # [ 4272.257487] relay systemd[1]: Finished Update flakelet service flakelet-relay.366relay # [ 4272.258060] relay systemd[1]: Reached target flakelet managed services.367relay # [ 4272.258234] relay systemd[1]: Reached target Multi-User System.368relay # [ 4272.258491] relay systemd[1]: Startup finished in 5.311s.369relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)370relay: waiting for unit nginx.service371relay: (finished: waiting for unit nginx.service, in 0.02 seconds)372agent: waiting for unit flakelet.target373agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)374agent: waiting for unit flakelet-agent.service375agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)376client: waiting for unit multi-user.target377client: (finished: waiting for unit multi-user.target, in 0.02 seconds)378relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'379agent # [ 4273.943557] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:51.905292Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}380relay # [ 4273.943947] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:51.905666Z","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"}381relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)382agent: must succeed: systemctl is-active app.service other.service383agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)384subtest: deploy with client certificate, relay found via SRV385agent: 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.json386agent: (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)387client: 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>&1388relay # [ 4274.761704] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:52.723430Z","level":"INFO","message":"deploy accepted","job":"b08899e4f5d9448ad0e62beee8dfb372","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}389agent # [ 4274.762409] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:52.724130Z","level":"INFO","message":"start","id":"6c8a2b22b9b638ee3bca1842049c9483","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}390agent # [ 4274.763355] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:52.725174Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6c8a2b22b9b638ee3bca1842049c9483\"]","target":"flakelet_relay::agent::jobs"}391agent # [ 4274.817525] agent systemd[1]: Starting flakelet update app (via relay)...392agent # [ 4274.847968] agent systemd[1]: Started flakelet update app (via relay).393agent # [ 4274.852758] agent flakelet[875]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2394agent # [ 4274.853409] agent flakelet[875]: app: activating generation 2395agent # [ 4274.867213] agent systemd[1]: Stopping app v1...396agent # [ 4274.867671] agent systemd[1]: app.service: Deactivated successfully.397agent # [ 4274.867936] agent systemd[1]: Stopped app v1.398agent # [ 4274.886902] agent systemd[1]: Reload requested from client PID 882 ('systemctl') (unit flakelet-relay-job-app.service)...399agent # [ 4274.886970] agent systemd[1]: Reloading...400agent # [ 4275.229893] agent systemd[1]: Reloading finished in 342 ms.401agent # [ 4275.320871] agent systemd[1]: Reload requested from client PID 915 ('systemctl') (unit flakelet-relay-job-app.service)...402agent # [ 4275.320906] agent systemd[1]: Reloading...403agent # [ 4275.649235] agent systemd[1]: Reloading finished in 327 ms.404agent # [ 4275.730516] agent systemd[1]: Reload requested from client PID 945 ('systemctl') (unit flakelet-relay-job-app.service)...405agent # [ 4275.730555] agent systemd[1]: Reloading...406agent # [ 4276.059021] agent systemd[1]: Reloading finished in 328 ms.407agent # [ 4276.140833] agent systemd[1]: Reload requested from client PID 978 ('systemctl') (unit flakelet-relay-job-app.service)...408agent # [ 4276.140874] agent systemd[1]: Reloading...409agent # [ 4276.468935] agent systemd[1]: Reloading finished in 327 ms.410agent # [ 4276.532855] agent systemd[1]: Starting app v2...411agent # [ 4276.557961] agent systemd[1]: Started app v2.412agent # [ 4276.570851] agent flakelet[875]: app: updated to generation 2413agent # [ 4276.573188] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.414client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.96 seconds)415agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'416agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)417agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'418agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)419(finished: subtest: deploy with client certificate, relay found via SRV, in 3.00 seconds)420subtest: deploy with OIDC token, sub principal421agent: 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.json422agent: (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)423client: 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)424client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)425client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/app 2>&1426agent # [ 4277.690429] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.652167Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}427agent # [ 4277.823543] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.785284Z","level":"INFO","message":"start","id":"1c39184043568d292bfd3e5893d98b5e","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}428agent # [ 4277.823886] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.785659Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"1c39184043568d292bfd3e5893d98b5e\"]","target":"flakelet_relay::agent::jobs"}429agent # [ 4277.865259] agent systemd[1]: Starting flakelet update app (via relay)...430agent # [ 4277.910109] agent systemd[1]: Started flakelet update app (via relay).431agent # [ 4277.914334] agent flakelet[1060]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1432agent # [ 4277.914970] agent flakelet[1060]: app: activating generation 3433agent # [ 4277.929123] agent systemd[1]: Stopping app v2...434agent # [ 4277.929608] agent systemd[1]: app.service: Deactivated successfully.435agent # [ 4277.929875] agent systemd[1]: Stopped app v2.436agent # [ 4277.948068] agent systemd[1]: Reload requested from client PID 1067 ('systemctl') (unit flakelet-relay-job-app.service)...437agent # [ 4277.948136] agent systemd[1]: Reloading...438relay # [ 4277.691795] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:55.653552Z","level":"INFO","message":"deploy finished","job":"b08899e4f5d9448ad0e62beee8dfb372","ok":true,"target":"flakelet_relay::relay::api"}439relay # [ 4277.823175] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:55.784948Z","level":"INFO","message":"deploy accepted","job":"4c9fe352143f106bd900e5e8de900986","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}440agent # [ 4278.286357] agent systemd[1]: Reloading finished in 337 ms.441agent # [ 4278.350940] agent systemd[1]: Reload requested from client PID 1097 ('systemctl') (unit flakelet-relay-job-app.service)...442agent # [ 4278.350976] agent systemd[1]: Reloading...443agent # [ 4278.676325] agent systemd[1]: Reloading finished in 324 ms.444agent # [ 4278.748935] agent systemd[1]: Reload requested from client PID 1126 ('systemctl') (unit flakelet-relay-job-app.service)...445agent # [ 4278.748975] agent systemd[1]: Reloading...446agent # [ 4279.074537] agent systemd[1]: Reloading finished in 325 ms.447agent # [ 4279.144770] agent systemd[1]: Reload requested from client PID 1160 ('systemctl') (unit flakelet-relay-job-app.service)...448agent # [ 4279.144804] agent systemd[1]: Reloading...449agent # [ 4279.467780] agent systemd[1]: Reloading finished in 322 ms.450agent # [ 4279.536359] agent systemd[1]: Starting app v1...451agent # [ 4279.578163] agent systemd[1]: Started app v1.452agent # [ 4279.589462] agent flakelet[1060]: app: updated to generation 3453agent # [ 4279.591585] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.454client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.90 seconds)455(finished: subtest: deploy with OIDC token, sub principal, in 2.97 seconds)456subtest: policy denies uncovered target457client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/other 2>&1458client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)459(finished: subtest: policy denies uncovered target, in 0.02 seconds)460subtest: claim principal from groups, unchanged counts as success461client: 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)462client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)463client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1OCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjU1OCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiT1YyNllRRUdCUVNMUT09PSIsIm5iZiI6MTc4ODY4MjU1OCwic3ViIjoic29tZW9uZSJ9.i5FVG64l7WxjnSghL_f_U8B8MrvTWdGmI707t5p3ZKjGeQFuH1qPUnfYelGEBwPoGGDO12Qa4Ch5i9sf6EViCw' push --relay https://relay:7443 deploy agent/other 2>&1464agent # [ 4280.686107] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.647836Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}465agent # [ 4280.784962] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.746717Z","level":"INFO","message":"start","id":"57dfb8dca462d7707e252cbe917ec54c","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}466agent # [ 4280.785309] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.747140Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"57dfb8dca462d7707e252cbe917ec54c\"]","target":"flakelet_relay::agent::jobs"}467agent # [ 4280.835065] agent systemd[1]: Starting flakelet update other (via relay)...468agent # [ 4280.869914] agent systemd[1]: Started flakelet update other (via relay).469agent # [ 4280.874258] agent flakelet[1226]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1470agent # [ 4280.874766] agent flakelet[1226]: other: up to date471agent # [ 4280.877998] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.472relay # [ 4280.687217] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:58.648945Z","level":"INFO","message":"deploy finished","job":"4c9fe352143f106bd900e5e8de900986","ok":true,"target":"flakelet_relay::relay::api"}473relay # [ 4280.784718] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:58.746482Z","level":"INFO","message":"deploy accepted","job":"c72b2526c5a009580f877a245aeaa6b7","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}474client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1OCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjU1OCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiT1YyNllRRUdCUVNMUT09PSIsIm5iZiI6MTc4ODY4MjU1OCwic3ViIjoic29tZW9uZSJ9.i5FVG64l7WxjnSghL_f_U8B8MrvTWdGmI707t5p3ZKjGeQFuH1qPUnfYelGEBwPoGGDO12Qa4Ch5i9sf6EViCw' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.67 seconds)475(finished: subtest: claim principal from groups, unchanged counts as success, in 0.72 seconds)476subtest: push login via device flow, cached token used afterwards477client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1478agent # [ 4281.430233] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:59.391960Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}479relay # [ 4281.431450] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:59.393201Z","level":"INFO","message":"deploy finished","job":"c72b2526c5a009580f877a245aeaa6b7","ok":true,"target":"flakelet_relay::relay::api"}480relay # [ 4281.457803] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:15:59] "POST /device HTTP/1.1" 200 -481relay # [ 4282.463803] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:16:00] "POST /token HTTP/1.1" 400 -482client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)483client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600484client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)485client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1486relay # [ 4283.513907] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:16:01] "POST /token HTTP/1.1" 200 -487relay # [ 4283.544224] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:01.506024Z","level":"INFO","message":"deploy accepted","job":"3846f68305ba7a8c5b66e0a9ffbe9e58","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}488agent # [ 4283.544575] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:01.506319Z","level":"INFO","message":"start","id":"d0a18a8bb985692c8cb008a99a08b77c","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}489agent # [ 4283.545302] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:01.507120Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"d0a18a8bb985692c8cb008a99a08b77c\"]","target":"flakelet_relay::agent::jobs"}490agent # [ 4283.596662] agent systemd[1]: Starting flakelet update other (via relay)...491agent # [ 4283.628037] agent systemd[1]: Started flakelet update other (via relay).492agent # [ 4283.632847] agent flakelet[1274]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1493agent # [ 4283.633361] agent flakelet[1274]: other: up to date494agent # [ 4283.636501] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.495client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.66 seconds)496client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1497agent # [ 4284.187441] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.149182Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}498agent # [ 4284.209255] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.171068Z","level":"INFO","message":"start","id":"679f3221e08f81b35983e4943b6e1de4","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}499agent # [ 4284.209470] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.171300Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"679f3221e08f81b35983e4943b6e1de4\"]","target":"flakelet_relay::agent::jobs"}500agent # [ 4284.268286] agent systemd[1]: Starting flakelet update other (via relay)...501agent # [ 4284.303993] agent systemd[1]: Started flakelet update other (via relay).502agent # [ 4284.308373] agent flakelet[1302]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1503agent # [ 4284.308910] agent flakelet[1302]: other: up to date504agent # [ 4284.310588] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.505relay # [ 4284.188708] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.150456Z","level":"INFO","message":"deploy finished","job":"3846f68305ba7a8c5b66e0a9ffbe9e58","ok":true,"target":"flakelet_relay::relay::api"}506relay # [ 4284.209066] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.170884Z","level":"INFO","message":"deploy accepted","job":"3fb621a90d1c4fe8d6c02115accb8284","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}507client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.67 seconds)508(finished: subtest: push login via device flow, cached token used afterwards, in 3.43 seconds)509subtest: waves: failing first wave skips the second510agent: 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.json511agent: (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)512client: 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>&1513agent # [ 4284.861167] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.822904Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}514agent # [ 4284.897668] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.859436Z","level":"INFO","message":"start","id":"60864decd9bfe1bb743beff185731eb3","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}515agent # [ 4284.897913] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.859690Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"60864decd9bfe1bb743beff185731eb3\"]","target":"flakelet_relay::agent::jobs"}516agent # [ 4284.957928] agent systemd[1]: Starting flakelet update app (via relay)...517agent # [ 4285.004193] agent systemd[1]: Started flakelet update app (via relay).518agent # [ 4285.008301] agent flakelet[1339]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken519agent # [ 4285.008956] agent flakelet[1339]: app: activating generation 4520agent # [ 4285.018688] agent systemd[1]: Stopping app v1...521agent # [ 4285.019423] agent systemd[1]: app.service: Deactivated successfully.522agent # [ 4285.019553] agent systemd[1]: Stopped app v1.523agent # [ 4285.029235] agent systemd[1]: Reload requested from client PID 1350 ('systemctl') (unit flakelet-relay-job-app.service)...524agent # [ 4285.029270] agent systemd[1]: Reloading...525relay # [ 4284.862234] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.824006Z","level":"INFO","message":"deploy finished","job":"3fb621a90d1c4fe8d6c02115accb8284","ok":true,"target":"flakelet_relay::relay::api"}526relay # [ 4284.897491] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.859309Z","level":"INFO","message":"deploy accepted","job":"8419c3ef1200ac1a3b2918807efb1372","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}527agent # [ 4285.355562] agent systemd[1]: Reloading finished in 325 ms.528agent # [ 4285.428381] agent systemd[1]: Reload requested from client PID 1380 ('systemctl') (unit flakelet-relay-job-app.service)...529agent # [ 4285.428418] agent systemd[1]: Reloading...530agent # [ 4285.753667] agent systemd[1]: Reloading finished in 324 ms.531agent # [ 4285.821643] agent systemd[1]: Reload requested from client PID 1409 ('systemctl') (unit flakelet-relay-job-app.service)...532agent # [ 4285.821680] agent systemd[1]: Reloading...533agent # [ 4286.146370] agent systemd[1]: Reloading finished in 324 ms.534agent # [ 4286.210573] agent systemd[1]: Reload requested from client PID 1440 ('systemctl') (unit flakelet-relay-job-app.service)...535agent # [ 4286.210607] agent systemd[1]: Reloading...536agent # [ 4286.537537] agent systemd[1]: Reloading finished in 326 ms.537agent # [ 4286.599997] agent systemd[1]: Starting app broken...538agent # [ 4286.635452] agent (nonexistent)[1470]: app.service: Unable to locate executable '/nonexistent': No such file or directory539agent # [ 4286.635475] agent (nonexistent)[1470]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory540agent # [ 4286.636856] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC541agent # [ 4286.636962] agent systemd[1]: app.service: Failed with result 'exit-code'.542agent # [ 4286.637332] agent systemd[1]: Failed to start app broken.543agent # [ 4286.669082] agent systemd[1]: Reload requested from client PID 1477 ('systemctl') (unit flakelet-relay-job-app.service)...544agent # [ 4286.669119] agent systemd[1]: Reloading...545agent # [ 4286.995429] agent systemd[1]: Reloading finished in 325 ms.546agent # [ 4287.072509] agent systemd[1]: Reload requested from client PID 1510 ('systemctl') (unit flakelet-relay-job-app.service)...547agent # [ 4287.072541] agent systemd[1]: Reloading...548agent # [ 4287.397221] agent systemd[1]: Reloading finished in 324 ms.549agent # [ 4287.457311] agent systemd[1]: Reload requested from client PID 1541 ('systemctl') (unit flakelet-relay-job-app.service)...550agent # [ 4287.457342] agent systemd[1]: Reloading...551agent # [ 4287.784621] agent systemd[1]: Reloading finished in 326 ms.552agent # [ 4287.870345] agent systemd[1]: Reload requested from client PID 1573 ('systemctl') (unit flakelet-relay-job-app.service)...553agent # [ 4287.870381] agent systemd[1]: Reloading...554agent # [ 4288.198166] agent systemd[1]: Reloading finished in 327 ms.555agent # [ 4288.262729] agent systemd[1]: Starting app v1...556agent # [ 4288.288954] agent systemd[1]: Started app v1.557agent # [ 4288.290067] agent flakelet[1339]: app: deploy failed, rolled back: systemctl start app.service failed:558agent # [ 4288.290067] agent flakelet[1339]: failed units: app.service. See journalctl -u app.service559agent # [ 4288.292140] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE560agent # [ 4288.292233] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.561client: (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.55 seconds)562agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'563agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds)564(finished: subtest: waves: failing first wave skips the second, in 4.58 seconds)565subtest: host patterns expand on the relay566agent: 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.json567agent: (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)568client: 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>&1569agent # [ 4289.421899] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.383644Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}570agent # [ 4289.478271] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.440025Z","level":"INFO","message":"start","id":"f1b32e63c63b348f6bcaa4dd85b44f1b","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}571agent # [ 4289.478711] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.440531Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"f1b32e63c63b348f6bcaa4dd85b44f1b\"]","target":"flakelet_relay::agent::jobs"}572agent # [ 4289.529511] agent systemd[1]: Starting flakelet update app (via relay)...573agent # [ 4289.561021] agent systemd[1]: Started flakelet update app (via relay).574agent # [ 4289.565340] agent flakelet[1651]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1575agent # [ 4289.565820] agent flakelet[1651]: app: up to date576agent # [ 4289.568937] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.577relay # [ 4289.423477] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:07.385244Z","level":"INFO","message":"deploy finished","job":"8419c3ef1200ac1a3b2918807efb1372","ok":false,"target":"flakelet_relay::relay::api"}578relay # [ 4289.477893] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:07.439686Z","level":"INFO","message":"deploy accepted","job":"54e64c0c23a29bd77f9ed013b2ca24de","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}579client: (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.67 seconds)580client: 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>&1581agent # [ 4290.121774] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.083507Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}582agent # [ 4290.144718] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.106518Z","level":"INFO","message":"start","id":"59ff063568ac4f65946781e56e050ce3","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}583agent # [ 4290.145117] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.106937Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"59ff063568ac4f65946781e56e050ce3\"]","target":"flakelet_relay::agent::jobs"}584agent # [ 4290.202398] agent systemd[1]: Starting flakelet update app (via relay)...585agent # [ 4290.235007] agent systemd[1]: Started flakelet update app (via relay).586agent # [ 4290.239365] agent flakelet[1679]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1587agent # [ 4290.239923] agent flakelet[1679]: app: up to date588agent # [ 4290.242509] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.589relay # [ 4290.123259] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.085025Z","level":"INFO","message":"deploy finished","job":"54e64c0c23a29bd77f9ed013b2ca24de","ok":true,"target":"flakelet_relay::relay::api"}590relay # [ 4290.144480] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.106300Z","level":"INFO","message":"deploy accepted","job":"beb907435b71cafa934c3fbf2377abc0","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}591client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.67 seconds)592client: 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>&1593agent # [ 4290.791811] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.753551Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}594agent # [ 4290.815252] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.777055Z","level":"INFO","message":"start","id":"a2fdbb9d6d5be999afc01028db739d51","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}595agent # [ 4290.815635] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.777456Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"a2fdbb9d6d5be999afc01028db739d51\"]","target":"flakelet_relay::agent::jobs"}596agent # [ 4290.876208] agent systemd[1]: Starting flakelet update app (via relay)...597agent # [ 4290.906953] agent systemd[1]: Started flakelet update app (via relay).598agent # [ 4290.911245] agent flakelet[1707]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1599agent # [ 4290.911734] agent flakelet[1707]: app: up to date600agent # [ 4290.914181] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.601relay # [ 4290.793271] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.755048Z","level":"INFO","message":"deploy finished","job":"beb907435b71cafa934c3fbf2377abc0","ok":false,"target":"flakelet_relay::relay::api"}602relay # [ 4290.815041] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.776856Z","level":"INFO","message":"deploy accepted","job":"d4e529abb3e862d24c8b30e1f7400bc7","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}603client: (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.67 seconds)604client: 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>&1605client: (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)606(finished: subtest: host patterns expand on the relay, in 2.04 seconds)607subtest: detach returns once the job is accepted608agent: 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.json609agent: (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)610client: 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>&1611client: (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)612agent: waiting for success: systemctl is-active flakelet-relay-job-app.service613agent # [ 4291.464705] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.426445Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}614agent # [ 4291.521924] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.483686Z","level":"INFO","message":"start","id":"cafe9eb7933849ac787c87a8e3aa3227","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}615agent # [ 4291.522385] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.484204Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cafe9eb7933849ac787c87a8e3aa3227\"]","target":"flakelet_relay::agent::jobs"}616agent # [ 4291.571039] agent systemd[1]: Starting flakelet update app (via relay)...617agent # [ 4291.599916] agent systemd[1]: Started flakelet update app (via relay).618agent # [ 4291.604208] agent flakelet[1749]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2619agent # [ 4291.604864] agent flakelet[1749]: app: activating generation 4620agent # [ 4291.618338] agent systemd[1]: Stopping app v1...621agent # [ 4291.618784] agent systemd[1]: app.service: Deactivated successfully.622agent # [ 4291.619057] agent systemd[1]: Stopped app v1.623agent # [ 4291.637189] agent systemd[1]: Reload requested from client PID 1756 ('systemctl') (unit flakelet-relay-job-app.service)...624agent # [ 4291.637257] agent systemd[1]: Reloading...625relay # [ 4291.466311] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:09.428079Z","level":"INFO","message":"deploy finished","job":"d4e529abb3e862d24c8b30e1f7400bc7","ok":false,"target":"flakelet_relay::relay::api"}626relay # [ 4291.521638] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:09.483434Z","level":"INFO","message":"deploy accepted","job":"54bf4db2326752f10b4c3da9a1be148e","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}627agent # [ 4291.970935] agent systemd[1]: Reloading finished in 332 ms.628agent # [ 4292.042489] agent systemd[1]: Reload requested from client PID 1786 ('systemctl') (unit flakelet-relay-job-app.service)...629agent # [ 4292.042526] agent systemd[1]: Reloading...630agent # [ 4292.367840] agent systemd[1]: Reloading finished in 324 ms.631agent # [ 4292.431553] agent systemd[1]: Reload requested from client PID 1815 ('systemctl') (unit flakelet-relay-job-app.service)...632agent # [ 4292.431591] agent systemd[1]: Reloading...633agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.29 seconds)634??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.635 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39636agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service637??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.638 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39639agent # [ 4292.756463] agent systemd[1]: Reloading finished in 324 ms.640agent # [ 4292.820893] agent systemd[1]: Reload requested from client PID 1848 ('systemctl') (unit flakelet-relay-job-app.service)...641agent # [ 4292.820928] agent systemd[1]: Reloading...642agent # [ 4293.145495] agent systemd[1]: Reloading finished in 324 ms.643agent # [ 4293.207787] agent systemd[1]: Starting app slow2...644agent # [ 4299.285035] agent systemd[1]: Started app slow2.645agent # [ 4299.302953] agent flakelet[1749]: app: updated to generation 4646agent # [ 4299.306097] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.647agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.49 seconds)648(finished: subtest: detach returns once the job is accepted, in 8.81 seconds)649subtest: unknown host is final, missing agent is retried, agents listing650client: 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>&1651client: (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)652agent: must succeed: systemctl stop flakelet-agent653agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.04 seconds)654relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'655relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)656client: 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 &657client: (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)658client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out659agent # [ 4300.332911] agent systemd[1]: Stopping flakelet-agent...660agent # [ 4300.361332] agent systemd[1]: flakelet-agent.service: Deactivated successfully.661agent # [ 4300.361777] agent systemd[1]: Stopped flakelet-agent.662agent # [ 4300.362230] agent systemd[1]: flakelet-agent.service: Consumed 2.572s CPU time over 31.510s wall clock time.663relay # [ 4300.332932] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:18.294715Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}664client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)665agent: must succeed: systemctl start flakelet-agent666agent: (finished: must succeed: systemctl start flakelet-agent, in 0.15 seconds)667??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.668 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39669client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out670agent # [ 4301.423397] agent systemd[1]: Starting flakelet-agent...671agent # [ 4301.475367] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.437142Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"cafe9eb7933849ac787c87a8e3aa3227\"]","target":"flakelet_relay::agent::jobs"}672agent # [ 4301.556960] agent systemd[1]: Started flakelet-agent.673agent # [ 4301.570257] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.532048Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}674relay # [ 4301.570325] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:19.532090Z","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"}675agent # [ 4302.036750] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.998470Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}676agent # [ 4303.406426] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:21.368154Z","level":"INFO","message":"start","id":"9a950a093acee1c7eca217400075cae1","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}677agent # [ 4303.407376] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:21.368812Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"9a950a093acee1c7eca217400075cae1\"]","target":"flakelet_relay::agent::jobs"}678agent # [ 4303.461664] agent systemd[1]: Starting flakelet update other (via relay)...679agent # [ 4303.495045] agent systemd[1]: Started flakelet update other (via relay).680agent # [ 4303.501049] agent flakelet[2375]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1681agent # [ 4303.501594] agent flakelet[2375]: other: up to date682agent # [ 4303.502320] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.683relay # [ 4303.405965] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:21.367730Z","level":"INFO","message":"deploy accepted","job":"91cdeb537d902f2bbfda54be7f1ee2de","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}684agent # [ 4304.055200] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:22.016933Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}685relay # [ 4304.056677] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:22.018445Z","level":"INFO","message":"deploy finished","job":"91cdeb537d902f2bbfda54be7f1ee2de","ok":true,"target":"flakelet_relay::relay::api"}686client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)687client: 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 agents688client: (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)689client: 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)690client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)691client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg4MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTgyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSNTRGUFpWUUhNTlNHPT09IiwibmJmIjoxNzg4NjgyNTgyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Iq3sKhHaBl7eLGLznpjPigr9cVJ0rexH0GsOepbDjdaEhadAE1AhgnFtlsKAIEW4uKWo867afXQc6ZpWPKlLDA' push --relay https://relay:7443 agents692client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg4MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTgyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSNTRGUFpWUUhNTlNHPT09IiwibmJmIjoxNzg4NjgyNTgyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Iq3sKhHaBl7eLGLznpjPigr9cVJ0rexH0GsOepbDjdaEhadAE1AhgnFtlsKAIEW4uKWo867afXQc6ZpWPKlLDA' push --relay https://relay:7443 agents, in 0.02 seconds)693(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.40 seconds)694subtest: out-of-band flakelet update reaches the relay without reconnect695agent: must succeed: flakelet status --json app | jq '.[0].generation'696agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.05 seconds)697agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true698agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)699agent: 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.json700agent: (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)701agent: must succeed: flakelet update app702app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2703app: activating generation 5704agent # [ 4304.792147] agent systemd[1]: Stopping app slow2...705agent # [ 4304.792681] agent systemd[1]: app.service: Deactivated successfully.706agent # [ 4304.792952] agent systemd[1]: Stopped app slow2.707agent # [ 4304.810191] agent systemd[1]: Reload requested from client PID 2423 ('systemctl')...708agent # [ 4304.810259] agent systemd[1]: Reloading...709agent # [ 4305.157074] agent systemd[1]: Reloading finished in 346 ms.710agent # [ 4305.244680] agent systemd[1]: Reload requested from client PID 2452 ('systemctl')...711agent # [ 4305.244719] agent systemd[1]: Reloading...712agent # [ 4305.572999] agent systemd[1]: Reloading finished in 327 ms.713agent # [ 4305.672977] agent systemd[1]: Reload requested from client PID 2482 ('systemctl')...714agent # [ 4305.673029] agent systemd[1]: Reloading...715agent # [ 4305.997803] agent systemd[1]: Reloading finished in 324 ms.716agent # [ 4306.075944] agent systemd[1]: Reload requested from client PID 2514 ('systemctl')...717agent # [ 4306.075976] agent systemd[1]: Reloading...718agent # [ 4306.402060] agent systemd[1]: Reloading finished in 325 ms.719agent: (finished: must succeed: flakelet update app, in 1.77 seconds)720client: 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'721agent # [ 4306.488699] agent systemd[1]: Starting app v2...722agent # [ 4306.518999] agent systemd[1]: Started app v2.723client: (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)724agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true725agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)726agent: 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.json727agent: (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)728agent: must succeed: flakelet update app729app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1730app: activating generation 6731agent # [ 4308.648174] agent systemd[1]: Stopping app v2...732agent # [ 4308.648676] agent systemd[1]: app.service: Deactivated successfully.733agent # [ 4308.648941] agent systemd[1]: Stopped app v2.734agent # [ 4308.666170] agent systemd[1]: Reload requested from client PID 2572 ('systemctl')...735agent # [ 4308.666238] agent systemd[1]: Reloading...736agent # [ 4309.011072] agent systemd[1]: Reloading finished in 344 ms.737agent # [ 4309.082523] agent systemd[1]: Reload requested from client PID 2601 ('systemctl')...738agent # [ 4309.082560] agent systemd[1]: Reloading...739agent # [ 4309.406690] agent systemd[1]: Reloading finished in 323 ms.740agent # [ 4309.474463] agent systemd[1]: Reload requested from client PID 2629 ('systemctl')...741agent # [ 4309.474501] agent systemd[1]: Reloading...742agent # [ 4309.796919] agent systemd[1]: Reloading finished in 321 ms.743agent # [ 4309.876130] agent systemd[1]: Reload requested from client PID 2661 ('systemctl')...744agent # [ 4309.876168] agent systemd[1]: Reloading...745agent # [ 4310.200994] agent systemd[1]: Reloading finished in 324 ms.746agent: (finished: must succeed: flakelet update app, in 1.70 seconds)747client: 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'748agent # [ 4310.272799] agent systemd[1]: Starting app v1...749agent # [ 4310.311188] agent systemd[1]: Started app v1.750client: (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)751(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.69 seconds)752subtest: certificate not listed under agents cannot connect as agent753client: 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/agent754client: (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)755(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.02 seconds)756subtest: metrics757relay: must succeed: curl -sf http://127.0.0.1:7400/metrics758relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)759(finished: subtest: metrics, in 0.01 seconds)760subtest: agent link drop mid-run replays missed lines once761agent: 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.json762agent: (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)763agent: must succeed: date +%s764agent: (finished: must succeed: date +%s, in 0.01 seconds)765client: 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 &766client: (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)767agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'app-slow'768agent # [ 4312.467100] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:30.428813Z","level":"INFO","message":"start","id":"b21bacf6c84543d38b3547c2e8da39c8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}769agent # [ 4312.467938] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:30.429553Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"b21bacf6c84543d38b3547c2e8da39c8\"]","target":"flakelet_relay::agent::jobs"}770agent # [ 4312.523642] agent systemd[1]: Starting flakelet update app (via relay)...771agent # [ 4312.656465] agent systemd[1]: Started flakelet update app (via relay).772agent # [ 4312.661740] agent flakelet[2725]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow773agent # [ 4312.662797] agent flakelet[2725]: app: activating generation 7774agent # [ 4312.676055] agent systemd[1]: Stopping app v1...775agent # [ 4312.676509] agent systemd[1]: app.service: Deactivated successfully.776agent # [ 4312.676774] agent systemd[1]: Stopped app v1.777agent # [ 4312.693137] agent systemd[1]: Reload requested from client PID 2732 ('systemctl') (unit flakelet-relay-job-app.service)...778agent # [ 4312.693201] agent systemd[1]: Reloading...779relay # [ 4312.409581] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:30.371345Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}780relay # [ 4312.466669] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:30.428477Z","level":"INFO","message":"deploy accepted","job":"f3469a74f8927189fefb099655270820","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}781agent # [ 4313.033255] agent systemd[1]: Reloading finished in 339 ms.782agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'app-slow', in 1.02 seconds)783agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done784agent: (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)785relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done786relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.05 seconds)787agent: must succeed: ss -K dport = 7443788agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)789agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'updated to generation'790agent # [ 4313.393152] agent systemd[1]: Reload requested from client PID 2762 ('systemctl') (unit flakelet-relay-job-app.service)...791agent # [ 4313.393194] agent systemd[1]: Reloading...792agent # [ 4313.581895] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:31.543621Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}793relay # [ 4313.548842] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:31.510585Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}794agent # [ 4313.884646] agent systemd[1]: Reloading finished in 491 ms.795agent # [ 4313.960977] agent systemd[1]: Reload requested from client PID 2808 ('systemctl') (unit flakelet-relay-job-app.service)...796agent # [ 4313.961035] agent systemd[1]: Reloading...797agent # [ 4314.286509] agent systemd[1]: Reloading finished in 325 ms.798agent # [ 4314.405909] agent systemd[1]: Reload requested from client PID 2841 ('systemctl') (unit flakelet-relay-job-app.service)...799agent # [ 4314.405945] agent systemd[1]: Reloading...800agent # [ 4314.584905] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:32.546475Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}801agent # [ 4314.737292] agent systemd[1]: Reloading finished in 330 ms.802agent # [ 4314.820191] agent systemd[1]: Starting app slow...803agent # [ 4316.587400] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:34.549117Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}804agent # [ 4320.589391] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:38.551036Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}805agent # [ 4320.889861] agent systemd[1]: Started app slow.806agent # [ 4320.907599] agent flakelet[2725]: app: updated to generation 7807agent # [ 4320.910667] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.808agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'updated to generation', in 8.12 seconds)809agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done810agent: (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)811client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out812agent # [ 4321.548254] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:39.509966Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}813client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 7.08 seconds)814client: must succeed: cat /tmp/slow.out815client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)816(finished: subtest: agent link drop mid-run replays missed lines once, in 16.38 seconds)817subtest: agent restart mid-run reattaches to the unit818agent: 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.json819agent: (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)820client: 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 &821client: (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)822agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'823relay # [ 4328.595391] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.557075Z","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"}824agent # [ 4328.595281] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.557000Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}825relay # [ 4328.596802] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.558623Z","level":"INFO","message":"deploy finished","job":"f3469a74f8927189fefb099655270820","ok":true,"target":"flakelet_relay::relay::api"}826agent # [ 4328.596434] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.558251Z","level":"INFO","message":"start","id":"b21bacf6c84543d38b3547c2e8da39c8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}827relay # [ 4328.846747] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.808343Z","level":"INFO","message":"deploy accepted","job":"0ddb9ea36fecb7d694381f79aeaf2b0e","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}828agent # [ 4328.847131] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.808668Z","level":"INFO","message":"start","id":"e5ae731e6705b9b81318c5da1e1a833c","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}829agent # [ 4328.847502] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.809320Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e5ae731e6705b9b81318c5da1e1a833c\"]","target":"flakelet_relay::agent::jobs"}830agent # [ 4328.902266] agent systemd[1]: Starting flakelet update app (via relay)...831agent # [ 4328.935993] agent systemd[1]: Started flakelet update app (via relay).832agent # [ 4328.941244] agent flakelet[3021]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2833agent # [ 4328.941873] agent flakelet[3021]: app: activating generation 8834agent # [ 4328.954753] agent systemd[1]: Stopping app slow...835agent # [ 4328.956555] agent systemd[1]: app.service: Deactivated successfully.836agent # [ 4328.956866] agent systemd[1]: Stopped app slow.837agent # [ 4328.971824] agent systemd[1]: Reload requested from client PID 3028 ('systemctl') (unit flakelet-relay-job-app.service)...838agent # [ 4328.971890] agent systemd[1]: Reloading...839agent # [ 4329.312712] agent systemd[1]: Reloading finished in 340 ms.840agent # [ 4329.383755] agent systemd[1]: Reload requested from client PID 3058 ('systemctl') (unit flakelet-relay-job-app.service)...841agent # [ 4329.383791] agent systemd[1]: Reloading...842agent # [ 4329.712869] agent systemd[1]: Reloading finished in 328 ms.843agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)844agent: must succeed: systemctl restart flakelet-agent845agent # [ 4329.778184] agent systemd[1]: Reload requested from client PID 3089 ('systemctl') (unit flakelet-relay-job-app.service)...846agent # [ 4329.778218] agent systemd[1]: Reloading...847agent # [ 4330.112241] agent systemd[1]: Reloading finished in 333 ms.848agent # [ 4330.189481] agent systemd[1]: Stopping flakelet-agent...849agent # [ 4330.196049] agent systemd[1]: Reload requested from client PID 3126 ('systemctl') (unit flakelet-relay-job-app.service)...850agent # [ 4330.196091] agent systemd[1]: Reloading...851relay # [ 4330.189811] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:48.151552Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}852agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.86 seconds)853agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"854agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)855client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out856agent # [ 4330.532183] agent systemd[1]: Reloading finished in 335 ms.857agent # [ 4330.596410] agent systemd[1]: flakelet-agent.service: Deactivated successfully.858agent # [ 4330.596588] agent systemd[1]: Stopped flakelet-agent.859agent # [ 4330.596605] agent systemd[1]: flakelet-agent.service: Consumed 1.814s CPU time over 29.173s wall clock time.860agent # [ 4330.600941] agent systemd[1]: Starting flakelet-agent...861agent # [ 4330.603443] agent systemd[1]: Starting app slow2...862agent # [ 4330.656259] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.618046Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"e5ae731e6705b9b81318c5da1e1a833c\"]","target":"flakelet_relay::agent::jobs"}863agent # [ 4330.722965] agent systemd[1]: Started flakelet-agent.864agent # [ 4330.736828] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.698620Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}865agent # [ 4330.738101] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.699918Z","level":"INFO","message":"start","id":"e5ae731e6705b9b81318c5da1e1a833c","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}866relay # [ 4330.736939] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:48.698690Z","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"}867agent # [ 4336.666944] agent systemd[1]: Started app slow2.868agent # [ 4336.682207] agent flakelet[3021]: app: updated to generation 8869agent # [ 4336.684105] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.870relay # [ 4337.262883] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:55.224631Z","level":"INFO","message":"deploy finished","job":"0ddb9ea36fecb7d694381f79aeaf2b0e","ok":true,"target":"flakelet_relay::relay::api"}871agent # [ 4337.261305] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.223014Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}872client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)873client: must succeed: cat /tmp/restart.out874client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)875agent: must succeed: systemctl is-active app.service876agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)877(finished: subtest: agent restart mid-run reattaches to the unit, in 9.03 seconds)878subtest: relay restart mid-run, push resumes via /v1/jobs879agent: 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.json880agent: (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)881agent: must succeed: date +%s882agent: (finished: must succeed: date +%s, in 0.01 seconds)883client: 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 &884client: (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)885agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682615 | grep -q 'app-slow'886agent # [ 4337.884309] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.846047Z","level":"INFO","message":"start","id":"519f6601f6d4802b65e1d410940f29e2","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}887agent # [ 4337.884934] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.846756Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"519f6601f6d4802b65e1d410940f29e2\"]","target":"flakelet_relay::agent::jobs"}888agent # [ 4337.936600] agent systemd[1]: Starting flakelet update app (via relay)...889agent # [ 4337.968056] agent systemd[1]: Started flakelet update app (via relay).890agent # [ 4337.972713] agent flakelet[3642]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow891agent # [ 4337.973341] agent flakelet[3642]: app: activating generation 9892agent # [ 4337.986602] agent systemd[1]: Stopping app slow2...893agent # [ 4337.987064] agent systemd[1]: app.service: Deactivated successfully.894agent # [ 4337.987327] agent systemd[1]: Stopped app slow2.895agent # [ 4338.006261] agent systemd[1]: Reload requested from client PID 3649 ('systemctl') (unit flakelet-relay-job-app.service)...896agent # [ 4338.006325] agent systemd[1]: Reloading...897relay # [ 4337.883861] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:55.845613Z","level":"INFO","message":"deploy accepted","job":"8ab76c92a77a0c8f36dc064757064de6","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}898agent # [ 4338.348044] agent systemd[1]: Reloading finished in 340 ms.899agent # [ 4338.456095] agent systemd[1]: Reload requested from client PID 3679 ('systemctl') (unit flakelet-relay-job-app.service)...900agent # [ 4338.456132] agent systemd[1]: Reloading...901agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682615 | grep -q 'app-slow', in 1.02 seconds)902relay: must succeed: systemctl restart flakelet-relay903agent # [ 4338.788286] agent systemd[1]: Reloading finished in 331 ms.904agent # [ 4338.875545] agent systemd[1]: Reload requested from client PID 3710 ('systemctl') (unit flakelet-relay-job-app.service)...905agent # [ 4338.875577] agent systemd[1]: Reloading...906agent # [ 4338.906740] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:56.868524Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}907relay # [ 4338.906320] relay systemd[1]: Stopping flakelet-relay...908relay # [ 4338.942125] relay systemd[1]: flakelet-relay.service: Deactivated successfully.909relay # [ 4338.942603] relay systemd[1]: Stopped flakelet-relay.910relay # [ 4338.942644] relay systemd[1]: flakelet-relay.service: Consumed 2.750s CPU time over 1min 8.893s wall clock time.911relay # [ 4338.981339] relay systemd[1]: Starting flakelet-relay...912agent # [ 4339.229836] agent systemd[1]: Reloading finished in 353 ms.913agent # [ 4339.318674] agent systemd[1]: Reload requested from client PID 3746 ('systemctl') (unit flakelet-relay-job-app.service)...914agent # [ 4339.318714] agent systemd[1]: Reloading...915agent # [ 4339.651864] agent systemd[1]: Reloading finished in 332 ms.916agent # [ 4339.736248] agent systemd[1]: Starting app slow...917agent # [ 4339.909881] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:57.871524Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}918relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.53 seconds)919client: waiting for success: grep -q '» ok' /tmp/resume.out920relay # [ 4340.421999] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:58.383741Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}921relay # [ 4340.422952] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:58.384141Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}922relay # [ 4340.422629] relay systemd[1]: Started flakelet-relay.923agent # [ 4341.924082] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:59.885791Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}924relay # [ 4341.924266] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:59.886013Z","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"}925relay # [ 4341.926334] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:59.888146Z","level":"INFO","message":"job reattached","job":"8ab76c92a77a0c8f36dc064757064de6","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}926agent # [ 4345.808957] agent systemd[1]: Started app slow.927agent # [ 4345.826799] agent flakelet[3642]: app: updated to generation 9928agent # [ 4345.829471] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.929agent # [ 4346.913189] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:04.874927Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}930client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)931client: must succeed: cat /tmp/resume.out932client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)933(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.67 seconds)934subtest: job history comes from the agents and survives a relay restart935client: 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>&1936agent # [ 4347.533732] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:05.495468Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}937agent # [ 4347.534375] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:05.496192Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}938agent # [ 4347.586363] agent systemd[1]: Starting flakelet update other (via relay)...939agent # [ 4347.620523] agent systemd[1]: Started flakelet update other (via relay).940agent # [ 4347.625902] agent flakelet[3859]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1941agent # [ 4347.626471] agent flakelet[3859]: other: up to date942agent # [ 4347.627523] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.943relay # [ 4347.533408] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:17:05.495083Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}944client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.67 seconds)945relay: must succeed: systemctl restart flakelet-relay946agent # [ 4348.179049] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:06.140782Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}947agent # [ 4348.194408] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:06.156190Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}948relay # [ 4348.180392] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:17:06.142147Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}949relay # [ 4348.193883] relay systemd[1]: Stopping flakelet-relay...950relay # [ 4348.247150] relay systemd[1]: flakelet-relay.service: Deactivated successfully.951relay # [ 4348.247627] relay systemd[1]: Stopped flakelet-relay.952relay # [ 4348.247669] relay systemd[1]: flakelet-relay.service: Consumed 2.041s CPU time over 9.265s wall clock time.953relay # [ 4348.284052] relay systemd[1]: Starting flakelet-relay...954agent # [ 4349.197493] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:07.159215Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}955relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.49 seconds)956relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'957relay # [ 4349.670608] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:07.632343Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}958relay # [ 4349.671578] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:07.632774Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}959relay # [ 4349.671194] relay systemd[1]: Started flakelet-relay.960agent # [ 4351.207200] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.168973Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}961relay # [ 4351.207343] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.169084Z","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"}962relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)963client: 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 jobs964client: (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)965client: 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)966client: (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)967client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjkyOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNjI5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDWVlZNlNTWUtRTklVPT09IiwibmJmIjoxNzg4NjgyNjI5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.0owOCgV_QvciKpjEZKBBXoa003pIKLx7Zmn79daCm8V4sI_R3_IXjw7wXVY3O05mD-JR3OxrdWTroHcGVTKADg' push --relay https://relay:7443 jobs968client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjkyOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNjI5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDWVlZNlNTWUtRTklVPT09IiwibmJmIjoxNzg4NjgyNjI5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.0owOCgV_QvciKpjEZKBBXoa003pIKLx7Zmn79daCm8V4sI_R3_IXjw7wXVY3O05mD-JR3OxrdWTroHcGVTKADg' push --relay https://relay:7443 jobs, in 0.02 seconds)969(finished: subtest: job history comes from the agents and survives a relay restart, in 4.31 seconds)970subtest: dashboard login via authorization code flow971client: 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'972client: (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)973client: 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/login974client: (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)975client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs976client: (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)977client: 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 hist1978client: (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)979client: 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 || true980client: (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)981client: 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 403982client: (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)983client: 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'984client: (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)985client: 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/2898b2a8a520ce1b90ca229229d36749/events || true986relay # [ 4351.874698] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:17:09] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=1KNzVBibdSVyboEPGKl-PdCIoQ7vehYyMPDFmNFtdyg&code_challenge=inwqMeyxARzYBCBF6Vy2xsmxYhCMss1bokJP7YYmnLs&code_challenge_method=S256 HTTP/1.1" 302 -987relay # [ 4351.920465] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:17:09] "POST /token HTTP/1.1" 200 -988relay # [ 4351.921726] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.883527Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}989relay # [ 4351.985154] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.946909Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}990relay # [ 4352.027165] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.988930Z","level":"INFO","message":"deploy accepted","job":"67e1fdd469ec58d1a761e0b3128acbe3","caller":"oidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}991relay # [ 4352.046918] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:10.008722Z","level":"INFO","message":"job reattached","job":"67e1fdd469ec58d1a761e0b3128acbe3","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}992agent # [ 4352.027413] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.989169Z","level":"INFO","message":"start","id":"ece355ae42cccaa7c0b1a99716e07372","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}993agent # [ 4352.027856] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.989674Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"ece355ae42cccaa7c0b1a99716e07372\"]","target":"flakelet_relay::agent::jobs"}994agent # [ 4352.079999] agent systemd[1]: Starting flakelet update other (via relay)...995agent # [ 4352.112998] agent systemd[1]: Started flakelet update other (via relay).996agent # [ 4352.118496] agent flakelet[3907]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1997agent # [ 4352.118986] agent flakelet[3907]: other: up to date998agent # [ 4352.121850] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.999client: (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/2898b2a8a520ce1b90ca229229d36749/events || true, in 0.65 seconds)1000client: 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/2898b2a8a520ce1b90ca229229d367491001client: (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/2898b2a8a520ce1b90ca229229d36749, in 0.02 seconds)1002client: 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.js1003client: (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)1004client: 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'1005client: (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)1006client: 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/other1007client: (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)1008client: 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'1009client: (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)1010client: 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=2898b2a8a520ce1b90ca229229d36749' | grep -q 4001011client: (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=2898b2a8a520ce1b90ca229229d36749' | grep -q 400, in 0.02 seconds)1012client: 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 &1013client: (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)1014client: 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/other1015» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)1016» wave 01017agent/other | Starting flakelet update other (via relay)...1018agent/other | Started flakelet update other (via relay).1019agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11020agent/other | other: up to date1021agent # [ 4352.672228] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.633970Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1022agent/otheragent # [ 4352.821123] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.782776Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}1023 | agent # [ 4352.821345] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.783148Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}1024flakelet-relay-job-other.service: Deactivated successfully.agent # [ 4352.868511] agent systemd[1]: Starting flakelet update other (via relay)...10251026agent # [ 4352.904098] agent systemd[1]: Started flakelet update other (via relay).1027agent # [ 4352.908518] agent flakelet[3945]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11028agent # [ 4352.908977] agent flakelet[3945]: other: up to date1029agent # [ 4352.911172] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1030relay # [ 4352.820688] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:10.782440Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1031» agent/other: unchanged (generation 1)1032» ok1033client: (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.66 seconds)1034client: waiting for success: grep -q live1 /tmp/ev.out1035client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)1036client: 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/logout1037client: (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)1038client: 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 3031039client: (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)1040(finished: subtest: dashboard login via authorization code flow, in 1.70 seconds)1041(finished: run the VM test script, in 87.10 seconds)1042test script finished in 87.14s1043cleanup1044kill NspawnMachine (pid 51)1045kill NspawnMachine (pid 53)1046Container agent terminated by signal KILL.1047kill NspawnMachine (pid 55)1048relay # [ 4353.465686] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:11.427442Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}1049Container client terminated by signal KILL.1050(finished: cleanup, in 0.34 seconds)1051additionally exposed symbols:1052 agent, client, relay,1053 vlan1,1054 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_ssh1055» job b08899e4f5d9448ad0e62beee8dfb372 via relay 0.1.0 (agents: agent 0.1.0)1056» wave 01057agent/app | Starting flakelet update app (via relay)...1058agent/app | Started flakelet update app (via relay).1059agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v21060agent/app | app: activating generation 21061agent/app | app: updated to generation 21062agent/app | flakelet-relay-job-app.service: Deactivated successfully.1063» agent/app: updated (generation 2)1064» ok10651066» job 8419c3ef1200ac1a3b2918807efb1372 via relay 0.1.0 (agents: agent 0.1.0)1067» wave 01068agent/app | Starting flakelet update app (via relay)...1069agent/app | Started flakelet update app (via relay).1070agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1071agent/app | app: activating generation 41072agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1073agent/app | failed units: app.service. See journalctl -u app.service1074agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1075agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1076» agent/app: rolled-back (generation 3)1077agent/app │ Starting app v1...1078agent/app │ Started app v1.1079agent/app │ Stopping app v1...1080agent/app │ app.service: Deactivated successfully.1081agent/app │ Stopped app v1.1082agent/app │ Starting app v2...1083agent/app │ Started app v2.1084agent/app │ Stopping app v2...1085agent/app │ app.service: Deactivated successfully.1086agent/app │ Stopped app v2.1087agent/app │ Starting app v1...1088agent/app │ Started app v1.1089agent/app │ Stopping app v1...1090agent/app │ app.service: Deactivated successfully.1091agent/app │ Stopped app v1.1092agent/app │ Starting app broken...1093agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1094agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1095agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1096agent/app │ app.service: Failed with result 'exit-code'.1097agent/app │ Failed to start app broken.1098agent/app │ Starting app v1...1099agent/app │ Started app v1.1100» skipped: agent/other1101» failed11021103» job f3469a74f8927189fefb099655270820 via relay 0.1.0 (agents: agent 0.1.0)1104» wave 01105agent/app | Starting flakelet update app (via relay)...1106agent/app | Started flakelet update app (via relay).1107agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1108agent/app | app: activating generation 71109agent/app | app: updated to generation 71110agent/app | flakelet-relay-job-app.service: Deactivated successfully.1111» agent/app: updated (generation 7)1112» ok11131114» job 0ddb9ea36fecb7d694381f79aeaf2b0e via relay 0.1.0 (agents: agent 0.1.0)1115» wave 01116agent/app | Starting flakelet update app (via relay)...1117agent/app | Started flakelet update app (via relay).1118agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21119agent/app | app: activating generation 81120agent/app | app: updated to generation 81121agent/app | flakelet-relay-job-app.service: Deactivated successfully.1122» agent/app: updated (generation 8)1123» ok11241125» job 8ab76c92a77a0c8f36dc064757064de6 via relay 0.1.0 (agents: agent 0.1.0)1126» wave 01127agent/app | Starting flakelet update app (via relay)...1128agent/app | Started flakelet update app (via relay).1129agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1130agent/app | app: activating generation 91131flakelet-push: stream: error reading a body from connection, resuming job 05d4231c307cb1cbf07c6a9bdf207b941132flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1133flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1134» job 8ab76c92a77a0c8f36dc064757064de6 via relay 0.1.0 (agents: agent 0.1.0)1135» wave 01136agent/app | app: updated to generation 91137agent/app | flakelet-relay-job-app.service: Deactivated successfully.1138» agent/app: updated (generation 9)1139» ok114011411788682625 hist1 x509:email:admin@example.org agent/other:unchanged11421788682615 05d4231c307cb1cbf07c6a9bdf207b94 x509:email:admin@example.org agent/app:updated11431788682606 23da240189104d19234d432efbf0057c x509:email:admin@example.org agent/app:updated11441788682590 bf8c5b2d59a0eb357752b8716c11533b x509:email:admin@example.org agent/app:updated11451788682581 ed963f79555867c956c14f32ad09afb0 x509:email:admin@example.org agent/other:unchanged11461788682569 313fecae7846ea2661401f4ecb3ed8e4 x509:email:admin@example.org agent/app:updated11471788682568 8c41e2d174f8f86377f9484d2d4de768 x509:email:admin@example.org agent/app:unchanged11481788682568 f0dba552df68fb3bfa8da79a34b4b5ad x509:email:admin@example.org agent/app:unchanged11491788682567 88eb7e9f3367c33813834b7f2f43b527 x509:email:admin@example.org agent/app:unchanged11501788682562 2115e6266c59c8f29486fc6de24a7806 x509:email:admin@example.org agent/app:rolled-back11511788682562 a19f817a842695e2740b28dda6c7fe5f oidc:mock:groups:wheel agent/other:unchanged11521788682561 78f0ab79312d1634498aab8f76da8cf2 oidc:mock:groups:wheel agent/other:unchanged11531788682558 963c04c021b1f0489e22438454ce0598 oidc:mock:groups:wheel agent/other:unchanged11541788682555 2bf3cd2fd9539cc177c5e7413bc3abfd oidc:mock:repo:github:example/app:ref:refs/heads/main agent/app:updated11551788682552 cd6104c2a4dc8a780b83d81f54901226 x509:email:admin@example.org agent/app:updated11561157Container relay terminated by signal KILL.