container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #43
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 52)10client: systemd-nspawn running (pid 53)11agent: Waiting for journal at /build/vm-state-agent/var/log/journal...12relay: systemd-nspawn running (pid 55)13client: Waiting for journal at /build/vm-state-client/var/log/journal...14relay: Waiting for journal at /build/vm-state-relay/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.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.26░ Spawning container client on /build/vm-state-client.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).31client # No journal files were found.32client # No journal boot entry found for the specified boot (+0).33relay # No journal files were found.34relay # No journal boot entry found for the specified boot (+0).35agent # [1118709.597855] agent systemd-journald[57]: Journal started36agent # [1118709.597897] agent systemd-journald[57]: Runtime Journal (/run/log/journal/cb44bd480c074869afbbe15ede2b8472) is 8M, max 4G, 3.9G free.37agent # [1118709.609136] agent systemd[1]: Finished Apply Kernel Variables.38agent # [1118709.621792] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [1118709.649672] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [1118709.650406] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [1118709.658822] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/cb44bd480c074869afbbe15ede2b8472 is 1.522ms for 6 entries.42agent # [1118709.658822] agent systemd-journald[57]: System Journal (/var/log/journal/cb44bd480c074869afbbe15ede2b8472) is 512B, max 4G, 3.9G free.43agent # [1118709.668760] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [1118709.669574] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [1118709.669685] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [1118709.681159] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [1118709.746782] agent systemd[1]: Finished Firewall.48agent # [1118710.617704] agent systemd[1]: Mounting /run/wrappers...49relay # [1118709.587693] relay systemd-journald[57]: Journal started50client # [1118709.597498] client systemd-journald[57]: Journal started51relay # [1118709.587736] relay systemd-journald[57]: Runtime Journal (/run/log/journal/6f516a1588764f53b614e5af80d9536b) is 8M, max 4G, 3.9G free.52client # [1118709.597539] client systemd-journald[57]: Runtime Journal (/run/log/journal/acde72d991bc482c94abd3116c5163d9) is 8M, max 4G, 3.9G free.53client # [1118709.608779] client systemd[1]: Finished Apply Kernel Variables.54relay # [1118709.598242] relay systemd[1]: Finished Apply Kernel Variables.55client # [1118709.621589] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.56relay # [1118709.610512] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.57client # [1118709.649555] client systemd[1]: Starting Flush Journal to Persistent Storage...58relay # [1118709.624975] relay systemd[1]: Starting Flush Journal to Persistent Storage...59client # [1118709.650242] client systemd[1]: Starting Create Static Device Nodes in /dev...60relay # [1118709.625632] relay systemd[1]: Starting Create Static Device Nodes in /dev...61client # [1118709.658107] client systemd-journald[57]: Time spent on flushing to /var/log/journal/acde72d991bc482c94abd3116c5163d9 is 2.533ms for 6 entries.62relay # [1118709.654832] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/6f516a1588764f53b614e5af80d9536b is 1.381ms for 6 entries.63client # [1118709.658107] client systemd-journald[57]: System Journal (/var/log/journal/acde72d991bc482c94abd3116c5163d9) is 512B, max 4G, 3.9G free.64relay # [1118709.654832] relay systemd-journald[57]: System Journal (/var/log/journal/6f516a1588764f53b614e5af80d9536b) is 512B, max 4G, 3.9G free.65client # [1118709.668699] client systemd[1]: Finished Create Static Device Nodes in /dev.66relay # [1118709.663140] relay systemd[1]: Finished Create Static Device Nodes in /dev.67client # [1118709.669477] client systemd[1]: Reached target Preparation for Local File Systems.68relay # [1118709.663910] relay systemd[1]: Reached target Preparation for Local File Systems.69client # [1118709.669619] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys70relay # [1118709.664027] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys71client # [1118709.673266] client systemd[1]: Finished Flush Journal to Persistent Storage.72relay # [1118709.676188] relay systemd[1]: Finished Flush Journal to Persistent Storage.73client # [1118709.742758] client systemd[1]: Finished Firewall.74client # [1118710.617881] client systemd[1]: Mounting /run/wrappers...75relay # [1118709.758313] relay systemd[1]: Finished Firewall.76relay # [1118710.586737] relay systemd[1]: Mounting /run/wrappers...77agent # [1118710.639409] agent systemd[1]: Mounted /run/wrappers.78agent # [1118710.640261] agent systemd[1]: Reached target Local File Systems.79agent # [1118710.641081] agent systemd[1]: Listening on Boot Loader Control Service Socket.80agent # [1118710.642254] agent systemd[1]: Starting Create SUID/SGID Wrappers...81agent # [1118710.642281] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container82agent # [1118710.643072] agent systemd[1]: Starting Save Transient machine-id to Disk...83agent # [1118710.643803] agent systemd[1]: Starting Create System Files and Directories...84agent # [1118710.661144] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85agent # [1118710.661570] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted86agent # [1118710.661883] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/cb44bd480c074869afbbe15ede2b8472 failed: Operation not permitted87agent # [1118710.662240] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted88client # [1118710.639513] client systemd[1]: Mounted /run/wrappers.89client # [1118710.640392] client systemd[1]: Reached target Local File Systems.90client # [1118710.641253] client systemd[1]: Listening on Boot Loader Control Service Socket.91client # [1118710.642215] client systemd[1]: Starting Create SUID/SGID Wrappers...92client # [1118710.642244] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container93client # [1118710.643192] client systemd[1]: Starting Save Transient machine-id to Disk...94client # [1118710.644137] client systemd[1]: Starting Create System Files and Directories...95client # [1118710.663199] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted96client # [1118710.663607] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted97client # [1118710.663938] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/acde72d991bc482c94abd3116c5163d9 failed: Operation not permitted98client # [1118710.664282] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted99relay # [1118710.649992] relay systemd[1]: Mounted /run/wrappers.100relay # [1118710.651300] relay systemd[1]: Reached target Local File Systems.101relay # [1118710.652618] relay systemd[1]: Listening on Boot Loader Control Service Socket.102relay # [1118710.653951] relay systemd[1]: Starting Create SUID/SGID Wrappers...103relay # [1118710.654016] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104relay # [1118710.655462] relay systemd[1]: Starting Save Transient machine-id to Disk...105relay # [1118710.656772] relay systemd[1]: Starting Create System Files and Directories...106relay # [1118710.675046] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.9wmImWYqep/chsh': Operation not permitted107relay # [1118710.675446] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted108relay # [1118710.675850] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted109relay # [1118710.676220] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/6f516a1588764f53b614e5af80d9536b failed: Operation not permitted110relay # [1118710.676549] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted111relay # [1118710.684363] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE112relay # [1118710.684400] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.113relay # [1118710.684451] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.114relay # [1118710.684963] relay systemd[1]: Finished Create System Files and Directories.115relay # [1118710.698258] relay systemd[1]: Starting Rebuild Journal Catalog...116relay # [1118710.699295] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...117relay # [1118710.712769] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.118relay # [1118710.716810] relay systemd[1]: Finished Rebuild Journal Catalog.119relay # [1118710.717879] relay systemd[1]: Starting Update is Completed...120relay # [1118710.727427] relay systemd[1]: Finished Update is Completed.121relay # [1118710.728032] relay systemd[1]: Reached target System Initialization.122relay # [1118710.728137] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123relay # [1118710.728175] relay systemd[1]: Started Daily Cleanup of Temporary Directories.124relay # [1118710.728195] relay systemd[1]: Reached target Timer Units.125relay # [1118710.728318] relay systemd[1]: Listening on D-Bus System Message Bus Socket.126relay # [1118710.728481] relay systemd[1]: Listening on Nix Daemon Socket.127relay # [1118710.728587] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128relay # [1118710.728600] relay systemd[1]: Reached target Socket Units.129relay # [1118710.728628] relay systemd[1]: Reached target Basic System.130relay # [1118710.729668] relay systemd[1]: Started device-mock.service.131relay # [1118710.730575] relay systemd[1]: Starting Re-link flakelet services at boot...132relay # [1118710.731271] relay systemd[1]: Starting Import lastlog data into lastlog2 database...133relay # [1118710.732091] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...134relay # [1118710.732789] relay systemd[1]: Starting resolvconf update...135relay # [1118710.743712] relay systemd[1]: Finished Re-link flakelet services at boot.136relay # [1118710.744571] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...137relay # [1118710.752366] relay systemd[1]: Finished Import lastlog data into lastlog2 database.138relay # [1118710.755431] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.139agent # [1118710.664760] agent systemd[1]: Finished Create System Files and Directories.140agent # [1118710.669041] agent suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.ufcljbCmnK/chsh': Operation not permitted141agent # [1118710.678399] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE142agent # [1118710.678493] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.143agent # [1118710.678641] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.144agent # [1118710.680456] agent systemd[1]: Starting Rebuild Journal Catalog...145agent # [1118710.681259] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...146agent # [1118710.693441] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.147agent # [1118710.700195] agent systemd[1]: Finished Rebuild Journal Catalog.148agent # [1118710.701329] agent systemd[1]: Starting Update is Completed...149agent # [1118710.711322] agent systemd[1]: Finished Update is Completed.150agent # [1118710.711422] agent systemd[1]: Reached target System Initialization.151agent # [1118710.711497] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container152agent # [1118710.711524] agent systemd[1]: Started Daily Cleanup of Temporary Directories.153agent # [1118710.711539] agent systemd[1]: Reached target Timer Units.154agent # [1118710.711641] agent systemd[1]: Listening on D-Bus System Message Bus Socket.155agent # [1118710.711871] agent systemd[1]: Listening on Nix Daemon Socket.156agent # [1118710.711973] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.157agent # [1118710.711988] agent systemd[1]: Reached target Socket Units.158agent # [1118710.712026] agent systemd[1]: Reached target Basic System.159agent # [1118710.713378] agent systemd[1]: Starting Re-link flakelet services at boot...160agent # [1118710.714272] agent systemd[1]: Starting Import lastlog data into lastlog2 database...161agent # [1118710.715148] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...162agent # [1118710.715928] agent systemd[1]: Starting resolvconf update...163agent # [1118710.726140] agent systemd[1]: Finished Re-link flakelet services at boot.164agent # [1118710.727188] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...165agent # [1118710.731353] agent systemd[1]: Finished Import lastlog data into lastlog2 database.166agent # [1118710.740515] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.167agent # [1118710.801515] agent systemd[1]: Finished resolvconf update.168agent # [1118710.801654] agent systemd[1]: Reached target Preparation for Network.169agent # [1118710.803025] agent systemd[1]: Starting Address configuration of eth1...170agent # [1118710.804029] agent systemd[1]: Starting Extra networking commands....171agent # [1118710.824826] agent network-addresses-eth1-start[236]: adding address 192.168.1.1/24... done172agent # [1118710.828697] agent network-addresses-eth1-start[236]: adding address 2001:db8:1::1/64... done173agent # [1118710.866471] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.174agent # [1118710.867265] agent systemd[1]: Finished Save Transient machine-id to Disk.175agent # [1118710.867461] agent systemd[1]: nscd.service: Deactivated successfully.176agent # [1118710.867590] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).177agent # [1118710.869023] agent systemd[1]: Finished Address configuration of eth1.178client # [1118710.666851] client systemd[1]: Finished Create System Files and Directories.179client # [1118710.669217] client suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.GxFABcgksH/chsh': Operation not permitted180client # [1118710.680157] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE181client # [1118710.680194] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.182client # [1118710.680245] client systemd[1]: Failed to start Create SUID/SGID Wrappers.183client # [1118710.681861] client systemd[1]: Starting Rebuild Journal Catalog...184client # [1118710.682477] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...185client # [1118710.693496] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.186client # [1118710.700845] client systemd[1]: Finished Rebuild Journal Catalog.187client # [1118710.701816] client systemd[1]: Starting Update is Completed...188client # [1118710.713020] client systemd[1]: Finished Update is Completed.189client # [1118710.713155] client systemd[1]: Reached target System Initialization.190client # [1118710.713218] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container191client # [1118710.713243] client systemd[1]: Started Daily Cleanup of Temporary Directories.192client # [1118710.713258] client systemd[1]: Reached target Timer Units.193client # [1118710.713355] client systemd[1]: Listening on D-Bus System Message Bus Socket.194client # [1118710.713575] client systemd[1]: Listening on Nix Daemon Socket.195client # [1118710.713801] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.196client # [1118710.713817] client systemd[1]: Reached target Socket Units.197client # [1118710.713843] client systemd[1]: Reached target Basic System.198client # [1118710.714861] client systemd[1]: Starting Import lastlog data into lastlog2 database...199client # [1118710.715813] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...200client # [1118710.716519] client systemd[1]: Starting resolvconf update...201client # [1118710.734379] client systemd[1]: Finished Import lastlog data into lastlog2 database.202client # [1118710.881559] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.203client # [1118710.882915] client systemd[1]: Finished Save Transient machine-id to Disk.204client # [1118710.909860] client systemd[1]: nscd.service: Deactivated successfully.205client # [1118710.923500] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).206client # [1118710.926732] client systemd[1]: Finished resolvconf update.207client # [1118710.928103] client systemd[1]: Reached target Preparation for Network.208client # [1118710.929707] client systemd[1]: Starting Address configuration of eth1...209client # [1118710.931283] client systemd[1]: Starting Extra networking commands....210client # [1118710.932955] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...211client # [1118710.951932] client network-addresses-eth1-start[236]: adding address 192.168.1.2/24... done212client # [1118710.955531] client network-addresses-eth1-start[236]: adding address 2001:db8:1::2/64... done213client # [1118710.960680] client systemd[1]: Finished Address configuration of eth1.214client # [1118711.023413] client systemd[1]: Finished Extra networking commands..215client # [1118711.023695] client systemd[1]: Reached target Network.216client # [1118711.029663] client systemd[1]: nscd.service: Deactivated successfully.217client # [1118711.029946] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).218client # [1118711.034411] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...219agent # [1118710.881757] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...220agent # [1118710.885193] agent systemd[1]: nscd.service: Deactivated successfully.221agent # [1118710.885284] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).222agent # [1118710.887407] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...223agent # [1118710.923398] agent systemd[1]: Finished Extra networking commands..224agent # [1118710.924201] agent systemd[1]: Reached target Network.225agent # [1118710.925508] agent systemd[1]: Starting Update flakelet service app...226agent # [1118710.926466] agent systemd[1]: Starting Update flakelet service flakelet-agent...227agent # [1118710.927524] agent systemd[1]: Starting Update flakelet service other...228agent # [1118710.937169] agent flakelet[307]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1229agent # [1118710.937722] agent flakelet[307]: app: activating generation 1230agent # [1118710.938444] agent flakelet[308]: flakelet-agent: using prebuilt artifact /nix/store/flgya4ggb72hyvnnjcsjw6zbknb4w1s4-flakelet-flakelet-agent231agent # [1118710.938976] agent flakelet[308]: flakelet-agent: activating generation 1232agent # [1118710.939299] agent flakelet[309]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1233agent # [1118710.939832] agent flakelet[309]: other: activating generation 1234agent # [1118710.943348] agent systemd[1]: Reload requested from client PID 310 ('systemctl') (unit flakelet-app.service)...235agent # [1118710.943383] agent systemd[1]: Reloading...236relay # [1118710.866047] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.237relay # [1118710.866927] relay systemd[1]: Finished Save Transient machine-id to Disk.238relay # [1118710.895302] relay systemd[1]: nscd.service: Deactivated successfully.239relay # [1118710.900227] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).240relay # [1118710.923832] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...241relay # [1118710.924083] relay systemd[1]: Finished resolvconf update.242relay # [1118710.924830] relay systemd[1]: Reached target Preparation for Network.243relay # [1118710.926237] relay systemd[1]: Starting Address configuration of eth1...244relay # [1118710.927565] relay systemd[1]: Starting Extra networking commands....245relay # [1118710.947892] relay network-addresses-eth1-start[250]: adding address 192.168.1.3/24... done246relay # [1118710.951906] relay network-addresses-eth1-start[250]: adding address 2001:db8:1::3/64... done247relay # [1118710.956029] relay systemd[1]: Finished Address configuration of eth1.248relay # [1118710.992568] relay systemd[1]: Finished Extra networking commands..249relay # [1118710.992660] relay systemd[1]: Reached target Network.250relay # [1118710.993939] relay systemd[1]: Starting Dnsmasq Daemon...251relay # [1118710.994832] relay systemd[1]: Starting Nginx Web Server...252relay # [1118710.995574] relay systemd[1]: Starting Update flakelet service flakelet-relay...253relay # [1118711.033150] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/55zvswj0bvimz7faqq19rhsjlvqasa00-flakelet-flakelet-relay254relay # [1118711.033853] relay flakelet[311]: flakelet-relay: activating generation 1255relay # [1118711.038020] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...256relay # [1118711.038060] relay systemd[1]: Reloading...257relay # [1118711.297663] relay nsncd[245]: Sep 24 11:56:59.584 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"258relay # [1118711.405201] relay systemd[1]: Reloading finished in 366 ms.259relay # [1118711.545948] relay systemd[1]: Started Name Service Cache Daemon (nsncd).260relay # [1118711.546546] relay systemd[1]: Reached target Host and Network Name Lookups.261relay # [1118711.546629] relay systemd[1]: Reached target User and Group Name Lookups.262relay # [1118711.547863] relay systemd[1]: Starting User Login Management...263client # [1118711.312572] client nsncd[303]: Sep 24 11:56:59.600 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"264client # [1118711.312699] client systemd[1]: Started Name Service Cache Daemon (nsncd).265client # [1118711.312799] client systemd[1]: Reached target Host and Network Name Lookups.266client # [1118711.312902] client systemd[1]: Reached target User and Group Name Lookups.267client # [1118711.315138] client systemd[1]: Starting User Login Management...268client # [1118711.316436] client systemd[1]: Starting Permit User Sessions...269client # [1118711.353576] client systemd[1]: Finished Permit User Sessions.270client # [1118711.355648] client systemd[1]: Started Console Getty.271client # [1118711.355698] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0272client # [1118711.355727] client systemd[1]: Reached target Login Prompts.273agent # [1118711.318637] agent nsncd[297]: Sep 24 11:56:59.606 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"274agent # [1118711.402644] agent systemd[1]: Reloading finished in 458 ms.275agent # [1118711.549910] agent systemd[1]: Started Name Service Cache Daemon (nsncd).276agent # [1118711.550581] agent systemd[1]: Reload requested from client PID 311 ('systemctl') (unit flakelet-flakelet-agent.service)...277agent # [1118711.550633] agent systemd[1]: Reloading...278relay # [1118711.548718] relay systemd[1]: Starting Permit User Sessions...279relay # [1118711.570872] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...280relay # [1118711.570904] relay systemd[1]: Reloading...281relay # [1118711.578826] relay dnsmasq-pre-start[360]: dnsmasq: syntax check OK.282agent # [1118711.953032] agent systemd[1]: Reloading finished in 401 ms.283agent # [1118712.032913] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-other.service)...284agent # [1118712.032961] agent systemd[1]: Reloading...285relay # [1118711.931427] relay systemd[1]: Reloading finished in 360 ms.286relay # [1118712.005618] relay systemd[1]: Finished Permit User Sessions.287relay # [1118712.031663] relay systemd[1]: Started Console Getty.288relay # [1118712.031730] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0289relay # [1118712.031798] relay systemd[1]: Reached target Login Prompts.290relay # [1118712.033644] relay systemd[1]: Starting flakelet-relay...291agent # [1118712.381724] agent systemd[1]: Reloading finished in 348 ms.292agent # [1118712.458466] agent systemd[1]: Reached target Host and Network Name Lookups.293agent # [1118712.458616] agent systemd[1]: Reached target User and Group Name Lookups.294agent # [1118712.460347] agent systemd[1]: Starting User Login Management...295agent # [1118712.461396] agent systemd[1]: Starting Permit User Sessions...296agent # [1118712.466010] agent systemd[1]: Reload requested from client PID 404 ('systemctl') (unit flakelet-app.service)...297agent # [1118712.466044] agent systemd[1]: Reloading...298relay # [1118712.550929] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/hwh65j4pm30lhgh5hab7anrqnnr1nfkx-nginx.conf syntax is ok299relay # [1118712.551678] relay nginx-pre-start[402]: nginx: configuration file /nix/store/hwh65j4pm30lhgh5hab7anrqnnr1nfkx-nginx.conf test is successful300relay # [1118712.571815] relay systemd[1]: Started Nginx Web Server.301relay # [1118712.690126] relay systemd[1]: Starting D-Bus System Message Bus...302client # [1118712.703816] client systemd-logind[315]: New seat seat0.303client # [1118712.704385] client systemd[1]: Started User Login Management.304client # [1118712.715773] client systemd[1]: Starting D-Bus System Message Bus...305client # [1118712.717406] client systemd[1]: Starting linger-users.service...306client # [1118712.756933] client systemd[1]: linger-users.service: Deactivated successfully.307client # [1118712.757296] client systemd[1]: Finished linger-users.service.308client # [1118712.757667] client systemd[1]: Reached target Multi-User System.309relay # [1118713.027169] relay systemd-logind[354]: New seat seat0.310relay # [1118713.027586] relay systemd[1]: Started User Login Management.311relay # [1118713.029848] relay systemd[1]: Starting linger-users.service...312relay # [1118713.075650] relay systemd[1]: linger-users.service: Deactivated successfully.313relay # [1118713.075862] relay systemd[1]: Finished linger-users.service.314relay # [1118713.271751] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...315relay # [1118713.273167] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'316relay # [1118713.273167] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/gzyya0rqnysc8n29w09licavwrfbk6c2-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"317relay # [1118713.274266] relay systemd[1]: Started D-Bus System Message Bus.318agent # [1118712.867494] agent systemd[1]: Reloading finished in 401 ms.319agent # [1118712.934912] agent systemd[1]: Finished Permit User Sessions.320agent # [1118712.948576] agent systemd[1]: Started Console Getty.321agent # [1118712.948689] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0322agent # [1118712.948818] agent systemd[1]: Reached target Login Prompts.323agent # [1118712.949872] agent systemd[1]: Reload requested from client PID 406 ('systemctl') (unit flakelet-flakelet-agent.service)...324agent # [1118712.949903] agent systemd[1]: Reloading...325client # [1118713.231094] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...326client # [1118713.232987] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'327client # [1118713.232987] client dbus-broker-launch[325]: Invalid user-name in /nix/store/kin0dpm07f5g7ivsrf5g15f6w5jakfhl-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"328client # [1118713.234114] client systemd[1]: Started D-Bus System Message Bus.329client # [1118713.234552] client systemd[1]: Startup finished in 4.096s.330client # [1118713.239115] client dbus-broker-launch[325]: Ready331relay # [1118713.280014] relay dbus-broker-launch[408]: Ready332relay # [1118713.283366] relay systemd[1]: Started Dnsmasq Daemon.333relay # [1118713.285332] relay dnsmasq[394]: started, version 2.93 cachesize 150334relay # [1118713.285339] relay dnsmasq[394]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth DNSSEC loop-detect inotify dumpfile335relay # [1118713.285344] relay dnsmasq[394]: DBus support enabled: connected to system bus336relay # [1118713.285351] relay dnsmasq[394]: no upstream servers configured - please set them from DBus337relay # [1118713.285442] relay dnsmasq[394]: read /etc/hosts - 9 names338agent # [1118713.299315] agent systemd[1]: Reloading finished in 348 ms.339agent # [1118713.376870] agent systemd[1]: Starting app v1...340agent # [1118713.378649] agent systemd[1]: Reload requested from client PID 443 ('systemctl') (unit flakelet-other.service)...341agent # [1118713.378693] agent systemd[1]: Reloading...342agent # [1118713.724357] agent systemd[1]: Reloading finished in 345 ms.343agent # [1118713.798221] agent systemd[1]: Started app v1.344agent # [1118713.802191] agent systemd[1]: Starting flakelet-agent...345agent # [1118713.806115] agent flakelet[307]: app: updated to generation 1346agent # [1118713.833182] agent systemd[1]: Starting other v1...347agent # [1118713.833678] agent systemd[1]: Finished Update flakelet service app.348agent # [1118713.865230] agent systemd[1]: Started other v1.349agent # [1118713.870230] agent flakelet[309]: other: updated to generation 1350agent # [1118713.872176] agent systemd[1]: Finished Update flakelet service other.351agent # [1118713.881685] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:02.169170Z","level":"INFO","message":"local change","flakelet":"app","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}352agent # [1118713.881907] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:02.169344Z","level":"INFO","message":"local change","flakelet":"other","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}353agent # [1118713.882013] agent systemd[1]: Started flakelet-agent.354agent # [1118713.884265] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:02.171748Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}355agent # [1118713.887040] agent flakelet[308]: flakelet-agent: updated to generation 1356agent # [1118713.888974] agent systemd[1]: Finished Update flakelet service flakelet-agent.357agent # [1118713.889140] agent systemd[1]: Reached target flakelet managed services.358agent # [1118713.906393] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:02.193890Z","level":"INFO","message":"local change","flakelet":"flakelet-agent","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}359agent # [1118713.924691] agent systemd-logind[403]: New seat seat0.360agent # [1118713.925707] agent systemd[1]: Starting D-Bus System Message Bus...361agent # [1118713.925783] agent systemd[1]: Started User Login Management.362agent # [1118713.926567] agent systemd[1]: Starting linger-users.service...363agent # [1118713.965129] agent systemd[1]: linger-users.service: Deactivated successfully.364agent # [1118713.965313] agent systemd[1]: Finished linger-users.service.365agent # [1118713.965476] agent systemd[1]: Reached target Multi-User System.366relay # [1118714.137928] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:02.425404Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}367relay # [1118714.138431] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:02.425856Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}368relay # [1118714.138627] relay systemd[1]: Started flakelet-relay.369relay # [1118714.148278] relay systemd[1]: Starting health for flakelet-relay...370relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)371relay: waiting for unit nginx.service372agent # [1118714.417686] agent dbus-broker-launch[902]: Looking up NSS user entry for 'systemd-timesync'...373agent # [1118714.420689] agent dbus-broker-launch[902]: NSS returned no entry for 'systemd-timesync'374agent # [1118714.420689] agent dbus-broker-launch[902]: Invalid user-name in /nix/store/phv8q4bqjivzlnv4zxgvb2lcnrlk0i4a-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"375agent # [1118714.425828] agent systemd[1]: Started D-Bus System Message Bus.376agent # [1118714.426450] agent systemd[1]: Startup finished in 5.285s.377agent # [1118714.431911] agent dbus-broker-launch[902]: Ready378relay: (finished: waiting for unit nginx.service, in 0.02 seconds)379agent: waiting for unit flakelet.target380agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)381agent: waiting for unit flakelet-agent.service382agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)383client: waiting for unit multi-user.target384client: (finished: waiting for unit multi-user.target, in 0.02 seconds)385relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'386relay # [1118714.457927] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.387relay # [1118714.458198] relay systemd[1]: Finished health for flakelet-relay.388relay # [1118714.466053] relay flakelet[311]: flakelet-relay: updated to generation 1389relay # [1118714.467797] relay systemd[1]: Finished Update flakelet service flakelet-relay.390relay # [1118714.468079] relay systemd[1]: Reached target flakelet managed services.391relay # [1118714.468161] relay systemd[1]: Reached target Multi-User System.392relay # [1118714.468322] relay systemd[1]: Startup finished in 5.323s.393agent # [1118715.898599] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:04.186058Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}394relay # [1118715.898674] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:04.186133Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}395relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)396agent: must succeed: systemctl is-active app.service other.service397agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)398subtest: deploy with client certificate, relay found via SRV399agent: must succeed: jq '.services.app.prebuilt="/nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json400agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)401client: must succeed: push --relay-srv test --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1402agent # [1118716.957535] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:05.244959Z","level":"INFO","message":"start","id":"a84e2e64de5b7f6a6e6aa7e0fe63bdc4","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}403agent # [1118716.958266] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:05.245758Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"a84e2e64de5b7f6a6e6aa7e0fe63bdc4\"]","target":"flakelet_relay::agent::jobs"}404agent # [1118716.999672] agent systemd[1]: Starting flakelet update app (via relay)...405agent # [1118717.031394] agent systemd[1]: Started flakelet update app (via relay).406agent # [1118717.036625] agent flakelet[924]: app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2407agent # [1118717.037332] agent flakelet[924]: app: activating generation 2408agent # [1118717.057423] agent systemd[1]: Stopping app v1...409agent # [1118717.057870] agent systemd[1]: app.service: Deactivated successfully.410agent # [1118717.058164] agent systemd[1]: Stopped app v1.411agent # [1118717.076769] agent systemd[1]: Reload requested from client PID 931 ('systemctl') (unit flakelet-relay-job-app.service)...412agent # [1118717.076837] agent systemd[1]: Reloading...413relay # [1118716.957052] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:05.244463Z","level":"INFO","message":"deploy accepted","job":"1871c3fd17edfdfcb76aed332435f41d","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}414agent # [1118717.424517] agent systemd[1]: Reloading finished in 346 ms.415agent # [1118717.513900] agent systemd[1]: Reload requested from client PID 961 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [1118717.513941] agent systemd[1]: Reloading...417agent # [1118717.850483] agent systemd[1]: Reloading finished in 336 ms.418agent # [1118717.938022] agent systemd[1]: Reload requested from client PID 992 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [1118717.938062] agent systemd[1]: Reloading...420agent # [1118718.278567] agent systemd[1]: Reloading finished in 340 ms.421agent # [1118718.368973] agent systemd[1]: Reload requested from client PID 1025 ('systemctl') (unit flakelet-relay-job-app.service)...422agent # [1118718.369020] agent systemd[1]: Reloading...423agent # [1118718.705275] agent systemd[1]: Reloading finished in 335 ms.424agent # [1118718.793516] agent systemd[1]: Starting app v2...425agent # [1118718.821877] agent systemd[1]: Started app v2.426agent # [1118718.827625] agent flakelet[924]: app: updated to generation 2427agent # [1118718.829853] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.428client: (finished: must succeed: push --relay-srv test --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.98 seconds)429agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'430agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)431agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'432agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)433agent: must succeed: flakelet status --json app | jq -c '.[0].changed.by'434agent: (finished: must succeed: flakelet status --json app | jq -c '.[0].changed.by', in 0.03 seconds)435(finished: subtest: deploy with client certificate, relay found via SRV, in 3.05 seconds)436subtest: deploy with OIDC token, sub principal437agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json438agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)439client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)440client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)441client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzM1U2Ujc0TzI2NllNPT09IiwibmJmIjoxNzkwMjUxMDI4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gDyVmzHwq2yEbHans97PhWwR-xObz7XnINUk1_WAXl6DUCbI-bForsGVISiA7urBrO-PHFTBA07As0-de6cBBQ' push --relay https://relay:7443 deploy agent/app 2>&1442agent # [1118719.908906] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:08.196351Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}443agent # [1118720.082213] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:08.369605Z","level":"INFO","message":"start","id":"18198525fba59166df6f37096fdd6c86","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"}444agent # [1118720.082686] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:08.370179Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"18198525fba59166df6f37096fdd6c86\"]","target":"flakelet_relay::agent::jobs"}445agent # [1118720.123320] agent systemd[1]: Starting flakelet update app (via relay)...446agent # [1118720.154286] agent systemd[1]: Started flakelet update app (via relay).447agent # [1118720.158046] agent flakelet[1094]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1448agent # [1118720.158707] agent flakelet[1094]: app: activating generation 3449agent # [1118720.173187] agent systemd[1]: Stopping app v2...450relay # [1118719.910634] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:08.198045Z","level":"INFO","message":"deploy finished","job":"1871c3fd17edfdfcb76aed332435f41d","ok":true,"target":"flakelet_relay::relay::api"}451relay # [1118720.081843] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:08.369267Z","level":"INFO","message":"deploy accepted","job":"cdecf93ce00bc2523ddec4012c746c8c","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}452agent # [1118720.174987] agent systemd[1]: app.service: Deactivated successfully.453agent # [1118720.175411] agent systemd[1]: Stopped app v2.454agent # [1118720.193182] agent systemd[1]: Reload requested from client PID 1101 ('systemctl') (unit flakelet-relay-job-app.service)...455agent # [1118720.193252] agent systemd[1]: Reloading...456agent # [1118720.545015] agent systemd[1]: Reloading finished in 351 ms.457agent # [1118720.644437] agent systemd[1]: Reload requested from client PID 1131 ('systemctl') (unit flakelet-relay-job-app.service)...458agent # [1118720.644483] agent systemd[1]: Reloading...459agent # [1118720.979720] agent systemd[1]: Reloading finished in 334 ms.460agent # [1118721.063177] agent systemd[1]: Reload requested from client PID 1160 ('systemctl') (unit flakelet-relay-job-app.service)...461agent # [1118721.063219] agent systemd[1]: Reloading...462agent # [1118721.400399] agent systemd[1]: Reloading finished in 336 ms.463agent # [1118721.500451] agent systemd[1]: Reload requested from client PID 1191 ('systemctl') (unit flakelet-relay-job-app.service)...464agent # [1118721.500493] agent systemd[1]: Reloading...465agent # [1118721.835428] agent systemd[1]: Reloading finished in 334 ms.466agent # [1118721.924591] agent systemd[1]: Starting app v1...467agent # [1118721.960397] agent systemd[1]: Started app v1.468agent # [1118721.966657] agent flakelet[1094]: app: updated to generation 3469agent # [1118721.968627] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.470client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzM1U2Ujc0TzI2NllNPT09IiwibmJmIjoxNzkwMjUxMDI4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gDyVmzHwq2yEbHans97PhWwR-xObz7XnINUk1_WAXl6DUCbI-bForsGVISiA7urBrO-PHFTBA07As0-de6cBBQ' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.99 seconds)471(finished: subtest: deploy with OIDC token, sub principal, in 3.06 seconds)472subtest: policy denies uncovered target473client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzM1U2Ujc0TzI2NllNPT09IiwibmJmIjoxNzkwMjUxMDI4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gDyVmzHwq2yEbHans97PhWwR-xObz7XnINUk1_WAXl6DUCbI-bForsGVISiA7urBrO-PHFTBA07As0-de6cBBQ' push --relay https://relay:7443 deploy agent/other 2>&1474client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMyOCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDI4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzM1U2Ujc0TzI2NllNPT09IiwibmJmIjoxNzkwMjUxMDI4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.gDyVmzHwq2yEbHans97PhWwR-xObz7XnINUk1_WAXl6DUCbI-bForsGVISiA7urBrO-PHFTBA07As0-de6cBBQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)475(finished: subtest: policy denies uncovered target, in 0.02 seconds)476subtest: claim principal from groups, unchanged counts as success477client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)478client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-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.06 seconds)479client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMzMSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDI1MTAzMSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiSkhXS1AzNkpQVk9TTT09PSIsIm5iZiI6MTc5MDI1MTAzMSwic3ViIjoic29tZW9uZSJ9.tWWzOPufWyI09f2e9JtsbisPYfocg-9ysmkOYXzxmIeBb3bvYC0bjuKSBvE1lgHkiOT91GkzKV-K-guBKWaGCA' push --relay https://relay:7443 deploy agent/other 2>&1480relay # [1118723.038468] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:11.325890Z","level":"INFO","message":"deploy finished","job":"cdecf93ce00bc2523ddec4012c746c8c","ok":true,"target":"flakelet_relay::relay::api"}481relay # [1118723.141336] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:11.428795Z","level":"INFO","message":"deploy accepted","job":"29978ed4b9de2615fac9e96a8a859654","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}482agent # [1118723.037235] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:11.324623Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}483agent # [1118723.141692] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:11.429129Z","level":"INFO","message":"start","id":"f2a409b99d4deeab64d0445259ebca7b","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"}484agent # [1118723.141974] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:11.429476Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f2a409b99d4deeab64d0445259ebca7b\"]","target":"flakelet_relay::agent::jobs"}485agent # [1118723.181241] agent systemd[1]: Starting flakelet update other (via relay)...486agent # [1118723.212406] agent systemd[1]: Started flakelet update other (via relay).487agent # [1118723.216647] agent flakelet[1245]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1488agent # [1118723.217255] agent flakelet[1245]: other: up to date489agent # [1118723.219403] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.490client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTMzMSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDI1MTAzMSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiSkhXS1AzNkpQVk9TTT09PSIsIm5iZiI6MTc5MDI1MTAzMSwic3ViIjoic29tZW9uZSJ9.tWWzOPufWyI09f2e9JtsbisPYfocg-9ysmkOYXzxmIeBb3bvYC0bjuKSBvE1lgHkiOT91GkzKV-K-guBKWaGCA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)491(finished: subtest: claim principal from groups, unchanged counts as success, in 0.69 seconds)492subtest: push login via device flow, cached token used afterwards493client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1494agent # [1118723.755993] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:12.043442Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}495relay # [1118723.757697] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:12.045108Z","level":"INFO","message":"deploy finished","job":"29978ed4b9de2615fac9e96a8a859654","ok":true,"target":"flakelet_relay::relay::api"}496relay # [1118723.782326] relay 7gsx6vaqmkb2vf8rr0w4y1g018hi9d43-device-mock[185]: 127.0.0.1 - - [24/Sep/2026 11:57:12] "POST /device HTTP/1.1" 200 -497relay # [1118724.787700] relay 7gsx6vaqmkb2vf8rr0w4y1g018hi9d43-device-mock[185]: 127.0.0.1 - - [24/Sep/2026 11:57:13] "POST /token HTTP/1.1" 400 -498client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.09 seconds)499client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600500client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)501client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1502relay # [1118725.842874] relay 7gsx6vaqmkb2vf8rr0w4y1g018hi9d43-device-mock[185]: 127.0.0.1 - - [24/Sep/2026 11:57:14] "POST /token HTTP/1.1" 200 -503relay # [1118725.873824] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:14.161296Z","level":"INFO","message":"deploy accepted","job":"939ee267879a39e6ee8d9d4eeb492bee","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}504agent # [1118725.874280] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:14.161705Z","level":"INFO","message":"start","id":"982a04f7251c9dc72fb8fa39009ed2de","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}505agent # [1118725.874887] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:14.162280Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"982a04f7251c9dc72fb8fa39009ed2de\"]","target":"flakelet_relay::agent::jobs"}506agent # [1118725.920632] agent systemd[1]: Starting flakelet update other (via relay)...507agent # [1118725.957276] agent systemd[1]: Started flakelet update other (via relay).508agent # [1118725.962092] agent flakelet[1273]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1509agent # [1118725.962680] agent flakelet[1273]: other: up to date510agent # [1118725.964559] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.511client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds)512client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1513agent # [1118726.505633] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:14.793038Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}514agent # [1118726.529942] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:14.817418Z","level":"INFO","message":"start","id":"2dce3537d090579454593b6b28a2770b","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}515agent # [1118726.530327] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:14.817816Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"2dce3537d090579454593b6b28a2770b\"]","target":"flakelet_relay::agent::jobs"}516agent # [1118726.568365] agent systemd[1]: Starting flakelet update other (via relay)...517agent # [1118726.600764] agent systemd[1]: Started flakelet update other (via relay).518agent # [1118726.606015] agent flakelet[1293]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1519agent # [1118726.606591] agent flakelet[1293]: other: up to date520agent # [1118726.608391] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.521relay # [1118726.507185] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:14.794601Z","level":"INFO","message":"deploy finished","job":"939ee267879a39e6ee8d9d4eeb492bee","ok":true,"target":"flakelet_relay::relay::api"}522relay # [1118726.529720] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:14.817194Z","level":"INFO","message":"deploy accepted","job":"1c1582ab37d3f816b886c7ce7ba821e2","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}523client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds)524(finished: subtest: push login via device flow, cached token used afterwards, in 3.39 seconds)525subtest: waves: failing first wave skips the second526agent: must succeed: jq '.services.app.prebuilt="/nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json527agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)528client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1529agent # [1118727.151590] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:15.439054Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}530agent # [1118727.187238] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:15.474723Z","level":"INFO","message":"start","id":"b9bd08d121d8d401636379972fec5a73","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}531agent # [1118727.187443] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:15.474946Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"b9bd08d121d8d401636379972fec5a73\"]","target":"flakelet_relay::agent::jobs"}532agent # [1118727.225329] agent systemd[1]: Starting flakelet update app (via relay)...533agent # [1118727.253235] agent systemd[1]: Started flakelet update app (via relay).534agent # [1118727.258483] agent flakelet[1316]: app: using prebuilt artifact /nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken535agent # [1118727.259186] agent flakelet[1316]: app: activating generation 4536agent # [1118727.275756] agent systemd[1]: Stopping app v1...537agent # [1118727.277565] agent systemd[1]: app.service: Deactivated successfully.538agent # [1118727.277944] agent systemd[1]: Stopped app v1.539agent # [1118727.293318] agent systemd[1]: Reload requested from client PID 1323 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [1118727.293385] agent systemd[1]: Reloading...541relay # [1118727.152693] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:15.440089Z","level":"INFO","message":"deploy finished","job":"1c1582ab37d3f816b886c7ce7ba821e2","ok":true,"target":"flakelet_relay::relay::api"}542relay # [1118727.186902] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:15.474381Z","level":"INFO","message":"deploy accepted","job":"2feedd7e91a8f353c42fa3ee97c25d43","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}543agent # [1118727.641504] agent systemd[1]: Reloading finished in 347 ms.544agent # [1118727.729603] agent systemd[1]: Reload requested from client PID 1353 ('systemctl') (unit flakelet-relay-job-app.service)...545agent # [1118727.729645] agent systemd[1]: Reloading...546agent # [1118728.063989] agent systemd[1]: Reloading finished in 333 ms.547agent # [1118728.148383] agent systemd[1]: Reload requested from client PID 1384 ('systemctl') (unit flakelet-relay-job-app.service)...548agent # [1118728.148422] agent systemd[1]: Reloading...549agent # [1118728.488621] agent systemd[1]: Reloading finished in 339 ms.550agent # [1118728.573937] agent systemd[1]: Reload requested from client PID 1417 ('systemctl') (unit flakelet-relay-job-app.service)...551agent # [1118728.573977] agent systemd[1]: Reloading...552agent # [1118728.912256] agent systemd[1]: Reloading finished in 337 ms.553agent # [1118729.002473] agent systemd[1]: Starting app broken...554agent # [1118729.036658] agent (nonexistent)[1447]: app.service: Unable to locate executable '/nonexistent': No such file or directory555agent # [1118729.036684] agent (nonexistent)[1447]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory556agent # [1118729.038266] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC557agent # [1118729.038380] agent systemd[1]: app.service: Failed with result 'exit-code'.558agent # [1118729.038799] agent systemd[1]: Failed to start app broken.559agent # [1118729.072363] agent systemd[1]: Reload requested from client PID 1453 ('systemctl') (unit flakelet-relay-job-app.service)...560agent # [1118729.072438] agent systemd[1]: Reloading...561agent # [1118729.418251] agent systemd[1]: Reloading finished in 345 ms.562agent # [1118729.506945] agent systemd[1]: Reload requested from client PID 1483 ('systemctl') (unit flakelet-relay-job-app.service)...563agent # [1118729.506989] agent systemd[1]: Reloading...564agent # [1118729.842076] agent systemd[1]: Reloading finished in 334 ms.565agent # [1118729.922449] agent systemd[1]: Reload requested from client PID 1515 ('systemctl') (unit flakelet-relay-job-app.service)...566agent # [1118729.922490] agent systemd[1]: Reloading...567agent # [1118730.269694] agent systemd[1]: Reloading finished in 346 ms.568agent # [1118730.361813] agent systemd[1]: Reload requested from client PID 1547 ('systemctl') (unit flakelet-relay-job-app.service)...569agent # [1118730.361853] agent systemd[1]: Reloading...570agent # [1118730.705587] agent systemd[1]: Reloading finished in 343 ms.571agent # [1118730.786666] agent systemd[1]: Starting app v1...572agent # [1118730.813092] agent systemd[1]: Started app v1.573agent # [1118730.814319] agent flakelet[1316]: app: deploy failed, rolled back: systemctl start app.service failed:574agent # [1118730.814319] agent flakelet[1316]: failed units: app.service. See journalctl -u app.service575agent # [1118730.816682] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE576agent # [1118730.816780] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.577client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.30 seconds)578agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'579agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds)580(finished: subtest: waves: failing first wave skips the second, in 4.34 seconds)581subtest: host patterns expand on the relay582agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json583agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)584client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1585agent # [1118731.468455] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:19.755883Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}586agent # [1118731.533466] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:19.820890Z","level":"INFO","message":"start","id":"2a09030c5fcb51fa7d467adc5538e813","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}587agent # [1118731.533875] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:19.821364Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2a09030c5fcb51fa7d467adc5538e813\"]","target":"flakelet_relay::agent::jobs"}588agent # [1118731.573825] agent systemd[1]: Starting flakelet update app (via relay)...589agent # [1118731.605267] agent systemd[1]: Started flakelet update app (via relay).590agent # [1118731.609980] agent flakelet[1603]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1591agent # [1118731.610552] agent flakelet[1603]: app: up to date592agent # [1118731.612984] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.593relay # [1118731.469995] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:19.757430Z","level":"INFO","message":"deploy finished","job":"2feedd7e91a8f353c42fa3ee97c25d43","ok":false,"target":"flakelet_relay::relay::api"}594relay # [1118731.533184] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:19.820610Z","level":"INFO","message":"deploy accepted","job":"c0dd401dca5a9884ec9bae3e704447a3","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}595client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.65 seconds)596client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1597agent # [1118732.155628] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:20.443080Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}598agent # [1118732.180443] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:20.467924Z","level":"INFO","message":"start","id":"183e5ec56796d97e3c573c98e3819a8d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}599agent # [1118732.180813] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:20.468308Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"183e5ec56796d97e3c573c98e3819a8d\"]","target":"flakelet_relay::agent::jobs"}600agent # [1118732.221067] agent systemd[1]: Starting flakelet update app (via relay)...601agent # [1118732.250190] agent systemd[1]: Started flakelet update app (via relay).602agent # [1118732.255668] agent flakelet[1627]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1603agent # [1118732.256273] agent flakelet[1627]: app: up to date604agent # [1118732.258293] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.605relay # [1118732.157145] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:20.444513Z","level":"INFO","message":"deploy finished","job":"c0dd401dca5a9884ec9bae3e704447a3","ok":true,"target":"flakelet_relay::relay::api"}606relay # [1118732.180269] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:20.467742Z","level":"INFO","message":"deploy accepted","job":"d2bf329c361ecc21b1a9e6936fec7d0a","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}607client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.64 seconds)608client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1609relay # [1118732.801204] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:21.088614Z","level":"INFO","message":"deploy finished","job":"d2bf329c361ecc21b1a9e6936fec7d0a","ok":false,"target":"flakelet_relay::relay::api"}610relay # [1118732.822357] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:21.109848Z","level":"INFO","message":"deploy accepted","job":"472d59ec9dafceeeb0186e474de41044","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}611agent # [1118732.799565] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.087015Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}612agent # [1118732.822618] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.110102Z","level":"INFO","message":"start","id":"962bc4eec0e73064ed8aa107903fd0e3","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}613agent # [1118732.822989] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.110483Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"962bc4eec0e73064ed8aa107903fd0e3\"]","target":"flakelet_relay::agent::jobs"}614agent # [1118732.860769] agent systemd[1]: Starting flakelet update app (via relay)...615agent # [1118732.890291] agent systemd[1]: Started flakelet update app (via relay).616agent # [1118732.895726] agent flakelet[1647]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1617agent # [1118732.896345] agent flakelet[1647]: app: up to date618agent # [1118732.898554] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.619client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.64 seconds)620client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1621client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)622(finished: subtest: host patterns expand on the relay, in 1.97 seconds)623subtest: detach returns once the job is accepted624agent: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json625agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)626client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1627client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)628agent: waiting for success: systemctl is-active flakelet-relay-job-app.service629agent # [1118733.438770] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.726218Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}630agent # [1118733.500137] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.787597Z","level":"INFO","message":"start","id":"8203995bd4cc07f2305145a76a28bdd5","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}631agent # [1118733.500585] agent flakelet-agent[502]: {"timestamp":"2026-09-24T11:57:21.788079Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"8203995bd4cc07f2305145a76a28bdd5\"]","target":"flakelet_relay::agent::jobs"}632agent # [1118733.543533] agent systemd[1]: Starting flakelet update app (via relay)...633agent # [1118733.572349] agent systemd[1]: Started flakelet update app (via relay).634agent # [1118733.577725] agent flakelet[1671]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2635agent # [1118733.578427] agent flakelet[1671]: app: activating generation 4636agent # [1118733.591848] agent systemd[1]: Stopping app v1...637agent # [1118733.592341] agent systemd[1]: app.service: Deactivated successfully.638agent # [1118733.592602] agent systemd[1]: Stopped app v1.639agent # [1118733.612218] agent systemd[1]: Reload requested from client PID 1678 ('systemctl') (unit flakelet-relay-job-app.service)...640agent # [1118733.612290] agent systemd[1]: Reloading...641relay # [1118733.440520] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:21.727933Z","level":"INFO","message":"deploy finished","job":"472d59ec9dafceeeb0186e474de41044","ok":false,"target":"flakelet_relay::relay::api"}642relay # [1118733.499922] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:21.787352Z","level":"INFO","message":"deploy accepted","job":"8fa8da58d62dacacb97fcd33499307c6","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}643agent # [1118733.962143] agent systemd[1]: Reloading finished in 349 ms.644agent # [1118734.050239] agent systemd[1]: Reload requested from client PID 1712 ('systemctl') (unit flakelet-relay-job-app.service)...645agent # [1118734.050278] agent systemd[1]: Reloading...646agent # [1118734.384345] agent systemd[1]: Reloading finished in 333 ms.647agent # [1118734.460551] agent systemd[1]: Reload requested from client PID 1741 ('systemctl') (unit flakelet-relay-job-app.service)...648agent # [1118734.460594] agent systemd[1]: Reloading...649agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.37 seconds)650??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.651 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39652agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service653??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.654 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39655agent # [1118734.794257] agent systemd[1]: Reloading finished in 333 ms.656agent # [1118734.884307] agent systemd[1]: Reload requested from client PID 1774 ('systemctl') (unit flakelet-relay-job-app.service)...657agent # [1118734.884347] agent systemd[1]: Reloading...658agent # [1118735.217139] agent systemd[1]: Reloading finished in 332 ms.659agent # [1118735.290703] agent systemd[1]: Starting app slow2...660agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 6.50 seconds)661(finished: subtest: detach returns once the job is accepted, in 7.91 seconds)662subtest: unknown host is final, missing agent is retried, agents listing663client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1664client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)665agent: must succeed: systemctl stop flakelet-agent666agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.08 seconds)667relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'668relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)669client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &670client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)671client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out672agent # [1118741.363337] agent systemd[1]: Started app slow2.673agent # [1118741.370717] agent flakelet[1671]: app: updated to generation 4674agent # [1118741.372999] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.675agent # [1118741.412199] agent systemd[1]: Stopping flakelet-agent...676agent # [1118741.446386] agent systemd[1]: flakelet-agent.service: Deactivated successfully.677agent # [1118741.446810] agent systemd[1]: Stopped flakelet-agent.678agent # [1118741.447266] agent systemd[1]: flakelet-agent.service: Consumed 1.963s CPU time over 27.644s wall clock time.679relay # [1118741.412331] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:29.699736Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}680client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)681agent: must succeed: systemctl start flakelet-agent682agent: (finished: must succeed: systemctl start flakelet-agent, in 0.10 seconds)683??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.684 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39685client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out686agent # [1118742.544460] agent systemd[1]: Starting flakelet-agent...687agent # [1118742.604437] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:30.891890Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"8203995bd4cc07f2305145a76a28bdd5\"]","target":"flakelet_relay::agent::jobs"}688agent # [1118742.625653] agent systemd[1]: Started flakelet-agent.689agent # [1118742.636351] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:30.923837Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}690relay # [1118742.636532] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:30.923939Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}691agent # [1118743.141350] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:31.428766Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}692agent # [1118744.527788] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:32.815220Z","level":"INFO","message":"start","id":"1dd06823958af220abf7708ecd0aa01e","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}693agent # [1118744.528791] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:32.815972Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"1dd06823958af220abf7708ecd0aa01e\"]","target":"flakelet_relay::agent::jobs"}694agent # [1118744.561793] agent systemd[1]: Starting flakelet update other (via relay)...695agent # [1118744.596248] agent systemd[1]: Started flakelet update other (via relay).696agent # [1118744.601092] agent flakelet[2249]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1697agent # [1118744.601693] agent flakelet[2249]: other: up to date698agent # [1118744.602222] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.699relay # [1118744.527448] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:32.814860Z","level":"INFO","message":"deploy accepted","job":"50b530bfa9fd7387c67181077e64bb80","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}700agent # [1118746.144717] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:34.432169Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}701relay # [1118746.146248] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:34.433658Z","level":"INFO","message":"deploy finished","job":"50b530bfa9fd7387c67181077e64bb80","ok":true,"target":"flakelet_relay::relay::api"}702client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 4.06 seconds)703client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents704client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)705client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)706client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-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)707client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTM1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVUk5SV1BQQlA2WERRPT09IiwibmJmIjoxNzkwMjUxMDU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.UpmKgLfWrLzicAcKdlbRYvCRQkUdBWwCqbGxgXnCcaNzmTFCIGjPiZKd-Z1kyBXtQJqYyXsM9PAQYv6hHuKIAg' push --relay https://relay:7443 agents708client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTM1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMDU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVUk5SV1BQQlA2WERRPT09IiwibmJmIjoxNzkwMjUxMDU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.UpmKgLfWrLzicAcKdlbRYvCRQkUdBWwCqbGxgXnCcaNzmTFCIGjPiZKd-Z1kyBXtQJqYyXsM9PAQYv6hHuKIAg' push --relay https://relay:7443 agents, in 0.02 seconds)709(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 5.41 seconds)710subtest: out-of-band flakelet update reaches the relay without reconnect711agent: must succeed: flakelet status --json app | jq '.[0].generation'712agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.03 seconds)713agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true714agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)715agent: must succeed: jq '.services.app.prebuilt="/nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json716agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)717agent: must succeed: flakelet update app718app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2719app: activating generation 5720agent # [1118746.883130] agent systemd[1]: Stopping app slow2...721agent # [1118746.884839] agent systemd[1]: app.service: Deactivated successfully.722agent # [1118746.885132] agent systemd[1]: Stopped app slow2.723agent # [1118746.901529] agent systemd[1]: Reload requested from client PID 2288 ('systemctl')...724agent # [1118746.901600] agent systemd[1]: Reloading...725agent # [1118747.251946] agent systemd[1]: Reloading finished in 349 ms.726agent # [1118747.352754] agent systemd[1]: Reload requested from client PID 2317 ('systemctl')...727agent # [1118747.352794] agent systemd[1]: Reloading...728agent # [1118747.684392] agent systemd[1]: Reloading finished in 331 ms.729agent # [1118747.770795] agent systemd[1]: Reload requested from client PID 2345 ('systemctl')...730agent # [1118747.770837] agent systemd[1]: Reloading...731agent # [1118748.108366] agent systemd[1]: Reloading finished in 337 ms.732agent # [1118748.196741] agent systemd[1]: Reload requested from client PID 2374 ('systemctl')...733agent # [1118748.196782] agent systemd[1]: Reloading...734agent # [1118748.530126] agent systemd[1]: Reloading finished in 332 ms.735agent: (finished: must succeed: flakelet update app, in 1.81 seconds)736client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'737agent # [1118748.617761] agent systemd[1]: Starting app v2...738agent # [1118748.654301] agent systemd[1]: Started app v2.739client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.08 seconds)740agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true741agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)742client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-743client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-, in 0.02 seconds)744client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-745client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-, in 0.02 seconds)746agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json747agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)748agent: must succeed: flakelet update app749app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1750app: activating generation 6751agent # [1118750.654548] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:38.941959Z","level":"INFO","message":"local change","flakelet":"app","generation":5,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}752agent # [1118750.845050] agent systemd[1]: Stopping app v2...753agent # [1118750.845586] agent systemd[1]: app.service: Deactivated successfully.754agent # [1118750.845852] agent systemd[1]: Stopped app v2.755agent # [1118750.860036] agent systemd[1]: Reload requested from client PID 2424 ('systemctl')...756agent # [1118750.860077] agent systemd[1]: Reloading...757agent # [1118751.196041] agent systemd[1]: Reloading finished in 335 ms.758agent # [1118751.295934] agent systemd[1]: Reload requested from client PID 2453 ('systemctl')...759agent # [1118751.295973] agent systemd[1]: Reloading...760agent # [1118751.626403] agent systemd[1]: Reloading finished in 330 ms.761agent # [1118751.713474] agent systemd[1]: Reload requested from client PID 2481 ('systemctl')...762agent # [1118751.713514] agent systemd[1]: Reloading...763agent # [1118752.044440] agent systemd[1]: Reloading finished in 330 ms.764agent # [1118752.134376] agent systemd[1]: Reload requested from client PID 2510 ('systemctl')...765agent # [1118752.134417] agent systemd[1]: Reloading...766agent # [1118752.465747] agent systemd[1]: Reloading finished in 330 ms.767agent: (finished: must succeed: flakelet update app, in 1.78 seconds)768client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'769agent # [1118752.544812] agent systemd[1]: Starting app v1...770agent # [1118752.581202] agent systemd[1]: Started app v1.771agent # [1118752.647237] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:40.934667Z","level":"INFO","message":"local change","flakelet":"app","generation":6,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}772client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 1.05 seconds)773(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 6.85 seconds)774subtest: certificate not listed under agents cannot connect as agent775client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent776client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.03 seconds)777(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)778subtest: metrics779relay: must succeed: curl -sf http://127.0.0.1:7400/metrics780relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.02 seconds)781(finished: subtest: metrics, in 0.02 seconds)782subtest: agent link drop mid-run replays missed lines once783agent: must succeed: jq '.services.app.prebuilt="/nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json784agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)785agent: must succeed: date +%s786agent: (finished: must succeed: date +%s, in 0.01 seconds)787client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &788client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)789agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251061 | grep -q 'app-slow'790agent # [1118753.719132] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:42.006493Z","level":"INFO","message":"start","id":"ac91accd03e100102dd231a1a2b4cd95","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}791agent # [1118753.719986] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:42.007342Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ac91accd03e100102dd231a1a2b4cd95\"]","target":"flakelet_relay::agent::jobs"}792agent # [1118753.761595] agent systemd[1]: Starting flakelet update app (via relay)...793agent # [1118753.798295] agent systemd[1]: Started flakelet update app (via relay).794agent # [1118753.802910] agent flakelet[2559]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow795agent # [1118753.803556] agent flakelet[2559]: app: activating generation 7796agent # [1118753.822180] agent systemd[1]: Stopping app v1...797agent # [1118753.822636] agent systemd[1]: app.service: Deactivated successfully.798agent # [1118753.822900] agent systemd[1]: Stopped app v1.799agent # [1118753.840990] agent systemd[1]: Reload requested from client PID 2566 ('systemctl') (unit flakelet-relay-job-app.service)...800agent # [1118753.841074] agent systemd[1]: Reloading...801relay # [1118753.663111] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:41.950443Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}802relay # [1118753.718737] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:42.006175Z","level":"INFO","message":"deploy accepted","job":"11a3ef7c61da4a02f5bbff6b59d558a2","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}803agent # [1118754.186143] agent systemd[1]: Reloading finished in 344 ms.804agent # [1118754.269472] agent systemd[1]: Reload requested from client PID 2596 ('systemctl') (unit flakelet-relay-job-app.service)...805agent # [1118754.269513] agent systemd[1]: Reloading...806agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251061 | grep -q 'app-slow', in 1.02 seconds)807agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done808agent: (finished: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done, in 0.02 seconds)809relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done810relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)811agent: must succeed: ss -K dport = 7443812agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)813agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251061 | grep -q 'updated to generation'814agent # [1118754.602341] agent systemd[1]: Reloading finished in 332 ms.815agent # [1118754.684727] agent systemd[1]: Reload requested from client PID 2628 ('systemctl') (unit flakelet-relay-job-app.service)...816agent # [1118754.684764] agent systemd[1]: Reloading...817agent # [1118754.829922] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:43.117356Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}818relay # [1118754.799821] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:43.087236Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}819agent # [1118755.014840] agent systemd[1]: Reloading finished in 329 ms.820agent # [1118755.106045] agent systemd[1]: Reload requested from client PID 2674 ('systemctl') (unit flakelet-relay-job-app.service)...821agent # [1118755.106083] agent systemd[1]: Reloading...822agent # [1118755.437942] agent systemd[1]: Reloading finished in 331 ms.823agent # [1118755.539328] agent systemd[1]: Starting app slow...824agent # [1118755.832469] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:44.119907Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}825agent # [1118757.835824] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:46.123179Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}826agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251061 | grep -q 'updated to generation', in 7.11 seconds)827agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done828agent: (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)829client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out830agent # [1118761.635444] agent systemd[1]: Started app slow.831agent # [1118761.642415] agent flakelet[2559]: app: updated to generation 7832agent # [1118761.644913] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.833agent # [1118761.838250] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:50.125645Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}834agent # [1118762.675221] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:50.962637Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}835client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.09 seconds)836client: must succeed: cat /tmp/slow.out837client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)838(finished: subtest: agent link drop mid-run replays missed lines once, in 16.39 seconds)839subtest: agent restart mid-run reattaches to the unit840agent: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json841agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)842client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &843client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)844agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'845relay # [1118769.841795] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:58.129208Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}846agent # [1118769.841695] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:58.129103Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}847relay # [1118769.843366] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:58.130846Z","level":"INFO","message":"deploy finished","job":"11a3ef7c61da4a02f5bbff6b59d558a2","ok":true,"target":"flakelet_relay::relay::api"}848agent # [1118769.842921] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:58.130409Z","level":"INFO","message":"start","id":"ac91accd03e100102dd231a1a2b4cd95","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}849relay # [1118770.101272] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:58.388593Z","level":"INFO","message":"deploy accepted","job":"a121d4f09d3479b4cb3db45ad5b65c0f","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}850agent # [1118770.101714] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:58.389038Z","level":"INFO","message":"start","id":"94c5b24cec9eb2a22e4236d052c26186","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}851agent # [1118770.102321] agent flakelet-agent[1836]: {"timestamp":"2026-09-24T11:57:58.389811Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"94c5b24cec9eb2a22e4236d052c26186\"]","target":"flakelet_relay::agent::jobs"}852agent # [1118770.145543] agent systemd[1]: Starting flakelet update app (via relay)...853agent # [1118770.173385] agent systemd[1]: Started flakelet update app (via relay).854agent # [1118770.178999] agent flakelet[2795]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2855agent # [1118770.179789] agent flakelet[2795]: app: activating generation 8856agent # [1118770.198540] agent systemd[1]: Stopping app slow...857agent # [1118770.200217] agent systemd[1]: app.service: Deactivated successfully.858agent # [1118770.200487] agent systemd[1]: Stopped app slow.859agent # [1118770.217512] agent systemd[1]: Reload requested from client PID 2802 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [1118770.217583] agent systemd[1]: Reloading...861agent # [1118770.569748] agent systemd[1]: Reloading finished in 351 ms.862agent # [1118770.654681] agent systemd[1]: Reload requested from client PID 2836 ('systemctl') (unit flakelet-relay-job-app.service)...863agent # [1118770.654730] agent systemd[1]: Reloading...864agent # [1118770.992584] agent systemd[1]: Reloading finished in 337 ms.865agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)866agent: must succeed: systemctl restart flakelet-agent867agent # [1118771.077329] agent systemd[1]: Reload requested from client PID 2865 ('systemctl') (unit flakelet-relay-job-app.service)...868agent # [1118771.077376] agent systemd[1]: Reloading...869agent # [1118771.417365] agent systemd[1]: Reloading finished in 339 ms.870agent # [1118771.500522] agent systemd[1]: Stopping flakelet-agent...871agent # [1118771.508985] agent systemd[1]: Reload requested from client PID 2900 ('systemctl') (unit flakelet-relay-job-app.service)...872agent # [1118771.509032] agent systemd[1]: Reloading...873relay # [1118771.500988] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:57:59.788337Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}874agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.91 seconds)875agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"876agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)877client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out878agent # [1118771.856103] agent systemd[1]: Reloading finished in 346 ms.879agent # [1118771.931383] agent systemd[1]: flakelet-agent.service: Deactivated successfully.880agent # [1118771.931599] agent systemd[1]: Stopped flakelet-agent.881agent # [1118771.931615] agent systemd[1]: flakelet-agent.service: Consumed 1.070s CPU time over 29.386s wall clock time.882agent # [1118771.950690] agent systemd[1]: Starting app slow2...883agent # [1118771.951525] agent systemd[1]: Starting flakelet-agent...884agent # [1118772.002390] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:00.289871Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"94c5b24cec9eb2a22e4236d052c26186\"]","target":"flakelet_relay::agent::jobs"}885agent # [1118772.022102] agent systemd[1]: Started flakelet-agent.886agent # [1118772.035618] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:00.323099Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}887agent # [1118772.036877] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:00.324378Z","level":"INFO","message":"start","id":"94c5b24cec9eb2a22e4236d052c26186","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}888relay # [1118772.035787] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:58:00.323203Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}889agent # [1118778.014158] agent systemd[1]: Started app slow2.890agent # [1118778.023809] agent flakelet[2795]: app: updated to generation 8891agent # [1118778.027315] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.892relay # [1118778.587758] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:58:06.875184Z","level":"INFO","message":"deploy finished","job":"a121d4f09d3479b4cb3db45ad5b65c0f","ok":true,"target":"flakelet_relay::relay::api"}893agent # [1118778.586574] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:06.874011Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}894client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)895client: must succeed: cat /tmp/restart.out896client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)897agent: must succeed: systemctl is-active app.service898agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)899(finished: subtest: agent restart mid-run reattaches to the unit, in 9.07 seconds)900subtest: relay restart mid-run, push resumes via /v1/jobs901agent: must succeed: jq '.services.app.prebuilt="/nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json902agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)903agent: must succeed: date +%s904agent: (finished: must succeed: date +%s, in 0.01 seconds)905client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &906client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)907agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251087 | grep -q 'app-slow'908agent # [1118779.181337] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:07.468744Z","level":"INFO","message":"start","id":"463c0da5a0baaf6443971e55beb90d08","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}909agent # [1118779.181955] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:07.469441Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"463c0da5a0baaf6443971e55beb90d08\"]","target":"flakelet_relay::agent::jobs"}910agent # [1118779.221629] agent systemd[1]: Starting flakelet update app (via relay)...911agent # [1118779.257361] agent systemd[1]: Started flakelet update app (via relay).912agent # [1118779.261668] agent flakelet[3377]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow913agent # [1118779.262303] agent flakelet[3377]: app: activating generation 9914agent # [1118779.281462] agent systemd[1]: Stopping app slow2...915agent # [1118779.281920] agent systemd[1]: app.service: Deactivated successfully.916agent # [1118779.282201] agent systemd[1]: Stopped app slow2.917agent # [1118779.300820] agent systemd[1]: Reload requested from client PID 3384 ('systemctl') (unit flakelet-relay-job-app.service)...918agent # [1118779.300892] agent systemd[1]: Reloading...919relay # [1118779.180938] relay flakelet-relay[400]: {"timestamp":"2026-09-24T11:58:07.468373Z","level":"INFO","message":"deploy accepted","job":"750ee61ffac0c2f6a8d99d70c270513a","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}920agent # [1118779.651430] agent systemd[1]: Reloading finished in 349 ms.921agent # [1118779.735335] agent systemd[1]: Reload requested from client PID 3414 ('systemctl') (unit flakelet-relay-job-app.service)...922agent # [1118779.735373] agent systemd[1]: Reloading...923agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790251087 | grep -q 'app-slow', in 1.02 seconds)924relay: must succeed: systemctl restart flakelet-relay925agent # [1118780.070570] agent systemd[1]: Reloading finished in 334 ms.926agent # [1118780.154898] agent systemd[1]: Reload requested from client PID 3445 ('systemctl') (unit flakelet-relay-job-app.service)...927agent # [1118780.154935] agent systemd[1]: Reloading...928agent # [1118780.207391] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:08.494847Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}929relay # [1118780.206888] relay systemd[1]: Stopping flakelet-relay...930relay # [1118780.255764] relay systemd[1]: flakelet-relay.service: Deactivated successfully.931relay # [1118780.256167] relay systemd[1]: Stopped flakelet-relay.932relay # [1118780.256204] relay systemd[1]: flakelet-relay.service: Consumed 2.588s CPU time over 1min 8.222s wall clock time.933relay # [1118780.292474] relay systemd[1]: Starting flakelet-relay...934agent # [1118780.510111] agent systemd[1]: Reloading finished in 354 ms.935agent # [1118780.599714] agent systemd[1]: Reload requested from client PID 3481 ('systemctl') (unit flakelet-relay-job-app.service)...936agent # [1118780.599751] agent systemd[1]: Reloading...937agent # [1118780.940068] agent systemd[1]: Reloading finished in 339 ms.938agent # [1118781.028522] agent systemd[1]: Starting app slow...939agent # [1118781.210614] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:09.497883Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}940relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.54 seconds)941client: waiting for success: grep -q '» ok' /tmp/resume.out942relay # [1118781.732519] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:10.019934Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}943relay # [1118781.733332] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:10.020375Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}944relay # [1118781.733080] relay systemd[1]: Started flakelet-relay.945agent # [1118783.222810] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:11.510223Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}946relay # [1118783.223087] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:11.510465Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}947agent # [1118787.105548] agent systemd[1]: Started app slow.948agent # [1118787.115093] agent flakelet[3377]: app: updated to generation 9949agent # [1118787.118544] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.950relay # [1118787.227118] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:15.514563Z","level":"INFO","message":"job reattached","job":"750ee61ffac0c2f6a8d99d70c270513a","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}951agent # [1118788.186432] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:16.473846Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}952client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.09 seconds)953client: must succeed: cat /tmp/resume.out954client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)955(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.70 seconds)956subtest: job history comes from the agents and survives a relay restart957client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1958relay # [1118788.860043] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:17.147454Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}959agent # [1118788.860448] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:17.147851Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}960agent # [1118788.861186] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:17.148669Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}961agent # [1118788.903997] agent systemd[1]: Starting flakelet update other (via relay)...962agent # [1118788.941379] agent systemd[1]: Started flakelet update other (via relay).963agent # [1118788.947474] agent flakelet[3555]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1964agent # [1118788.948096] agent flakelet[3555]: other: up to date965agent # [1118788.948983] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.966client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.65 seconds)967relay: must succeed: systemctl restart flakelet-relay968agent # [1118789.488344] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:17.775759Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}969agent # [1118789.507149] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:17.794623Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}970relay # [1118789.489794] relay flakelet-relay[932]: {"timestamp":"2026-09-24T11:58:17.777239Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}971relay # [1118789.506870] relay systemd[1]: Stopping flakelet-relay...972relay # [1118789.544862] relay systemd[1]: flakelet-relay.service: Deactivated successfully.973relay # [1118789.545374] relay systemd[1]: Stopped flakelet-relay.974relay # [1118789.545421] relay systemd[1]: flakelet-relay.service: Consumed 2.110s CPU time over 9.252s wall clock time.975relay # [1118789.581093] relay systemd[1]: Starting flakelet-relay...976agent # [1118790.509605] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:18.797008Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}977relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.52 seconds)978relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'979relay # [1118791.010944] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:19.298356Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}980relay # [1118791.011747] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:19.298865Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}981relay # [1118791.011481] relay systemd[1]: Started flakelet-relay.982agent # [1118792.524638] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:20.812054Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}983relay # [1118792.524779] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:20.812182Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}984relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds)985client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs986client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)987client: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)988client: (finished: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/4y8k1nvlafnzaadg5frncjjarv7aw3ry-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)989client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTQwMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMTAxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzTVRKTlBJUzJWRFdNPT09IiwibmJmIjoxNzkwMjUxMTAxLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.lINMgbb0MANNMmTT1tSzLs1P29Ai55_vuUBCOJ5YDCV6-xd6TdU0n84tST_WPYddDDx4i121ejlWtumQgO_vAg' push --relay https://relay:7443 deploy --id hist2 agent/app990» job 6a239dbf87cfec796e49404c351d787f via relay 0.1.0 (agents: agent 0.1.0)991» wave 0992agent/app | Starting flakelet update app (via relay)...993agent/app | Started flakelet update app (via relay).994agent/app | app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow995agent/app | app: up to date996agent # [1118793.170757] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:21.458195Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"}997agent # [1118793.171388] agent flakelet-agent[2932]: {"timestamp":"2026-09-24T11:58:21.458880Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}998agent # [1118793.209944] agent systemd[1]: Starting flakelet update app (via relay)...999agent # [1118793.237159] agent systemd[1]: Started flakelet update app (via relay).1000agent # [1118793.242240] agent flakelet[3583]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1001agent # [1118793.242898] agent flakelet[3583]: app: up to date1002agent # [1118793.245331] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.1003agent/app | flakelet-relay-job-app.service: Deactivated successfully.1004relay # [1118793.170301] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:21.457727Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}1005» agent/app: unchanged (generation 9)1006» ok1007client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTQwMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMTAxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzTVRKTlBJUzJWRFdNPT09IiwibmJmIjoxNzkwMjUxMTAxLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.lINMgbb0MANNMmTT1tSzLs1P29Ai55_vuUBCOJ5YDCV6-xd6TdU0n84tST_WPYddDDx4i121ejlWtumQgO_vAg' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.64 seconds)1008client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTQwMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMTAxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzTVRKTlBJUzJWRFdNPT09IiwibmJmIjoxNzkwMjUxMTAxLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.lINMgbb0MANNMmTT1tSzLs1P29Ai55_vuUBCOJ5YDCV6-xd6TdU0n84tST_WPYddDDx4i121ejlWtumQgO_vAg' push --relay https://relay:7443 jobs1009client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDI1MTQwMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwMjUxMTAxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzTVRKTlBJUzJWRFdNPT09IiwibmJmIjoxNzkwMjUxMTAxLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.lINMgbb0MANNMmTT1tSzLs1P29Ai55_vuUBCOJ5YDCV6-xd6TdU0n84tST_WPYddDDx4i121ejlWtumQgO_vAg' push --relay https://relay:7443 jobs, in 0.02 seconds)1010(finished: subtest: job history comes from the agents and survives a relay restart, in 4.97 seconds)1011subtest: dashboard login via authorization code flow1012client: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login'1013client: (finished: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login', in 0.02 seconds)1014client: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login1015client: (finished: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.09 seconds)1016client: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs1017client: (finished: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)1018!!! Test "dashboard login via authorization code flow" failed with error: ""1019cleanup1020kill NspawnMachine (pid 52)1021kill NspawnMachine (pid 53)1022Container agent terminated by signal KILL.1023relay # [1118793.788480] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:22.075915Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1024relay # [1118793.864678] relay 7gsx6vaqmkb2vf8rr0w4y1g018hi9d43-device-mock[185]: 127.0.0.1 - - [24/Sep/2026 11:58:22] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=vWfvZLp8qwDvfD0IBDDJEn0YHMasVLtww-yDTP23VDQ&code_challenge=YW2Unp543V1T3NPLETFFxZhwb2lL9KAtlDxowwo2L8w&code_challenge_method=S256 HTTP/1.1" 302 -1025relay # [1118793.916767] relay 7gsx6vaqmkb2vf8rr0w4y1g018hi9d43-device-mock[185]: 127.0.0.1 - - [24/Sep/2026 11:58:22] "POST /token HTTP/1.1" 200 -1026relay # [1118793.917547] relay flakelet-relay[1322]: {"timestamp":"2026-09-24T11:58:22.205017Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1027kill NspawnMachine (pid 55)1028Container client terminated by signal KILL.1029(finished: cleanup, in 0.34 seconds)1030additionally exposed symbols:1031 agent, client, relay,1032 vlan1,1033 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_ssh1034» job 1871c3fd17edfdfcb76aed332435f41d via relay 0.1.0 (agents: agent 0.1.0)1035» wave 01036agent/app | Starting flakelet update app (via relay)...1037agent/app | Started flakelet update app (via relay).1038agent/app | app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v21039agent/app | app: activating generation 21040agent/app | app: updated to generation 21041agent/app | flakelet-relay-job-app.service: Deactivated successfully.1042» agent/app: updated (generation 2)1043» ok10441045» job 2feedd7e91a8f353c42fa3ee97c25d43 via relay 0.1.0 (agents: agent 0.1.0)1046» wave 01047agent/app | Starting flakelet update app (via relay)...1048agent/app | Started flakelet update app (via relay).1049agent/app | app: using prebuilt artifact /nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken1050agent/app | app: activating generation 41051agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1052agent/app | failed units: app.service. See journalctl -u app.service1053agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1054agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1055» agent/app: rolled-back (generation 3)1056agent/app │ Starting app v1...1057agent/app │ Started app v1.1058agent/app │ Stopping app v1...1059agent/app │ app.service: Deactivated successfully.1060agent/app │ Stopped app v1.1061agent/app │ Starting app v2...1062agent/app │ Started app v2.1063agent/app │ Stopping app v2...1064agent/app │ app.service: Deactivated successfully.1065agent/app │ Stopped app v2.1066agent/app │ Starting app v1...1067agent/app │ Started app v1.1068agent/app │ Stopping app v1...1069agent/app │ app.service: Deactivated successfully.1070agent/app │ Stopped app v1.1071agent/app │ Starting app broken...1072agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1073agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1074agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1075agent/app │ app.service: Failed with result 'exit-code'.1076agent/app │ Failed to start app broken.1077agent/app │ Starting app v1...1078agent/app │ Started app v1.1079» skipped: agent/other1080» failed10811082» job 11a3ef7c61da4a02f5bbff6b59d558a2 via relay 0.1.0 (agents: agent 0.1.0)1083» wave 01084agent/app | Starting flakelet update app (via relay)...1085agent/app | Started flakelet update app (via relay).1086agent/app | app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1087agent/app | app: activating generation 71088agent/app | app: updated to generation 71089agent/app | flakelet-relay-job-app.service: Deactivated successfully.1090» agent/app: updated (generation 7)1091» ok10921093» job a121d4f09d3479b4cb3db45ad5b65c0f via relay 0.1.0 (agents: agent 0.1.0)1094» wave 01095agent/app | Starting flakelet update app (via relay)...1096agent/app | Started flakelet update app (via relay).1097agent/app | app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow21098agent/app | app: activating generation 81099agent/app | app: updated to generation 81100agent/app | flakelet-relay-job-app.service: Deactivated successfully.1101» agent/app: updated (generation 8)1102» ok11031104» job 750ee61ffac0c2f6a8d99d70c270513a via relay 0.1.0 (agents: agent 0.1.0)1105» wave 01106agent/app | Starting flakelet update app (via relay)...1107agent/app | Started flakelet update app (via relay).1108agent/app | app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1109agent/app | app: activating generation 91110flakelet-push: stream: error reading a body from connection, resuming job ba06e9013ed242407d983748a5eb08fe1111flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1112flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1113flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1114» job 750ee61ffac0c2f6a8d99d70c270513a via relay 0.1.0 (agents: agent 0.1.0)1115» wave 01116agent/app | app: updated to generation 91117agent/app | flakelet-relay-job-app.service: Deactivated successfully.1118» agent/app: updated (generation 9)1119» ok112011211790251097 hist1 admin@example.org agent/other:unchanged11221790251087 ba06e9013ed242407d983748a5eb08fe admin@example.org agent/app:updated11231790251078 6416dc9854ff34b089f74a6bb79fdc3a admin@example.org agent/app:updated11241790251062 19a8da5978cf2a08888bed115cdcd869 admin@example.org agent/app:updated11251790251060 local-app-6-1790251060 root (shell) agent/app:updated11261790251056 local-app-5-1790251056 root (shell) agent/app:updated11271790251052 e1526e36a54fa5b10badfed7a0340029 admin@example.org agent/other:unchanged11281790251041 2a1723a12e9a30fb0c0543aa8b50a943 admin@example.org agent/app:unchanged11291790251041 36adedcd03ad08b6ca3aebdb619f23b6 admin@example.org agent/app:updated11301790251040 574fd2a0e6c176b93b19ffcde65edf9b admin@example.org agent/app:unchanged11311790251039 0380202514fd490c030680d7ee2f2a83 admin@example.org agent/app:unchanged11321790251035 8fda3fab2737ba048367e777c6fffb3b admin@example.org agent/app:rolled-back11331790251034 70d9ed21da305f4b22d4267326a7352e dev@example.org agent/other:unchanged11341790251034 b1f1bda563c13fa1a0977dffff4a9f37 dev@example.org agent/other:unchanged11351790251031 1e80f73d1cbf36e77e9eb96bd80d74d4 someone agent/other:unchanged11361790251028 a88ee4187cc3aed4b9f43615d3569972 repo:github:example/app:ref:refs/heads/main agent/app:updated11371790251025 f46c37388dded28a93e329ce6c334a4a admin@example.org agent/app:updated11381790251022 local-app-1-1790251022 host activation agent/app:updated11391790251022 local-flakelet-agent-1-1790251022 host activation agent/flakelet-agent:updated11401790251022 local-other-1-1790251022 host activation agent/other:updated11411142Traceback (most recent call last):1143 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/bin/.nixos-test-driver-wrapped", line 9, in <module>1144 sys.exit(main())1145 ~~~~^^1146 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/__init__.py", line 194, in main1147 driver.run_tests()1148 ~~~~~~~~~~~~~~~~^^1149 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 437, in run_tests1150 self.test_script()1151 ~~~~~~~~~~~~~~~~^^1152 File "/nix/store/1pfwbz29g35j2afnmzzhnp99xjq1kqx9-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 395, in test_script1153 exec(self.tests, symbols, None)1154 ~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^1155 File "<string>", line 208, in <module>1156AssertionError1157Container relay terminated by signal KILL.