container-test-run-flakelet-relay log

succeeded `container-test-run-flakelet-relay` `checks.x86_64-linux.nixos-test` · build #17 · raw

1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 51)10client: systemd-nspawn running (pid 53)11relay: systemd-nspawn running (pid 55)12agent: Waiting for journal at /build/vm-state-agent/var/log/journal...13relay: Waiting for journal at /build/vm-state-relay/var/log/journal...14client: Waiting for journal at /build/vm-state-client/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.25░ Spawning container client on /build/vm-state-client.26░ Spawning container relay on /build/vm-state-relay.27Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.28░ Spawning container agent on /build/vm-state-agent.29agent # [ 3730.936603] agent systemd-journald[57]: Journal started30relay # [ 3730.944305] relay systemd-journald[57]: Journal started31client # [ 3730.944874] client systemd-journald[57]: Journal started32agent # [ 3730.936646] agent systemd-journald[57]: Runtime Journal (/run/log/journal/0ed16da082fc4f188210f69ebe34bf56) is 8M, max 4G, 3.9G free.33relay # [ 3730.944346] relay systemd-journald[57]: Runtime Journal (/run/log/journal/594236f018094374a5cdd079f9142a82) is 8M, max 4G, 3.9G free.34agent # [ 3730.945927] agent systemd[1]: Finished Apply Kernel Variables.35client # [ 3730.944918] client systemd-journald[57]: Runtime Journal (/run/log/journal/331fb7719d394cb6921d076dafddcdb8) is 8M, max 4G, 3.9G free.36agent # [ 3730.957624] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.37agent # [ 3730.973996] agent systemd[1]: Starting Flush Journal to Persistent Storage...38agent # [ 3730.974782] agent systemd[1]: Starting Create Static Device Nodes in /dev...39relay # [ 3730.953999] relay systemd[1]: Finished Apply Kernel Variables.40client # [ 3730.956098] client systemd[1]: Finished Apply Kernel Variables.41agent # [ 3731.006844] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/0ed16da082fc4f188210f69ebe34bf56 is 1.376ms for 6 entries.42relay # [ 3730.965698] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.43client # [ 3730.968448] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.44relay # [ 3731.001447] relay systemd[1]: Starting Flush Journal to Persistent Storage...45client # [ 3731.001606] client systemd[1]: Starting Flush Journal to Persistent Storage...46relay # [ 3731.002166] relay systemd[1]: Starting Create Static Device Nodes in /dev...47client # [ 3731.002311] client systemd[1]: Starting Create Static Device Nodes in /dev...48relay # [ 3731.010142] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/594236f018094374a5cdd079f9142a82 is 1.381ms for 6 entries.49client # [ 3731.010172] client systemd-journald[57]: Time spent on flushing to /var/log/journal/331fb7719d394cb6921d076dafddcdb8 is 1.526ms for 6 entries.50relay # [ 3731.010142] relay systemd-journald[57]: System Journal (/var/log/journal/594236f018094374a5cdd079f9142a82) is 512B, max 4G, 3.9G free.51relay # [ 3731.020414] relay systemd[1]: Finished Flush Journal to Persistent Storage.52relay # [ 3731.020742] relay systemd[1]: Finished Create Static Device Nodes in /dev.53relay # [ 3731.021873] relay systemd[1]: Reached target Preparation for Local File Systems.54relay # [ 3731.021977] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys55relay # [ 3731.116450] relay systemd[1]: Finished Firewall.56client # [ 3731.010172] client systemd-journald[57]: System Journal (/var/log/journal/331fb7719d394cb6921d076dafddcdb8) is 512B, max 4G, 3.9G free.57client # [ 3731.020675] client systemd[1]: Finished Create Static Device Nodes in /dev.58client # [ 3731.021310] client systemd[1]: Reached target Preparation for Local File Systems.59client # [ 3731.021431] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys60client # [ 3731.031960] client systemd[1]: Finished Flush Journal to Persistent Storage.61client # [ 3731.112450] client systemd[1]: Finished Firewall.62agent # [ 3731.006844] agent systemd-journald[57]: System Journal (/var/log/journal/0ed16da082fc4f188210f69ebe34bf56) is 512B, max 4G, 3.9G free.63agent # [ 3731.014671] agent systemd[1]: Finished Create Static Device Nodes in /dev.64agent # [ 3731.015442] agent systemd[1]: Reached target Preparation for Local File Systems.65agent # [ 3731.015559] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys66agent # [ 3731.029167] agent systemd[1]: Finished Flush Journal to Persistent Storage.67agent # [ 3731.111377] agent systemd[1]: Finished Firewall.68relay # [ 3731.943751] relay systemd[1]: Mounting /run/wrappers...69relay # [ 3731.987726] relay systemd[1]: Mounted /run/wrappers.70relay # [ 3731.988421] relay systemd[1]: Reached target Local File Systems.71relay # [ 3731.989169] relay systemd[1]: Listening on Boot Loader Control Service Socket.72relay # [ 3731.990119] relay systemd[1]: Starting Create SUID/SGID Wrappers...73relay # [ 3731.990146] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container74relay # [ 3731.991415] relay systemd[1]: Starting Save Transient machine-id to Disk...75relay # [ 3731.992124] relay systemd[1]: Starting Create System Files and Directories...76relay # [ 3732.009612] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted77relay # [ 3732.010102] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted78relay # [ 3732.010427] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/594236f018094374a5cdd079f9142a82 failed: Operation not permitted79relay # [ 3732.010771] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted80client # [ 3731.970630] client systemd[1]: Mounting /run/wrappers...81client # [ 3731.991155] client systemd[1]: Mounted /run/wrappers.82client # [ 3731.991879] client systemd[1]: Reached target Local File Systems.83client # [ 3731.992687] client systemd[1]: Listening on Boot Loader Control Service Socket.84client # [ 3731.993615] client systemd[1]: Starting Create SUID/SGID Wrappers...85client # [ 3731.993644] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container86client # [ 3731.994462] client systemd[1]: Starting Save Transient machine-id to Disk...87client # [ 3731.995144] client systemd[1]: Starting Create System Files and Directories...88client # [ 3732.013576] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted89client # [ 3732.014017] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted90client # [ 3732.014385] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/331fb7719d394cb6921d076dafddcdb8 failed: Operation not permitted91client # [ 3732.014755] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted92agent # [ 3731.943398] agent systemd[1]: Mounting /run/wrappers...93agent # [ 3731.995717] agent systemd[1]: Mounted /run/wrappers.94agent # [ 3731.996946] agent systemd[1]: Reached target Local File Systems.95agent # [ 3731.998117] agent systemd[1]: Listening on Boot Loader Control Service Socket.96agent # [ 3731.999453] agent systemd[1]: Starting Create SUID/SGID Wrappers...97agent # [ 3731.999492] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container98agent # [ 3732.000292] agent systemd[1]: Starting Save Transient machine-id to Disk...99agent # [ 3732.001465] agent systemd[1]: Starting Create System Files and Directories...100agent # [ 3732.020560] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.xVNUw6tT0n/chsh': Operation not permitted101agent # [ 3732.020601] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted102agent # [ 3732.021051] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted103agent # [ 3732.021384] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/0ed16da082fc4f188210f69ebe34bf56 failed: Operation not permitted104agent # [ 3732.021737] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted105relay # [ 3732.013209] relay systemd[1]: Finished Create System Files and Directories.106relay # [ 3732.015307] relay suid-sgid-wrappers-start[177]: chmod: changing permissions of '/run/wrappers/wrappers.eraaezfBzT/chsh': Operation not permitted107relay # [ 3732.027189] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE108relay # [ 3732.027284] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.109relay # [ 3732.027429] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.110relay # [ 3732.029138] relay systemd[1]: Starting Rebuild Journal Catalog...111relay # [ 3732.029955] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...112relay # [ 3732.041930] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.113relay # [ 3732.048451] relay systemd[1]: Finished Rebuild Journal Catalog.114relay # [ 3732.049735] relay systemd[1]: Starting Update is Completed...115relay # [ 3732.060592] relay systemd[1]: Finished Update is Completed.116relay # [ 3732.060672] relay systemd[1]: Reached target System Initialization.117relay # [ 3732.060729] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container118relay # [ 3732.060750] relay systemd[1]: Started Daily Cleanup of Temporary Directories.119relay # [ 3732.060765] relay systemd[1]: Reached target Timer Units.120relay # [ 3732.060859] relay systemd[1]: Listening on D-Bus System Message Bus Socket.121relay # [ 3732.060997] relay systemd[1]: Listening on Nix Daemon Socket.122relay # [ 3732.061116] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.123relay # [ 3732.061129] relay systemd[1]: Reached target Socket Units.124relay # [ 3732.061157] relay systemd[1]: Reached target Basic System.125relay # [ 3732.062244] relay systemd[1]: Started device-mock.service.126relay # [ 3732.062931] relay systemd[1]: Starting Re-link flakelet services at boot...127relay # [ 3732.063553] relay systemd[1]: Starting Import lastlog data into lastlog2 database...128relay # [ 3732.064363] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...129relay # [ 3732.065186] relay systemd[1]: Starting resolvconf update...130relay # [ 3732.074902] relay systemd[1]: Finished Re-link flakelet services at boot.131relay # [ 3732.075778] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...132relay # [ 3732.080476] relay systemd[1]: Finished Import lastlog data into lastlog2 database.133relay # [ 3732.087485] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.134relay # [ 3732.141188] relay systemd[1]: Finished resolvconf update.135relay # [ 3732.141322] relay systemd[1]: Reached target Preparation for Network.136relay # [ 3732.142298] relay systemd[1]: Starting Address configuration of eth1...137relay # [ 3732.143098] relay systemd[1]: Starting Extra networking commands....138relay # [ 3732.186058] relay network-addresses-eth1-start[245]: adding address 192.168.1.3/24... done139relay # [ 3732.186817] relay systemd[1]: nscd.service: Deactivated successfully.140relay # [ 3732.187155] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).141relay # [ 3732.191108] relay network-addresses-eth1-start[245]: adding address 2001:db8:1::3/64... done142relay # [ 3732.191157] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...143agent # [ 3732.027612] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE144agent # [ 3732.027664] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.145agent # [ 3732.027726] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.146agent # [ 3732.028698] agent systemd[1]: Finished Create System Files and Directories.147agent # [ 3732.048803] agent systemd[1]: Starting Rebuild Journal Catalog...148agent # [ 3732.049932] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...149agent # [ 3732.060797] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.150agent # [ 3732.070107] agent systemd[1]: Finished Rebuild Journal Catalog.151agent # [ 3732.071751] agent systemd[1]: Starting Update is Completed...152agent # [ 3732.081442] agent systemd[1]: Finished Update is Completed.153agent # [ 3732.081534] agent systemd[1]: Reached target System Initialization.154agent # [ 3732.081607] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container155agent # [ 3732.081636] agent systemd[1]: Started Daily Cleanup of Temporary Directories.156agent # [ 3732.081653] agent systemd[1]: Reached target Timer Units.157agent # [ 3732.081758] agent systemd[1]: Listening on D-Bus System Message Bus Socket.158agent # [ 3732.081925] agent systemd[1]: Listening on Nix Daemon Socket.159agent # [ 3732.082041] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.160agent # [ 3732.082056] agent systemd[1]: Reached target Socket Units.161agent # [ 3732.082089] agent systemd[1]: Reached target Basic System.162agent # [ 3732.083292] agent systemd[1]: Starting Re-link flakelet services at boot...163agent # [ 3732.083995] agent systemd[1]: Starting Import lastlog data into lastlog2 database...164agent # [ 3732.084784] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...165agent # [ 3732.085638] agent systemd[1]: Starting resolvconf update...166agent # [ 3732.094326] agent systemd[1]: Finished Re-link flakelet services at boot.167agent # [ 3732.096678] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...168agent # [ 3732.102661] agent systemd[1]: Finished Import lastlog data into lastlog2 database.169agent # [ 3732.107496] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.170agent # [ 3732.177121] agent systemd[1]: nscd.service: Deactivated successfully.171agent # [ 3732.177217] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).172agent # [ 3732.179548] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...173agent # [ 3732.187148] agent systemd[1]: Finished resolvconf update.174agent # [ 3732.187258] agent systemd[1]: Reached target Preparation for Network.175agent # [ 3732.188119] agent systemd[1]: Starting Address configuration of eth1...176agent # [ 3732.188771] agent systemd[1]: Starting Extra networking commands....177client # [ 3732.016463] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.4sZj0LCDog/chsh': Operation not permitted178client # [ 3732.017282] client systemd[1]: Finished Create System Files and Directories.179client # [ 3732.029962] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE180client # [ 3732.030012] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.181client # [ 3732.030068] client systemd[1]: Failed to start Create SUID/SGID Wrappers.182client # [ 3732.032440] client systemd[1]: Starting Rebuild Journal Catalog...183client # [ 3732.033078] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...184client # [ 3732.046392] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.185client # [ 3732.052149] client systemd[1]: Finished Rebuild Journal Catalog.186client # [ 3732.053033] client systemd[1]: Starting Update is Completed...187client # [ 3732.062303] client systemd[1]: Finished Update is Completed.188client # [ 3732.062402] client systemd[1]: Reached target System Initialization.189client # [ 3732.062489] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container190client # [ 3732.062528] client systemd[1]: Started Daily Cleanup of Temporary Directories.191client # [ 3732.062546] client systemd[1]: Reached target Timer Units.192client # [ 3732.062653] client systemd[1]: Listening on D-Bus System Message Bus Socket.193client # [ 3732.062842] client systemd[1]: Listening on Nix Daemon Socket.194client # [ 3732.062939] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.195client # [ 3732.062955] client systemd[1]: Reached target Socket Units.196client # [ 3732.062982] client systemd[1]: Reached target Basic System.197client # [ 3732.063941] client systemd[1]: Starting Import lastlog data into lastlog2 database...198client # [ 3732.064798] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...199client # [ 3732.065554] client systemd[1]: Starting resolvconf update...200client # [ 3732.082225] client systemd[1]: Finished Import lastlog data into lastlog2 database.201client # [ 3732.145792] client systemd[1]: Finished resolvconf update.202client # [ 3732.145918] client systemd[1]: Reached target Preparation for Network.203client # [ 3732.147032] client systemd[1]: Starting Address configuration of eth1...204client # [ 3732.147637] client systemd[1]: Starting Extra networking commands....205client # [ 3732.176943] client systemd[1]: nscd.service: Deactivated successfully.206client # [ 3732.177078] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).207client # [ 3732.179354] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...208client # [ 3732.192886] client network-addresses-eth1-start[232]: adding address 192.168.1.2/24... done209client # [ 3732.195380] client network-addresses-eth1-start[232]: adding address 2001:db8:1::2/64... done210client # [ 3732.199542] client systemd[1]: Finished Address configuration of eth1.211client # [ 3732.247475] client systemd[1]: nscd.service: Deactivated successfully.212client # [ 3732.247646] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).213relay # [ 3732.196548] relay systemd[1]: Finished Address configuration of eth1.214relay # [ 3732.234280] relay systemd[1]: Finished Extra networking commands..215relay # [ 3732.234375] relay systemd[1]: Reached target Network.216relay # [ 3732.235605] relay systemd[1]: Starting Dnsmasq Daemon...217relay # [ 3732.236506] relay systemd[1]: Starting Nginx Web Server...218relay # [ 3732.237401] relay systemd[1]: Starting Update flakelet service flakelet-relay...219relay # [ 3732.265600] relay flakelet[310]: flakelet-relay: using prebuilt artifact /nix/store/354ldavl3xmydpbgkhdc3qi58mz6j5na-flakelet-flakelet-relay220relay # [ 3732.266288] relay flakelet[310]: flakelet-relay: activating generation 1221relay # [ 3732.444174] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.222relay # [ 3732.445378] relay systemd[1]: Finished Save Transient machine-id to Disk.223relay # [ 3732.450493] relay systemd[1]: Reload requested from client PID 315 ('systemctl') (unit flakelet-flakelet-relay.service)...224relay # [ 3732.450563] relay systemd[1]: Reloading...225agent # [ 3732.206318] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done226agent # [ 3732.209535] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done227agent # [ 3732.213854] agent systemd[1]: Finished Address configuration of eth1.228agent # [ 3732.248286] agent systemd[1]: nscd.service: Deactivated successfully.229agent # [ 3732.248378] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).230agent # [ 3732.265991] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...231agent # [ 3732.430131] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.232agent # [ 3732.431160] agent systemd[1]: Finished Save Transient machine-id to Disk.233agent # [ 3732.431359] agent systemd[1]: Finished Extra networking commands..234agent # [ 3732.432477] agent systemd[1]: Reached target Network.235agent # [ 3732.434431] agent systemd[1]: Starting flakelet-agent...236agent # [ 3732.435207] agent systemd[1]: Starting Update flakelet service app...237agent # [ 3732.435861] agent systemd[1]: Starting Update flakelet service other...238client # [ 3732.260501] client systemd[1]: Finished Extra networking commands..239client # [ 3732.266704] client systemd[1]: Reached target Network.240client # [ 3732.267842] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...241client # [ 3732.445389] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.242client # [ 3732.446655] client systemd[1]: Finished Save Transient machine-id to Disk.243relay # [ 3732.656469] relay nsncd[261]: Sep 06 08:06:50.618 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"244agent # [ 3732.473688] agent flakelet[310]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1245agent # [ 3732.474352] agent flakelet[311]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1246agent # [ 3732.474756] agent flakelet[311]: other: activating generation 1247agent # [ 3732.474806] agent flakelet[310]: app: activating generation 1248agent # [ 3732.478516] agent systemd[1]: Reload requested from client PID 321 ('systemctl') (unit flakelet-other.service)...249agent # [ 3732.478557] agent systemd[1]: Reloading...250agent # [ 3732.498156] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:50.459872Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}251agent # [ 3732.653654] agent nsncd[303]: Sep 06 08:06:50.615 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"252agent # [ 3732.838526] agent systemd[1]: Reloading finished in 359 ms.253client # [ 3732.659396] client nsncd[302]: Sep 06 08:06:50.621 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"254client # [ 3732.659520] client systemd[1]: Started Name Service Cache Daemon (nsncd).255client # [ 3732.659629] client systemd[1]: Reached target Host and Network Name Lookups.256client # [ 3732.659734] client systemd[1]: Reached target User and Group Name Lookups.257client # [ 3732.663359] client systemd[1]: Starting User Login Management...258client # [ 3732.664617] client systemd[1]: Starting Permit User Sessions...259client # [ 3732.706335] client systemd[1]: Finished Permit User Sessions.260client # [ 3732.709412] client systemd[1]: Started Console Getty.261client # [ 3732.709469] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0262client # [ 3732.709498] client systemd[1]: Reached target Login Prompts.263relay # [ 3732.818432] relay systemd[1]: Reloading finished in 367 ms.264relay # [ 3732.953561] relay systemd[1]: Started Name Service Cache Daemon (nsncd).265relay # [ 3732.954292] relay dnsmasq-pre-start[356]: dnsmasq: syntax check OK.266relay # [ 3732.954440] relay systemd[1]: Reached target Host and Network Name Lookups.267relay # [ 3732.954584] relay systemd[1]: Reached target User and Group Name Lookups.268relay # [ 3732.959093] relay systemd[1]: Starting User Login Management...269relay # [ 3732.962726] relay systemd[1]: Starting Permit User Sessions...270relay # [ 3733.002284] relay systemd[1]: Finished Permit User Sessions.271relay # [ 3733.002782] relay systemd[1]: Reload requested from client PID 360 ('systemctl') (unit flakelet-flakelet-relay.service)...272relay # [ 3733.002850] relay systemd[1]: Reloading...273agent # [ 3732.950658] agent systemd[1]: Started flakelet-agent.274agent # [ 3732.950835] agent systemd[1]: Started Name Service Cache Daemon (nsncd).275agent # [ 3732.951379] agent systemd[1]: Reload requested from client PID 324 ('systemctl') (unit flakelet-app.service)...276agent # [ 3732.951422] agent systemd[1]: Reloading...277relay # [ 3733.348349] relay systemd[1]: Reloading finished in 344 ms.278relay # [ 3733.483264] relay systemd[1]: Started Console Getty.279relay # [ 3733.483329] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0280relay # [ 3733.483392] relay systemd[1]: Reached target Login Prompts.281relay # [ 3733.517453] relay systemd[1]: Starting flakelet-relay...282relay # [ 3733.537265] relay systemd[1]: Starting D-Bus System Message Bus...283agent # [ 3733.367484] agent systemd[1]: Reloading finished in 415 ms.284agent # [ 3733.482021] agent systemd[1]: Reached target Host and Network Name Lookups.285agent # [ 3733.482106] agent systemd[1]: Reached target User and Group Name Lookups.286agent # [ 3733.483397] agent systemd[1]: Starting User Login Management...287agent # [ 3733.484374] agent systemd[1]: Starting Permit User Sessions...288agent # [ 3733.487868] agent systemd[1]: Reload requested from client PID 765 ('systemctl') (unit flakelet-other.service)...289agent # [ 3733.487899] agent systemd[1]: Reloading...290agent # [ 3733.902676] agent systemd[1]: Reloading finished in 414 ms.291agent # [ 3733.990725] agent systemd[1]: Finished Permit User Sessions.292agent # [ 3733.994997] agent systemd[1]: Started Console Getty.293agent # [ 3733.995092] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0294agent # [ 3733.995206] agent systemd[1]: Reached target Login Prompts.295agent # [ 3733.997435] agent systemd[1]: Reload requested from client PID 767 ('systemctl') (unit flakelet-app.service)...296agent # [ 3733.997465] agent systemd[1]: Reloading...297relay # [ 3734.103028] relay dbus-broker-launch[404]: Looking up NSS user entry for 'systemd-timesync'...298relay # [ 3734.104479] relay dbus-broker-launch[404]: NSS returned no entry for 'systemd-timesync'299relay # [ 3734.104479] relay dbus-broker-launch[404]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"300relay # [ 3734.105258] relay systemd[1]: Started D-Bus System Message Bus.301relay # [ 3734.113418] relay systemd[1]: Started Dnsmasq Daemon.302relay # [ 3734.115037] relay dbus-broker-launch[404]: Ready303relay # [ 3734.117128] relay dnsmasq[362]: started, version 2.93 cachesize 150304relay # [ 3734.117136] relay dnsmasq[362]: 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 dumpfile305relay # [ 3734.117143] relay dnsmasq[362]: DBus support enabled: connected to system bus306relay # [ 3734.117149] relay dnsmasq[362]: no upstream servers configured - please set them from DBus307relay # [ 3734.117247] relay dnsmasq[362]: read /etc/hosts - 9 names308relay # [ 3734.153763] relay nginx-pre-start[407]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok309relay # [ 3734.154325] relay nginx-pre-start[407]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful310relay # [ 3734.168737] relay systemd[1]: Started Nginx Web Server.311client # [ 3734.243825] client systemd-logind[315]: New seat seat0.312client # [ 3734.244299] client systemd[1]: Started User Login Management.313client # [ 3734.246263] client systemd[1]: Starting D-Bus System Message Bus...314client # [ 3734.247621] client systemd[1]: Starting linger-users.service...315client # [ 3734.272659] client systemd[1]: linger-users.service: Deactivated successfully.316client # [ 3734.272993] client systemd[1]: Finished linger-users.service.317client # [ 3734.274308] client systemd[1]: Reached target Multi-User System.318agent # [ 3734.356273] agent systemd[1]: Reloading finished in 358 ms.319agent # [ 3734.412119] agent systemd[1]: Starting other v1...320agent # [ 3734.431101] agent systemd[1]: Starting app v1...321agent # [ 3734.434038] agent systemd[1]: Started other v1.322agent # [ 3734.440749] agent systemd[1]: Started app v1.323agent # [ 3734.446865] agent flakelet[311]: other: updated to generation 1324agent # [ 3734.448447] agent systemd[1]: Finished Update flakelet service other.325agent # [ 3734.453917] agent flakelet[310]: app: updated to generation 1326agent # [ 3734.455232] agent systemd[1]: Finished Update flakelet service app.327agent # [ 3734.455355] agent systemd[1]: Reached target flakelet managed services.328relay # [ 3734.579246] relay systemd-logind[358]: New seat seat0.329relay # [ 3734.579626] relay systemd[1]: Started User Login Management.330relay # [ 3734.582333] relay systemd[1]: Starting linger-users.service...331relay # [ 3734.623632] relay systemd[1]: linger-users.service: Deactivated successfully.332relay # [ 3734.623976] relay systemd[1]: Finished linger-users.service.333client # [ 3734.736598] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...334client # [ 3734.737898] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'335client # [ 3734.737898] client dbus-broker-launch[325]: Invalid user-name in /nix/store/nl8naw022xp7bnjlgfpnvn4gpzc7jcpd-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"336client # [ 3734.738407] client systemd[1]: Started D-Bus System Message Bus.337client # [ 3734.738684] client systemd[1]: Startup finished in 4.210s.338client # [ 3734.743018] client dbus-broker-launch[325]: Ready339agent # [ 3734.968633] agent systemd-logind[764]: New seat seat0.340agent # [ 3734.969841] agent systemd[1]: Starting D-Bus System Message Bus...341agent # [ 3734.969972] agent systemd[1]: Started User Login Management.342agent # [ 3734.971706] agent systemd[1]: Starting linger-users.service...343agent # [ 3734.985739] agent systemd[1]: linger-users.service: Deactivated successfully.344agent # [ 3734.986060] agent systemd[1]: Finished linger-users.service.345agent # [ 3734.986414] agent systemd[1]: Reached target Multi-User System.346agent # [ 3735.434608] agent dbus-broker-launch[839]: Looking up NSS user entry for 'systemd-timesync'...347agent # [ 3735.436140] agent dbus-broker-launch[839]: NSS returned no entry for 'systemd-timesync'348agent # [ 3735.436140] agent dbus-broker-launch[839]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"349agent # [ 3735.436811] agent systemd[1]: Started D-Bus System Message Bus.350agent # [ 3735.437146] agent systemd[1]: Startup finished in 4.905s.351agent # [ 3735.442203] agent dbus-broker-launch[839]: Ready352relay # [ 3735.552109] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:53.513591Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}353relay # [ 3735.552109] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:53.513821Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}354relay # [ 3735.552186] relay systemd[1]: Started flakelet-relay.355relay # [ 3735.561642] relay systemd[1]: Starting health for flakelet-relay...356relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)357relay: waiting for unit nginx.service358relay: (finished: waiting for unit nginx.service, in 0.02 seconds)359agent: waiting for unit flakelet.target360agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)361agent: waiting for unit flakelet-agent.service362agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)363client: waiting for unit multi-user.target364client: (finished: waiting for unit multi-user.target, in 0.01 seconds)365relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'366relay # [ 3735.861692] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.367relay # [ 3735.862057] relay systemd[1]: Finished health for flakelet-relay.368relay # [ 3735.905888] relay flakelet[310]: flakelet-relay: updated to generation 1369relay # [ 3735.908559] relay systemd[1]: Finished Update flakelet service flakelet-relay.370relay # [ 3735.909141] relay systemd[1]: Reached target flakelet managed services.371relay # [ 3735.909329] relay systemd[1]: Reached target Multi-User System.372relay # [ 3735.909560] relay systemd[1]: Startup finished in 5.382s.373relay # [ 3737.581445] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:55.543173Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}374agent # [ 3737.581223] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:55.542968Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}375relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)376agent: must succeed: systemctl is-active app.service other.service377agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)378subtest: deploy with client certificate, relay found via SRV379agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json380agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)381client: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1382relay # [ 3738.327795] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:56.289570Z","level":"INFO","message":"deploy accepted","job":"ff72ff843a7b29cc82f1d6904c1208b3","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}383agent # [ 3738.328516] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:56.290253Z","level":"INFO","message":"start","id":"402ef878a3f6608106745fa13cdf4f41","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}384agent # [ 3738.329373] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:56.291195Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"402ef878a3f6608106745fa13cdf4f41\"]","target":"flakelet_relay::agent::jobs"}385agent # [ 3738.382907] agent systemd[1]: Starting flakelet update app (via relay)...386agent # [ 3738.390185] agent systemd[1]: Started flakelet update app (via relay).387agent # [ 3738.394184] agent flakelet[868]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2388agent # [ 3738.394772] agent flakelet[868]: app: activating generation 2389agent # [ 3738.402106] agent systemd[1]: Stopping app v1...390agent # [ 3738.402798] agent systemd[1]: app.service: Deactivated successfully.391agent # [ 3738.402948] agent systemd[1]: Stopped app v1.392agent # [ 3738.412683] agent systemd[1]: Reload requested from client PID 875 ('systemctl') (unit flakelet-relay-job-app.service)...393agent # [ 3738.412720] agent systemd[1]: Reloading...394agent # [ 3738.772065] agent systemd[1]: Reloading finished in 358 ms.395agent # [ 3738.869753] agent systemd[1]: Reload requested from client PID 905 ('systemctl') (unit flakelet-relay-job-app.service)...396agent # [ 3738.869793] agent systemd[1]: Reloading...397agent # [ 3739.223264] agent systemd[1]: Reloading finished in 353 ms.398agent # [ 3739.323783] agent systemd[1]: Reload requested from client PID 934 ('systemctl') (unit flakelet-relay-job-app.service)...399agent # [ 3739.323821] agent systemd[1]: Reloading...400agent # [ 3739.684198] agent systemd[1]: Reloading finished in 359 ms.401agent # [ 3739.777761] agent systemd[1]: Reload requested from client PID 965 ('systemctl') (unit flakelet-relay-job-app.service)...402agent # [ 3739.777800] agent systemd[1]: Reloading...403agent # [ 3740.125393] agent systemd[1]: Reloading finished in 347 ms.404agent # [ 3740.223173] agent systemd[1]: Starting app v2...405agent # [ 3740.231044] agent systemd[1]: Started app v2.406agent # [ 3740.244989] agent flakelet[868]: app: updated to generation 2407agent # [ 3740.246765] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.408client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 3.03 seconds)409agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'410agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.01 seconds)411agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'412agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)413(finished: subtest: deploy with client certificate, relay found via SRV, in 3.06 seconds)414subtest: deploy with OIDC token, sub principal415agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json416agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)417client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)418client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)419client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMxOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDE5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDRVE1WUI0U1EzUE00PT09IiwibmJmIjoxNzg4NjgyMDE5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.8bqk_JfvLwgvWXgIqGvMDggTsAVvAlKwEiVxJ6mDGHZpk69x2ySqo22p22ouaENZWYJMCUaju_2i00NGhgYNAw' push --relay https://relay:7443 deploy agent/app 2>&1420relay # [ 3741.333294] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:59.295041Z","level":"INFO","message":"deploy finished","job":"ff72ff843a7b29cc82f1d6904c1208b3","ok":true,"target":"flakelet_relay::relay::api"}421relay # [ 3741.458929] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:06:59.420700Z","level":"INFO","message":"deploy accepted","job":"08f563eeea6817b8c54d656d58171e5e","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}422agent # [ 3741.332411] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:59.294206Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}423agent # [ 3741.459296] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:59.421045Z","level":"INFO","message":"start","id":"66a6f702275db3a2d7c47b8b08d9e19c","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}424agent # [ 3741.459686] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:06:59.421515Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"66a6f702275db3a2d7c47b8b08d9e19c\"]","target":"flakelet_relay::agent::jobs"}425agent # [ 3741.497880] agent systemd[1]: Starting flakelet update app (via relay)...426agent # [ 3741.504556] agent systemd[1]: Started flakelet update app (via relay).427agent # [ 3741.507973] agent flakelet[1023]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1428agent # [ 3741.508540] agent flakelet[1023]: app: activating generation 3429agent # [ 3741.515845] agent systemd[1]: Stopping app v2...430agent # [ 3741.516049] agent systemd[1]: app.service: Deactivated successfully.431agent # [ 3741.516180] agent systemd[1]: Stopped app v2.432agent # [ 3741.525793] agent systemd[1]: Reload requested from client PID 1030 ('systemctl') (unit flakelet-relay-job-app.service)...433agent # [ 3741.525827] agent systemd[1]: Reloading...434agent # [ 3741.866181] agent systemd[1]: Reloading finished in 339 ms.435agent # [ 3741.953934] agent systemd[1]: Reload requested from client PID 1060 ('systemctl') (unit flakelet-relay-job-app.service)...436agent # [ 3741.953971] agent systemd[1]: Reloading...437agent # [ 3742.297147] agent systemd[1]: Reloading finished in 342 ms.438agent # [ 3742.379161] agent systemd[1]: Reload requested from client PID 1089 ('systemctl') (unit flakelet-relay-job-app.service)...439agent # [ 3742.379212] agent systemd[1]: Reloading...440agent # [ 3742.723324] agent systemd[1]: Reloading finished in 343 ms.441agent # [ 3742.818452] agent systemd[1]: Reload requested from client PID 1120 ('systemctl') (unit flakelet-relay-job-app.service)...442agent # [ 3742.818485] agent systemd[1]: Reloading...443agent # [ 3743.308449] agent systemd[1]: Reloading finished in 489 ms.444agent # [ 3743.406804] agent systemd[1]: Starting app v1...445agent # [ 3743.413226] agent systemd[1]: Started app v1.446agent # [ 3743.430459] agent flakelet[1023]: app: updated to generation 3447agent # [ 3743.432375] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.448client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMxOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDE5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDRVE1WUI0U1EzUE00PT09IiwibmJmIjoxNzg4NjgyMDE5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.8bqk_JfvLwgvWXgIqGvMDggTsAVvAlKwEiVxJ6mDGHZpk69x2ySqo22p22ouaENZWYJMCUaju_2i00NGhgYNAw' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.95 seconds)449(finished: subtest: deploy with OIDC token, sub principal, in 3.02 seconds)450subtest: policy denies uncovered target451client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMxOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDE5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDRVE1WUI0U1EzUE00PT09IiwibmJmIjoxNzg4NjgyMDE5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.8bqk_JfvLwgvWXgIqGvMDggTsAVvAlKwEiVxJ6mDGHZpk69x2ySqo22p22ouaENZWYJMCUaju_2i00NGhgYNAw' push --relay https://relay:7443 deploy agent/other 2>&1452client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMxOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDE5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDRVE1WUI0U1EzUE00PT09IiwibmJmIjoxNzg4NjgyMDE5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.8bqk_JfvLwgvWXgIqGvMDggTsAVvAlKwEiVxJ6mDGHZpk69x2ySqo22p22ouaENZWYJMCUaju_2i00NGhgYNAw' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)453(finished: subtest: policy denies uncovered target, in 0.02 seconds)454subtest: claim principal from groups, unchanged counts as success455client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)456client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)457client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMyMiwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAyMiwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiUzRTVTJTVzZXVDU3ST09PSIsIm5iZiI6MTc4ODY4MjAyMiwic3ViIjoic29tZW9uZSJ9.JlQjsDVxl3cjbQ-4VvR6QiQOPm5Xu0RRMneappC7U9Hf1vmx42l-AyDCeaE_2MblgMBc_SlZt40Q6Cy8n2WSBQ' push --relay https://relay:7443 deploy agent/other 2>&1458relay # [ 3744.373596] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:02.335383Z","level":"INFO","message":"deploy finished","job":"08f563eeea6817b8c54d656d58171e5e","ok":true,"target":"flakelet_relay::relay::api"}459agent # [ 3744.372743] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:02.334521Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}460relay # [ 3744.477158] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:02.438941Z","level":"INFO","message":"deploy accepted","job":"517b709b01e19838fd0c81d350e676c3","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}461agent # [ 3744.477628] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:02.439353Z","level":"INFO","message":"start","id":"ad00bb99c4e51375bdd813ace0ff758c","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}462agent # [ 3744.479292] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:02.441114Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"ad00bb99c4e51375bdd813ace0ff758c\"]","target":"flakelet_relay::agent::jobs"}463agent # [ 3744.529184] agent systemd[1]: Starting flakelet update other (via relay)...464agent # [ 3744.537677] agent systemd[1]: Started flakelet update other (via relay).465agent # [ 3744.542485] agent flakelet[1169]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1466agent # [ 3744.543447] agent flakelet[1169]: other: up to date467agent # [ 3744.545348] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.468client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMyMiwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAyMiwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiUzRTVTJTVzZXVDU3ST09PSIsIm5iZiI6MTc4ODY4MjAyMiwic3ViIjoic29tZW9uZSJ9.JlQjsDVxl3cjbQ-4VvR6QiQOPm5Xu0RRMneappC7U9Hf1vmx42l-AyDCeaE_2MblgMBc_SlZt40Q6Cy8n2WSBQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 1.65 seconds)469(finished: subtest: claim principal from groups, unchanged counts as success, in 1.71 seconds)470subtest: push login via device flow, cached token used afterwards471client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1472relay # [ 3746.100828] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:04.062511Z","level":"INFO","message":"deploy finished","job":"517b709b01e19838fd0c81d350e676c3","ok":true,"target":"flakelet_relay::relay::api"}473relay # [ 3746.122412] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:04] "POST /device HTTP/1.1" 200 -474agent # [ 3746.100261] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:04.062005Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}475relay # [ 3747.127829] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:05] "POST /token HTTP/1.1" 400 -476client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)477client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600478client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)479client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1480agent # [ 3748.205466] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:06.167259Z","level":"INFO","message":"start","id":"3a5a9f7c73363b6366456d609f5e5771","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}481agent # [ 3748.205894] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:06.167540Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3a5a9f7c73363b6366456d609f5e5771\"]","target":"flakelet_relay::agent::jobs"}482agent # [ 3748.278698] agent systemd[1]: Starting flakelet update other (via relay)...483agent # [ 3748.286696] agent systemd[1]: Started flakelet update other (via relay).484agent # [ 3748.291351] agent flakelet[1188]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1485agent # [ 3748.291863] agent flakelet[1188]: other: up to date486agent # [ 3748.293412] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.487relay # [ 3748.176878] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:06] "POST /token HTTP/1.1" 200 -488relay # [ 3748.205055] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:06.166829Z","level":"INFO","message":"deploy accepted","job":"4331a9bd50eae5a5284b238ccc2cdc03","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}489client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)490client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1491relay # [ 3748.830977] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:06.792758Z","level":"INFO","message":"deploy finished","job":"4331a9bd50eae5a5284b238ccc2cdc03","ok":true,"target":"flakelet_relay::relay::api"}492relay # [ 3748.847569] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:06.809370Z","level":"INFO","message":"deploy accepted","job":"a7794f24250ac8a5961b961dcdb35bdf","caller":"oidc:mock:groups:wheel\noidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}493agent # [ 3748.830498] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:06.792299Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}494agent # [ 3748.847727] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:06.809544Z","level":"INFO","message":"start","id":"5c31f021b5b39d6949d88359396bcef2","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}495agent # [ 3748.847937] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:06.809769Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5c31f021b5b39d6949d88359396bcef2\"]","target":"flakelet_relay::agent::jobs"}496agent # [ 3748.904341] agent systemd[1]: Starting flakelet update other (via relay)...497agent # [ 3748.911235] agent systemd[1]: Started flakelet update other (via relay).498agent # [ 3748.915254] agent flakelet[1206]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1499agent # [ 3748.915716] agent flakelet[1206]: other: up to date500agent # [ 3748.918800] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.501client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.63 seconds)502(finished: subtest: push login via device flow, cached token used afterwards, in 3.36 seconds)503subtest: waves: failing first wave skips the second504agent: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json505agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)506client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1507agent # [ 3749.465388] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:07.427179Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}508agent # [ 3749.500106] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:07.461922Z","level":"INFO","message":"start","id":"929fd68c7b1854de445654ff1da32268","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}509agent # [ 3749.500343] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:07.462176Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"929fd68c7b1854de445654ff1da32268\"]","target":"flakelet_relay::agent::jobs"}510agent # [ 3749.554659] agent systemd[1]: Starting flakelet update app (via relay)...511agent # [ 3749.583318] agent systemd[1]: Started flakelet update app (via relay).512agent # [ 3749.587032] agent flakelet[1227]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken513agent # [ 3749.587656] agent flakelet[1227]: app: activating generation 4514agent # [ 3749.600706] agent systemd[1]: Stopping app v1...515agent # [ 3749.601165] agent systemd[1]: app.service: Deactivated successfully.516agent # [ 3749.601482] agent systemd[1]: Stopped app v1.517agent # [ 3749.619302] agent systemd[1]: Reload requested from client PID 1234 ('systemctl') (unit flakelet-relay-job-app.service)...518agent # [ 3749.619346] agent systemd[1]: Reloading...519relay # [ 3749.465954] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:07.427709Z","level":"INFO","message":"deploy finished","job":"a7794f24250ac8a5961b961dcdb35bdf","ok":true,"target":"flakelet_relay::relay::api"}520relay # [ 3749.499789] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:07.461570Z","level":"INFO","message":"deploy accepted","job":"68329352ce608a7a2c1c3592c7ff4456","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}521agent # [ 3750.003104] agent systemd[1]: Reloading finished in 383 ms.522agent # [ 3750.090225] agent systemd[1]: Reload requested from client PID 1264 ('systemctl') (unit flakelet-relay-job-app.service)...523agent # [ 3750.090264] agent systemd[1]: Reloading...524agent # [ 3750.460677] agent systemd[1]: Reloading finished in 370 ms.525agent # [ 3750.537922] agent systemd[1]: Reload requested from client PID 1293 ('systemctl') (unit flakelet-relay-job-app.service)...526agent # [ 3750.537961] agent systemd[1]: Reloading...527agent # [ 3750.905488] agent systemd[1]: Reloading finished in 367 ms.528agent # [ 3751.006669] agent systemd[1]: Reload requested from client PID 1324 ('systemctl') (unit flakelet-relay-job-app.service)...529agent # [ 3751.006708] agent systemd[1]: Reloading...530agent # [ 3751.363718] agent systemd[1]: Reloading finished in 356 ms.531agent # [ 3751.466379] agent systemd[1]: Starting app broken...532agent # [ 3751.473361] agent (nonexistent)[1354]: app.service: Unable to locate executable '/nonexistent': No such file or directory533agent # [ 3751.473382] agent (nonexistent)[1354]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory534agent # [ 3751.474695] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC535agent # [ 3751.474820] agent systemd[1]: app.service: Failed with result 'exit-code'.536agent # [ 3751.475186] agent systemd[1]: Failed to start app broken.537agent # [ 3751.506756] agent systemd[1]: Reload requested from client PID 1361 ('systemctl') (unit flakelet-relay-job-app.service)...538agent # [ 3751.506818] agent systemd[1]: Reloading...539agent # [ 3751.870737] agent systemd[1]: Reloading finished in 363 ms.540agent # [ 3751.959445] agent systemd[1]: Reload requested from client PID 1391 ('systemctl') (unit flakelet-relay-job-app.service)...541agent # [ 3751.959485] agent systemd[1]: Reloading...542agent # [ 3752.342152] agent systemd[1]: Reloading finished in 382 ms.543agent # [ 3752.420646] agent systemd[1]: Reload requested from client PID 1421 ('systemctl') (unit flakelet-relay-job-app.service)...544agent # [ 3752.420687] agent systemd[1]: Reloading...545agent # [ 3752.759884] agent systemd[1]: Reloading finished in 338 ms.546agent # [ 3752.858632] agent systemd[1]: Reload requested from client PID 1451 ('systemctl') (unit flakelet-relay-job-app.service)...547agent # [ 3752.858674] agent systemd[1]: Reloading...548agent # [ 3753.248914] agent systemd[1]: Reloading finished in 389 ms.549agent # [ 3753.341403] agent systemd[1]: Starting app v1...550agent # [ 3753.348332] agent systemd[1]: Started app v1.551agent # [ 3753.350071] agent flakelet[1227]: app: deploy failed, rolled back: systemctl start app.service failed:552agent # [ 3753.350071] agent flakelet[1227]: failed units: app.service. See journalctl -u app.service553agent # [ 3753.352249] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE554agent # [ 3753.352346] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.555client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.51 seconds)556agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'557agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.01 seconds)558(finished: subtest: waves: failing first wave skips the second, in 4.54 seconds)559subtest: host patterns expand on the relay560agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json561agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)562client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1563relay # [ 3753.993385] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:11.955168Z","level":"INFO","message":"deploy finished","job":"68329352ce608a7a2c1c3592c7ff4456","ok":false,"target":"flakelet_relay::relay::api"}564relay # [ 3754.041768] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:12.003551Z","level":"INFO","message":"deploy accepted","job":"de80d0096e6abae15f876299a984a094","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}565agent # [ 3753.992624] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:11.954389Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}566agent # [ 3754.041961] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:12.003734Z","level":"INFO","message":"start","id":"85f8a52b6fd0db68a59afb6dc60a356b","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}567agent # [ 3754.042357] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:12.004177Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"85f8a52b6fd0db68a59afb6dc60a356b\"]","target":"flakelet_relay::agent::jobs"}568agent # [ 3754.098804] agent systemd[1]: Starting flakelet update app (via relay)...569agent # [ 3754.105080] agent systemd[1]: Started flakelet update app (via relay).570agent # [ 3754.109623] agent flakelet[1505]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1571agent # [ 3754.110146] agent flakelet[1505]: app: up to date572agent # [ 3754.112024] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.573client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.64 seconds)574client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1575agent # [ 3754.661450] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:12.623231Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}576agent # [ 3754.680172] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:12.641968Z","level":"INFO","message":"start","id":"edb4e272f3f4d60cb4327b576c0de717","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}577agent # [ 3754.680677] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:12.642496Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"edb4e272f3f4d60cb4327b576c0de717\"]","target":"flakelet_relay::agent::jobs"}578agent # [ 3754.719996] agent systemd[1]: Starting flakelet update app (via relay)...579agent # [ 3754.726982] agent systemd[1]: Started flakelet update app (via relay).580agent # [ 3754.731784] agent flakelet[1523]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1581agent # [ 3754.732310] agent flakelet[1523]: app: up to date582agent # [ 3754.736179] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.583relay # [ 3754.661968] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:12.623728Z","level":"INFO","message":"deploy finished","job":"de80d0096e6abae15f876299a984a094","ok":true,"target":"flakelet_relay::relay::api"}584relay # [ 3754.679840] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:12.641646Z","level":"INFO","message":"deploy accepted","job":"407f3ffefa1507b1d2f1e79902a14eea","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}585client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 1.63 seconds)586client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1587relay # [ 3756.291278] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:14.253051Z","level":"INFO","message":"deploy finished","job":"407f3ffefa1507b1d2f1e79902a14eea","ok":false,"target":"flakelet_relay::relay::api"}588relay # [ 3756.313286] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:14.275095Z","level":"INFO","message":"deploy accepted","job":"64c594255cc87e7adc09d4db31ffe1ab","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}589agent # [ 3756.290689] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.252462Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}590agent # [ 3756.313533] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.275353Z","level":"INFO","message":"start","id":"dd26ac0ca2719dd27e92e883016a3cb6","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}591agent # [ 3756.313725] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.275556Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dd26ac0ca2719dd27e92e883016a3cb6\"]","target":"flakelet_relay::agent::jobs"}592agent # [ 3756.364607] agent systemd[1]: Starting flakelet update app (via relay)...593agent # [ 3756.371449] agent systemd[1]: Started flakelet update app (via relay).594agent # [ 3756.375574] agent flakelet[1542]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1595agent # [ 3756.376108] agent flakelet[1542]: app: up to date596agent # [ 3756.376698] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.597client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.65 seconds)598client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1599client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)600(finished: subtest: host patterns expand on the relay, in 2.95 seconds)601subtest: detach returns once the job is accepted602agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json603agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)604client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1605client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)606agent: waiting for success: systemctl is-active flakelet-relay-job-app.service607agent # [ 3756.936599] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.898401Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}608agent # [ 3756.989686] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.951497Z","level":"INFO","message":"start","id":"6415a8111a6af56d21524e3070cded96","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}609agent # [ 3756.990010] agent flakelet-agent[309]: {"timestamp":"2026-09-06T08:07:14.951838Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6415a8111a6af56d21524e3070cded96\"]","target":"flakelet_relay::agent::jobs"}610agent # [ 3757.048868] agent systemd[1]: Starting flakelet update app (via relay)...611agent # [ 3757.056156] agent systemd[1]: Started flakelet update app (via relay).612agent # [ 3757.061374] agent flakelet[1564]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2613agent # [ 3757.062101] agent flakelet[1564]: app: activating generation 4614agent # [ 3757.074812] agent systemd[1]: Stopping app v1...615agent # [ 3757.077182] agent systemd[1]: app.service: Deactivated successfully.616agent # [ 3757.077494] agent systemd[1]: Stopped app v1.617agent # [ 3757.096086] agent systemd[1]: Reload requested from client PID 1571 ('systemctl') (unit flakelet-relay-job-app.service)...618agent # [ 3757.096153] agent systemd[1]: Reloading...619relay # [ 3756.937261] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:14.899041Z","level":"INFO","message":"deploy finished","job":"64c594255cc87e7adc09d4db31ffe1ab","ok":false,"target":"flakelet_relay::relay::api"}620relay # [ 3756.989482] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:14.951286Z","level":"INFO","message":"deploy accepted","job":"94e2acba286c0aac621bb97beea4e11e","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}621agent # [ 3757.475318] agent systemd[1]: Reloading finished in 378 ms.622agent # [ 3757.565290] agent systemd[1]: Reload requested from client PID 1601 ('systemctl') (unit flakelet-relay-job-app.service)...623agent # [ 3757.565328] agent systemd[1]: Reloading...624agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.04 seconds)625??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.626 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39627agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service628??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.629 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39630agent # [ 3757.944937] agent systemd[1]: Reloading finished in 379 ms.631agent # [ 3758.034736] agent systemd[1]: Reload requested from client PID 1631 ('systemctl') (unit flakelet-relay-job-app.service)...632agent # [ 3758.034774] agent systemd[1]: Reloading...633agent # [ 3758.397802] agent systemd[1]: Reloading finished in 362 ms.634agent # [ 3758.496029] agent systemd[1]: Reload requested from client PID 1663 ('systemctl') (unit flakelet-relay-job-app.service)...635agent # [ 3758.496067] agent systemd[1]: Reloading...636agent # [ 3758.885465] agent systemd[1]: Reloading finished in 389 ms.637agent # [ 3758.965013] agent systemd[1]: Starting app slow2...638agent # [ 3765.007959] agent systemd[1]: Started app slow2.639agent # [ 3765.031619] agent flakelet[1564]: app: updated to generation 4640agent # [ 3765.036059] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.641agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.55 seconds)642(finished: subtest: detach returns once the job is accepted, in 8.62 seconds)643subtest: unknown host is final, missing agent is retried, agents listing644client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1645client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)646agent: must succeed: systemctl stop flakelet-agent647agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.06 seconds)648relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'649relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.01 seconds)650client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &651client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)652client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out653agent # [ 3765.609556] agent systemd[1]: Stopping flakelet-agent...654agent # [ 3765.637523] agent systemd[1]: flakelet-agent.service: Deactivated successfully.655agent # [ 3765.656292] agent systemd[1]: Stopped flakelet-agent.656agent # [ 3765.656546] agent systemd[1]: flakelet-agent.service: Consumed 1.226s CPU time over 33.203s wall clock time.657relay # [ 3765.610311] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:23.572059Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}658client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)659agent: must succeed: systemctl start flakelet-agent660agent: (finished: must succeed: systemctl start flakelet-agent, in 0.07 seconds)661??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.662 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39663client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out664agent # [ 3766.725113] agent systemd[1]: Starting flakelet-agent...665agent # [ 3766.761882] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:24.723682Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"6415a8111a6af56d21524e3070cded96\"]","target":"flakelet_relay::agent::jobs"}666agent # [ 3766.761977] agent systemd[1]: Started flakelet-agent.667agent # [ 3766.838558] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:24.800357Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}668relay # [ 3766.838613] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:24.800375Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}669agent # [ 3767.322119] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:25.283840Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}670agent # [ 3768.697467] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:26.659233Z","level":"INFO","message":"start","id":"f4e1cd34ec7722ade7e7ec6f12b07a75","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}671agent # [ 3768.698293] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:26.659957Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f4e1cd34ec7722ade7e7ec6f12b07a75\"]","target":"flakelet_relay::agent::jobs"}672agent # [ 3768.750258] agent systemd[1]: Starting flakelet update other (via relay)...673agent # [ 3768.756954] agent systemd[1]: Started flakelet update other (via relay).674agent # [ 3768.760828] agent flakelet[2130]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1675agent # [ 3768.761322] agent flakelet[2130]: other: up to date676agent # [ 3768.764063] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.677relay # [ 3768.696950] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:26.658761Z","level":"INFO","message":"deploy accepted","job":"ff27fa552d9f20d927d116677af72045","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}678relay # [ 3769.313588] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:27.275358Z","level":"INFO","message":"deploy finished","job":"ff27fa552d9f20d927d116677af72045","ok":true,"target":"flakelet_relay::relay::api"}679agent # [ 3769.312757] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:27.274541Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}680client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)681client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents682client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)683client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)684client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)685client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM0NywiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDQ3LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFWURXUVdHTFRFR09LPT09IiwibmJmIjoxNzg4NjgyMDQ3LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0._BxJlIA2kYb2AxJ5lhs-0yvMzRsMFtekgmg_EKHQv28StbEvtzV8a4j0J2rfOSbR_10RX0j4ejBBKcwcJmXqCg' push --relay https://relay:7443 agents686client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM0NywiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDQ3LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFWURXUVdHTFRFR09LPT09IiwibmJmIjoxNzg4NjgyMDQ3LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0._BxJlIA2kYb2AxJ5lhs-0yvMzRsMFtekgmg_EKHQv28StbEvtzV8a4j0J2rfOSbR_10RX0j4ejBBKcwcJmXqCg' push --relay https://relay:7443 agents, in 0.02 seconds)687(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.33 seconds)688subtest: certificate not listed under agents cannot connect as agent689client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent690client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.03 seconds)691(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)692subtest: metrics693relay: must succeed: curl -sf http://127.0.0.1:7400/metrics694relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)695(finished: subtest: metrics, in 0.01 seconds)696subtest: agent link drop mid-run replays missed lines once697agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json698agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)699agent: must succeed: date +%s700agent: (finished: must succeed: date +%s, in 0.01 seconds)701client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &702client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)703agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682047 | grep -q 'app-slow'704relay # [ 3769.932085] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:27.893874Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}705relay # [ 3769.992309] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:27.954099Z","level":"INFO","message":"deploy accepted","job":"c3765f7aa2367c0f7d5c91ee8a96b396","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}706agent # [ 3769.992725] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:27.954474Z","level":"INFO","message":"start","id":"979ff8cad74104866afe10c7a1eb4edf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}707agent # [ 3769.993490] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:27.955147Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"979ff8cad74104866afe10c7a1eb4edf\"]","target":"flakelet_relay::agent::jobs"}708agent # [ 3770.046524] agent systemd[1]: Starting flakelet update app (via relay)...709agent # [ 3770.078997] agent systemd[1]: Started flakelet update app (via relay).710agent # [ 3770.083012] agent flakelet[2155]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow711agent # [ 3770.083630] agent flakelet[2155]: app: activating generation 5712agent # [ 3770.096103] agent systemd[1]: Stopping app slow2...713agent # [ 3770.096554] agent systemd[1]: app.service: Deactivated successfully.714agent # [ 3770.096823] agent systemd[1]: Stopped app slow2.715agent # [ 3770.119572] agent systemd[1]: Reload requested from client PID 2162 ('systemctl') (unit flakelet-relay-job-app.service)...716agent # [ 3770.119639] agent systemd[1]: Reloading...717agent # [ 3770.472558] agent systemd[1]: Reloading finished in 352 ms.718agent # [ 3770.555591] agent systemd[1]: Reload requested from client PID 2192 ('systemctl') (unit flakelet-relay-job-app.service)...719agent # [ 3770.555625] agent systemd[1]: Reloading...720agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682047 | grep -q 'app-slow', in 1.02 seconds)721agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done722agent: (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)723relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done724relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)725agent: must succeed: ss -K dport = 7443726agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)727agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682047 | grep -q 'updated to generation'728agent # [ 3770.887646] agent systemd[1]: Reloading finished in 331 ms.729agent # [ 3770.970365] agent systemd[1]: Reload requested from client PID 2221 ('systemctl') (unit flakelet-relay-job-app.service)...730agent # [ 3770.970402] agent systemd[1]: Reloading...731agent # [ 3771.112539] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:29.074297Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}732relay # [ 3771.075850] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:29.037629Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}733agent # [ 3771.305357] agent systemd[1]: Reloading finished in 334 ms.734agent # [ 3771.397211] agent systemd[1]: Reload requested from client PID 2266 ('systemctl') (unit flakelet-relay-job-app.service)...735agent # [ 3771.397251] agent systemd[1]: Reloading...736agent # [ 3771.735362] agent systemd[1]: Reloading finished in 337 ms.737agent # [ 3771.824858] agent systemd[1]: Starting app slow...738agent # [ 3772.193915] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:30.155609Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}739agent # [ 3774.261156] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:32.222918Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}740agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682047 | grep -q 'updated to generation', in 7.10 seconds)741agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done742agent # [ 3777.866770] agent systemd[1]: Started app slow.743agent # [ 3777.887195] agent flakelet[2155]: app: updated to generation 5744agent # [ 3777.889993] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.745agent: (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)746client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out747relay # [ 3778.323107] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:36.284843Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}748agent # [ 3778.323081] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:36.284772Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}749agent # [ 3778.324215] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:36.286033Z","level":"INFO","message":"start","id":"979ff8cad74104866afe10c7a1eb4edf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}750client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 1.02 seconds)751client: must succeed: cat /tmp/slow.out752client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)753(finished: subtest: agent link drop mid-run replays missed lines once, in 9.31 seconds)754subtest: agent restart mid-run reattaches to the unit755agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json756agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)757client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &758client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)759agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'760relay # [ 3778.975504] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:36.937243Z","level":"INFO","message":"deploy finished","job":"c3765f7aa2367c0f7d5c91ee8a96b396","ok":true,"target":"flakelet_relay::relay::api"}761agent # [ 3778.974804] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:36.936575Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(5)","target":"flakelet_relay::agent::jobs"}762agent # [ 3779.294637] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:37.256282Z","level":"INFO","message":"start","id":"c0573973c7aaa8284c402b324b45ac23","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}763relay # [ 3779.294325] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:37.255901Z","level":"INFO","message":"deploy accepted","job":"824d0f0a88349ca0f9858fcfc5e503f1","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}764agent # [ 3779.295165] agent flakelet-agent[1717]: {"timestamp":"2026-09-06T08:07:37.256984Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"c0573973c7aaa8284c402b324b45ac23\"]","target":"flakelet_relay::agent::jobs"}765agent # [ 3779.351789] agent systemd[1]: Starting flakelet update app (via relay)...766agent # [ 3779.385160] agent systemd[1]: Started flakelet update app (via relay).767agent # [ 3779.389660] agent flakelet[2387]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2768agent # [ 3779.390306] agent flakelet[2387]: app: activating generation 6769agent # [ 3779.403504] agent systemd[1]: Stopping app slow...770agent # [ 3779.403950] agent systemd[1]: app.service: Deactivated successfully.771agent # [ 3779.404256] agent systemd[1]: Stopped app slow.772agent # [ 3779.420978] agent systemd[1]: Reload requested from client PID 2394 ('systemctl') (unit flakelet-relay-job-app.service)...773agent # [ 3779.421079] agent systemd[1]: Reloading...774agent # [ 3779.784331] agent systemd[1]: Reloading finished in 362 ms.775agent # [ 3779.874707] agent systemd[1]: Reload requested from client PID 2424 ('systemctl') (unit flakelet-relay-job-app.service)...776agent # [ 3779.874750] agent systemd[1]: Reloading...777agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)778agent: must succeed: systemctl restart flakelet-agent779agent # [ 3780.234290] agent systemd[1]: Reloading finished in 359 ms.780agent # [ 3780.310623] agent systemd[1]: Reload requested from client PID 2456 ('systemctl') (unit flakelet-relay-job-app.service)...781agent # [ 3780.310663] agent systemd[1]: Reloading...782agent # [ 3780.664619] agent systemd[1]: Reloading finished in 353 ms.783agent # [ 3780.750611] agent systemd[1]: Stopping flakelet-agent...784agent # [ 3780.758818] agent systemd[1]: Reload requested from client PID 2488 ('systemctl') (unit flakelet-relay-job-app.service)...785agent # [ 3780.758857] agent systemd[1]: Reloading...786relay # [ 3780.750821] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:38.712568Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}787agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.95 seconds)788agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"789agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)790client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out791agent # [ 3781.116553] agent systemd[1]: Reloading finished in 357 ms.792agent # [ 3781.194082] agent systemd[1]: flakelet-agent.service: Deactivated successfully.793agent # [ 3781.194283] agent systemd[1]: Stopped flakelet-agent.794agent # [ 3781.194300] agent systemd[1]: flakelet-agent.service: Consumed 1.021s CPU time over 14.469s wall clock time.795agent # [ 3781.198213] agent systemd[1]: Starting flakelet-agent...796agent # [ 3781.200736] agent systemd[1]: Starting app slow2...797agent # [ 3781.253986] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:39.215788Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"c0573973c7aaa8284c402b324b45ac23\"]","target":"flakelet_relay::agent::jobs"}798agent # [ 3781.254099] agent systemd[1]: Started flakelet-agent.799agent # [ 3781.322127] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:39.283910Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}800agent # [ 3781.323284] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:39.285105Z","level":"INFO","message":"start","id":"c0573973c7aaa8284c402b324b45ac23","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}801relay # [ 3781.322174] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:39.283963Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}802agent # [ 3787.277515] agent systemd[1]: Started app slow2.803agent # [ 3787.294877] agent flakelet[2387]: app: updated to generation 6804agent # [ 3787.297738] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.805agent # [ 3787.860805] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:45.822573Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(6)","target":"flakelet_relay::agent::jobs"}806client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.09 seconds)807client: must succeed: cat /tmp/restart.out808relay # [ 3787.861881] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:45.823633Z","level":"INFO","message":"deploy finished","job":"824d0f0a88349ca0f9858fcfc5e503f1","ok":true,"target":"flakelet_relay::relay::api"}809client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)810agent: must succeed: systemctl is-active app.service811agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)812(finished: subtest: agent restart mid-run reattaches to the unit, in 9.12 seconds)813subtest: relay restart mid-run, push resumes via /v1/jobs814agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json815agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)816agent: must succeed: date +%s817agent: (finished: must succeed: date +%s, in 0.01 seconds)818client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &819client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)820agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682066 | grep -q 'app-slow'821agent # [ 3788.418328] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:46.380105Z","level":"INFO","message":"start","id":"ea83c93e38cf5f38b478487d00cda383","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}822agent # [ 3788.418868] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:46.380688Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ea83c93e38cf5f38b478487d00cda383\"]","target":"flakelet_relay::agent::jobs"}823agent # [ 3788.469560] agent systemd[1]: Starting flakelet update app (via relay)...824agent # [ 3788.497378] agent systemd[1]: Started flakelet update app (via relay).825agent # [ 3788.501510] agent flakelet[2954]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow826agent # [ 3788.502364] agent flakelet[2954]: app: activating generation 7827agent # [ 3788.515813] agent systemd[1]: Stopping app slow2...828agent # [ 3788.516299] agent systemd[1]: app.service: Deactivated successfully.829agent # [ 3788.516576] agent systemd[1]: Stopped app slow2.830agent # [ 3788.533240] agent systemd[1]: Reload requested from client PID 2961 ('systemctl') (unit flakelet-relay-job-app.service)...831agent # [ 3788.533309] agent systemd[1]: Reloading...832relay # [ 3788.417976] relay flakelet-relay[402]: {"timestamp":"2026-09-06T08:07:46.379761Z","level":"INFO","message":"deploy accepted","job":"f43144b58d7704fbd50080b41c8ea784","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}833agent # [ 3788.886029] agent systemd[1]: Reloading finished in 352 ms.834agent # [ 3788.979687] agent systemd[1]: Reload requested from client PID 2991 ('systemctl') (unit flakelet-relay-job-app.service)...835agent # [ 3788.979728] agent systemd[1]: Reloading...836agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682066 | grep -q 'app-slow', in 1.03 seconds)837relay: must succeed: systemctl restart flakelet-relay838agent # [ 3789.337156] agent systemd[1]: Reloading finished in 357 ms.839agent # [ 3789.423386] agent systemd[1]: Reload requested from client PID 3020 ('systemctl') (unit flakelet-relay-job-app.service)...840agent # [ 3789.423428] agent systemd[1]: Reloading...841agent # [ 3789.447382] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:47.409145Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}842relay # [ 3789.446471] relay systemd[1]: Stopping flakelet-relay...843relay # [ 3789.496895] relay systemd[1]: flakelet-relay.service: Deactivated successfully.844relay # [ 3789.516839] relay systemd[1]: Stopped flakelet-relay.845relay # [ 3789.516915] relay systemd[1]: flakelet-relay.service: Consumed 2.411s CPU time over 55.979s wall clock time.846relay # [ 3789.560339] relay systemd[1]: Starting flakelet-relay...847agent # [ 3789.799887] agent systemd[1]: Reloading finished in 376 ms.848agent # [ 3789.890407] agent systemd[1]: Reload requested from client PID 3054 ('systemctl') (unit flakelet-relay-job-app.service)...849agent # [ 3789.890447] agent systemd[1]: Reloading...850agent # [ 3790.254628] agent systemd[1]: Reloading finished in 363 ms.851agent # [ 3790.340228] agent systemd[1]: Starting app slow...852agent # [ 3790.538334] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:48.499950Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}853relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.87 seconds)854client: waiting for success: grep -q '» ok' /tmp/resume.out855relay # [ 3791.302865] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:49.264626Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}856relay # [ 3791.303660] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:49.265071Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}857relay # [ 3791.303344] relay systemd[1]: Started flakelet-relay.858agent # [ 3792.613340] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:50.575127Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}859relay # [ 3792.613494] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:50.575226Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(6), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}860agent # [ 3796.384684] agent systemd[1]: Started app slow.861agent # [ 3796.403240] agent flakelet[2954]: app: updated to generation 7862agent # [ 3796.406477] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.863relay # [ 3796.464679] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:54.426418Z","level":"INFO","message":"job reattached","job":"f43144b58d7704fbd50080b41c8ea784","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}864agent # [ 3797.486898] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:55.448657Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}865client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)866client: must succeed: cat /tmp/resume.out867client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)868(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 10.02 seconds)869subtest: job history comes from the agents and survives a relay restart870client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1871agent # [ 3798.419610] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:56.381349Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}872agent # [ 3798.420198] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:56.382017Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}873agent # [ 3798.472824] agent systemd[1]: Starting flakelet update other (via relay)...874agent # [ 3798.509062] agent systemd[1]: Started flakelet update other (via relay).875agent # [ 3798.513767] agent flakelet[3131]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1876agent # [ 3798.514277] agent flakelet[3131]: other: up to date877agent # [ 3798.516570] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.878relay # [ 3798.419160] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:56.380909Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}879client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.67 seconds)880relay: must succeed: systemctl restart flakelet-relay881relay # [ 3799.069720] relay flakelet-relay[936]: {"timestamp":"2026-09-06T08:07:57.031481Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}882relay # [ 3799.084835] relay systemd[1]: Stopping flakelet-relay...883relay # [ 3799.144783] relay systemd[1]: flakelet-relay.service: Deactivated successfully.884relay # [ 3799.145321] relay systemd[1]: Stopped flakelet-relay.885relay # [ 3799.145365] relay systemd[1]: flakelet-relay.service: Consumed 2.166s CPU time over 9.584s wall clock time.886relay # [ 3799.183340] relay systemd[1]: Starting flakelet-relay...887agent # [ 3799.068728] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:57.030465Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}888agent # [ 3799.084921] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:57.046725Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}889agent # [ 3800.163722] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:07:58.125501Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}890relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.78 seconds)891relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'892relay # [ 3800.846366] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:07:58.808115Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}893relay # [ 3800.847268] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:07:58.808510Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}894relay # [ 3800.846800] relay systemd[1]: Started flakelet-relay.895relay # [ 3802.258275] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:00.220045Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}896agent # [ 3802.258186] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:00.219924Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}897relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds)898client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs899client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs, in 0.04 seconds)900client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)901client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)902client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUUVRaQ1RJTVhIM0RNPT09IiwibmJmIjoxNzg4NjgyMDgwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.7qMLKDVlXs81BxXId1JxxPT0EBQPYsaTw-G4o-RVdftSaAizfPyXN8Vs3qsrkppBNH70AksywjMkNDw4P1IXCA' push --relay https://relay:7443 jobs903client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUUVRaQ1RJTVhIM0RNPT09IiwibmJmIjoxNzg4NjgyMDgwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.7qMLKDVlXs81BxXId1JxxPT0EBQPYsaTw-G4o-RVdftSaAizfPyXN8Vs3qsrkppBNH70AksywjMkNDw4P1IXCA' push --relay https://relay:7443 jobs, in 0.02 seconds)904(finished: subtest: job history comes from the agents and survives a relay restart, in 4.62 seconds)905subtest: dashboard login via authorization code flow906client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login'907client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login', in 0.02 seconds)908client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login909client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds)910client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs911client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)912client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1913client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1, in 0.02 seconds)914client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true915client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true, in 0.02 seconds)916client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403917client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403, in 0.02 seconds)918client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other'919client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other', in 0.02 seconds)920client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/d5227279880866405f19b2e50e36eda1/events || true921relay # [ 3803.068747] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:01] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=ALu-5wDa2kZttsHkTpBp0qjKe5zcurc9FHQJQwJpTuE&code_challenge=ra6QYT1GPW2JFhDpG9qUAP_oXhv05soAdTb7oahDOa0&code_challenge_method=S256 HTTP/1.1" 302 -922relay # [ 3803.116564] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:01] "POST /token HTTP/1.1" 200 -923relay # [ 3803.117532] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:01.079343Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}924relay # [ 3803.183132] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:01.144884Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}925relay # [ 3803.227291] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:01.189050Z","level":"INFO","message":"deploy accepted","job":"20ca25c8cbd7b0aa7bc8341cf8cacef9","caller":"oidc:mock:someone\noidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}926relay # [ 3803.250039] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:01.211830Z","level":"INFO","message":"job reattached","job":"20ca25c8cbd7b0aa7bc8341cf8cacef9","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}927agent # [ 3803.227650] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:01.189433Z","level":"INFO","message":"start","id":"517efc93267304995cee814c14ae4abe","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}928agent # [ 3803.227923] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:01.189741Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"517efc93267304995cee814c14ae4abe\"]","target":"flakelet_relay::agent::jobs"}929agent # [ 3803.279557] agent systemd[1]: Starting flakelet update other (via relay)...930agent # [ 3803.312184] agent systemd[1]: Started flakelet update other (via relay).931agent # [ 3803.316521] agent flakelet[3169]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1932agent # [ 3803.317086] agent flakelet[3169]: other: up to date933agent # [ 3803.320081] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.934client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/d5227279880866405f19b2e50e36eda1/events || true, in 0.64 seconds)935client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/d5227279880866405f19b2e50e36eda1936client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/d5227279880866405f19b2e50e36eda1, in 0.02 seconds)937client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js938client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js, in 0.02 seconds)939client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth'940client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth', in 0.02 seconds)941client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other942client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other, in 0.02 seconds)943client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected'944client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected', in 0.02 seconds)945client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=d5227279880866405f19b2e50e36eda1' | grep -q 400946client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=d5227279880866405f19b2e50e36eda1' | grep -q 400, in 0.02 seconds)947client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &948client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &, in 0.01 seconds)949client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other950» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)951» wave 0952agent/other | Starting flakelet update other (via relay)...953agent/other | Started flakelet update other (via relay).954agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1955agent/other | other: up to date956agent # [ 3803.862482] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:01.824228Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}957agent/other | flakelet-relay-job-other.service: Deactivated successfully.958agent # [ 3803.998435] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:01.960222Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}959agent # [ 3803.998753] agent flakelet-agent[2519]: {"timestamp":"2026-09-06T08:08:01.960583Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}960agent # [ 3804.047837] agent systemd[1]: Starting flakelet update other (via relay)...961agent # [ 3804.081753] agent systemd[1]: Started flakelet update other (via relay).962agent # [ 3804.085457] agent flakelet[3187]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1963agent # [ 3804.085929] agent flakelet[3187]: other: up to date964agent # [ 3804.089128] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.965relay # [ 3803.998116] relay flakelet-relay[1326]: {"timestamp":"2026-09-06T08:08:01.959903Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}966» agent/other: unchanged (generation 1)967» ok968client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 0.66 seconds)969client: waiting for success: grep -q live1 /tmp/ev.out970client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)971client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout972client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout, in 0.02 seconds)973client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303974client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303, in 0.02 seconds)975(finished: subtest: dashboard login via authorization code flow, in 1.67 seconds)976(finished: run the VM test script, in 74.68 seconds)977test script finished in 74.72s978cleanup979kill NspawnMachine (pid 51)980kill NspawnMachine (pid 53)981Container agent terminated by signal KILL.982kill NspawnMachine (pid 55)983Container client terminated by signal KILL.984Container relay terminated by signal KILL.985(finished: cleanup, in 0.39 seconds)986additionally exposed symbols:987 agent, client, relay,988 vlan1,989 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_ssh990» job ff72ff843a7b29cc82f1d6904c1208b3 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/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2995agent/app | app: activating generation 2996agent/app | app: updated to generation 2997agent/app | flakelet-relay-job-app.service: Deactivated successfully.998» agent/app: updated (generation 2)999» ok10001001» job 68329352ce608a7a2c1c3592c7ff4456 via relay 0.1.0 (agents: agent 0.1.0)1002» wave 01003agent/app | Starting flakelet update app (via relay)...1004agent/app | Started flakelet update app (via relay).1005agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1006agent/app | app: activating generation 41007agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1008agent/app | failed units: app.service. See journalctl -u app.service1009agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1010agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1011» agent/app: rolled-back (generation 3)1012agent/app │ Starting app v1...1013agent/app │ Started app v1.1014agent/app │ Stopping app v1...1015agent/app │ app.service: Deactivated successfully.1016agent/app │ Stopped app v1.1017agent/app │ Starting app v2...1018agent/app │ Started app v2.1019agent/app │ Stopping app v2...1020agent/app │ app.service: Deactivated successfully.1021agent/app │ Stopped app v2.1022agent/app │ Starting app v1...1023agent/app │ Started app v1.1024agent/app │ Stopping app v1...1025agent/app │ app.service: Deactivated successfully.1026agent/app │ Stopped app v1.1027agent/app │ Starting app broken...1028agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1029agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1030agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1031agent/app │ app.service: Failed with result 'exit-code'.1032agent/app │ Failed to start app broken.1033agent/app │ Starting app v1...1034agent/app │ Started app v1.1035» skipped: agent/other1036» failed10371038» job c3765f7aa2367c0f7d5c91ee8a96b396 via relay 0.1.0 (agents: agent 0.1.0)1039» wave 01040agent/app | Starting flakelet update app (via relay)...1041agent/app | Started flakelet update app (via relay).1042agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1043agent/app | app: activating generation 51044agent/app | app: updated to generation 51045agent/app | flakelet-relay-job-app.service: Deactivated successfully.1046» agent/app: updated (generation 5)1047» ok10481049» job 824d0f0a88349ca0f9858fcfc5e503f1 via relay 0.1.0 (agents: agent 0.1.0)1050» wave 01051agent/app | Starting flakelet update app (via relay)...1052agent/app | Started flakelet update app (via relay).1053agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21054agent/app | app: activating generation 61055agent/app | app: updated to generation 61056agent/app | flakelet-relay-job-app.service: Deactivated successfully.1057» agent/app: updated (generation 6)1058» ok10591060» job f43144b58d7704fbd50080b41c8ea784 via relay 0.1.0 (agents: agent 0.1.0)1061» wave 01062agent/app | Starting flakelet update app (via relay)...1063agent/app | Started flakelet update app (via relay).1064agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1065agent/app | app: activating generation 71066flakelet-push: stream: error reading a body from connection, resuming job 545a568622105d8896b9c5e2d3690e301067flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1068flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1069flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1070» job f43144b58d7704fbd50080b41c8ea784 via relay 0.1.0 (agents: agent 0.1.0)1071» wave 01072agent/app | app: updated to generation 71073agent/app | flakelet-relay-job-app.service: Deactivated successfully.1074» agent/app: updated (generation 7)1075» ok107610771788682076 hist1 x509:email:admin@example.org agent/other:unchanged10781788682066 545a568622105d8896b9c5e2d3690e30 x509:email:admin@example.org agent/app:updated10791788682057 0c40adac69cb3af57a6e6a2673d66cc1 x509:email:admin@example.org agent/app:updated10801788682047 ffbba3cee244b43d306b03c9f9232092 x509:email:admin@example.org agent/app:updated10811788682046 a20b2af0366b360b0e04dd283bf953fc x509:email:admin@example.org agent/other:unchanged10821788682034 14fed5d4c41cea491c9e97118636aede x509:email:admin@example.org agent/app:unchanged10831788682034 1ae11c79e6c68a6aebfcffa50d413e3f x509:email:admin@example.org agent/app:updated10841788682032 2a524190919b4c3979865ff3edf10a56 x509:email:admin@example.org agent/app:unchanged10851788682032 ae930e8cbc386d538b700b78501cc0f6 x509:email:admin@example.org agent/app:unchanged10861788682027 29503fb289fe1ec289d23f1d68ff70f5 x509:email:admin@example.org agent/app:rolled-back10871788682026 286d4e6998ca4d9b6b6bbbc7045afcbc oidc:mock:groups:wheel agent/other:unchanged10881788682026 8f042cca6a08083399502cf283bc6613 oidc:mock:groups:wheel agent/other:unchanged10891788682022 c55dbab9759968d1d5824011108c5c09 oidc:mock:groups:wheel agent/other:unchanged10901788682019 6c7441853cf9c760de7e007f9860b697 oidc:mock:repo:github:example/app:ref:refs/heads/main agent/app:updated10911788682016 ed1b4041f2f14ced3e1984f519ba5483 x509:email:admin@example.org agent/app:updated1092

succeeded container-test-run-flakelet-relay checks.x86_64-linux.nixos-test · build #17 · raw

succeeded `container-test-run-flakelet-relay` `checks.x86_64-linux.nixos-test` · build #17 · raw