container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #45
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 51)10agent: Waiting for journal at /build/vm-state-agent/var/log/journal...11client: systemd-nspawn running (pid 55)12relay: systemd-nspawn running (pid 56)13client: Waiting for journal at /build/vm-state-client/var/log/journal...14relay: Waiting for journal at /build/vm-state-relay/var/log/journal...15(finished: start all VMs, in 0.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.24░ Spawning container agent on /build/vm-state-agent.25Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.26Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.27░ Spawning container relay on /build/vm-state-relay.28░ Spawning container client on /build/vm-state-client.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31client # No journal files were found.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 # [1723876.723584] agent systemd-journald[57]: Journal started36agent # [1723876.723628] agent systemd-journald[57]: Runtime Journal (/run/log/journal/ea8a77b338724dfeb30912c983fb4987) is 8M, max 4G, 3.9G free.37agent # [1723876.733542] agent systemd[1]: Finished Apply Kernel Variables.38agent # [1723876.745651] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [1723876.760250] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [1723876.760828] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [1723876.794654] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/ea8a77b338724dfeb30912c983fb4987 is 1.623ms for 6 entries.42agent # [1723876.794654] agent systemd-journald[57]: System Journal (/var/log/journal/ea8a77b338724dfeb30912c983fb4987) is 512B, max 4G, 3.9G free.43agent # [1723876.802694] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [1723876.803484] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [1723876.803631] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [1723876.817281] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [1723876.881744] agent systemd[1]: Finished Firewall.48agent # [1723877.745776] agent systemd[1]: Mounting /run/wrappers...49client # [1723876.730924] client systemd-journald[57]: Journal started50client # [1723876.730967] client systemd-journald[57]: Runtime Journal (/run/log/journal/0e8c16792dcd41359486fb1a282938f5) is 8M, max 4G, 3.9G free.51client # [1723876.741708] client systemd[1]: Finished Apply Kernel Variables.52client # [1723876.753945] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.53client # [1723876.788590] client systemd[1]: Starting Flush Journal to Persistent Storage...54client # [1723876.789330] client systemd[1]: Starting Create Static Device Nodes in /dev...55client # [1723876.798326] client systemd-journald[57]: Time spent on flushing to /var/log/journal/0e8c16792dcd41359486fb1a282938f5 is 1.549ms for 6 entries.56client # [1723876.798326] client systemd-journald[57]: System Journal (/var/log/journal/0e8c16792dcd41359486fb1a282938f5) is 512B, max 4G, 3.9G free.57client # [1723876.808599] client systemd[1]: Finished Create Static Device Nodes in /dev.58client # [1723876.809540] client systemd[1]: Reached target Preparation for Local File Systems.59relay # [1723876.721241] relay systemd-journald[57]: Journal started60relay # [1723876.721282] relay systemd-journald[57]: Runtime Journal (/run/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342) is 8M, max 4G, 3.9G free.61client # [1723876.809686] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys62relay # [1723876.732065] relay systemd[1]: Finished Apply Kernel Variables.63client # [1723876.821708] client systemd[1]: Finished Flush Journal to Persistent Storage.64relay # [1723876.744757] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.65client # [1723876.892230] client systemd[1]: Finished Firewall.66relay # [1723876.759271] relay systemd[1]: Starting Flush Journal to Persistent Storage...67client # [1723877.745745] client systemd[1]: Mounting /run/wrappers...68relay # [1723876.760092] relay systemd[1]: Starting Create Static Device Nodes in /dev...69relay # [1723876.794126] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342 is 3.268ms for 6 entries.70relay # [1723876.794126] relay systemd-journald[57]: System Journal (/var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342) is 512B, max 4G, 3.9G free.71relay # [1723876.802752] relay systemd[1]: Finished Create Static Device Nodes in /dev.72relay # [1723876.803474] relay systemd[1]: Reached target Preparation for Local File Systems.73relay # [1723876.803594] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys74relay # [1723876.823442] relay systemd[1]: Finished Flush Journal to Persistent Storage.75relay # [1723876.892499] relay systemd[1]: Finished Firewall.76relay # [1723877.720242] relay systemd[1]: Mounting /run/wrappers...77client # [1723877.767699] client systemd[1]: Mounted /run/wrappers.78client # [1723877.768561] client systemd[1]: Reached target Local File Systems.79client # [1723877.769454] client systemd[1]: Listening on Boot Loader Control Service Socket.80client # [1723877.770484] client systemd[1]: Starting Create SUID/SGID Wrappers...81client # [1723877.770514] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container82client # [1723877.771250] client systemd[1]: Starting Save Transient machine-id to Disk...83client # [1723877.771968] client systemd[1]: Starting Create System Files and Directories...84client # [1723877.788917] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85client # [1723877.789325] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted86client # [1723877.789635] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/0e8c16792dcd41359486fb1a282938f5 failed: Operation not permitted87client # [1723877.789963] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted88relay # [1723877.777457] relay systemd[1]: Mounted /run/wrappers.89relay # [1723877.778552] relay systemd[1]: Reached target Local File Systems.90relay # [1723877.779823] relay systemd[1]: Listening on Boot Loader Control Service Socket.91relay # [1723877.781128] relay systemd[1]: Starting Create SUID/SGID Wrappers...92relay # [1723877.781159] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container93relay # [1723877.782058] relay systemd[1]: Starting Save Transient machine-id to Disk...94relay # [1723877.782936] relay systemd[1]: Starting Create System Files and Directories...95relay # [1723877.799690] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted96relay # [1723877.800127] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted97relay # [1723877.800431] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342 failed: Operation not permitted98relay # [1723877.800764] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted99agent # [1723877.777582] agent systemd[1]: Mounted /run/wrappers.100agent # [1723877.778888] agent systemd[1]: Reached target Local File Systems.101agent # [1723877.780345] agent systemd[1]: Listening on Boot Loader Control Service Socket.102agent # [1723877.781516] agent systemd[1]: Starting Create SUID/SGID Wrappers...103agent # [1723877.781562] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104agent # [1723877.782620] agent systemd[1]: Starting Save Transient machine-id to Disk...105agent # [1723877.783798] agent systemd[1]: Starting Create System Files and Directories...106agent # [1723877.802512] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted107agent # [1723877.802898] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108agent # [1723877.803198] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/ea8a77b338724dfeb30912c983fb4987 failed: Operation not permitted109agent # [1723877.803527] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110relay # [1723877.803998] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.Z82M0ZL3Ow/chsh': Operation not permitted111relay # [1723877.868480] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.112relay # [1723877.883546] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE113relay # [1723877.883584] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.114relay # [1723877.908213] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.115relay # [1723877.908449] relay systemd[1]: Finished Save Transient machine-id to Disk.116relay # [1723877.908764] relay systemd[1]: Finished Create System Files and Directories.117relay # [1723877.924213] relay systemd[1]: Starting Rebuild Journal Catalog...118relay # [1723877.925203] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...119relay # [1723877.937879] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.120relay # [1723877.943754] relay systemd[1]: Finished Rebuild Journal Catalog.121relay # [1723877.945629] relay systemd[1]: Starting Update is Completed...122relay # [1723877.956296] relay systemd[1]: Finished Update is Completed.123relay # [1723877.956383] relay systemd[1]: Reached target System Initialization.124relay # [1723877.956477] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container125relay # [1723877.956506] relay systemd[1]: Started Daily Cleanup of Temporary Directories.126relay # [1723877.956524] relay systemd[1]: Reached target Timer Units.127relay # [1723877.956633] relay systemd[1]: Listening on D-Bus System Message Bus Socket.128relay # [1723877.956808] relay systemd[1]: Listening on Nix Daemon Socket.129relay # [1723877.956907] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.130relay # [1723877.956921] relay systemd[1]: Reached target Socket Units.131relay # [1723877.956948] relay systemd[1]: Reached target Basic System.132relay # [1723877.958047] relay systemd[1]: Started device-mock.service.133relay # [1723877.958747] relay systemd[1]: Starting Re-link flakelet services at boot...134relay # [1723877.959738] relay systemd[1]: Starting Import lastlog data into lastlog2 database...135relay # [1723877.960768] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...136relay # [1723877.961650] relay systemd[1]: Starting resolvconf update...137client # [1723877.792805] client systemd[1]: Finished Create System Files and Directories.138client # [1723877.795579] client suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.bcp1gwo66l/chsh': Operation not permitted139client # [1723877.860215] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.140client # [1723877.871615] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE141client # [1723877.871712] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.142client # [1723877.871885] client systemd[1]: Failed to start Create SUID/SGID Wrappers.143client # [1723877.872112] client systemd[1]: Finished Save Transient machine-id to Disk.144client # [1723877.874894] client systemd[1]: Starting Rebuild Journal Catalog...145client # [1723877.876058] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...146client # [1723877.918168] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.147client # [1723877.924890] client systemd[1]: Finished Rebuild Journal Catalog.148client # [1723877.926326] client systemd[1]: Starting Update is Completed...149client # [1723877.936853] client systemd[1]: Finished Update is Completed.150client # [1723877.936943] client systemd[1]: Reached target System Initialization.151client # [1723877.937025] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container152client # [1723877.937048] client systemd[1]: Started Daily Cleanup of Temporary Directories.153client # [1723877.937061] client systemd[1]: Reached target Timer Units.154client # [1723877.937160] client systemd[1]: Listening on D-Bus System Message Bus Socket.155client # [1723877.937372] client systemd[1]: Listening on Nix Daemon Socket.156client # [1723877.937467] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.157client # [1723877.937481] client systemd[1]: Reached target Socket Units.158client # [1723877.937510] client systemd[1]: Reached target Basic System.159client # [1723877.938646] client systemd[1]: Starting Import lastlog data into lastlog2 database...160client # [1723877.939815] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...161client # [1723877.940555] client systemd[1]: Starting resolvconf update...162client # [1723877.954388] client systemd[1]: Finished Import lastlog data into lastlog2 database.163client # [1723878.018651] client systemd[1]: Finished resolvconf update.164agent # [1723877.803875] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.8IlBaCviYc/chsh': Operation not permitted165agent # [1723877.869076] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.166agent # [1723877.882770] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE167agent # [1723877.882806] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.168agent # [1723877.882859] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.169agent # [1723877.883053] agent systemd[1]: Finished Save Transient machine-id to Disk.170agent # [1723877.908523] agent systemd[1]: Finished Create System Files and Directories.171agent # [1723877.924235] agent systemd[1]: Starting Rebuild Journal Catalog...172agent # [1723877.925567] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...173agent # [1723877.938379] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.174agent # [1723877.942526] agent systemd[1]: Finished Rebuild Journal Catalog.175agent # [1723877.943548] agent systemd[1]: Starting Update is Completed...176agent # [1723877.952068] agent systemd[1]: Finished Update is Completed.177agent # [1723877.952193] agent systemd[1]: Reached target System Initialization.178agent # [1723877.952255] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container179agent # [1723877.952276] agent systemd[1]: Started Daily Cleanup of Temporary Directories.180agent # [1723877.952289] agent systemd[1]: Reached target Timer Units.181agent # [1723877.952381] agent systemd[1]: Listening on D-Bus System Message Bus Socket.182agent # [1723877.952565] agent systemd[1]: Listening on Nix Daemon Socket.183agent # [1723877.952657] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.184agent # [1723877.952670] agent systemd[1]: Reached target Socket Units.185agent # [1723877.952699] agent systemd[1]: Reached target Basic System.186agent # [1723877.953739] agent systemd[1]: Starting Re-link flakelet services at boot...187agent # [1723877.954373] agent systemd[1]: Starting Import lastlog data into lastlog2 database...188agent # [1723877.955182] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...189agent # [1723877.955831] agent systemd[1]: Starting resolvconf update...190agent # [1723877.963647] agent systemd[1]: Finished Re-link flakelet services at boot.191agent # [1723877.965172] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...192agent # [1723877.974733] agent systemd[1]: Finished Import lastlog data into lastlog2 database.193agent # [1723877.975077] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.194relay # [1723877.971294] relay systemd[1]: Finished Re-link flakelet services at boot.195relay # [1723877.972700] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...196relay # [1723877.978470] relay systemd[1]: Finished Import lastlog data into lastlog2 database.197relay # [1723877.984964] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.198relay # [1723878.046182] relay systemd[1]: nscd.service: Deactivated successfully.199relay # [1723878.046306] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).200relay # [1723878.048648] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...201relay # [1723878.084344] relay systemd[1]: Finished resolvconf update.202relay # [1723878.084565] relay systemd[1]: Reached target Preparation for Network.203relay # [1723878.085423] relay systemd[1]: Starting Address configuration of eth1...204relay # [1723878.086176] relay systemd[1]: Starting Extra networking commands....205relay # [1723878.107315] relay network-addresses-eth1-start[251]: adding address 192.168.1.3/24... done206relay # [1723878.110418] relay network-addresses-eth1-start[251]: adding address 2001:db8:1::3/64... done207relay # [1723878.114405] relay systemd[1]: Finished Address configuration of eth1.208relay # [1723878.154887] relay systemd[1]: Finished Extra networking commands..209relay # [1723878.154975] relay systemd[1]: Reached target Network.210relay # [1723878.160357] relay systemd[1]: Starting Dnsmasq Daemon...211relay # [1723878.166964] relay systemd[1]: Starting Nginx Web Server...212relay # [1723878.167727] relay systemd[1]: Starting Update flakelet service flakelet-relay...213relay # [1723878.209815] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/jfcc1waibf4w5cwgizlwlq212x74y7c1-flakelet-flakelet-relay214relay # [1723878.210471] relay flakelet[311]: flakelet-relay: activating generation 1215relay # [1723878.215558] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...216relay # [1723878.215597] relay systemd[1]: Reloading...217client # [1723878.019483] client systemd[1]: Reached target Preparation for Network.218client # [1723878.046288] client systemd[1]: Starting Address configuration of eth1...219client # [1723878.047303] client systemd[1]: Starting Extra networking commands....220client # [1723878.055783] client systemd[1]: nscd.service: Deactivated successfully.221client # [1723878.084289] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).222client # [1723878.087610] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...223client # [1723878.102569] client network-addresses-eth1-start[233]: adding address 192.168.1.2/24... done224client # [1723878.106238] client network-addresses-eth1-start[233]: adding address 2001:db8:1::2/64... done225client # [1723878.110214] client systemd[1]: Finished Address configuration of eth1.226client # [1723878.166899] client systemd[1]: nscd.service: Deactivated successfully.227client # [1723878.167056] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).228client # [1723878.168490] client systemd[1]: Finished Extra networking commands..229client # [1723878.169224] client systemd[1]: Reached target Network.230client # [1723878.200578] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...231agent # [1723878.046790] agent systemd[1]: nscd.service: Deactivated successfully.232agent # [1723878.047019] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).233agent # [1723878.084647] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...234agent # [1723878.084882] agent systemd[1]: Finished resolvconf update.235agent # [1723878.086121] agent systemd[1]: Reached target Preparation for Network.236agent # [1723878.087719] agent systemd[1]: Starting Address configuration of eth1...237agent # [1723878.088847] agent systemd[1]: Starting Extra networking commands....238agent # [1723878.109017] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done239agent # [1723878.112252] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done240agent # [1723878.117192] agent systemd[1]: Finished Address configuration of eth1.241agent # [1723878.171959] agent systemd[1]: nscd.service: Deactivated successfully.242agent # [1723878.200227] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).243agent # [1723878.202069] agent systemd[1]: Finished Extra networking commands..244agent # [1723878.202862] agent systemd[1]: Reached target Network.245agent # [1723878.204091] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...246agent # [1723878.204920] agent systemd[1]: Starting Update flakelet service app...247agent # [1723878.205953] agent systemd[1]: Starting Update flakelet service flakelet-agent...248agent # [1723878.206953] agent systemd[1]: Starting Update flakelet service other...249agent # [1723878.216236] agent flakelet[308]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1250agent # [1723878.216774] agent flakelet[308]: app: activating generation 1251agent # [1723878.217902] agent flakelet[309]: flakelet-agent: using prebuilt artifact /nix/store/aj0lf71lc5h1sqimklbn8wyidli7z0sx-flakelet-flakelet-agent252agent # [1723878.218437] agent flakelet[309]: flakelet-agent: activating generation 1253agent # [1723878.219835] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-app.service)...254agent # [1723878.219872] agent systemd[1]: Reloading...255agent # [1723878.220174] agent flakelet[310]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1256agent # [1723878.220672] agent flakelet[310]: other: activating generation 1257relay # [1723878.499890] relay nsncd[242]: Oct 01 12:03:06.787 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"258relay # [1723878.624707] relay systemd[1]: Reloading finished in 408 ms.259client # [1723878.549727] client nsncd[303]: Oct 01 12:03:06.837 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"260client # [1723878.549728] client systemd[1]: Started Name Service Cache Daemon (nsncd).261client # [1723878.549813] client systemd[1]: Reached target Host and Network Name Lookups.262client # [1723878.549930] client systemd[1]: Reached target User and Group Name Lookups.263client # [1723878.552540] client systemd[1]: Starting User Login Management...264client # [1723878.554030] client systemd[1]: Starting Permit User Sessions...265client # [1723878.590210] client systemd[1]: Finished Permit User Sessions.266client # [1723878.591559] client systemd[1]: Started Console Getty.267client # [1723878.591583] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0268client # [1723878.591595] client systemd[1]: Reached target Login Prompts.269agent # [1723878.556045] agent nsncd[307]: Oct 01 12:03:06.843 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"270agent # [1723878.628845] agent systemd[1]: Reloading finished in 408 ms.271agent # [1723878.763904] agent systemd[1]: Started Name Service Cache Daemon (nsncd).272agent # [1723878.767011] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-flakelet-agent.service)...273agent # [1723878.767056] agent systemd[1]: Reloading...274relay # [1723878.763380] relay systemd[1]: Started Name Service Cache Daemon (nsncd).275relay # [1723878.763867] relay systemd[1]: Reached target Host and Network Name Lookups.276relay # [1723878.763950] relay systemd[1]: Reached target User and Group Name Lookups.277relay # [1723878.765112] relay systemd[1]: Starting User Login Management...278relay # [1723878.765865] relay systemd[1]: Starting Permit User Sessions...279relay # [1723878.786978] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...280relay # [1723878.787052] relay systemd[1]: Reloading...281relay # [1723878.850348] relay dnsmasq-pre-start[375]: dnsmasq: syntax check OK.282agent # [1723879.154383] agent systemd[1]: Reloading finished in 386 ms.283agent # [1723879.297154] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-other.service)...284agent # [1723879.297203] agent systemd[1]: Reloading...285relay # [1723879.148110] relay systemd[1]: Reloading finished in 360 ms.286relay # [1723879.268603] relay systemd[1]: Finished Permit User Sessions.287relay # [1723879.272616] relay systemd[1]: Started Console Getty.288relay # [1723879.272684] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0289relay # [1723879.272749] relay systemd[1]: Reached target Login Prompts.290relay # [1723879.296471] relay systemd[1]: Starting flakelet-relay...291agent # [1723879.641572] agent systemd[1]: Reloading finished in 343 ms.292agent # [1723879.717699] agent systemd[1]: Reached target Host and Network Name Lookups.293agent # [1723879.717761] agent systemd[1]: Reached target User and Group Name Lookups.294agent # [1723879.719144] agent systemd[1]: Starting User Login Management...295agent # [1723879.720149] agent systemd[1]: Starting Permit User Sessions...296agent # [1723879.724172] agent systemd[1]: Reload requested from client PID 405 ('systemctl') (unit flakelet-flakelet-agent.service)...297agent # [1723879.724204] agent systemd[1]: Reloading...298relay # [1723879.768125] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/rwna8pp008by3mwnv5bx8ims12jy7ca2-nginx.conf syntax is ok299relay # [1723879.768746] relay nginx-pre-start[402]: nginx: configuration file /nix/store/rwna8pp008by3mwnv5bx8ims12jy7ca2-nginx.conf test is successful300relay # [1723879.801300] relay systemd[1]: Started Nginx Web Server.301relay # [1723879.889896] relay systemd[1]: Starting D-Bus System Message Bus...302client # [1723879.959131] client systemd-logind[315]: New seat seat0.303client # [1723879.959672] client systemd[1]: Started User Login Management.304client # [1723879.961888] client systemd[1]: Starting D-Bus System Message Bus...305client # [1723879.963485] client systemd[1]: Starting linger-users.service...306client # [1723880.002489] client systemd[1]: linger-users.service: Deactivated successfully.307client # [1723880.002862] client systemd[1]: Finished linger-users.service.308client # [1723880.003217] client systemd[1]: Reached target Multi-User System.309relay # [1723880.188223] relay systemd-logind[354]: New seat seat0.310relay # [1723880.188657] relay systemd[1]: Started User Login Management.311relay # [1723880.192438] relay systemd[1]: Starting linger-users.service...312relay # [1723880.232257] relay systemd[1]: linger-users.service: Deactivated successfully.313relay # [1723880.232611] relay systemd[1]: Finished linger-users.service.314relay # [1723880.434403] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...315relay # [1723880.435970] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'316relay # [1723880.435970] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/95gfk1imjmlbwin4q78zl8gp4aam6lf4-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"317relay # [1723880.436921] relay systemd[1]: Started D-Bus System Message Bus.318agent # [1723880.130145] agent systemd[1]: Reloading finished in 405 ms.319agent # [1723880.195147] agent systemd[1]: Finished Permit User Sessions.320agent # [1723880.220628] agent systemd[1]: Started Console Getty.321agent # [1723880.220696] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0322agent # [1723880.220768] agent systemd[1]: Reached target Login Prompts.323agent # [1723880.225208] agent systemd[1]: Reload requested from client PID 409 ('systemctl') (unit flakelet-app.service)...324agent # [1723880.225237] agent systemd[1]: Reloading...325relay # [1723880.441963] relay dbus-broker-launch[408]: Ready326relay # [1723880.445384] relay systemd[1]: Started Dnsmasq Daemon.327relay # [1723880.448058] relay dnsmasq[394]: started, version 2.93 cachesize 150328relay # [1723880.448124] 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 dumpfile329relay # [1723880.448138] relay dnsmasq[394]: DBus support enabled: connected to system bus330relay # [1723880.448154] relay dnsmasq[394]: no upstream servers configured - please set them from DBus331relay # [1723880.448314] relay dnsmasq[394]: read /etc/hosts - 9 names332client # [1723880.498887] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...333client # [1723880.500079] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'334client # [1723880.500079] client dbus-broker-launch[325]: Invalid user-name in /nix/store/87clbw76nins7jrhaxxqysv9xs5dc1i5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"335client # [1723880.500644] client systemd[1]: Started D-Bus System Message Bus.336client # [1723880.501126] client systemd[1]: Startup finished in 4.216s.337client # [1723880.507060] client dbus-broker-launch[325]: Ready338agent # [1723880.578920] agent systemd[1]: Reloading finished in 353 ms.339agent # [1723880.653394] agent systemd[1]: Starting flakelet-agent...340agent # [1723880.653605] agent systemd[1]: Reload requested from client PID 444 ('systemctl') (unit flakelet-other.service)...341agent # [1723880.653653] agent systemd[1]: Reloading...342agent # [1723880.718663] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:09.006123Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}343agent # [1723880.992112] agent systemd[1]: Reloading finished in 338 ms.344agent # [1723881.075430] agent systemd[1]: Started flakelet-agent.345agent # [1723881.081371] agent systemd[1]: Starting app v1...346agent # [1723881.083060] agent systemd[1]: Starting other v1...347agent # [1723881.087475] agent flakelet[309]: flakelet-agent: updated to generation 1348agent # [1723881.113202] agent systemd[1]: Finished Update flakelet service flakelet-agent.349agent # [1723881.117680] agent systemd[1]: Started other v1.350agent # [1723881.117825] agent systemd-logind[407]: New seat seat0.351agent # [1723881.117830] agent systemd[1]: Started app v1.352agent # [1723881.117980] agent systemd[1]: Started User Login Management.353agent # [1723881.120533] agent systemd[1]: Starting D-Bus System Message Bus...354agent # [1723881.121423] agent systemd[1]: Starting linger-users.service...355agent # [1723881.124820] agent flakelet[310]: other: updated to generation 1356agent # [1723881.125290] agent flakelet[308]: app: updated to generation 1357agent # [1723881.127591] agent systemd[1]: Finished Update flakelet service app.358agent # [1723881.127812] agent systemd[1]: Finished Update flakelet service other.359agent # [1723881.128618] agent systemd[1]: Reached target flakelet managed services.360agent # [1723881.134759] agent systemd[1]: linger-users.service: Deactivated successfully.361agent # [1723881.134904] agent systemd[1]: Finished linger-users.service.362agent # [1723881.135076] agent systemd[1]: Reached target Multi-User System.363relay # [1723881.274174] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:09.561605Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}364relay # [1723881.274962] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:09.562144Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}365relay # [1723881.274767] relay systemd[1]: Started flakelet-relay.366relay # [1723881.285630] relay systemd[1]: Starting health for flakelet-relay...367relay # [1723881.549120] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.368relay # [1723881.549543] relay systemd[1]: Finished health for flakelet-relay.369relay # [1723881.568036] relay flakelet[311]: flakelet-relay: updated to generation 1370relay # [1723881.570873] relay systemd[1]: Finished Update flakelet service flakelet-relay.371relay # [1723881.571472] relay systemd[1]: Reached target flakelet managed services.372relay # [1723881.571659] relay systemd[1]: Reached target Multi-User System.373relay # [1723881.571906] relay systemd[1]: Startup finished in 5.288s.374relay: (finished: waiting for unit flakelet-relay.service, in 6.17 seconds)375relay: waiting for unit nginx.service376relay: (finished: waiting for unit nginx.service, in 0.02 seconds)377agent: waiting for unit flakelet.target378agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)379agent: waiting for unit flakelet-agent.service380agent # [1723881.569581] agent dbus-broker-launch[897]: Looking up NSS user entry for 'systemd-timesync'...381agent # [1723881.571148] agent dbus-broker-launch[897]: NSS returned no entry for 'systemd-timesync'382agent # [1723881.571148] agent dbus-broker-launch[897]: Invalid user-name in /nix/store/jg4hdwp4bn0pbiqkxaybjr51bdgpqjb9-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"383agent # [1723881.571649] agent systemd[1]: Started D-Bus System Message Bus.384agent # [1723881.577077] agent systemd[1]: Startup finished in 5.293s.385agent # [1723881.577718] agent dbus-broker-launch[897]: Ready386agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)387client: waiting for unit multi-user.target388client: (finished: waiting for unit multi-user.target, in 0.02 seconds)389relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'390relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 1.03 seconds)391agent: must succeed: systemctl is-active app.service other.service392agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)393subtest: deploy with client certificate, relay found via SRV394agent: 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.json395agent: (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.02 seconds)396client: 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>&1397relay # [1723882.733071] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:11.020496Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: None, revision: None }, Named { name: \"flakelet-agent\", generation: None, revision: None }, Named { name: \"other\", generation: None, revision: None }]","target":"flakelet_relay::relay::agent_conn"}398relay # [1723883.077487] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:11.364813Z","level":"INFO","message":"deploy accepted","job":"86a81216942784b0ee6f88e96d36cd9e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}399agent # [1723882.733036] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.020444Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}400agent # [1723882.744954] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.032437Z","level":"INFO","message":"local change","flakelet":"app","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}401agent # [1723882.745389] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.032883Z","level":"INFO","message":"local change","flakelet":"flakelet-agent","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}402agent # [1723882.745585] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.033073Z","level":"INFO","message":"local change","flakelet":"other","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}403agent # [1723883.077874] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.365130Z","level":"INFO","message":"start","id":"ec90ace156c268c796fbd51fd41b4977","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}404agent # [1723883.078126] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.365484Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ec90ace156c268c796fbd51fd41b4977\"]","target":"flakelet_relay::agent::jobs"}405agent # [1723883.116284] agent systemd[1]: Starting flakelet update app (via relay)...406agent # [1723883.145241] agent systemd[1]: Started flakelet update app (via relay).407agent # [1723883.150068] agent flakelet[921]: app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2408agent # [1723883.150780] agent flakelet[921]: app: activating generation 2409agent # [1723883.169063] agent systemd[1]: Stopping app v1...410agent # [1723883.170731] agent systemd[1]: app.service: Deactivated successfully.411agent # [1723883.171014] agent systemd[1]: Stopped app v1.412agent # [1723883.188121] agent systemd[1]: Reload requested from client PID 928 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [1723883.188190] agent systemd[1]: Reloading...414agent # [1723883.537029] agent systemd[1]: Reloading finished in 348 ms.415agent # [1723883.613711] agent systemd[1]: Reload requested from client PID 958 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [1723883.613750] agent systemd[1]: Reloading...417agent # [1723883.949132] agent systemd[1]: Reloading finished in 334 ms.418agent # [1723884.035079] agent systemd[1]: Reload requested from client PID 987 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [1723884.035120] agent systemd[1]: Reloading...420agent # [1723884.368965] agent systemd[1]: Reloading finished in 333 ms.421agent # [1723884.441795] agent systemd[1]: Reload requested from client PID 1018 ('systemctl') (unit flakelet-relay-job-app.service)...422agent # [1723884.441832] agent systemd[1]: Reloading...423agent # [1723884.777238] agent systemd[1]: Reloading finished in 335 ms.424agent # [1723884.846899] agent systemd[1]: Starting app v2...425agent # [1723884.885344] agent systemd[1]: Started app v2.426agent # [1723884.891404] agent flakelet[921]: app: updated to generation 2427agent # [1723884.894453] 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.92 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.02 seconds)435(finished: subtest: deploy with client certificate, relay found via SRV, in 2.99 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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/app 2>&1442agent # [1723885.970134] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.257563Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}443agent # [1723886.132581] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.419923Z","level":"INFO","message":"start","id":"71272a98b77e554d9fda8f48706b143d","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"}444agent # [1723886.132797] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.420298Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"71272a98b77e554d9fda8f48706b143d\"]","target":"flakelet_relay::agent::jobs"}445agent # [1723886.170616] agent systemd[1]: Starting flakelet update app (via relay)...446agent # [1723886.199166] agent systemd[1]: Started flakelet update app (via relay).447agent # [1723886.203025] agent flakelet[1087]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1448agent # [1723886.203669] agent flakelet[1087]: app: activating generation 3449agent # [1723886.218367] agent systemd[1]: Stopping app v2...450agent # [1723886.218814] agent systemd[1]: app.service: Deactivated successfully.451agent # [1723886.219085] agent systemd[1]: Stopped app v2.452agent # [1723886.236503] agent systemd[1]: Reload requested from client PID 1094 ('systemctl') (unit flakelet-relay-job-app.service)...453agent # [1723886.236575] agent systemd[1]: Reloading...454relay # [1723885.971381] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:14.258794Z","level":"INFO","message":"deploy finished","job":"86a81216942784b0ee6f88e96d36cd9e","ok":true,"target":"flakelet_relay::relay::api"}455relay # [1723886.132238] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:14.419692Z","level":"INFO","message":"deploy accepted","job":"34297ea70f89701d7d9bb78619ec8d12","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}456agent # [1723886.584759] agent systemd[1]: Reloading finished in 347 ms.457agent # [1723886.659521] agent systemd[1]: Reload requested from client PID 1124 ('systemctl') (unit flakelet-relay-job-app.service)...458agent # [1723886.659562] agent systemd[1]: Reloading...459agent # [1723886.991834] agent systemd[1]: Reloading finished in 331 ms.460agent # [1723887.081330] agent systemd[1]: Reload requested from client PID 1156 ('systemctl') (unit flakelet-relay-job-app.service)...461agent # [1723887.081367] agent systemd[1]: Reloading...462agent # [1723887.421640] agent systemd[1]: Reloading finished in 339 ms.463agent # [1723887.517180] agent systemd[1]: Reload requested from client PID 1188 ('systemctl') (unit flakelet-relay-job-app.service)...464agent # [1723887.517216] agent systemd[1]: Reloading...465agent # [1723887.853373] agent systemd[1]: Reloading finished in 335 ms.466agent # [1723887.937618] agent systemd[1]: Starting app v1...467agent # [1723887.969215] agent systemd[1]: Started app v1.468agent # [1723887.974052] agent flakelet[1087]: app: updated to generation 3469agent # [1723887.976411] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.470client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.96 seconds)471(finished: subtest: deploy with OIDC token, sub principal, in 3.03 seconds)472subtest: policy denies uncovered target473client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/other 2>&1474client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' 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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDg1NjE5NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMjVHQTJUSTJRM0ZPND09PSIsIm5iZiI6MTc5MDg1NjE5Nywic3ViIjoic29tZW9uZSJ9.qTwWmVDFk7U2Z5X5yNOBB8po7yAJuJD6msGKcbThh73ecXMNGENJZbvM4PZxFgIncZMB6uTGtxCOwQjNUEI1CQ' push --relay https://relay:7443 deploy agent/other 2>&1480relay # [1723889.055603] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:17.343012Z","level":"INFO","message":"deploy finished","job":"34297ea70f89701d7d9bb78619ec8d12","ok":true,"target":"flakelet_relay::relay::api"}481relay # [1723889.158574] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:17.446032Z","level":"INFO","message":"deploy accepted","job":"87ef92a677acc0f8f4b6a914fbf1987c","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}482agent # [1723889.054216] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.341627Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}483agent # [1723889.159108] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.446428Z","level":"INFO","message":"start","id":"1bc1ae54859c737c0bfe42337f68e065","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"}484agent # [1723889.159432] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.446926Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"1bc1ae54859c737c0bfe42337f68e065\"]","target":"flakelet_relay::agent::jobs"}485agent # [1723889.201420] agent systemd[1]: Starting flakelet update other (via relay)...486agent # [1723889.234259] agent systemd[1]: Started flakelet update other (via relay).487agent # [1723889.239208] agent flakelet[1242]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1488agent # [1723889.239671] agent flakelet[1242]: other: up to date489agent # [1723889.242207] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.490client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDg1NjE5NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMjVHQTJUSTJRM0ZPND09PSIsIm5iZiI6MTc5MDg1NjE5Nywic3ViIjoic29tZW9uZSJ9.qTwWmVDFk7U2Z5X5yNOBB8po7yAJuJD6msGKcbThh73ecXMNGENJZbvM4PZxFgIncZMB6uTGtxCOwQjNUEI1CQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds)491(finished: subtest: claim principal from groups, unchanged counts as success, in 0.70 seconds)492subtest: push login via device flow, cached token used afterwards493client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1494relay # [1723889.783788] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:18.071195Z","level":"INFO","message":"deploy finished","job":"87ef92a677acc0f8f4b6a914fbf1987c","ok":true,"target":"flakelet_relay::relay::api"}495relay # [1723889.807359] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:18] "POST /device HTTP/1.1" 200 -496agent # [1723889.782418] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:18.069827Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}497relay # [1723890.812459] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:19] "POST /token HTTP/1.1" 400 -498client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 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>&1502agent # [1723891.891794] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.179245Z","level":"INFO","message":"start","id":"3e233ab2eb367d8740e8b7a62d9933ee","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}503agent # [1723891.892640] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.179961Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3e233ab2eb367d8740e8b7a62d9933ee\"]","target":"flakelet_relay::agent::jobs"}504agent # [1723891.935492] agent systemd[1]: Starting flakelet update other (via relay)...505agent # [1723891.969612] agent systemd[1]: Started flakelet update other (via relay).506agent # [1723891.974923] agent flakelet[1266]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1507agent # [1723891.975467] agent flakelet[1266]: other: up to date508agent # [1723891.976924] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.509relay # [1723891.859922] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:20] "POST /token HTTP/1.1" 200 -510relay # [1723891.891378] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.178832Z","level":"INFO","message":"deploy accepted","job":"95053516e55514095bfa17b77df7c77e","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}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>&1513relay # [1723892.517312] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.804722Z","level":"INFO","message":"deploy finished","job":"95053516e55514095bfa17b77df7c77e","ok":true,"target":"flakelet_relay::relay::api"}514relay # [1723892.535968] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.823415Z","level":"INFO","message":"deploy accepted","job":"84cc3b1f030bc93248646e4b449d2570","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}515agent # [1723892.516306] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.803738Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}516agent # [1723892.536291] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.823779Z","level":"INFO","message":"start","id":"fff8bfaab99afe8c63d44872308c7058","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}517agent # [1723892.536494] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.823995Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"fff8bfaab99afe8c63d44872308c7058\"]","target":"flakelet_relay::agent::jobs"}518agent # [1723892.575795] agent systemd[1]: Starting flakelet update other (via relay)...519agent # [1723892.604249] agent systemd[1]: Started flakelet update other (via relay).520agent # [1723892.608709] agent flakelet[1286]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1521agent # [1723892.609277] agent flakelet[1286]: other: up to date522agent # [1723892.612581] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.523client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)524(finished: subtest: push login via device flow, cached token used afterwards, in 3.37 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 # [1723893.154690] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.442153Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}530agent # [1723893.192083] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.479564Z","level":"INFO","message":"start","id":"cc564c1f4cf1d674dd817f94d316c731","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}531agent # [1723893.192305] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.479805Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cc564c1f4cf1d674dd817f94d316c731\"]","target":"flakelet_relay::agent::jobs"}532agent # [1723893.230165] agent systemd[1]: Starting flakelet update app (via relay)...533agent # [1723893.263187] agent systemd[1]: Started flakelet update app (via relay).534agent # [1723893.267771] agent flakelet[1313]: app: using prebuilt artifact /nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken535agent # [1723893.268446] agent flakelet[1313]: app: activating generation 4536agent # [1723893.286282] agent systemd[1]: Stopping app v1...537agent # [1723893.286735] agent systemd[1]: app.service: Deactivated successfully.538agent # [1723893.286996] agent systemd[1]: Stopped app v1.539agent # [1723893.304176] agent systemd[1]: Reload requested from client PID 1320 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [1723893.304244] agent systemd[1]: Reloading...541relay # [1723893.155538] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:21.442959Z","level":"INFO","message":"deploy finished","job":"84cc3b1f030bc93248646e4b449d2570","ok":true,"target":"flakelet_relay::relay::api"}542relay # [1723893.191801] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:21.479242Z","level":"INFO","message":"deploy accepted","job":"1c2a28ffb5c770daeba76919b2dbd4b1","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}543agent # [1723893.648933] agent systemd[1]: Reloading finished in 343 ms.544agent # [1723893.717845] agent systemd[1]: Reload requested from client PID 1350 ('systemctl') (unit flakelet-relay-job-app.service)...545agent # [1723893.717884] agent systemd[1]: Reloading...546agent # [1723894.050214] agent systemd[1]: Reloading finished in 331 ms.547agent # [1723894.116983] agent systemd[1]: Reload requested from client PID 1379 ('systemctl') (unit flakelet-relay-job-app.service)...548agent # [1723894.117029] agent systemd[1]: Reloading...549agent # [1723894.448309] agent systemd[1]: Reloading finished in 330 ms.550agent # [1723894.513401] agent systemd[1]: Reload requested from client PID 1410 ('systemctl') (unit flakelet-relay-job-app.service)...551agent # [1723894.513439] agent systemd[1]: Reloading...552agent # [1723894.844652] agent systemd[1]: Reloading finished in 330 ms.553agent # [1723894.921725] agent systemd[1]: Starting app broken...554agent # [1723894.929309] agent (nonexistent)[1443]: app.service: Unable to locate executable '/nonexistent': No such file or directory555agent # [1723894.929332] agent (nonexistent)[1443]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory556agent # [1723894.930119] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC557agent # [1723894.930215] agent systemd[1]: app.service: Failed with result 'exit-code'.558agent # [1723894.930414] agent systemd[1]: Failed to start app broken.559agent # [1723894.958940] agent systemd[1]: Reload requested from client PID 1450 ('systemctl') (unit flakelet-relay-job-app.service)...560agent # [1723894.959024] agent systemd[1]: Reloading...561agent # [1723895.315091] agent systemd[1]: Reloading finished in 355 ms.562agent # [1723895.382224] agent systemd[1]: Reload requested from client PID 1480 ('systemctl') (unit flakelet-relay-job-app.service)...563agent # [1723895.382262] agent systemd[1]: Reloading...564agent # [1723895.723291] agent systemd[1]: Reloading finished in 340 ms.565agent # [1723895.793040] agent systemd[1]: Reload requested from client PID 1510 ('systemctl') (unit flakelet-relay-job-app.service)...566agent # [1723895.793081] agent systemd[1]: Reloading...567agent # [1723896.135200] agent systemd[1]: Reloading finished in 341 ms.568agent # [1723896.225293] agent systemd[1]: Reload requested from client PID 1540 ('systemctl') (unit flakelet-relay-job-app.service)...569agent # [1723896.225332] agent systemd[1]: Reloading...570agent # [1723896.564619] agent systemd[1]: Reloading finished in 338 ms.571agent # [1723896.658242] agent systemd[1]: Starting app v1...572agent # [1723896.666180] agent systemd[1]: Started app v1.573agent # [1723896.667288] agent flakelet[1313]: app: deploy failed, rolled back: systemctl start app.service failed:574agent # [1723896.667288] agent flakelet[1313]: failed units: app.service. See journalctl -u app.service575agent # [1723896.670222] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE576agent # [1723896.670318] 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.17 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.21 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 # [1723897.338933] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.626379Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}586agent # [1723897.404312] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.691746Z","level":"INFO","message":"start","id":"2dd0b0d037d467162fa1f1ee764747ba","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}587agent # [1723897.404797] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.692289Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2dd0b0d037d467162fa1f1ee764747ba\"]","target":"flakelet_relay::agent::jobs"}588agent # [1723897.445551] agent systemd[1]: Starting flakelet update app (via relay)...589agent # [1723897.478151] agent systemd[1]: Started flakelet update app (via relay).590agent # [1723897.482442] agent flakelet[1600]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1591agent # [1723897.482986] agent flakelet[1600]: app: up to date592agent # [1723897.486542] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.593relay # [1723897.340355] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:25.627786Z","level":"INFO","message":"deploy finished","job":"1c2a28ffb5c770daeba76919b2dbd4b1","ok":false,"target":"flakelet_relay::relay::api"}594relay # [1723897.403955] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:25.691406Z","level":"INFO","message":"deploy accepted","job":"d5830c29e7096747f8d35e1896764a09","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>&1597relay # [1723898.026706] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.314151Z","level":"INFO","message":"deploy finished","job":"d5830c29e7096747f8d35e1896764a09","ok":true,"target":"flakelet_relay::relay::api"}598relay # [1723898.048244] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.335727Z","level":"INFO","message":"deploy accepted","job":"1c69bfa50585b5e8118fcb5919322db3","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}599agent # [1723898.025403] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.312859Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}600agent # [1723898.048538] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.336019Z","level":"INFO","message":"start","id":"b7d0c7772f3d115a6567d7f1550efcb1","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}601agent # [1723898.048915] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.336411Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"b7d0c7772f3d115a6567d7f1550efcb1\"]","target":"flakelet_relay::agent::jobs"}602agent # [1723898.087648] agent systemd[1]: Starting flakelet update app (via relay)...603agent # [1723898.121277] agent systemd[1]: Started flakelet update app (via relay).604agent # [1723898.126437] agent flakelet[1620]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1605agent # [1723898.126951] agent flakelet[1620]: app: up to date606agent # [1723898.128765] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.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>&1609agent # [1723898.668519] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.955969Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}610agent # [1723898.694154] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.981631Z","level":"INFO","message":"start","id":"e3b0d0f5a8789ec5d400876e577add73","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}611agent # [1723898.694526] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.982021Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e3b0d0f5a8789ec5d400876e577add73\"]","target":"flakelet_relay::agent::jobs"}612agent # [1723898.736038] agent systemd[1]: Starting flakelet update app (via relay)...613agent # [1723898.766177] agent systemd[1]: Started flakelet update app (via relay).614agent # [1723898.771359] agent flakelet[1643]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1615agent # [1723898.771880] agent flakelet[1643]: app: up to date616agent # [1723898.775015] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.617relay # [1723898.670176] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.957618Z","level":"INFO","message":"deploy finished","job":"1c69bfa50585b5e8118fcb5919322db3","ok":false,"target":"flakelet_relay::relay::api"}618relay # [1723898.693786] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.981276Z","level":"INFO","message":"deploy accepted","job":"0065dcf2edfacfd0037786fce8fc30f9","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}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.65 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.98 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.02 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.service629relay # [1723899.318566] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:27.606007Z","level":"INFO","message":"deploy finished","job":"0065dcf2edfacfd0037786fce8fc30f9","ok":false,"target":"flakelet_relay::relay::api"}630relay # [1723899.383209] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:27.670657Z","level":"INFO","message":"deploy accepted","job":"3a95e3c37847f25eff8ecdb03448ba0a","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}631agent # [1723899.316939] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.604386Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}632agent # [1723899.383562] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.670996Z","level":"INFO","message":"start","id":"394442565fd8040c1ee18df9a37e0e98","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}633agent # [1723899.384052] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.671546Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"394442565fd8040c1ee18df9a37e0e98\"]","target":"flakelet_relay::agent::jobs"}634agent # [1723899.427069] agent systemd[1]: Starting flakelet update app (via relay)...635agent # [1723899.457181] agent systemd[1]: Started flakelet update app (via relay).636agent # [1723899.462652] agent flakelet[1668]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2637agent # [1723899.463303] agent flakelet[1668]: app: activating generation 4638agent # [1723899.476317] agent systemd[1]: Stopping app v1...639agent # [1723899.478394] agent systemd[1]: app.service: Deactivated successfully.640agent # [1723899.478818] agent systemd[1]: Stopped app v1.641agent # [1723899.497250] agent systemd[1]: Reload requested from client PID 1675 ('systemctl') (unit flakelet-relay-job-app.service)...642agent # [1723899.497317] agent systemd[1]: Reloading...643agent # [1723899.841570] agent systemd[1]: Reloading finished in 343 ms.644agent # [1723899.908619] agent systemd[1]: Reload requested from client PID 1705 ('systemctl') (unit flakelet-relay-job-app.service)...645agent # [1723899.908657] agent systemd[1]: Reloading...646agent # [1723900.242360] agent systemd[1]: Reloading finished in 333 ms.647agent # [1723900.318595] agent systemd[1]: Reload requested from client PID 1734 ('systemctl') (unit flakelet-relay-job-app.service)...648agent # [1723900.318638] agent systemd[1]: Reloading...649agent # [1723900.649728] agent systemd[1]: Reloading finished in 330 ms.650agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.33 seconds)651??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.652 File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39653agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service654??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.655 File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39656agent # [1723900.722734] agent systemd[1]: Reload requested from client PID 1768 ('systemctl') (unit flakelet-relay-job-app.service)...657agent # [1723900.722774] agent systemd[1]: Reloading...658agent # [1723901.054818] agent systemd[1]: Reloading finished in 331 ms.659agent # [1723901.131547] agent systemd[1]: Starting app slow2...660agent # [1723907.202231] agent systemd[1]: Started app slow2.661agent # [1723907.211323] agent flakelet[1668]: app: updated to generation 4662agent # [1723907.212038] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.663agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.51 seconds)664(finished: subtest: detach returns once the job is accepted, in 8.88 seconds)665subtest: unknown host is final, missing agent is retried, agents listing666client: 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>&1667client: (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)668agent: must succeed: systemctl stop flakelet-agent669agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.08 seconds)670relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'671relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)672client: 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 &673client: (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)674client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out675relay # [1723908.258748] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:36.546168Z","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"}676agent # [1723908.258784] agent systemd[1]: Stopping flakelet-agent...677agent # [1723908.290411] agent systemd[1]: flakelet-agent.service: Deactivated successfully.678agent # [1723908.290875] agent systemd[1]: Stopped flakelet-agent.679agent # [1723908.291372] agent systemd[1]: flakelet-agent.service: Consumed 1.606s CPU time over 27.637s wall clock time.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/29sx6wcid88iz35qayaccsr67l3kdrpk-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 # [1723909.388183] agent systemd[1]: Starting flakelet-agent...687agent # [1723909.440957] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:37.728432Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"394442565fd8040c1ee18df9a37e0e98\"]","target":"flakelet_relay::agent::jobs"}688agent # [1723909.469359] agent systemd[1]: Started flakelet-agent.689agent # [1723909.479934] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:37.767405Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}690relay # [1723909.480061] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:37.767478Z","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 # [1723909.986661] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:38.274111Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}692agent # [1723911.375231] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:39.662642Z","level":"INFO","message":"start","id":"92fb2595afad90c3633d2e58de95a460","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}693agent # [1723911.376159] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:39.663233Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"92fb2595afad90c3633d2e58de95a460\"]","target":"flakelet_relay::agent::jobs"}694agent # [1723911.416610] agent systemd[1]: Starting flakelet update other (via relay)...695agent # [1723911.446310] agent systemd[1]: Started flakelet update other (via relay).696agent # [1723911.452273] agent flakelet[2249]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1697agent # [1723911.452797] agent flakelet[2249]: other: up to date698agent # [1723911.453718] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.699relay # [1723911.374738] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:39.662157Z","level":"INFO","message":"deploy accepted","job":"af7c52be6d90f55ed3d2ccda74a6ab02","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}700relay # [1723911.989757] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:40.277200Z","level":"INFO","message":"deploy finished","job":"af7c52be6d90f55ed3d2ccda74a6ab02","ok":true,"target":"flakelet_relay::relay::api"}701agent # [1723911.987989] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:40.275437Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}702client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjUyMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjIwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJETlNDSlhWNzc0VFpRPT09IiwibmJmIjoxNzkwODU2MjIwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.6DVP9prSfsBefadS7ChNErffEzyfcm6OE6GN2pnt0gafLsKB3zcdZQv7EFNJ2LIQl9QNyEvNeXA61jrgpm4AAA' push --relay https://relay:7443 agents708client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjUyMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjIwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJETlNDSlhWNzc0VFpRPT09IiwibmJmIjoxNzkwODU2MjIwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.6DVP9prSfsBefadS7ChNErffEzyfcm6OE6GN2pnt0gafLsKB3zcdZQv7EFNJ2LIQl9QNyEvNeXA61jrgpm4AAA' push --relay https://relay:7443 agents, in 0.02 seconds)709(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.38 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 # [1723912.700148] agent systemd[1]: Stopping app slow2...721agent # [1723912.700609] agent systemd[1]: app.service: Deactivated successfully.722agent # [1723912.700880] agent systemd[1]: Stopped app slow2.723agent # [1723912.719331] agent systemd[1]: Reload requested from client PID 2283 ('systemctl')...724agent # [1723912.719401] agent systemd[1]: Reloading...725agent # [1723913.064664] agent systemd[1]: Reloading finished in 344 ms.726agent # [1723913.153688] agent systemd[1]: Reload requested from client PID 2312 ('systemctl')...727agent # [1723913.153730] agent systemd[1]: Reloading...728agent # [1723913.484816] agent systemd[1]: Reloading finished in 330 ms.729agent # [1723913.555543] agent systemd[1]: Reload requested from client PID 2342 ('systemctl')...730agent # [1723913.555583] agent systemd[1]: Reloading...731agent # [1723913.888718] agent systemd[1]: Reloading finished in 332 ms.732agent # [1723913.953660] agent systemd[1]: Reload requested from client PID 2373 ('systemctl')...733agent # [1723913.953709] agent systemd[1]: Reloading...734agent: (finished: must succeed: flakelet update app, in 1.72 seconds)735client: 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'736agent # [1723914.285554] agent systemd[1]: Reloading finished in 331 ms.737agent # [1723914.352986] agent systemd[1]: Starting app v2...738agent # [1723914.377095] agent systemd[1]: Started app v2.739agent # [1723915.490290] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:43.777755Z","level":"INFO","message":"local change","flakelet":"app","generation":5,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}740client: (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.07 seconds)741agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true742agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)743client: 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-744client: (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)745client: 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-746client: (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)747agent: 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.json748agent: (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)749agent: must succeed: flakelet update app750app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1751app: activating generation 6752agent # [1723916.556997] agent systemd[1]: Stopping app v2...753agent # [1723916.557477] agent systemd[1]: app.service: Deactivated successfully.754agent # [1723916.557742] agent systemd[1]: Stopped app v2.755agent # [1723916.577236] agent systemd[1]: Reload requested from client PID 2419 ('systemctl')...756agent # [1723916.577308] agent systemd[1]: Reloading...757agent # [1723916.926105] agent systemd[1]: Reloading finished in 348 ms.758agent # [1723917.001090] agent systemd[1]: Reload requested from client PID 2448 ('systemctl')...759agent # [1723917.001131] agent systemd[1]: Reloading...760agent # [1723917.334265] agent systemd[1]: Reloading finished in 332 ms.761agent # [1723917.404255] agent systemd[1]: Reload requested from client PID 2476 ('systemctl')...762agent # [1723917.404298] agent systemd[1]: Reloading...763agent # [1723917.735965] agent systemd[1]: Reloading finished in 331 ms.764agent # [1723917.822857] agent systemd[1]: Reload requested from client PID 2509 ('systemctl')...765agent # [1723917.822897] agent systemd[1]: Reloading...766agent # [1723918.154670] agent systemd[1]: Reloading finished in 331 ms.767agent: (finished: must succeed: flakelet update app, in 1.74 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 # [1723918.229243] agent systemd[1]: Starting app v1...770agent # [1723918.258057] agent systemd[1]: Started app v1.771agent # [1723919.497516] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:47.784955Z","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 2.07 seconds)773(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.72 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=@1790856228 | grep -q 'app-slow'790agent # [1723920.417562] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:48.704962Z","level":"INFO","message":"start","id":"7a249324f2f8dcc84d01cbaa339caaf3","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}791agent # [1723920.418168] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:48.705655Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"7a249324f2f8dcc84d01cbaa339caaf3\"]","target":"flakelet_relay::agent::jobs"}792agent # [1723920.458448] agent systemd[1]: Starting flakelet update app (via relay)...793agent # [1723920.488239] agent systemd[1]: Started flakelet update app (via relay).794agent # [1723920.492386] agent flakelet[2558]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow795agent # [1723920.492976] agent flakelet[2558]: app: activating generation 7796agent # [1723920.516474] agent systemd[1]: Stopping app v1...797agent # [1723920.518472] agent systemd[1]: app.service: Deactivated successfully.798agent # [1723920.518838] agent systemd[1]: Stopped app v1.799agent # [1723920.535326] agent systemd[1]: Reload requested from client PID 2565 ('systemctl') (unit flakelet-relay-job-app.service)...800agent # [1723920.535393] agent systemd[1]: Reloading...801relay # [1723920.355021] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:48.642487Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}802relay # [1723920.417019] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:48.704493Z","level":"INFO","message":"deploy accepted","job":"0deea8b1fc66516c837f2aabf7092244","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}803agent # [1723920.876693] agent systemd[1]: Reloading finished in 340 ms.804agent # [1723920.961824] agent systemd[1]: Reload requested from client PID 2595 ('systemctl') (unit flakelet-relay-job-app.service)...805agent # [1723920.961866] agent systemd[1]: Reloading...806agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856228 | 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=@1790856228 | grep -q 'updated to generation'814agent # [1723921.292084] agent systemd[1]: Reloading finished in 329 ms.815agent # [1723921.359896] agent systemd[1]: Reload requested from client PID 2624 ('systemctl') (unit flakelet-relay-job-app.service)...816agent # [1723921.359934] agent systemd[1]: Reloading...817agent # [1723921.530635] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:49.818053Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}818relay # [1723921.499222] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:49.786634Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}819agent # [1723921.717860] agent systemd[1]: Reloading finished in 357 ms.820agent # [1723921.813260] agent systemd[1]: Reload requested from client PID 2672 ('systemctl') (unit flakelet-relay-job-app.service)...821agent # [1723921.813301] agent systemd[1]: Reloading...822agent # [1723922.150566] agent systemd[1]: Reloading finished in 336 ms.823agent # [1723922.220771] agent systemd[1]: Starting app slow...824agent # [1723922.533735] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:50.821155Z","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 # [1723924.536391] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:52.823800Z","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 # [1723928.286183] agent systemd[1]: Started app slow.827agent # [1723928.294716] agent flakelet[2558]: app: updated to generation 7828agent # [1723928.295746] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.829agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856228 | grep -q 'updated to generation', in 7.11 seconds)830agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done831agent: (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)832client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out833agent # [1723928.539813] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:56.827066Z","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 # [1723929.399790] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:57.687232Z","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.40 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.03 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 # [1723936.544041] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:04.831454Z","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 # [1723936.543947] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:04.831357Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}847relay # [1723936.545537] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:04.833025Z","level":"INFO","message":"deploy finished","job":"0deea8b1fc66516c837f2aabf7092244","ok":true,"target":"flakelet_relay::relay::api"}848agent # [1723936.545171] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:04.832661Z","level":"INFO","message":"start","id":"7a249324f2f8dcc84d01cbaa339caaf3","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}849relay # [1723936.822498] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:05.109813Z","level":"INFO","message":"deploy accepted","job":"0214376e1376797b6231c8053fe3f06e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}850agent # [1723936.822872] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:05.110185Z","level":"INFO","message":"start","id":"3f24754a8f186d7529d273edef4c5d6d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}851agent # [1723936.823412] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:05.110898Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"3f24754a8f186d7529d273edef4c5d6d\"]","target":"flakelet_relay::agent::jobs"}852agent # [1723936.862295] agent systemd[1]: Starting flakelet update app (via relay)...853agent # [1723936.890207] agent systemd[1]: Started flakelet update app (via relay).854agent # [1723936.910494] agent flakelet[2794]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2855agent # [1723936.911673] agent flakelet[2794]: app: activating generation 8856agent # [1723936.936940] agent systemd[1]: Stopping app slow...857agent # [1723936.940787] agent systemd[1]: app.service: Deactivated successfully.858agent # [1723936.942269] agent systemd[1]: Stopped app slow.859agent # [1723936.969475] agent systemd[1]: Reload requested from client PID 2801 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [1723936.969543] agent systemd[1]: Reloading...861agent # [1723937.314294] agent systemd[1]: Reloading finished in 344 ms.862agent # [1723937.392853] agent systemd[1]: Reload requested from client PID 2831 ('systemctl') (unit flakelet-relay-job-app.service)...863agent # [1723937.392895] agent systemd[1]: Reloading...864agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)865agent: must succeed: systemctl restart flakelet-agent866agent # [1723937.726287] agent systemd[1]: Reloading finished in 332 ms.867agent # [1723937.808535] agent systemd[1]: Reload requested from client PID 2863 ('systemctl') (unit flakelet-relay-job-app.service)...868agent # [1723937.808572] agent systemd[1]: Reloading...869agent # [1723938.141654] agent systemd[1]: Reloading finished in 332 ms.870agent # [1723938.205788] agent systemd[1]: Stopping flakelet-agent...871agent # [1723938.212401] agent systemd[1]: Reload requested from client PID 2899 ('systemctl') (unit flakelet-relay-job-app.service)...872agent # [1723938.212435] agent systemd[1]: Reloading...873relay # [1723938.206480] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:06.493509Z","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.87 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 # [1723938.549989] agent systemd[1]: Reloading finished in 337 ms.879agent # [1723938.618381] agent systemd[1]: flakelet-agent.service: Deactivated successfully.880agent # [1723938.618546] agent systemd[1]: Stopped flakelet-agent.881agent # [1723938.618560] agent systemd[1]: flakelet-agent.service: Consumed 1.250s CPU time over 29.230s wall clock time.882agent # [1723938.637815] agent systemd[1]: Starting app slow2...883agent # [1723938.638765] agent systemd[1]: Starting flakelet-agent...884agent # [1723938.695313] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:06.982778Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"3f24754a8f186d7529d273edef4c5d6d\"]","target":"flakelet_relay::agent::jobs"}885agent # [1723938.711672] agent systemd[1]: Started flakelet-agent.886agent # [1723938.725100] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:07.012582Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}887agent # [1723938.726380] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:07.013874Z","level":"INFO","message":"start","id":"3f24754a8f186d7529d273edef4c5d6d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}888relay # [1723938.725252] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:07.012678Z","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 # [1723944.710113] agent systemd[1]: Started app slow2.890agent # [1723944.719534] agent flakelet[2794]: app: updated to generation 8891agent # [1723944.723281] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.892agent # [1723945.287531] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:13.575005Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}893relay # [1723945.288594] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:13.576060Z","level":"INFO","message":"deploy finished","job":"0214376e1376797b6231c8053fe3f06e","ok":true,"target":"flakelet_relay::relay::api"}894client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.09 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.02 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=@1790856254 | grep -q 'app-slow'908agent # [1723945.888502] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:14.175938Z","level":"INFO","message":"start","id":"79568b1870a18eddf3ff096c6fe2a72e","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}909agent # [1723945.889149] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:14.176638Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"79568b1870a18eddf3ff096c6fe2a72e\"]","target":"flakelet_relay::agent::jobs"}910agent # [1723945.926532] agent systemd[1]: Starting flakelet update app (via relay)...911agent # [1723945.936942] agent systemd[1]: Started flakelet update app (via relay).912agent # [1723945.941394] agent flakelet[3376]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow913agent # [1723945.942049] agent flakelet[3376]: app: activating generation 9914agent # [1723945.953580] agent systemd[1]: Stopping app slow2...915agent # [1723945.954300] agent systemd[1]: app.service: Deactivated successfully.916agent # [1723945.954501] agent systemd[1]: Stopped app slow2.917agent # [1723945.964613] agent systemd[1]: Reload requested from client PID 3383 ('systemctl') (unit flakelet-relay-job-app.service)...918agent # [1723945.964655] agent systemd[1]: Reloading...919relay # [1723945.888134] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:14.175596Z","level":"INFO","message":"deploy accepted","job":"4618a827b932dcb3dae7b71cf2d16982","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}920agent # [1723946.345073] agent systemd[1]: Reloading finished in 380 ms.921agent # [1723946.447935] agent systemd[1]: Reload requested from client PID 3413 ('systemctl') (unit flakelet-relay-job-app.service)...922agent # [1723946.447976] agent systemd[1]: Reloading...923agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856254 | grep -q 'app-slow', in 1.03 seconds)924relay: must succeed: systemctl restart flakelet-relay925agent # [1723946.830841] agent systemd[1]: Reloading finished in 382 ms.926agent # [1723946.916513] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:15.203977Z","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"}927agent # [1723946.929600] agent systemd[1]: Reload requested from client PID 3448 ('systemctl') (unit flakelet-relay-job-app.service)...928agent # [1723946.929638] agent systemd[1]: Reloading...929relay # [1723946.916108] relay systemd[1]: Stopping flakelet-relay...930relay # [1723946.965660] relay systemd[1]: flakelet-relay.service: Deactivated successfully.931relay # [1723946.967102] relay systemd[1]: Stopped flakelet-relay.932relay # [1723946.967144] relay systemd[1]: flakelet-relay.service: Consumed 2.651s CPU time over 1min 7.669s wall clock time.933relay # [1723947.041083] relay systemd[1]: Starting flakelet-relay...934agent # [1723947.344205] agent systemd[1]: Reloading finished in 414 ms.935agent # [1723947.426662] agent systemd[1]: Reload requested from client PID 3480 ('systemctl') (unit flakelet-relay-job-app.service)...936agent # [1723947.426700] agent systemd[1]: Reloading...937agent # [1723947.797458] agent systemd[1]: Reloading finished in 370 ms.938agent # [1723947.856261] agent systemd[1]: Starting app slow...939agent # [1723947.920109] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:16.207509Z","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.78 seconds)941client: waiting for success: grep -q '» ok' /tmp/resume.out942relay # [1723948.679314] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:16.966730Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}943relay # [1723948.680309] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:16.967180Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}944relay # [1723948.679813] relay systemd[1]: Started flakelet-relay.945agent # [1723949.932878] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:18.220304Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}946relay # [1723949.933094] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:18.220493Z","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"}947relay # [1723949.934862] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:18.222360Z","level":"INFO","message":"job reattached","job":"4618a827b932dcb3dae7b71cf2d16982","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}948agent # [1723953.895053] agent systemd[1]: Started app slow.949agent # [1723953.903629] agent flakelet[3376]: app: updated to generation 9950agent # [1723953.907127] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.951agent # [1723955.001338] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:23.288796Z","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.07 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.93 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 # [1723955.787675] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:24.075083Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}959agent # [1723955.788046] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.075463Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}960agent # [1723955.788736] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.076228Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}961agent # [1723955.828790] agent systemd[1]: Starting flakelet update other (via relay)...962agent # [1723955.862227] agent systemd[1]: Started flakelet update other (via relay).963agent # [1723955.866448] agent flakelet[3554]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1964agent # [1723955.867009] agent flakelet[3554]: other: up to date965agent # [1723955.869731] 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 # [1723956.409292] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.696695Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}969agent # [1723956.428072] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.715472Z","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 # [1723956.410575] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:24.697989Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}971relay # [1723956.427827] relay systemd[1]: Stopping flakelet-relay...972relay # [1723956.479548] relay systemd[1]: flakelet-relay.service: Deactivated successfully.973relay # [1723956.479861] relay systemd[1]: Stopped flakelet-relay.974relay # [1723956.479903] relay systemd[1]: flakelet-relay.service: Consumed 2.453s CPU time over 9.438s wall clock time.975relay # [1723956.498132] relay systemd[1]: Starting flakelet-relay...976agent # [1723957.431712] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:25.719066Z","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.53 seconds)978relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'979relay # [1723957.940248] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:26.227696Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}980relay # [1723957.940790] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:26.228109Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}981relay # [1723957.940961] relay systemd[1]: Started flakelet-relay.982agent # [1723959.445164] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:27.732496Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}983relay # [1723959.445318] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:27.732634Z","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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' 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 # [1723960.101250] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:28.388678Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"}997agent/appagent # [1723960.101757] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:28.389249Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}998 | flakelet-relay-job-app.service: Deactivated successfully.agent # [1723960.140264] agent systemd[1]: Starting flakelet update app (via relay)...9991000agent # [1723960.172163] agent systemd[1]: Started flakelet update app (via relay).1001agent # [1723960.176501] agent flakelet[3582]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1002agent # [1723960.177030] agent flakelet[3582]: app: up to date1003agent # [1723960.180458] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.1004relay # [1723960.100800] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:28.388251Z","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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.65 seconds)1008client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' push --relay https://relay:7443 jobs1009client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' 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.98 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.08 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 51)1021kill NspawnMachine (pid 55)1022kill NspawnMachine (pid 56)1023Container agent terminated by signal KILL.1024relay # [1723960.725395] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:29.012810Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1025relay # [1723960.800808] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:04:29] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=IpxheFPAMdF3Mu-o3N483ndWPgH7844rTX5m0F7nG5w&code_challenge=lqWB09musStEYFGyJaxO1fDnCUl3bAJplZ9JVAMoQ94&code_challenge_method=S256 HTTP/1.1" 302 -1026relay # [1723960.847743] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:04:29] "POST /token HTTP/1.1" 200 -1027relay # [1723960.848615] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:29.136086Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1028Container client terminated by signal KILL.1029Container relay terminated by signal KILL.1030(finished: cleanup, in 0.39 seconds)1031additionally exposed symbols:1032 agent, client, relay,1033 vlan1,1034 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_ssh1035» job 86a81216942784b0ee6f88e96d36cd9e via relay 0.1.0 (agents: agent 0.1.0)1036» wave 01037agent/app | Starting flakelet update app (via relay)...1038agent/app | Started flakelet update app (via relay).1039agent/app | app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v21040agent/app | app: activating generation 21041agent/app | app: updated to generation 21042agent/app | flakelet-relay-job-app.service: Deactivated successfully.1043» agent/app: updated (generation 2)1044» ok10451046» job 1c2a28ffb5c770daeba76919b2dbd4b1 via relay 0.1.0 (agents: agent 0.1.0)1047» wave 01048agent/app | Starting flakelet update app (via relay)...1049agent/app | Started flakelet update app (via relay).1050agent/app | app: using prebuilt artifact /nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken1051agent/app | app: activating generation 41052agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1053agent/app | failed units: app.service. See journalctl -u app.service1054agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1055agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1056» agent/app: rolled-back (generation 3)1057agent/app │ Starting app v1...1058agent/app │ Started app v1.1059agent/app │ Stopping app v1...1060agent/app │ app.service: Deactivated successfully.1061agent/app │ Stopped app v1.1062agent/app │ Starting app v2...1063agent/app │ Started app v2.1064agent/app │ Stopping app v2...1065agent/app │ app.service: Deactivated successfully.1066agent/app │ Stopped app v2.1067agent/app │ Starting app v1...1068agent/app │ Started app v1.1069agent/app │ Stopping app v1...1070agent/app │ app.service: Deactivated successfully.1071agent/app │ Stopped app v1.1072agent/app │ Starting app broken...1073agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1074agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1075agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1076agent/app │ app.service: Failed with result 'exit-code'.1077agent/app │ Failed to start app broken.1078agent/app │ Starting app v1...1079agent/app │ Started app v1.1080» skipped: agent/other1081» failed10821083» job 0deea8b1fc66516c837f2aabf7092244 via relay 0.1.0 (agents: agent 0.1.0)1084» wave 01085agent/app | Starting flakelet update app (via relay)...1086agent/app | Started flakelet update app (via relay).1087agent/app | app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1088agent/app | app: activating generation 71089agent/app | app: updated to generation 71090agent/app | flakelet-relay-job-app.service: Deactivated successfully.1091» agent/app: updated (generation 7)1092» ok10931094» job 0214376e1376797b6231c8053fe3f06e via relay 0.1.0 (agents: agent 0.1.0)1095» wave 01096agent/app | Starting flakelet update app (via relay)...1097agent/app | Started flakelet update app (via relay).1098agent/app | app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow21099agent/app | app: activating generation 81100agent/app | app: updated to generation 81101agent/app | flakelet-relay-job-app.service: Deactivated successfully.1102» agent/app: updated (generation 8)1103» ok11041105» job 4618a827b932dcb3dae7b71cf2d16982 via relay 0.1.0 (agents: agent 0.1.0)1106» wave 01107agent/app | Starting flakelet update app (via relay)...1108agent/app | Started flakelet update app (via relay).1109agent/app | app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow1110agent/app | app: activating generation 91111flakelet-push: stream: error reading a body from connection, resuming job 1a38fccf7b28c28d866ba8bc9e7c69771112flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1113flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1114» job 4618a827b932dcb3dae7b71cf2d16982 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» ok112011211790856264 hist1 admin@example.org agent/other:unchanged11221790856254 1a38fccf7b28c28d866ba8bc9e7c6977 admin@example.org agent/app:updated11231790856245 90ce4e731fcbf97478ecf3f0442a764c admin@example.org agent/app:updated11241790856228 27bf17ad835d2015286f125e806dff05 admin@example.org agent/app:updated11251790856226 local-app-6-1790856226 root (shell) agent/app:updated11261790856222 local-app-5-1790856222 root (shell) agent/app:updated11271790856219 fc16f53f0cf78bed20e0af5a9ffdccee admin@example.org agent/other:unchanged11281790856207 4fdb7f565417002cb3f5b08d720a6ff5 admin@example.org agent/app:updated11291790856206 81e74aaa63beab2823c0f5bd842cde46 admin@example.org agent/app:unchanged11301790856206 9bdbcb288ca52522e0fc351f8619314f admin@example.org agent/app:unchanged11311790856205 4926c124545383671a20fba52b46a705 admin@example.org agent/app:unchanged11321790856201 55fdd2109331f70eec8c21648e229c15 admin@example.org agent/app:rolled-back11331790856200 0675e922875e3d9b3f0bddc66361c4e8 dev@example.org agent/other:unchanged11341790856200 bc2258243445b7e4d129c6df071c96cb dev@example.org agent/other:unchanged11351790856197 7245dfc67cd00633cf815e33e9600288 someone agent/other:unchanged11361790856194 3b87149eb8229b251a73361fd9550610 repo:github:example/app:ref:refs/heads/main agent/app:updated11371790856191 76f43bd28a044ed969a4f30c05548526 admin@example.org agent/app:updated11381790856189 local-app-1-1790856189 host activation agent/app:updated11391790856189 local-flakelet-agent-1-1790856189 host activation agent/flakelet-agent:updated11401790856189 local-other-1-1790856189 host activation agent/other:updated11411142Traceback (most recent call last):1143 File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/bin/.nixos-test-driver-wrapped", line 9, in <module>1144 sys.exit(main())1145 ~~~~^^1146 File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-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/29sx6wcid88iz35qayaccsr67l3kdrpk-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/29sx6wcid88iz35qayaccsr67l3kdrpk-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>1156AssertionError