container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #12
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 52)10client: systemd-nspawn running (pid 53)11relay: systemd-nspawn running (pid 54)12agent: Waiting for journal at /build/vm-state-agent/var/log/journal...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(agent): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24░ Spawning container client on /build/vm-state-client.25Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.26Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.27░ Spawning container relay on /build/vm-state-relay.28░ Spawning container agent on /build/vm-state-agent.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31relay # No journal files were found.32relay # No journal boot entry found for the specified boot (+0).33client # No journal files were found.34client # No journal boot entry found for the specified boot (+0).35agent # [84900.952206] agent systemd-journald[57]: Journal started36agent # [84900.952248] agent systemd-journald[57]: Runtime Journal (/run/log/journal/fdb647dac4674313a4b71cbec1ef960b) is 8M, max 4G, 3.9G free.37agent # [84900.962708] agent systemd[1]: Finished Apply Kernel Variables.38agent # [84900.974264] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [84901.007506] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [84901.008209] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [84901.016401] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/fdb647dac4674313a4b71cbec1ef960b is 1.744ms for 6 entries.42agent # [84901.016401] agent systemd-journald[57]: System Journal (/var/log/journal/fdb647dac4674313a4b71cbec1ef960b) is 512B, max 4G, 3.9G free.43agent # [84901.028938] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [84901.029793] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [84901.029925] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [84901.039076] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [84901.112361] agent systemd[1]: Finished Firewall.48client # [84900.944399] client systemd-journald[57]: Journal started49relay # [84900.953840] relay systemd-journald[57]: Journal started50client # [84900.944440] client systemd-journald[57]: Runtime Journal (/run/log/journal/703e661a5c0b4c66b458fca3cfd9754f) is 8M, max 4G, 3.9G free.51relay # [84900.953885] relay systemd-journald[57]: Runtime Journal (/run/log/journal/c570373fcc0240218ae60b94573eace1) is 8M, max 4G, 3.9G free.52client # [84900.954034] client systemd[1]: Finished Apply Kernel Variables.53relay # [84900.965393] relay systemd[1]: Finished Apply Kernel Variables.54client # [84900.965821] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.55relay # [84900.977497] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.56client # [84900.981403] client systemd[1]: Starting Flush Journal to Persistent Storage...57relay # [84901.007557] relay systemd[1]: Starting Flush Journal to Persistent Storage...58client # [84900.982113] client systemd[1]: Starting Create Static Device Nodes in /dev...59relay # [84901.008390] relay systemd[1]: Starting Create Static Device Nodes in /dev...60relay # [84901.017052] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/c570373fcc0240218ae60b94573eace1 is 1.503ms for 6 entries.61client # [84901.013810] client systemd-journald[57]: Time spent on flushing to /var/log/journal/703e661a5c0b4c66b458fca3cfd9754f is 1.563ms for 6 entries.62relay # [84901.017052] relay systemd-journald[57]: System Journal (/var/log/journal/c570373fcc0240218ae60b94573eace1) is 512B, max 4G, 3.9G free.63relay # [84901.028133] relay systemd[1]: Finished Create Static Device Nodes in /dev.64relay # [84901.028893] relay systemd[1]: Reached target Preparation for Local File Systems.65relay # [84901.029012] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys66client # [84901.013810] client systemd-journald[57]: System Journal (/var/log/journal/703e661a5c0b4c66b458fca3cfd9754f) is 512B, max 4G, 3.9G free.67relay # [84901.041572] relay systemd[1]: Finished Flush Journal to Persistent Storage.68relay # [84901.127751] relay systemd[1]: Finished Firewall.69relay # [84901.954649] relay systemd[1]: Mounting /run/wrappers...70client # [84901.022086] client systemd[1]: Finished Create Static Device Nodes in /dev.71client # [84901.022777] client systemd[1]: Reached target Preparation for Local File Systems.72client # [84901.022885] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys73client # [84901.035034] client systemd[1]: Finished Flush Journal to Persistent Storage.74client # [84901.102179] client systemd[1]: Finished Firewall.75relay # [84902.003960] relay systemd[1]: Mounted /run/wrappers.76relay # [84902.004777] relay systemd[1]: Reached target Local File Systems.77relay # [84902.006176] relay systemd[1]: Listening on Boot Loader Control Service Socket.78relay # [84902.007457] relay systemd[1]: Starting Create SUID/SGID Wrappers...79relay # [84902.007505] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container80relay # [84902.008664] relay systemd[1]: Starting Save Transient machine-id to Disk...81relay # [84902.009724] relay systemd[1]: Starting Create System Files and Directories...82relay # [84902.030911] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted83relay # [84902.031367] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted84relay # [84902.031692] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/c570373fcc0240218ae60b94573eace1 failed: Operation not permitted85relay # [84902.032072] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted86agent # [84901.986765] agent systemd[1]: Mounting /run/wrappers...87agent # [84902.025667] agent systemd[1]: Mounted /run/wrappers.88agent # [84902.026941] agent systemd[1]: Reached target Local File Systems.89agent # [84902.028386] agent systemd[1]: Listening on Boot Loader Control Service Socket.90agent # [84902.029769] agent systemd[1]: Starting Create SUID/SGID Wrappers...91agent # [84902.029820] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container92agent # [84902.030728] agent systemd[1]: Starting Save Transient machine-id to Disk...93agent # [84902.031667] agent systemd[1]: Starting Create System Files and Directories...94agent # [84902.051168] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted95agent # [84902.051615] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted96agent # [84902.051967] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/fdb647dac4674313a4b71cbec1ef960b failed: Operation not permitted97agent # [84902.052392] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted98client # [84901.986761] client systemd[1]: Mounting /run/wrappers...99client # [84902.026241] client systemd[1]: Mounted /run/wrappers.100client # [84902.027534] client systemd[1]: Reached target Local File Systems.101client # [84902.028925] client systemd[1]: Listening on Boot Loader Control Service Socket.102client # [84902.030199] client systemd[1]: Starting Create SUID/SGID Wrappers...103client # [84902.030246] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104client # [84902.031225] client systemd[1]: Starting Save Transient machine-id to Disk...105client # [84902.032111] client systemd[1]: Starting Create System Files and Directories...106client # [84902.052766] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted107client # [84902.053203] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108client # [84902.053544] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/703e661a5c0b4c66b458fca3cfd9754f failed: Operation not permitted109client # [84902.053913] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110relay # [84902.034229] relay systemd[1]: Finished Create System Files and Directories.111relay # [84902.034367] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.YIHsudkI03/chsh': Operation not permitted112relay # [84902.045939] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE113relay # [84902.046183] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.114relay # [84902.046321] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.115relay # [84902.048703] relay systemd[1]: Starting Rebuild Journal Catalog...116relay # [84902.049365] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...117relay # [84902.061047] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.118relay # [84902.074782] relay systemd[1]: Finished Rebuild Journal Catalog.119relay # [84902.075956] relay systemd[1]: Starting Update is Completed...120relay # [84902.088539] relay systemd[1]: Finished Update is Completed.121relay # [84902.088699] relay systemd[1]: Reached target System Initialization.122relay # [84902.088772] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123relay # [84902.088799] relay systemd[1]: Started Daily Cleanup of Temporary Directories.124relay # [84902.088816] relay systemd[1]: Reached target Timer Units.125relay # [84902.088938] relay systemd[1]: Listening on D-Bus System Message Bus Socket.126relay # [84902.089184] relay systemd[1]: Listening on Nix Daemon Socket.127relay # [84902.089297] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128relay # [84902.089313] relay systemd[1]: Reached target Socket Units.129relay # [84902.089346] relay systemd[1]: Reached target Basic System.130relay # [84902.090654] relay systemd[1]: Started device-mock.service.131relay # [84902.091366] relay systemd[1]: Starting Re-link flakelet services at boot...132relay # [84902.092288] relay systemd[1]: Starting Import lastlog data into lastlog2 database...133relay # [84902.093306] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...134relay # [84902.094079] relay systemd[1]: Starting resolvconf update...135relay # [84902.104362] relay systemd[1]: Finished Re-link flakelet services at boot.136relay # [84902.105863] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...137relay # [84902.113523] relay systemd[1]: Finished Import lastlog data into lastlog2 database.138relay # [84902.120549] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.139relay # [84902.173575] relay systemd[1]: Finished resolvconf update.140relay # [84902.174246] relay systemd[1]: Reached target Preparation for Network.141relay # [84902.175288] relay systemd[1]: Starting Address configuration of eth1...142relay # [84902.176618] relay systemd[1]: Starting Extra networking commands....143relay # [84902.194547] relay network-addresses-eth1-start[245]: adding address 192.168.1.3/24... done144relay # [84902.200077] relay network-addresses-eth1-start[245]: adding address 2001:db8:1::3/64... done145client # [84902.055830] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.1RMV5ysm0P/chsh': Operation not permitted146client # [84902.056752] client systemd[1]: Finished Create System Files and Directories.147client # [84902.081514] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE148agent # [84902.052675] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.zTLlGtOMN2/chsh': Operation not permitted149client # [84902.081557] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.150client # [84902.081605] client systemd[1]: Failed to start Create SUID/SGID Wrappers.151agent # [84902.058081] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE152client # [84902.084637] client systemd[1]: Starting Rebuild Journal Catalog...153agent # [84902.058124] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.154client # [84902.085345] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...155client # [84902.097970] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.156agent # [84902.058176] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.157client # [84902.106146] client systemd[1]: Finished Rebuild Journal Catalog.158agent # [84902.058653] agent systemd[1]: Finished Create System Files and Directories.159client # [84902.107460] client systemd[1]: Starting Update is Completed...160agent # [84902.085514] agent systemd[1]: Starting Rebuild Journal Catalog...161client # [84902.116629] client systemd[1]: Finished Update is Completed.162agent # [84902.086175] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...163client # [84902.116726] client systemd[1]: Reached target System Initialization.164agent # [84902.098560] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.165client # [84902.116796] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container166agent # [84902.107016] agent systemd[1]: Finished Rebuild Journal Catalog.167client # [84902.116825] client systemd[1]: Started Daily Cleanup of Temporary Directories.168agent # [84902.108189] agent systemd[1]: Starting Update is Completed...169client # [84902.116844] client systemd[1]: Reached target Timer Units.170agent # [84902.118610] agent systemd[1]: Finished Update is Completed.171client # [84902.116957] client systemd[1]: Listening on D-Bus System Message Bus Socket.172agent # [84902.119379] agent systemd[1]: Reached target System Initialization.173client # [84902.117158] client systemd[1]: Listening on Nix Daemon Socket.174agent # [84902.119541] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container175client # [84902.117272] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.176agent # [84902.119615] agent systemd[1]: Started Daily Cleanup of Temporary Directories.177client # [84902.117287] client systemd[1]: Reached target Socket Units.178agent # [84902.119644] agent systemd[1]: Reached target Timer Units.179client # [84902.117319] client systemd[1]: Reached target Basic System.180agent # [84902.119863] agent systemd[1]: Listening on D-Bus System Message Bus Socket.181client # [84902.118718] client systemd[1]: Starting Import lastlog data into lastlog2 database...182agent # [84902.120135] agent systemd[1]: Listening on Nix Daemon Socket.183client # [84902.119552] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...184agent # [84902.120335] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.185client # [84902.120211] client systemd[1]: Starting resolvconf update...186agent # [84902.120361] agent systemd[1]: Reached target Socket Units.187client # [84902.150415] client systemd[1]: Finished Import lastlog data into lastlog2 database.188agent # [84902.120415] agent systemd[1]: Reached target Basic System.189client # [84902.220978] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.190agent # [84902.122255] agent systemd[1]: Starting Re-link flakelet services at boot...191client # [84902.221997] client systemd[1]: Finished Save Transient machine-id to Disk.192agent # [84902.123283] agent systemd[1]: Starting Import lastlog data into lastlog2 database...193client # [84902.222218] client systemd[1]: nscd.service: Deactivated successfully.194agent # [84902.124847] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...195client # [84902.222370] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).196agent # [84902.125733] agent systemd[1]: Starting resolvconf update...197client # [84902.224187] client systemd[1]: Finished resolvconf update.198agent # [84902.138552] agent systemd[1]: Finished Re-link flakelet services at boot.199client # [84902.226332] client systemd[1]: Reached target Preparation for Network.200agent # [84902.141719] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...201client # [84902.227228] client systemd[1]: Starting Address configuration of eth1...202agent # [84902.150652] agent systemd[1]: Finished Import lastlog data into lastlog2 database.203client # [84902.227963] client systemd[1]: Starting Extra networking commands....204agent # [84902.155307] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.205client # [84902.233886] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...206agent # [84902.220873] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.207agent # [84902.221943] agent systemd[1]: Finished Save Transient machine-id to Disk.208agent # [84902.222142] agent systemd[1]: nscd.service: Deactivated successfully.209agent # [84902.222356] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).210agent # [84902.224183] agent systemd[1]: Finished resolvconf update.211agent # [84902.226385] agent systemd[1]: Reached target Preparation for Network.212agent # [84902.227226] agent systemd[1]: Starting Address configuration of eth1...213agent # [84902.227922] agent systemd[1]: Starting Extra networking commands....214agent # [84902.233888] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...215client # [84902.283820] client network-addresses-eth1-start[236]: adding address 192.168.1.2/24... done216client # [84902.287112] client network-addresses-eth1-start[236]: adding address 2001:db8:1::2/64... done217client # [84902.290643] client systemd[1]: Finished Address configuration of eth1.218client # [84902.330937] client systemd[1]: Finished Extra networking commands..219client # [84902.331092] client systemd[1]: Reached target Network.220client # [84902.404299] client systemd[1]: nscd.service: Deactivated successfully.221client # [84902.404490] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).222client # [84902.407278] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...223agent # [84902.286355] agent network-addresses-eth1-start[240]: adding address 192.168.1.1/24... done224agent # [84902.289375] agent network-addresses-eth1-start[240]: adding address 2001:db8:1::1/64... done225agent # [84902.294525] agent systemd[1]: Finished Address configuration of eth1.226agent # [84902.336643] agent systemd[1]: Finished Extra networking commands..227agent # [84902.337353] agent systemd[1]: Reached target Network.228agent # [84902.338585] agent systemd[1]: Starting flakelet-agent...229agent # [84902.339253] agent systemd[1]: Starting Update flakelet service app...230agent # [84902.339944] agent systemd[1]: Starting Update flakelet service other...231agent # [84902.374631] agent systemd[1]: nscd.service: Deactivated successfully.232agent # [84902.386384] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).233agent # [84902.390551] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...234agent # [84902.400292] agent flakelet[306]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1235agent # [84902.401166] agent flakelet[306]: other: activating generation 1236agent # [84902.401303] agent flakelet[305]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1237agent # [84902.402021] agent flakelet[305]: app: activating generation 1238agent # [84902.409368] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-other.service)...239agent # [84902.409461] agent systemd[1]: Reloading...240agent # [84902.449106] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:23.578226Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}241relay # [84902.227301] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.242relay # [84902.228357] relay systemd[1]: Finished Save Transient machine-id to Disk.243relay # [84902.229012] relay systemd[1]: nscd.service: Deactivated successfully.244relay # [84902.233919] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).245relay # [84902.235598] relay systemd[1]: Finished Address configuration of eth1.246relay # [84902.266677] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...247relay # [84902.266930] relay systemd[1]: Finished Extra networking commands..248relay # [84902.267848] relay systemd[1]: Reached target Network.249relay # [84902.269142] relay systemd[1]: Starting Dnsmasq Daemon...250relay # [84902.270157] relay systemd[1]: Starting Nginx Web Server...251relay # [84902.271043] relay systemd[1]: Starting Update flakelet service flakelet-relay...252relay # [84902.282852] relay flakelet[310]: flakelet-relay: using prebuilt artifact /nix/store/7zwd9c7nvf99s9x33v3aakwppzscxpbq-flakelet-flakelet-relay253relay # [84902.283579] relay flakelet[310]: flakelet-relay: activating generation 1254relay # [84902.287514] relay systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-flakelet-relay.service)...255relay # [84902.287563] relay systemd[1]: Reloading...256relay # [84902.720396] relay nsncd[298]: Sep 06 06:14:23.849 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"257relay # [84902.811931] relay systemd[1]: Reloading finished in 523 ms.258relay # [84902.948058] relay systemd[1]: Started Name Service Cache Daemon (nsncd).259relay # [84902.950456] relay systemd[1]: Reached target Host and Network Name Lookups.260relay # [84902.950674] relay systemd[1]: Reached target User and Group Name Lookups.261relay # [84902.953397] relay systemd[1]: Starting User Login Management...262relay # [84902.954213] relay systemd[1]: Starting Permit User Sessions...263relay # [84902.967861] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...264relay # [84902.967948] relay systemd[1]: Reloading...265client # [84902.684079] client nsncd[303]: Sep 06 06:14:23.813 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"266client # [84902.684043] client systemd[1]: Started Name Service Cache Daemon (nsncd).267client # [84902.684126] client systemd[1]: Reached target Host and Network Name Lookups.268client # [84902.684185] client systemd[1]: Reached target User and Group Name Lookups.269client # [84902.686019] client systemd[1]: Starting User Login Management...270client # [84902.686900] client systemd[1]: Starting Permit User Sessions...271client # [84902.720484] client systemd[1]: Finished Permit User Sessions.272client # [84902.722013] client systemd[1]: Started Console Getty.273client # [84902.722043] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0274client # [84902.722060] client systemd[1]: Reached target Login Prompts.275agent # [84902.712337] agent nsncd[311]: Sep 06 06:14:23.841 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"276agent # [84902.818296] agent systemd[1]: Reloading finished in 407 ms.277agent # [84902.952072] agent systemd[1]: Started flakelet-agent.278agent # [84902.952233] agent systemd[1]: Started Name Service Cache Daemon (nsncd).279agent # [84902.953895] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-app.service)...280agent # [84902.953947] agent systemd[1]: Reloading...281relay # [84902.972095] relay dnsmasq-pre-start[360]: dnsmasq: syntax check OK.282relay # [84903.347541] relay systemd[1]: Reloading finished in 378 ms.283agent # [84903.352784] agent systemd[1]: Reloading finished in 398 ms.284agent # [84903.529252] agent systemd[1]: Reached target Host and Network Name Lookups.285agent # [84903.529367] agent systemd[1]: Reached target User and Group Name Lookups.286agent # [84903.530835] agent systemd[1]: Starting User Login Management...287agent # [84903.531910] agent systemd[1]: Starting Permit User Sessions...288agent # [84903.540986] agent systemd[1]: Reload requested from client PID 764 ('systemctl') (unit flakelet-other.service)...289agent # [84903.541088] agent systemd[1]: Reloading...290relay # [84903.528703] relay systemd[1]: Finished Permit User Sessions.291relay # [84903.537690] relay systemd[1]: Started Console Getty.292relay # [84903.537809] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0293relay # [84903.537941] relay systemd[1]: Reached target Login Prompts.294relay # [84903.540571] relay systemd[1]: Starting flakelet-relay...295agent # [84903.929112] agent systemd[1]: Reloading finished in 387 ms.296agent # [84903.997466] agent systemd[1]: Finished Permit User Sessions.297agent # [84904.001989] agent systemd[1]: Started Console Getty.298agent # [84904.002107] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0299agent # [84904.002249] agent systemd[1]: Reached target Login Prompts.300agent # [84904.002611] agent systemd[1]: Reload requested from client PID 767 ('systemctl') (unit flakelet-app.service)...301agent # [84904.002639] agent systemd[1]: Reloading...302relay # [84904.041258] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok303relay # [84904.041940] relay nginx-pre-start[402]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful304relay # [84904.056658] relay systemd[1]: Started Nginx Web Server.305relay # [84904.217663] relay systemd[1]: Starting D-Bus System Message Bus...306client # [84904.182866] client systemd-logind[315]: New seat seat0.307client # [84904.183222] client systemd[1]: Started User Login Management.308client # [84904.184804] client systemd[1]: Starting D-Bus System Message Bus...309client # [84904.193291] client systemd[1]: Starting linger-users.service...310client # [84904.227518] client systemd[1]: linger-users.service: Deactivated successfully.311client # [84904.227814] client systemd[1]: Finished linger-users.service.312client # [84904.228039] client systemd[1]: Reached target Multi-User System.313agent # [84904.409122] agent systemd[1]: Reloading finished in 406 ms.314agent # [84904.487084] agent systemd[1]: Starting other v1...315agent # [84904.521360] agent systemd[1]: Starting app v1...316agent # [84904.525247] agent systemd[1]: Started other v1.317agent # [84904.531580] agent systemd[1]: Started app v1.318agent # [84904.554734] agent flakelet[306]: other: updated to generation 1319agent # [84904.555780] agent systemd[1]: Finished Update flakelet service other.320agent # [84904.559697] agent flakelet[305]: app: updated to generation 1321agent # [84904.561264] agent systemd[1]: Finished Update flakelet service app.322agent # [84904.561403] agent systemd[1]: Reached target flakelet managed services.323relay # [84904.514957] relay systemd-logind[354]: New seat seat0.324relay # [84904.515210] relay systemd[1]: Started User Login Management.325relay # [84904.521537] relay systemd[1]: Starting linger-users.service...326relay # [84904.534674] relay systemd[1]: linger-users.service: Deactivated successfully.327relay # [84904.534943] relay systemd[1]: Finished linger-users.service.328relay # [84904.745565] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...329relay # [84904.746680] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'330relay # [84904.746680] 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"331relay # [84904.747560] relay systemd[1]: Started D-Bus System Message Bus.332relay # [84904.757620] relay dbus-broker-launch[408]: Ready333relay # [84904.761789] relay systemd[1]: Started Dnsmasq Daemon.334relay # [84904.763723] relay dnsmasq[395]: started, version 2.93 cachesize 150335relay # [84904.763731] relay dnsmasq[395]: 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 dumpfile336relay # [84904.763736] relay dnsmasq[395]: DBus support enabled: connected to system bus337relay # [84904.763744] relay dnsmasq[395]: no upstream servers configured - please set them from DBus338relay # [84904.763829] relay dnsmasq[395]: read /etc/hosts - 9 names339client # [84904.763765] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...340client # [84904.765057] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'341client # [84904.765057] client dbus-broker-launch[325]: Invalid user-name in /nix/store/bja873g16bkdjc9pijmr630xwdjl32m3-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"342client # [84904.766271] client systemd[1]: Started D-Bus System Message Bus.343client # [84904.766783] client systemd[1]: Startup finished in 4.258s.344client # [84904.772207] client dbus-broker-launch[325]: Ready345agent # [84905.032411] agent systemd-logind[765]: New seat seat0.346agent # [84905.032888] agent systemd[1]: Started User Login Management.347agent # [84905.034447] agent systemd[1]: Starting D-Bus System Message Bus...348agent # [84905.035538] agent systemd[1]: Starting linger-users.service...349agent # [84905.078140] agent systemd[1]: linger-users.service: Deactivated successfully.350agent # [84905.078584] agent systemd[1]: Finished linger-users.service.351agent # [84905.079978] agent systemd[1]: Reached target Multi-User System.352relay # [84905.575521] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:26.704654Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}353relay # [84905.576149] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:26.705138Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}354relay # [84905.576078] relay systemd[1]: Started flakelet-relay.355relay # [84905.594666] relay systemd[1]: Starting health for flakelet-relay...356relay # [84905.826519] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.357agent # [84905.456809] agent dbus-broker-launch[841]: Looking up NSS user entry for 'systemd-timesync'...358agent # [84905.458515] agent dbus-broker-launch[841]: NSS returned no entry for 'systemd-timesync'359agent # [84905.458515] agent dbus-broker-launch[841]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"360agent # [84905.459262] agent systemd[1]: Started D-Bus System Message Bus.361agent # [84905.459834] agent systemd[1]: Startup finished in 4.949s.362agent # [84905.464541] agent dbus-broker-launch[841]: Ready363relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)364relay: waiting for unit nginx.service365relay: (finished: waiting for unit nginx.service, in 0.01 seconds)366agent: waiting for unit flakelet.target367agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)368agent: waiting for unit flakelet-agent.service369agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)370client: waiting for unit multi-user.target371client: (finished: waiting for unit multi-user.target, in 0.01 seconds)372relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'373relay # [84905.827129] relay systemd[1]: Finished health for flakelet-relay.374relay # [84905.875140] relay flakelet[310]: flakelet-relay: updated to generation 1375relay # [84905.876250] relay systemd[1]: Finished Update flakelet service flakelet-relay.376relay # [84905.878209] relay systemd[1]: Reached target flakelet managed services.377relay # [84905.878571] relay systemd[1]: Reached target Multi-User System.378relay # [84905.878876] relay systemd[1]: Startup finished in 5.370s.379agent # [84907.558538] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:28.687684Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}380relay # [84907.558796] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:28.687968Z","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>&1388agent # [84908.284278] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:29.413504Z","level":"INFO","message":"start","id":"dd05e7f5f3c9b9817dd220b61bba6d04","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}389agent # [84908.285090] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:29.414362Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dd05e7f5f3c9b9817dd220b61bba6d04\"]","target":"flakelet_relay::agent::jobs"}390agent # [84908.341448] agent systemd[1]: Starting flakelet update app (via relay)...391agent # [84908.373774] agent systemd[1]: Started flakelet update app (via relay).392agent # [84908.379608] agent flakelet[870]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2393agent # [84908.380290] agent flakelet[870]: app: activating generation 2394agent # [84908.394238] agent systemd[1]: Stopping app v1...395agent # [84908.394760] agent systemd[1]: app.service: Deactivated successfully.396agent # [84908.395137] agent systemd[1]: Stopped app v1.397agent # [84908.415097] agent systemd[1]: Reload requested from client PID 877 ('systemctl') (unit flakelet-relay-job-app.service)...398agent # [84908.415189] agent systemd[1]: Reloading...399relay # [84908.283337] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:29.412557Z","level":"INFO","message":"deploy accepted","job":"7f630172135f1077f4a87a31e7dfb9d9","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}400agent # [84908.777258] agent systemd[1]: Reloading finished in 361 ms.401agent # [84908.860331] agent systemd[1]: Reload requested from client PID 907 ('systemctl') (unit flakelet-relay-job-app.service)...402agent # [84908.860380] agent systemd[1]: Reloading...403agent # [84909.203307] agent systemd[1]: Reloading finished in 342 ms.404agent # [84909.286851] agent systemd[1]: Reload requested from client PID 936 ('systemctl') (unit flakelet-relay-job-app.service)...405agent # [84909.286893] agent systemd[1]: Reloading...406agent # [84909.642521] agent systemd[1]: Reloading finished in 355 ms.407agent # [84909.727686] agent systemd[1]: Reload requested from client PID 967 ('systemctl') (unit flakelet-relay-job-app.service)...408agent # [84909.727774] agent systemd[1]: Reloading...409agent # [84910.072244] agent systemd[1]: Reloading finished in 343 ms.410agent # [84910.158246] agent systemd[1]: Starting app v2...411agent # [84910.199686] agent systemd[1]: Started app v2.412agent # [84910.221633] agent flakelet[870]: app: updated to generation 2413agent # [84910.224967] 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 3.02 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.01 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.06 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MjcyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTSUxFNllPN1A0VlBTPT09IiwibmJmIjoxNzg4Njc1MjcyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HQuGntogsht3ERYbnBfLpdawDAKI5Bx7OiIn1ar3dHvgnYHILW_b5E9oz55vpuk2YVIcA5xurXIyqnkZSjQWDw' push --relay https://relay:7443 deploy agent/app 2>&1426agent # [84911.280814] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:32.410030Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}427agent # [84911.410247] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:32.539439Z","level":"INFO","message":"start","id":"f600d91a22cf57f15cb4e5781b592650","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}428agent # [84911.410771] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:32.540065Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"f600d91a22cf57f15cb4e5781b592650\"]","target":"flakelet_relay::agent::jobs"}429agent # [84911.468051] agent systemd[1]: Starting flakelet update app (via relay)...430agent # [84911.504525] agent systemd[1]: Started flakelet update app (via relay).431agent # [84911.508834] agent flakelet[1025]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1432agent # [84911.509560] agent flakelet[1025]: app: activating generation 3433agent # [84911.527012] agent systemd[1]: Stopping app v2...434agent # [84911.527289] agent systemd[1]: app.service: Deactivated successfully.435agent # [84911.527496] agent systemd[1]: Stopped app v2.436agent # [84911.542319] agent systemd[1]: Reload requested from client PID 1032 ('systemctl') (unit flakelet-relay-job-app.service)...437agent # [84911.542409] agent systemd[1]: Reloading...438relay # [84911.281835] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:32.411036Z","level":"INFO","message":"deploy finished","job":"7f630172135f1077f4a87a31e7dfb9d9","ok":true,"target":"flakelet_relay::relay::api"}439relay # [84911.409697] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:32.538953Z","level":"INFO","message":"deploy accepted","job":"79a6eb067ad5df00df61f597ee17baba","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}440agent # [84911.902999] agent systemd[1]: Reloading finished in 359 ms.441agent # [84911.987962] agent systemd[1]: Reload requested from client PID 1062 ('systemctl') (unit flakelet-relay-job-app.service)...442agent # [84911.988033] agent systemd[1]: Reloading...443agent # [84912.331060] agent systemd[1]: Reloading finished in 342 ms.444agent # [84912.423041] agent systemd[1]: Reload requested from client PID 1091 ('systemctl') (unit flakelet-relay-job-app.service)...445agent # [84912.423100] agent systemd[1]: Reloading...446agent # [84912.764568] agent systemd[1]: Reloading finished in 340 ms.447agent # [84912.854114] agent systemd[1]: Reload requested from client PID 1122 ('systemctl') (unit flakelet-relay-job-app.service)...448agent # [84912.854165] agent systemd[1]: Reloading...449agent # [84913.202480] agent systemd[1]: Reloading finished in 347 ms.450agent # [84913.290951] agent systemd[1]: Starting app v1...451agent # [84913.325353] agent systemd[1]: Started app v1.452agent # [84913.351161] agent flakelet[1025]: app: updated to generation 3453agent # [84913.354581] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.454client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MjcyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTSUxFNllPN1A0VlBTPT09IiwibmJmIjoxNzg4Njc1MjcyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HQuGntogsht3ERYbnBfLpdawDAKI5Bx7OiIn1ar3dHvgnYHILW_b5E9oz55vpuk2YVIcA5xurXIyqnkZSjQWDw' push --relay https://relay:7443 deploy agent/app 2>&1, in 3.04 seconds)455(finished: subtest: deploy with OIDC token, sub principal, in 3.11 seconds)456subtest: policy denies uncovered target457client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MjcyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTSUxFNllPN1A0VlBTPT09IiwibmJmIjoxNzg4Njc1MjcyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HQuGntogsht3ERYbnBfLpdawDAKI5Bx7OiIn1ar3dHvgnYHILW_b5E9oz55vpuk2YVIcA5xurXIyqnkZSjQWDw' push --relay https://relay:7443 deploy agent/other 2>&1458client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MjcyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTSUxFNllPN1A0VlBTPT09IiwibmJmIjoxNzg4Njc1MjcyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HQuGntogsht3ERYbnBfLpdawDAKI5Bx7OiIn1ar3dHvgnYHILW_b5E9oz55vpuk2YVIcA5xurXIyqnkZSjQWDw' 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3NSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY3NTI3NSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMzNIVENLRk5LVk5CMj09PSIsIm5iZiI6MTc4ODY3NTI3NSwic3ViIjoic29tZW9uZSJ9.XdcDm7E1XcvU6CnM0p2QN7ka7a67eiNkwDRcs5HJ4GTnccSYMeNWudMD-F7iq5mPIWffpHWXyXtSpm6yI99XCA' push --relay https://relay:7443 deploy agent/other 2>&1464relay # [84914.415425] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:35.544639Z","level":"INFO","message":"deploy finished","job":"79a6eb067ad5df00df61f597ee17baba","ok":true,"target":"flakelet_relay::relay::api"}465relay # [84914.509882] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:35.639095Z","level":"INFO","message":"deploy accepted","job":"1e20c51c4f0451f1c80a79960289ba28","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}466agent # [84914.414552] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:35.543764Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}467agent # [84914.510320] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:35.639522Z","level":"INFO","message":"start","id":"116f713ffd806c1abf7467b4e7bca3b5","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}468agent # [84914.510701] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:35.639953Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"116f713ffd806c1abf7467b4e7bca3b5\"]","target":"flakelet_relay::agent::jobs"}469agent # [84914.569385] agent systemd[1]: Starting flakelet update other (via relay)...470agent # [84914.618407] agent systemd[1]: Started flakelet update other (via relay).471agent # [84914.623511] agent flakelet[1171]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1472agent # [84914.624365] agent flakelet[1171]: other: up to date473agent # [84914.626855] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.474client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU3NSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY3NTI3NSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMzNIVENLRk5LVk5CMj09PSIsIm5iZiI6MTc4ODY3NTI3NSwic3ViIjoic29tZW9uZSJ9.XdcDm7E1XcvU6CnM0p2QN7ka7a67eiNkwDRcs5HJ4GTnccSYMeNWudMD-F7iq5mPIWffpHWXyXtSpm6yI99XCA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.69 seconds)475(finished: subtest: claim principal from groups, unchanged counts as success, in 0.74 seconds)476subtest: push login via device flow, cached token used afterwards477client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1478relay # [84915.174959] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:36.304215Z","level":"INFO","message":"deploy finished","job":"1e20c51c4f0451f1c80a79960289ba28","ok":true,"target":"flakelet_relay::relay::api"}479relay # [84915.200262] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 06:14:36] "POST /device HTTP/1.1" 200 -480agent # [84915.174276] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:36.303492Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}481relay # [84916.205627] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 06:14:37] "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>&1486agent # [84917.278727] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:38.407937Z","level":"INFO","message":"start","id":"14457d368d0786df7ad554cb3c34c093","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}487agent # [84917.279711] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:38.408518Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"14457d368d0786df7ad554cb3c34c093\"]","target":"flakelet_relay::agent::jobs"}488agent # [84917.312882] agent systemd[1]: Starting flakelet update other (via relay)...489agent # [84917.346950] agent systemd[1]: Started flakelet update other (via relay).490agent # [84917.352427] agent flakelet[1189]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1491agent # [84917.352971] agent flakelet[1189]: other: up to date492agent # [84917.355240] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.493relay # [84917.251357] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 06:14:38] "POST /token HTTP/1.1" 200 -494relay # [84917.278263] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:38.407520Z","level":"INFO","message":"deploy accepted","job":"25218d3e6135daf23480ff25eb424e8b","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}495client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)496client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1497relay # [84917.900836] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:39.030092Z","level":"INFO","message":"deploy finished","job":"25218d3e6135daf23480ff25eb424e8b","ok":true,"target":"flakelet_relay::relay::api"}498relay # [84917.919255] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:39.048499Z","level":"INFO","message":"deploy accepted","job":"822444a1b1309653e979b866219cdf34","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}499agent # [84917.900304] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.029552Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}500agent # [84917.919548] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.048786Z","level":"INFO","message":"start","id":"625552199fde351965a3f3909508eea7","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}501agent # [84917.919970] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.049261Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"625552199fde351965a3f3909508eea7\"]","target":"flakelet_relay::agent::jobs"}502agent # [84917.965525] agent systemd[1]: Starting flakelet update other (via relay)...503agent # [84918.001750] agent systemd[1]: Started flakelet update other (via relay).504agent # [84918.006574] agent flakelet[1207]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1505agent # [84918.007476] agent flakelet[1207]: other: up to date506agent # [84918.010683] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.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.40 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 # [84918.569978] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.699182Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}514agent # [84918.606817] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.736094Z","level":"INFO","message":"start","id":"1f0c84abfe046ab751b69914e8ef2ec0","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}515agent # [84918.607065] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:39.736361Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"1f0c84abfe046ab751b69914e8ef2ec0\"]","target":"flakelet_relay::agent::jobs"}516agent # [84918.660825] agent systemd[1]: Starting flakelet update app (via relay)...517agent # [84918.693881] agent systemd[1]: Started flakelet update app (via relay).518agent # [84918.698415] agent flakelet[1228]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken519agent # [84918.699109] agent flakelet[1228]: app: activating generation 4520agent # [84918.713270] agent systemd[1]: Stopping app v1...521agent # [84918.713779] agent systemd[1]: app.service: Deactivated successfully.522agent # [84918.714159] agent systemd[1]: Stopped app v1.523agent # [84918.731901] agent systemd[1]: Reload requested from client PID 1235 ('systemctl') (unit flakelet-relay-job-app.service)...524agent # [84918.731986] agent systemd[1]: Reloading...525relay # [84918.570925] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:39.700142Z","level":"INFO","message":"deploy finished","job":"822444a1b1309653e979b866219cdf34","ok":true,"target":"flakelet_relay::relay::api"}526relay # [84918.606601] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:39.735861Z","level":"INFO","message":"deploy accepted","job":"233d11327806c6ba4302b8da0bf6b8a9","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}527agent # [84919.080377] agent systemd[1]: Reloading finished in 347 ms.528agent # [84919.168878] agent systemd[1]: Reload requested from client PID 1265 ('systemctl') (unit flakelet-relay-job-app.service)...529agent # [84919.168936] agent systemd[1]: Reloading...530agent # [84919.506261] agent systemd[1]: Reloading finished in 336 ms.531agent # [84919.592834] agent systemd[1]: Reload requested from client PID 1294 ('systemctl') (unit flakelet-relay-job-app.service)...532agent # [84919.592933] agent systemd[1]: Reloading...533agent # [84919.931432] agent systemd[1]: Reloading finished in 337 ms.534agent # [84920.020634] agent systemd[1]: Reload requested from client PID 1325 ('systemctl') (unit flakelet-relay-job-app.service)...535agent # [84920.020686] agent systemd[1]: Reloading...536agent # [84920.361111] agent systemd[1]: Reloading finished in 340 ms.537agent # [84920.445405] agent systemd[1]: Starting app broken...538agent # [84920.477538] agent (nonexistent)[1355]: app.service: Unable to locate executable '/nonexistent': No such file or directory539agent # [84920.477564] agent (nonexistent)[1355]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory540agent # [84920.478401] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC541agent # [84920.478655] agent systemd[1]: app.service: Failed with result 'exit-code'.542agent # [84920.479271] agent systemd[1]: Failed to start app broken.543agent # [84920.519415] agent systemd[1]: Reload requested from client PID 1362 ('systemctl') (unit flakelet-relay-job-app.service)...544agent # [84920.519474] agent systemd[1]: Reloading...545agent # [84920.860217] agent systemd[1]: Reloading finished in 340 ms.546agent # [84920.948253] agent systemd[1]: Reload requested from client PID 1392 ('systemctl') (unit flakelet-relay-job-app.service)...547agent # [84920.948309] agent systemd[1]: Reloading...548agent # [84921.286823] agent systemd[1]: Reloading finished in 338 ms.549agent # [84921.373421] agent systemd[1]: Reload requested from client PID 1422 ('systemctl') (unit flakelet-relay-job-app.service)...550agent # [84921.373521] agent systemd[1]: Reloading...551agent # [84921.715943] agent systemd[1]: Reloading finished in 341 ms.552agent # [84921.793023] agent systemd[1]: Reload requested from client PID 1452 ('systemctl') (unit flakelet-relay-job-app.service)...553agent # [84921.793065] agent systemd[1]: Reloading...554agent # [84922.128917] agent systemd[1]: Reloading finished in 335 ms.555agent # [84922.216705] agent systemd[1]: Starting app v1...556agent # [84922.246083] agent systemd[1]: Started app v1.557agent # [84922.246853] agent flakelet[1228]: app: deploy failed, rolled back: systemctl start app.service failed:558agent # [84922.246853] agent flakelet[1228]: failed units: app.service. See journalctl -u app.service559agent # [84922.248970] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE560agent # [84922.249090] 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.36 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.01 seconds)564(finished: subtest: waves: failing first wave skips the second, in 4.38 seconds)565subtest: detach returns once the job is accepted566agent: 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.json567agent: (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)568client: 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>&1569client: (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)570agent: waiting for success: systemctl is-active flakelet-relay-job-app.service571relay # [84922.940893] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:44.070074Z","level":"INFO","message":"deploy finished","job":"233d11327806c6ba4302b8da0bf6b8a9","ok":false,"target":"flakelet_relay::relay::api"}572relay # [84922.989791] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:44.119062Z","level":"INFO","message":"deploy accepted","job":"f0ef0f172dadfeb757f8028afc7ad84d","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}573agent # [84922.940012] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:44.069199Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}574agent # [84922.990053] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:44.119251Z","level":"INFO","message":"start","id":"24727bc93796d2bbe431b12b80c8febe","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}575agent # [84922.990259] agent flakelet-agent[304]: {"timestamp":"2026-09-06T06:14:44.119559Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"24727bc93796d2bbe431b12b80c8febe\"]","target":"flakelet_relay::agent::jobs"}576agent # [84923.043345] agent systemd[1]: Starting flakelet update app (via relay)...577agent # [84923.074349] agent systemd[1]: Started flakelet update app (via relay).578agent # [84923.079249] agent flakelet[1507]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2579agent # [84923.079893] agent flakelet[1507]: app: activating generation 4580agent # [84923.095029] agent systemd[1]: Stopping app v1...581agent # [84923.095541] agent systemd[1]: app.service: Deactivated successfully.582agent # [84923.095899] agent systemd[1]: Stopped app v1.583agent # [84923.112627] agent systemd[1]: Reload requested from client PID 1514 ('systemctl') (unit flakelet-relay-job-app.service)...584agent # [84923.112670] agent systemd[1]: Reloading...585agent # [84923.454122] agent systemd[1]: Reloading finished in 341 ms.586agent # [84923.542375] agent systemd[1]: Reload requested from client PID 1544 ('systemctl') (unit flakelet-relay-job-app.service)...587agent # [84923.542447] agent systemd[1]: Reloading...588agent # [84923.880717] agent systemd[1]: Reloading finished in 337 ms.589agent # [84923.972201] agent systemd[1]: Reload requested from client PID 1573 ('systemctl') (unit flakelet-relay-job-app.service)...590agent # [84923.972259] agent systemd[1]: Reloading...591agent # [84924.313348] agent systemd[1]: Reloading finished in 340 ms.592agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.40 seconds)593??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.594 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39595agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service596??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.597 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39598agent # [84924.394553] agent systemd[1]: Reload requested from client PID 1605 ('systemctl') (unit flakelet-relay-job-app.service)...599agent # [84924.394605] agent systemd[1]: Reloading...600agent # [84924.732794] agent systemd[1]: Reloading finished in 337 ms.601agent # [84924.824093] agent systemd[1]: Starting app slow2...602agent # [84930.912763] agent systemd[1]: Started app slow2.603agent # [84930.936839] agent flakelet[1507]: app: updated to generation 4604agent # [84930.940166] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.605agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.52 seconds)606(finished: subtest: detach returns once the job is accepted, in 8.95 seconds)607subtest: unknown host is final, missing agent is retried, agents listing608client: 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>&1609client: (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)610agent: must succeed: systemctl stop flakelet-agent611agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.03 seconds)612relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'613relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)614client: 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 &615client: (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)616client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out617relay # [84931.937088] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:53.066355Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}618agent # [84931.937201] agent systemd[1]: Stopping flakelet-agent...619agent # [84931.957139] agent systemd[1]: flakelet-agent.service: Deactivated successfully.620agent # [84931.957804] agent systemd[1]: Stopped flakelet-agent.621client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)622agent: must succeed: systemctl start flakelet-agent623agent: (finished: must succeed: systemctl start flakelet-agent, in 0.07 seconds)624??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.625 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39626client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out627agent # [84933.016695] agent systemd[1]: Starting flakelet-agent...628agent # [84933.071795] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:54.201056Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"24727bc93796d2bbe431b12b80c8febe\"]","target":"flakelet_relay::agent::jobs"}629agent # [84933.071972] agent systemd[1]: Started flakelet-agent.630agent # [84933.170393] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:54.299626Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}631relay # [84933.170461] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:54.299689Z","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"}632agent # [84933.633488] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:54.762710Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}633agent # [84935.005305] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:56.134515Z","level":"INFO","message":"start","id":"341a24f36eee22891cac419dfdd39181","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}634agent # [84935.006270] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:56.135113Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"341a24f36eee22891cac419dfdd39181\"]","target":"flakelet_relay::agent::jobs"}635agent # [84935.065062] agent systemd[1]: Starting flakelet update other (via relay)...636agent # [84935.100420] agent systemd[1]: Started flakelet update other (via relay).637agent # [84935.105940] agent flakelet[2073]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1638agent # [84935.106766] agent flakelet[2073]: other: up to date639agent # [84935.109037] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.640relay # [84935.005034] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:56.134248Z","level":"INFO","message":"deploy accepted","job":"37114be9c0062fbf49e54771d81fad12","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}641relay # [84935.660993] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:56.790264Z","level":"INFO","message":"deploy finished","job":"37114be9c0062fbf49e54771d81fad12","ok":true,"target":"flakelet_relay::relay::api"}642client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.05 seconds)643client: 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 agents644agent # [84935.660276] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:56.789527Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}645client: (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)646client: 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)647client: (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)648client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU5NywiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1Mjk3LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJBREJLVE03S0tLUFlNPT09IiwibmJmIjoxNzg4Njc1Mjk3LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.zlGRHorh3UEfTilEPwHEbrVQVf__7AxnM_oH1QEKJ8Wq3-DbPQNsbeyynoj-qQemCL0NjJIb6drtxNzUOaSWCg' push --relay https://relay:7443 agents649client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTU5NywiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1Mjk3LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJBREJLVE03S0tLUFlNPT09IiwibmJmIjoxNzg4Njc1Mjk3LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.zlGRHorh3UEfTilEPwHEbrVQVf__7AxnM_oH1QEKJ8Wq3-DbPQNsbeyynoj-qQemCL0NjJIb6drtxNzUOaSWCg' push --relay https://relay:7443 agents, in 0.02 seconds)650(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.30 seconds)651subtest: certificate not listed under agents cannot connect as agent652client: 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/agent653client: (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)654(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.02 seconds)655subtest: metrics656relay: must succeed: curl -sf http://127.0.0.1:7400/metrics657relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.02 seconds)658(finished: subtest: metrics, in 0.02 seconds)659subtest: agent link drop mid-run replays missed lines once660agent: 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.json661agent: (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)662agent: must succeed: date +%s663agent: (finished: must succeed: date +%s, in 0.01 seconds)664client: 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 &665client: (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)666agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675297 | grep -q 'app-slow'667agent # [84936.286568] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:57.415808Z","level":"INFO","message":"start","id":"7a94d5587e6f543e3c1b2fcac4d90fd6","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}668agent # [84936.287157] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:57.416394Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"7a94d5587e6f543e3c1b2fcac4d90fd6\"]","target":"flakelet_relay::agent::jobs"}669agent # [84936.349979] agent systemd[1]: Starting flakelet update app (via relay)...670agent # [84936.384082] agent systemd[1]: Started flakelet update app (via relay).671agent # [84936.389545] agent flakelet[2098]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow672agent # [84936.390286] agent flakelet[2098]: app: activating generation 5673agent # [84936.406632] agent systemd[1]: Stopping app slow2...674agent # [84936.407185] agent systemd[1]: app.service: Deactivated successfully.675agent # [84936.407576] agent systemd[1]: Stopped app slow2.676agent # [84936.430502] agent systemd[1]: Reload requested from client PID 2105 ('systemctl') (unit flakelet-relay-job-app.service)...677agent # [84936.430596] agent systemd[1]: Reloading...678relay # [84936.226326] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:57.355592Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}679relay # [84936.286179] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:57.415393Z","level":"INFO","message":"deploy accepted","job":"1ec5f3b6d0fcfa69c747402c5d67d6e5","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}680agent # [84936.811995] agent systemd[1]: Reloading finished in 380 ms.681agent # [84936.901052] agent systemd[1]: Reload requested from client PID 2135 ('systemctl') (unit flakelet-relay-job-app.service)...682agent # [84936.901100] agent systemd[1]: Reloading...683agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675297 | grep -q 'app-slow', in 1.02 seconds)684agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done685agent: (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)686relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done687relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)688agent: must succeed: ss -K dport = 7443689agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)690agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675297 | grep -q 'updated to generation'691agent # [84937.268833] agent systemd[1]: Reloading finished in 367 ms.692agent # [84937.351574] agent systemd[1]: Reload requested from client PID 2174 ('systemctl') (unit flakelet-relay-job-app.service)...693agent # [84937.351620] agent systemd[1]: Reloading...694agent # [84937.397141] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:58.526394Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}695relay # [84937.366564] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:14:58.495771Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}696agent # [84937.697606] agent systemd[1]: Reloading finished in 345 ms.697agent # [84937.787986] agent systemd[1]: Reload requested from client PID 2209 ('systemctl') (unit flakelet-relay-job-app.service)...698agent # [84937.788037] agent systemd[1]: Reloading...699agent # [84938.131774] agent systemd[1]: Reloading finished in 343 ms.700agent # [84938.224466] agent systemd[1]: Starting app slow...701agent # [84938.490272] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:14:59.619430Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}702agent # [84940.568161] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:01.697416Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}703agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675297 | grep -q 'updated to generation', in 7.09 seconds)704agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done705agent: (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)706client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out707agent # [84944.295555] agent systemd[1]: Started app slow.708agent # [84944.311975] agent flakelet[2098]: app: updated to generation 5709agent # [84944.312934] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.710relay # [84944.654166] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:05.783403Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}711agent # [84944.654102] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:05.783339Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}712agent # [84944.655290] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:05.784583Z","level":"INFO","message":"start","id":"7a94d5587e6f543e3c1b2fcac4d90fd6","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}713client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 1.02 seconds)714client: must succeed: cat /tmp/slow.out715client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)716(finished: subtest: agent link drop mid-run replays missed lines once, in 9.29 seconds)717subtest: agent restart mid-run reattaches to the unit718agent: 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.json719agent: (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)720client: 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 &721client: (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)722agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'723agent # [84945.386387] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:06.515602Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(5)","target":"flakelet_relay::agent::jobs"}724agent # [84945.570399] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:06.699611Z","level":"INFO","message":"start","id":"9d04c88ad4f512fa4f82c5100d18fc16","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}725agent # [84945.570977] agent flakelet-agent[1660]: {"timestamp":"2026-09-06T06:15:06.700246Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"9d04c88ad4f512fa4f82c5100d18fc16\"]","target":"flakelet_relay::agent::jobs"}726agent # [84945.633762] agent systemd[1]: Starting flakelet update app (via relay)...727relay # [84945.387136] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:06.516378Z","level":"INFO","message":"deploy finished","job":"1ec5f3b6d0fcfa69c747402c5d67d6e5","ok":true,"target":"flakelet_relay::relay::api"}728relay # [84945.569938] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:06.699197Z","level":"INFO","message":"deploy accepted","job":"9c34d306b5e457f2f406e05a8fbb7e1f","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}729agent # [84945.641578] agent systemd[1]: Started flakelet update app (via relay).730agent # [84945.645323] agent flakelet[2330]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2731agent # [84945.646246] agent flakelet[2330]: app: activating generation 6732agent # [84945.660062] agent systemd[1]: Stopping app slow...733agent # [84945.661805] agent systemd[1]: app.service: Deactivated successfully.734agent # [84945.662226] agent systemd[1]: Stopped app slow.735agent # [84945.673782] agent systemd[1]: Reload requested from client PID 2337 ('systemctl') (unit flakelet-relay-job-app.service)...736agent # [84945.673823] agent systemd[1]: Reloading...737agent # [84946.064258] agent systemd[1]: Reloading finished in 390 ms.738agent # [84946.162236] agent systemd[1]: Reload requested from client PID 2367 ('systemctl') (unit flakelet-relay-job-app.service)...739agent # [84946.162337] agent systemd[1]: Reloading...740agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)741agent: must succeed: systemctl restart flakelet-agent742agent # [84946.664344] agent systemd[1]: Reloading finished in 501 ms.743agent # [84946.764537] agent systemd[1]: Reload requested from client PID 2401 ('systemctl') (unit flakelet-relay-job-app.service)...744agent # [84946.764585] agent systemd[1]: Reloading...745agent # [84947.148375] agent systemd[1]: Reloading finished in 383 ms.746agent # [84947.238071] agent systemd[1]: Stopping flakelet-agent...747agent # [84947.247123] agent systemd[1]: Reload requested from client PID 2431 ('systemctl') (unit flakelet-relay-job-app.service)...748agent # [84947.247164] agent systemd[1]: Reloading...749agent # [84947.602463] agent systemd[1]: Reloading finished in 354 ms.750relay # [84947.238378] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:08.367580Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}751agent: (finished: must succeed: systemctl restart flakelet-agent, in 1.17 seconds)752agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"753agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)754client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out755agent # [84947.681340] agent systemd[1]: flakelet-agent.service: Deactivated successfully.756agent # [84947.681610] agent systemd[1]: Stopped flakelet-agent.757agent # [84947.687443] agent systemd[1]: Starting flakelet-agent...758agent # [84947.688849] agent systemd[1]: Starting app slow2...759agent # [84947.753711] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:08.882920Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"9d04c88ad4f512fa4f82c5100d18fc16\"]","target":"flakelet_relay::agent::jobs"}760agent # [84947.753772] agent systemd[1]: Started flakelet-agent.761agent # [84947.836197] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:08.965461Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}762agent # [84947.836376] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:08.965561Z","level":"INFO","message":"start","id":"9d04c88ad4f512fa4f82c5100d18fc16","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}763relay # [84947.836236] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:08.965494Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}764agent # [84953.756111] agent systemd[1]: Started app slow2.765agent # [84953.775326] agent flakelet[2330]: app: updated to generation 6766agent # [84953.777629] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.767agent # [84954.342454] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:15.471684Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(6)","target":"flakelet_relay::agent::jobs"}768relay # [84954.343329] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:15.472531Z","level":"INFO","message":"deploy finished","job":"9c34d306b5e457f2f406e05a8fbb7e1f","ok":true,"target":"flakelet_relay::relay::api"}769client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)770client: must succeed: cat /tmp/restart.out771client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)772agent: must succeed: systemctl is-active app.service773agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)774(finished: subtest: agent restart mid-run reattaches to the unit, in 9.33 seconds)775subtest: relay restart mid-run, push resumes via /v1/jobs776agent: 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.json777agent: (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)778agent: must succeed: date +%s779agent: (finished: must succeed: date +%s, in 0.01 seconds)780client: 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 &781client: (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)782agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675316 | grep -q 'app-slow'783agent # [84954.914584] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:16.043809Z","level":"INFO","message":"start","id":"6c5fb2032d298fc6f8a54a82f99273a2","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}784relay # [84954.914228] relay flakelet-relay[400]: {"timestamp":"2026-09-06T06:15:16.043389Z","level":"INFO","message":"deploy accepted","job":"c46a149e7623dfbfd5aecd8bb1d94a27","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}785agent # [84954.915115] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:16.044406Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6c5fb2032d298fc6f8a54a82f99273a2\"]","target":"flakelet_relay::agent::jobs"}786agent # [84954.975782] agent systemd[1]: Starting flakelet update app (via relay)...787agent # [84954.984070] agent systemd[1]: Started flakelet update app (via relay).788agent # [84954.988817] agent flakelet[2897]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow789agent # [84954.989520] agent flakelet[2897]: app: activating generation 7790agent # [84955.002783] agent systemd[1]: Stopping app slow2...791agent # [84955.003700] agent systemd[1]: app.service: Deactivated successfully.792agent # [84955.003892] agent systemd[1]: Stopped app slow2.793agent # [84955.016477] agent systemd[1]: Reload requested from client PID 2904 ('systemctl') (unit flakelet-relay-job-app.service)...794agent # [84955.016569] agent systemd[1]: Reloading...795agent # [84955.491591] agent systemd[1]: Reloading finished in 474 ms.796agent # [84955.579613] agent systemd[1]: Reload requested from client PID 2934 ('systemctl') (unit flakelet-relay-job-app.service)...797agent # [84955.579669] agent systemd[1]: Reloading...798agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788675316 | grep -q 'app-slow', in 1.02 seconds)799relay: must succeed: systemctl restart flakelet-relay800relay # [84955.933851] relay systemd[1]: Stopping flakelet-relay...801relay # [84955.964925] relay systemd[1]: flakelet-relay.service: Deactivated successfully.802relay # [84955.965334] relay systemd[1]: Stopped flakelet-relay.803relay # [84955.965355] relay systemd[1]: flakelet-relay.service: Consumed 2.173s CPU time over 52.424s wall clock time.804relay # [84955.984527] relay systemd[1]: Starting flakelet-relay...805agent # [84955.934262] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:17.063504Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}806agent # [84956.163696] agent systemd[1]: Reloading finished in 583 ms.807agent # [84956.272418] agent systemd[1]: Reload requested from client PID 2967 ('systemctl') (unit flakelet-relay-job-app.service)...808agent # [84956.272462] agent systemd[1]: Reloading...809agent # [84956.707168] agent systemd[1]: Reloading finished in 434 ms.810agent # [84956.812105] agent systemd[1]: Reload requested from client PID 2997 ('systemctl') (unit flakelet-relay-job-app.service)...811agent # [84956.812146] agent systemd[1]: Reloading...812agent # [84957.218486] agent systemd[1]: Reloading finished in 405 ms.813agent # [84957.311143] agent systemd[1]: Starting app slow...814agent # [84957.376183] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:18.505432Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}815relay: (finished: must succeed: systemctl restart flakelet-relay, in 2.53 seconds)816client: waiting for success: grep -q '» ok' /tmp/resume.out817relay # [84958.450241] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:19.579483Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}818relay # [84958.451098] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:19.579896Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}819relay # [84958.450827] relay systemd[1]: Started flakelet-relay.820agent # [84959.469222] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:20.598467Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}821relay # [84959.469298] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:20.598545Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(6), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}822relay # [84962.953553] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:24.082804Z","level":"INFO","message":"job reattached","job":"c46a149e7623dfbfd5aecd8bb1d94a27","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}823agent # [84963.354363] agent systemd[1]: Started app slow.824agent # [84963.376430] agent flakelet[2897]: app: updated to generation 7825agent # [84963.380247] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.826client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 6.07 seconds)827client: must succeed: cat /tmp/resume.out828client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)829(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.66 seconds)830subtest: job history comes from the agents and survives a relay restart831client: 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>&1832relay # [84964.552031] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:25.681241Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}833agent # [84964.418314] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:25.547562Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}834agent # [84964.552481] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:25.681728Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}835agent # [84964.552937] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:25.682210Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}836agent # [84964.613816] agent systemd[1]: Starting flakelet update other (via relay)...837agent # [84964.621686] agent systemd[1]: Started flakelet update other (via relay).838agent # [84964.625423] agent flakelet[3074]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1839agent # [84964.626012] agent flakelet[3074]: other: up to date840agent # [84964.630877] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.841client: (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.66 seconds)842relay: must succeed: systemctl restart flakelet-relay843relay # [84965.188612] relay flakelet-relay[933]: {"timestamp":"2026-09-06T06:15:26.317835Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}844relay # [84965.205103] relay systemd[1]: Stopping flakelet-relay...845relay # [84965.254869] relay systemd[1]: flakelet-relay.service: Deactivated successfully.846relay # [84965.255421] relay systemd[1]: Stopped flakelet-relay.847relay # [84965.255466] relay systemd[1]: flakelet-relay.service: Consumed 2.064s CPU time over 9.270s wall clock time.848relay # [84965.294043] relay systemd[1]: Starting flakelet-relay...849agent # [84965.187790] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:26.317006Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}850agent # [84965.205316] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:26.334590Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}851agent # [84966.293588] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:27.422846Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}852relay: (finished: must succeed: systemctl restart flakelet-relay, in 2.62 seconds)853relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'854relay # [84967.808445] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:28.937654Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}855relay # [84967.809325] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:28.938060Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}856relay # [84967.808934] relay systemd[1]: Started flakelet-relay.857relay # [84968.381317] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:29.510573Z","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"}858relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 1.04 seconds)859client: 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 jobs860client: (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)861client: 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)862agent # [84968.381259] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:29.510520Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}863client: (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)864client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTYzMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MzMwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJEN1ZKR0g3S0hSRlY2PT09IiwibmJmIjoxNzg4Njc1MzMwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.xyPeegCtYbiMow3k0t1GT0t8Z4U2uq2iYo4KAzM4dSlmb3-21ZmqG-qAc0iqztEXEejC9giHz_G3xz0MOmPCDw' push --relay https://relay:7443 jobs865client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY3NTYzMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4Njc1MzMwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJEN1ZKR0g3S0hSRlY2PT09IiwibmJmIjoxNzg4Njc1MzMwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.xyPeegCtYbiMow3k0t1GT0t8Z4U2uq2iYo4KAzM4dSlmb3-21ZmqG-qAc0iqztEXEejC9giHz_G3xz0MOmPCDw' push --relay https://relay:7443 jobs, in 0.02 seconds)866(finished: subtest: job history comes from the agents and survives a relay restart, in 4.41 seconds)867subtest: dashboard login via authorization code flow868client: 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'869client: (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)870client: 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/login871client: (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.09 seconds)872client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs873client: (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)874client: 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 hist1875client: (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)876client: 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 || true877client: (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)878client: 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 403879client: (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)880client: 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'881client: (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)882client: 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/e8ad9998b92795e99537ef719d2e5d3d/events || true883relay # [84968.991790] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 06:15:30] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=ryJccPXTE41y5X4MiTWpAyCLT7yE-Ygnwd4cr9j0uN4&code_challenge=I3lWc3H6RYYoUGETDTt3XQicCdOyRoAhaTh7L-wEd_A&code_challenge_method=S256 HTTP/1.1" 302 -884relay # [84969.044908] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 06:15:30] "POST /token HTTP/1.1" 200 -885relay # [84969.045654] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:30.174895Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}886relay # [84969.108393] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:30.237657Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}887relay # [84969.149318] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:30.278598Z","level":"INFO","message":"deploy accepted","job":"e8237b7e1d163f31bd30ffe5974f7bcd","caller":"oidc:mock:someone\noidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}888relay # [84969.166995] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:30.296287Z","level":"INFO","message":"job reattached","job":"e8237b7e1d163f31bd30ffe5974f7bcd","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}889agent # [84969.149501] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:30.278756Z","level":"INFO","message":"start","id":"176b615e057aa56f0dcd0f7febf10c20","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}890agent # [84969.149781] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:30.279083Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"176b615e057aa56f0dcd0f7febf10c20\"]","target":"flakelet_relay::agent::jobs"}891agent # [84969.215024] agent systemd[1]: Starting flakelet update other (via relay)...892agent # [84969.249326] agent systemd[1]: Started flakelet update other (via relay).893agent # [84969.253611] agent flakelet[3112]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1894agent # [84969.254127] agent flakelet[3112]: other: up to date895agent # [84969.256485] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.896client: (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/e8ad9998b92795e99537ef719d2e5d3d/events || true, in 0.67 seconds)897client: 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/e8ad9998b92795e99537ef719d2e5d3d898client: (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/e8ad9998b92795e99537ef719d2e5d3d, in 0.03 seconds)899client: 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.js900client: (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)901client: 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'902client: (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)903client: 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/other904client: (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)905client: 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'906client: (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)907client: 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=e8ad9998b92795e99537ef719d2e5d3d' | grep -q 400908client: (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=e8ad9998b92795e99537ef719d2e5d3d' | grep -q 400, in 0.02 seconds)909client: 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 &910client: (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)911client: 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/other912» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)913» wave 0914agent # [84969.814658] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:30.943873Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}915agent # [84969.961991] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:31.091186Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}916agent # [84969.962592] agent flakelet-agent[2462]: {"timestamp":"2026-09-06T06:15:31.091877Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}917agent # [84970.032244] agent systemd[1]: Starting flakelet update other (via relay)...918agent/other | Starting flakelet update other (via relay)...919agent/other | Started flakelet update other (via relay).920agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1921agent/other | other: up to date922agent # [84970.071178] agent systemd[1]: Started flakelet update other (via relay).923agent # [84970.076867] agent flakelet[3130]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1924agent # [84970.077375] agent flakelet[3130]: other: up to date925relay # [84969.961466] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:31.090734Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}926agent # [84970.080524] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.927agent/other | flakelet-relay-job-other.service: Deactivated successfully.928» agent/other: unchanged (generation 1)929» ok930client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 0.69 seconds)931client: waiting for success: grep -q live1 /tmp/ev.out932client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)933client: 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/logout934client: (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)935client: 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 303936client: (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)937(finished: subtest: dashboard login via authorization code flow, in 1.75 seconds)938(finished: run the VM test script, in 70.73 seconds)939test script finished in 70.78s940cleanup941kill NspawnMachine (pid 52)942kill NspawnMachine (pid 53)943Container agent terminated by signal KILL.944relay # [84970.636541] relay flakelet-relay[1323]: {"timestamp":"2026-09-06T06:15:31.765765Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}945kill NspawnMachine (pid 54)946Container client terminated by signal KILL.947Container relay terminated by signal KILL.948(finished: cleanup, in 0.44 seconds)949additionally exposed symbols:950 agent, client, relay,951 vlan1,952 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_ssh953» job 7f630172135f1077f4a87a31e7dfb9d9 via relay 0.1.0 (agents: agent 0.1.0)954» wave 0955agent/app | Starting flakelet update app (via relay)...956agent/app | Started flakelet update app (via relay).957agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2958agent/app | app: activating generation 2959agent/app | app: updated to generation 2960agent/app | flakelet-relay-job-app.service: Deactivated successfully.961» agent/app: updated (generation 2)962» ok963964» job 233d11327806c6ba4302b8da0bf6b8a9 via relay 0.1.0 (agents: agent 0.1.0)965» wave 0966agent/app | Starting flakelet update app (via relay)...967agent/app | Started flakelet update app (via relay).968agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken969agent/app | app: activating generation 4970agent/app | app: deploy failed, rolled back: systemctl start app.service failed:971agent/app | failed units: app.service. See journalctl -u app.service972agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE973agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.974» agent/app: rolled-back (generation 3)975agent/app │ Starting app v1...976agent/app │ Started app v1.977agent/app │ Stopping app v1...978agent/app │ app.service: Deactivated successfully.979agent/app │ Stopped app v1.980agent/app │ Starting app v2...981agent/app │ Started app v2.982agent/app │ Stopping app v2...983agent/app │ app.service: Deactivated successfully.984agent/app │ Stopped app v2.985agent/app │ Starting app v1...986agent/app │ Started app v1.987agent/app │ Stopping app v1...988agent/app │ app.service: Deactivated successfully.989agent/app │ Stopped app v1.990agent/app │ Starting app broken...991agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory992agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory993agent/app │ app.service: Main process exited, code=exited, status=203/EXEC994agent/app │ app.service: Failed with result 'exit-code'.995agent/app │ Failed to start app broken.996agent/app │ Starting app v1...997agent/app │ Started app v1.998» skipped: agent/other999» failed10001001» job 1ec5f3b6d0fcfa69c747402c5d67d6e5 via relay 0.1.0 (agents: agent 0.1.0)1002» wave 01003agent/app | Starting flakelet update app (via relay)...1004agent/app | Started flakelet update app (via relay).1005agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1006agent/app | app: activating generation 51007agent/app | app: updated to generation 51008agent/app | flakelet-relay-job-app.service: Deactivated successfully.1009» agent/app: updated (generation 5)1010» ok10111012» job 9c34d306b5e457f2f406e05a8fbb7e1f via relay 0.1.0 (agents: agent 0.1.0)1013» wave 01014agent/app | Starting flakelet update app (via relay)...1015agent/app | Started flakelet update app (via relay).1016agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21017agent/app | app: activating generation 61018agent/app | app: updated to generation 61019agent/app | flakelet-relay-job-app.service: Deactivated successfully.1020» agent/app: updated (generation 6)1021» ok10221023» job c46a149e7623dfbfd5aecd8bb1d94a27 via relay 0.1.0 (agents: agent 0.1.0)1024» wave 01025agent/app | Starting flakelet update app (via relay)...1026agent/app | Started flakelet update app (via relay).1027agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1028agent/app | app: activating generation 71029flakelet-push: stream: error reading a body from connection, resuming job f7683a0ce29721a893dd359ba17cba131030flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1031flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1032flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1033» job c46a149e7623dfbfd5aecd8bb1d94a27 via relay 0.1.0 (agents: agent 0.1.0)1034» wave 01035agent/app | app: updated to generation 71036agent/app | flakelet-relay-job-app.service: Deactivated successfully.1037» agent/app: updated (generation 7)1038» ok103910401788675325 hist1 x509:email:admin@example.org agent/other:unchanged10411788675316 f7683a0ce29721a893dd359ba17cba13 x509:email:admin@example.org agent/app:updated10421788675306 eb5c779a430282edcb4d478bee9f7140 x509:email:admin@example.org agent/app:updated10431788675297 d050d46ecd9126c68d4b97f049ef602e x509:email:admin@example.org agent/app:updated10441788675296 8ace4d79cbf786d8c9ea4c19127dfe18 x509:email:admin@example.org agent/other:unchanged10451788675284 62394e456da1426a48dd2e78304317f4 x509:email:admin@example.org agent/app:updated10461788675279 3bfbb9f9530087af5ec2c6b46ae89995 oidc:mock:groups:wheel agent/other:unchanged10471788675279 9bf48c7cda48d19e71679ef5253466d5 x509:email:admin@example.org agent/app:rolled-back10481788675278 d35781d1578a43dcce2bdef9fe8387f9 oidc:mock:groups:wheel agent/other:unchanged10491788675275 4398d84dff3af5c7a22b44068a165fe8 oidc:mock:groups:wheel agent/other:unchanged10501788675272 2ce159da99576c3c57adebdf891c528e oidc:mock:repo:github:example/app:ref:refs/heads/main agent/app:updated10511788675269 d87e7fa6c6fd40d99a781b8f1ed6bb6b x509:email:admin@example.org agent/app:updated1052