container-test-run-flakelet-relay
checks.x86_64-linux.nixos-test
· build #28
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9agent: systemd-nspawn running (pid 52)10client: systemd-nspawn running (pid 54)11agent: Waiting for journal at /build/vm-state-agent/var/log/journal...12client: Waiting for journal at /build/vm-state-client/var/log/journal...13relay: systemd-nspawn running (pid 56)14relay: Waiting for journal at /build/vm-state-relay/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(client): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(relay): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE22nixos-nspawn(agent): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.23Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.24Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.25░ Spawning container relay on /build/vm-state-relay.26Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.27░ Spawning container client on /build/vm-state-client.28░ Spawning container agent on /build/vm-state-agent.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31client # No journal files were found.32client # No journal boot entry found for the specified boot (+0).33relay # No journal files were found.34relay # No journal boot entry found for the specified boot (+0).35agent # [13779.732380] agent systemd-journald[57]: Journal started36agent # [13779.732423] agent systemd-journald[57]: Runtime Journal (/run/log/journal/0a227b56a4594bfca0c93f50f6110508) is 8M, max 4G, 3.9G free.37agent # [13779.743181] agent systemd[1]: Finished Apply Kernel Variables.38agent # [13779.756783] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39agent # [13779.797571] agent systemd[1]: Starting Flush Journal to Persistent Storage...40agent # [13779.798512] agent systemd[1]: Starting Create Static Device Nodes in /dev...41agent # [13779.807556] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/0a227b56a4594bfca0c93f50f6110508 is 2.505ms for 6 entries.42agent # [13779.807556] agent systemd-journald[57]: System Journal (/var/log/journal/0a227b56a4594bfca0c93f50f6110508) is 512B, max 4G, 3.9G free.43agent # [13779.816659] agent systemd[1]: Finished Create Static Device Nodes in /dev.44agent # [13779.817520] agent systemd[1]: Reached target Preparation for Local File Systems.45agent # [13779.817613] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46agent # [13779.841621] agent systemd[1]: Finished Flush Journal to Persistent Storage.47agent # [13779.912099] agent systemd[1]: Finished Firewall.48agent # [13780.742140] agent systemd[1]: Mounting /run/wrappers...49agent # [13780.783755] agent systemd[1]: Mounted /run/wrappers.50agent # [13780.784875] agent systemd[1]: Reached target Local File Systems.51agent # [13780.786218] agent systemd[1]: Listening on Boot Loader Control Service Socket.52agent # [13780.787627] agent systemd[1]: Starting Create SUID/SGID Wrappers...53agent # [13780.787674] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container54agent # [13780.788684] agent systemd[1]: Starting Save Transient machine-id to Disk...55agent # [13780.789767] agent systemd[1]: Starting Create System Files and Directories...56client # [13779.733014] client systemd-journald[57]: Journal started57client # [13779.733058] client systemd-journald[57]: Runtime Journal (/run/log/journal/768415d70e1f4bbdb72c81cb9b697b8a) is 8M, max 4G, 3.9G free.58client # [13779.743856] client systemd[1]: Finished Apply Kernel Variables.59client # [13779.757357] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.60client # [13779.797526] client systemd[1]: Starting Flush Journal to Persistent Storage...61client # [13779.798463] client systemd[1]: Starting Create Static Device Nodes in /dev...62client # [13779.806872] client systemd-journald[57]: Time spent on flushing to /var/log/journal/768415d70e1f4bbdb72c81cb9b697b8a is 3.002ms for 6 entries.63client # [13779.806872] client systemd-journald[57]: System Journal (/var/log/journal/768415d70e1f4bbdb72c81cb9b697b8a) is 512B, max 4G, 3.9G free.64client # [13779.817149] client systemd[1]: Finished Create Static Device Nodes in /dev.65client # [13779.817837] client systemd[1]: Reached target Preparation for Local File Systems.66client # [13779.817939] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys67client # [13779.845422] client systemd[1]: Finished Flush Journal to Persistent Storage.68client # [13779.907856] client systemd[1]: Finished Firewall.69client # [13780.741785] client systemd[1]: Mounting /run/wrappers...70client # [13780.783532] client systemd[1]: Mounted /run/wrappers.71client # [13780.784584] client systemd[1]: Reached target Local File Systems.72client # [13780.785822] client systemd[1]: Listening on Boot Loader Control Service Socket.73client # [13780.787096] client systemd[1]: Starting Create SUID/SGID Wrappers...74client # [13780.787145] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container75client # [13780.788135] client systemd[1]: Starting Save Transient machine-id to Disk...76client # [13780.789085] client systemd[1]: Starting Create System Files and Directories...77relay # [13779.724433] relay systemd-journald[57]: Journal started78relay # [13779.724474] relay systemd-journald[57]: Runtime Journal (/run/log/journal/c2e0cc80a76946869391671b60cc0c4f) is 8M, max 4G, 3.9G free.79relay # [13779.734330] relay systemd[1]: Finished Apply Kernel Variables.80relay # [13779.746334] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.81relay # [13779.760850] relay systemd[1]: Starting Flush Journal to Persistent Storage...82relay # [13779.761913] relay systemd[1]: Starting Create Static Device Nodes in /dev...83relay # [13779.803312] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/c2e0cc80a76946869391671b60cc0c4f is 1.352ms for 6 entries.84relay # [13779.803312] relay systemd-journald[57]: System Journal (/var/log/journal/c2e0cc80a76946869391671b60cc0c4f) is 512B, max 4G, 3.9G free.85relay # [13779.813419] relay systemd[1]: Finished Create Static Device Nodes in /dev.86relay # [13779.814218] relay systemd[1]: Reached target Preparation for Local File Systems.87relay # [13779.814355] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys88relay # [13779.829617] relay systemd[1]: Finished Flush Journal to Persistent Storage.89relay # [13779.923527] relay systemd[1]: Finished Firewall.90relay # [13780.736314] relay systemd[1]: Mounting /run/wrappers...91relay # [13780.766209] relay systemd[1]: Mounted /run/wrappers.92relay # [13780.767015] relay systemd[1]: Reached target Local File Systems.93relay # [13780.767813] relay systemd[1]: Listening on Boot Loader Control Service Socket.94relay # [13780.768727] relay systemd[1]: Starting Create SUID/SGID Wrappers...95relay # [13780.768754] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container96relay # [13780.769696] relay systemd[1]: Starting Save Transient machine-id to Disk...97relay # [13780.770589] relay systemd[1]: Starting Create System Files and Directories...98relay # [13780.789385] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted99relay # [13780.789789] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted100relay # [13780.790082] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/c2e0cc80a76946869391671b60cc0c4f failed: Operation not permitted101relay # [13780.790414] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted102relay # [13780.796697] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.XIevAPSPyS/chsh': Operation not permitted103client # [13780.806497] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted104client # [13780.806902] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted105client # [13780.807301] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/768415d70e1f4bbdb72c81cb9b697b8a failed: Operation not permitted106client # [13780.807623] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted107agent # [13780.811912] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted108agent # [13780.812345] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted109agent # [13780.812666] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/0a227b56a4594bfca0c93f50f6110508 failed: Operation not permitted110agent # [13780.812998] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted111relay # [13780.799162] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE112relay # [13780.799409] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.113relay # [13780.799595] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.114relay # [13780.799991] relay systemd[1]: Finished Create System Files and Directories.115relay # [13780.819299] relay systemd[1]: Starting Rebuild Journal Catalog...116relay # [13780.820163] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...117relay # [13780.832318] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.118relay # [13780.838868] relay systemd[1]: Finished Rebuild Journal Catalog.119relay # [13780.840095] relay systemd[1]: Starting Update is Completed...120relay # [13780.849417] relay systemd[1]: Finished Update is Completed.121relay # [13780.849500] relay systemd[1]: Reached target System Initialization.122relay # [13780.849561] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123relay # [13780.849587] relay systemd[1]: Started Daily Cleanup of Temporary Directories.124relay # [13780.849603] relay systemd[1]: Reached target Timer Units.125relay # [13780.849704] relay systemd[1]: Listening on D-Bus System Message Bus Socket.126relay # [13780.849873] relay systemd[1]: Listening on Nix Daemon Socket.127relay # [13780.849963] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128relay # [13780.849977] relay systemd[1]: Reached target Socket Units.129relay # [13780.850011] relay systemd[1]: Reached target Basic System.130relay # [13780.851198] relay systemd[1]: Started device-mock.service.131relay # [13780.852157] relay systemd[1]: Starting Re-link flakelet services at boot...132relay # [13780.854209] relay systemd[1]: Starting Import lastlog data into lastlog2 database...133relay # [13780.855320] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...134relay # [13780.856179] relay systemd[1]: Starting resolvconf update...135relay # [13780.866693] relay systemd[1]: Finished Re-link flakelet services at boot.136relay # [13780.868953] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...137relay # [13780.876016] relay systemd[1]: Finished Import lastlog data into lastlog2 database.138relay # [13780.880745] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.139relay # [13780.943450] relay systemd[1]: nscd.service: Deactivated successfully.140relay # [13780.943591] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).141relay # [13780.950957] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...142relay # [13780.992312] relay systemd[1]: Finished resolvconf update.143client # [13780.814481] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.dHCPOKYvvx/chsh': Operation not permitted144client # [13780.821514] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE145client # [13780.821556] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.146client # [13780.821604] client systemd[1]: Failed to start Create SUID/SGID Wrappers.147client # [13780.822080] client systemd[1]: Finished Create System Files and Directories.148client # [13780.836517] client systemd[1]: Starting Rebuild Journal Catalog...149client # [13780.837321] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...150client # [13780.850419] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.151client # [13780.855256] client systemd[1]: Finished Rebuild Journal Catalog.152client # [13780.856579] client systemd[1]: Starting Update is Completed...153client # [13780.867882] client systemd[1]: Finished Update is Completed.154client # [13780.867971] client systemd[1]: Reached target System Initialization.155client # [13780.868066] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container156client # [13780.868116] client systemd[1]: Started Daily Cleanup of Temporary Directories.157client # [13780.868135] client systemd[1]: Reached target Timer Units.158client # [13780.868257] client systemd[1]: Listening on D-Bus System Message Bus Socket.159client # [13780.868452] client systemd[1]: Listening on Nix Daemon Socket.160client # [13780.868559] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.161client # [13780.868580] client systemd[1]: Reached target Socket Units.162client # [13780.868615] client systemd[1]: Reached target Basic System.163client # [13780.869809] client systemd[1]: Starting Import lastlog data into lastlog2 database...164client # [13780.870625] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...165client # [13780.871347] client systemd[1]: Starting resolvconf update...166client # [13780.889157] client systemd[1]: Finished Import lastlog data into lastlog2 database.167agent # [13780.813805] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.Y0g9u8eZuO/chsh': Operation not permitted168agent # [13780.824272] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE169agent # [13780.824311] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.170agent # [13780.824367] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.171agent # [13780.824909] agent systemd[1]: Finished Create System Files and Directories.172agent # [13780.841509] agent systemd[1]: Starting Rebuild Journal Catalog...173agent # [13780.842395] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...174agent # [13780.856033] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.175agent # [13780.863048] agent systemd[1]: Finished Rebuild Journal Catalog.176agent # [13780.864144] agent systemd[1]: Starting Update is Completed...177agent # [13780.874962] agent systemd[1]: Finished Update is Completed.178agent # [13780.875106] agent systemd[1]: Reached target System Initialization.179agent # [13780.875168] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container180agent # [13780.875194] agent systemd[1]: Started Daily Cleanup of Temporary Directories.181agent # [13780.875207] agent systemd[1]: Reached target Timer Units.182agent # [13780.875301] agent systemd[1]: Listening on D-Bus System Message Bus Socket.183agent # [13780.875481] agent systemd[1]: Listening on Nix Daemon Socket.184agent # [13780.875578] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.185agent # [13780.875592] agent systemd[1]: Reached target Socket Units.186agent # [13780.875714] agent systemd[1]: Reached target Basic System.187agent # [13780.877034] agent systemd[1]: Starting Re-link flakelet services at boot...188agent # [13780.877641] agent systemd[1]: Starting Import lastlog data into lastlog2 database...189agent # [13780.878416] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...190agent # [13780.879092] agent systemd[1]: Starting resolvconf update...191agent # [13780.890339] agent systemd[1]: Finished Re-link flakelet services at boot.192agent # [13780.891414] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...193agent # [13780.893267] agent systemd[1]: Finished Import lastlog data into lastlog2 database.194agent # [13780.906424] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.195agent # [13780.999673] agent systemd[1]: nscd.service: Deactivated successfully.196agent # [13780.999967] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).197agent # [13781.002812] agent systemd[1]: Finished resolvconf update.198agent # [13781.004245] agent systemd[1]: Reached target Preparation for Network.199agent # [13781.005977] agent systemd[1]: Starting Address configuration of eth1...200agent # [13781.007326] agent systemd[1]: Starting Extra networking commands....201agent # [13781.008968] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...202agent # [13781.027938] agent network-addresses-eth1-start[239]: adding address 192.168.1.1/24... done203agent # [13781.031246] agent network-addresses-eth1-start[239]: adding address 2001:db8:1::1/64... done204agent # [13781.036937] agent systemd[1]: Finished Address configuration of eth1.205relay # [13780.993669] relay systemd[1]: Reached target Preparation for Network.206agent # [13781.091067] agent systemd[1]: nscd.service: Deactivated successfully.207relay # [13780.995647] relay systemd[1]: Starting Address configuration of eth1...208agent # [13781.091317] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).209relay # [13780.997366] relay systemd[1]: Starting Extra networking commands....210agent # [13781.093705] agent systemd[1]: Finished Extra networking commands..211relay # [13781.018512] relay network-addresses-eth1-start[250]: adding address 192.168.1.3/24... done212agent # [13781.094927] agent systemd[1]: Reached target Network.213relay # [13781.022299] relay network-addresses-eth1-start[250]: adding address 2001:db8:1::3/64... done214agent # [13781.096499] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...215relay # [13781.029039] relay systemd[1]: Finished Address configuration of eth1.216agent # [13781.097842] agent systemd[1]: Starting Update flakelet service app...217relay # [13781.065435] relay systemd[1]: Finished Extra networking commands..218agent # [13781.099073] agent systemd[1]: Starting Update flakelet service flakelet-agent...219relay # [13781.066103] relay systemd[1]: Reached target Network.220agent # [13781.100259] agent systemd[1]: Starting Update flakelet service other...221relay # [13781.067564] relay systemd[1]: Starting Dnsmasq Daemon...222agent # [13781.110927] agent flakelet[308]: flakelet-agent: using prebuilt artifact /nix/store/8kqvay1p8vv145jvk6s1sp0j3q4w3drk-flakelet-flakelet-agent223relay # [13781.068437] relay systemd[1]: Starting Nginx Web Server...224agent # [13781.111574] agent flakelet[307]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1225relay # [13781.069373] relay systemd[1]: Starting Update flakelet service flakelet-relay...226agent # [13781.112074] agent flakelet[307]: app: activating generation 1227relay # [13781.094302] relay flakelet[310]: flakelet-relay: using prebuilt artifact /nix/store/b2nmz15xs52x4jlbl3w1w7mjivxz0lxn-flakelet-flakelet-relay228agent # [13781.112129] agent flakelet[308]: flakelet-agent: activating generation 1229relay # [13781.094983] relay flakelet[310]: flakelet-relay: activating generation 1230agent # [13781.113739] agent flakelet[309]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1231relay # [13781.099035] relay systemd[1]: Reload requested from client PID 315 ('systemctl') (unit flakelet-flakelet-relay.service)...232agent # [13781.114351] agent flakelet[309]: other: activating generation 1233relay # [13781.099074] relay systemd[1]: Reloading...234agent # [13781.119788] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-app.service)...235agent # [13781.119853] agent systemd[1]: Reloading...236client # [13780.994392] client systemd[1]: Finished resolvconf update.237client # [13780.994657] client systemd[1]: Reached target Preparation for Network.238client # [13780.995995] client systemd[1]: Starting Address configuration of eth1...239client # [13780.997220] client systemd[1]: Starting Extra networking commands....240client # [13780.997549] client systemd[1]: nscd.service: Deactivated successfully.241client # [13780.997729] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).242client # [13781.001666] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...243client # [13781.018470] client network-addresses-eth1-start[233]: adding address 192.168.1.2/24... done244client # [13781.022601] client network-addresses-eth1-start[233]: adding address 2001:db8:1::2/64... done245client # [13781.027612] client systemd[1]: Finished Address configuration of eth1.246client # [13781.086714] client systemd[1]: Finished Extra networking commands..247client # [13781.090651] client systemd[1]: Reached target Network.248client # [13781.092780] client systemd[1]: nscd.service: Deactivated successfully.249client # [13781.092973] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).250client # [13781.096482] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...251relay # [13781.458029] relay nsncd[242]: Sep 06 10:54:19.419 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"252relay # [13781.525019] relay systemd[1]: Reloading finished in 425 ms.253relay # [13781.668391] relay systemd[1]: Started Name Service Cache Daemon (nsncd).254relay # [13781.668886] relay systemd[1]: Reached target Host and Network Name Lookups.255relay # [13781.668975] relay systemd[1]: Reached target User and Group Name Lookups.256relay # [13781.670184] relay systemd[1]: Starting User Login Management...257relay # [13781.671248] relay systemd[1]: Starting Permit User Sessions...258relay # [13781.686839] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...259relay # [13781.686874] relay systemd[1]: Reloading...260agent # [13781.422665] agent nsncd[306]: Sep 06 10:54:19.384 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"261agent # [13781.518358] agent systemd[1]: Reloading finished in 397 ms.262agent # [13781.709979] agent systemd[1]: Started Name Service Cache Daemon (nsncd).263client # [13781.428777] client nsncd[302]: Sep 06 10:54:19.390 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"264client # [13781.428904] client systemd[1]: Started Name Service Cache Daemon (nsncd).265client # [13781.428984] client systemd[1]: Reached target Host and Network Name Lookups.266client # [13781.429159] client systemd[1]: Reached target User and Group Name Lookups.267client # [13781.431710] client systemd[1]: Starting User Login Management...268client # [13781.433222] client systemd[1]: Starting Permit User Sessions...269client # [13781.472564] client systemd[1]: Finished Permit User Sessions.270client # [13781.474806] client systemd[1]: Started Console Getty.271client # [13781.474861] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0272client # [13781.474891] client systemd[1]: Reached target Login Prompts.273agent # [13781.714601] agent systemd[1]: Reload requested from client PID 311 ('systemctl') (unit flakelet-flakelet-agent.service)...274agent # [13781.714675] agent systemd[1]: Reloading...275relay # [13781.729473] relay dnsmasq-pre-start[375]: dnsmasq: syntax check OK.276client # [13781.887419] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.277client # [13781.888451] client systemd[1]: Finished Save Transient machine-id to Disk.278agent # [13782.146805] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.279agent # [13782.146991] agent systemd[1]: Reloading finished in 431 ms.280agent # [13782.305636] agent systemd[1]: Finished Save Transient machine-id to Disk.281agent # [13782.306339] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-other.service)...282agent # [13782.306386] agent systemd[1]: Reloading...283relay # [13782.157431] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.284relay # [13782.157806] relay systemd[1]: Reloading finished in 470 ms.285relay # [13782.303914] relay systemd[1]: Finished Save Transient machine-id to Disk.286relay # [13782.305304] relay systemd[1]: Finished Permit User Sessions.287relay # [13782.337639] relay systemd[1]: Started Console Getty.288relay # [13782.337724] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0289relay # [13782.337796] relay systemd[1]: Reached target Login Prompts.290relay # [13782.340089] relay systemd[1]: Starting flakelet-relay...291agent # [13782.680890] agent systemd[1]: Reloading finished in 373 ms.292agent # [13782.752679] agent systemd[1]: Reached target Host and Network Name Lookups.293agent # [13782.752807] agent systemd[1]: Reached target User and Group Name Lookups.294agent # [13782.754301] agent systemd[1]: Starting User Login Management...295agent # [13782.755303] agent systemd[1]: Starting Permit User Sessions...296agent # [13782.758984] agent systemd[1]: Reload requested from client PID 408 ('systemctl') (unit flakelet-app.service)...297agent # [13782.759020] agent systemd[1]: Reloading...298relay # [13782.883352] relay nginx-pre-start[404]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok299relay # [13782.883992] relay nginx-pre-start[404]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful300relay # [13782.904155] relay systemd[1]: Started Nginx Web Server.301relay # [13782.933133] relay systemd[1]: Starting D-Bus System Message Bus...302client # [13783.013414] client systemd-logind[314]: New seat seat0.303client # [13783.013856] client systemd[1]: Started User Login Management.304client # [13783.015859] client systemd[1]: Starting D-Bus System Message Bus...305client # [13783.017401] client systemd[1]: Starting linger-users.service...306client # [13783.056228] client systemd[1]: linger-users.service: Deactivated successfully.307client # [13783.056617] client systemd[1]: Finished linger-users.service.308client # [13783.056974] client systemd[1]: Reached target Multi-User System.309relay # [13783.229963] relay systemd-logind[354]: New seat seat0.310relay # [13783.230370] relay systemd[1]: Started User Login Management.311relay # [13783.232848] relay systemd[1]: Starting linger-users.service...312relay # [13783.280830] relay systemd[1]: linger-users.service: Deactivated successfully.313relay # [13783.281196] relay systemd[1]: Finished linger-users.service.314agent # [13783.137411] agent systemd[1]: Reloading finished in 378 ms.315agent # [13783.218743] agent systemd[1]: Finished Permit User Sessions.316agent # [13783.224488] agent systemd[1]: Started Console Getty.317agent # [13783.224579] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0318agent # [13783.224689] agent systemd[1]: Reached target Login Prompts.319agent # [13783.226799] agent systemd[1]: Reload requested from client PID 412 ('systemctl') (unit flakelet-flakelet-agent.service)...320agent # [13783.226828] agent systemd[1]: Reloading...321agent # [13783.561938] agent systemd[1]: Reloading finished in 334 ms.322agent # [13783.647996] agent systemd[1]: Starting app v1...323agent # [13783.649635] agent systemd[1]: Reload requested from client PID 448 ('systemctl') (unit flakelet-other.service)...324agent # [13783.649675] agent systemd[1]: Reloading...325relay # [13783.497850] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...326relay # [13783.498882] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'327relay # [13783.498882] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"328relay # [13783.499741] relay systemd[1]: Started D-Bus System Message Bus.329relay # [13783.505805] relay dbus-broker-launch[408]: Ready330relay # [13783.509447] relay systemd[1]: Started Dnsmasq Daemon.331relay # [13783.511458] relay dnsmasq[396]: started, version 2.93 cachesize 150332relay # [13783.511473] relay dnsmasq[396]: 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 dumpfile333relay # [13783.511486] relay dnsmasq[396]: DBus support enabled: connected to system bus334relay # [13783.511497] relay dnsmasq[396]: no upstream servers configured - please set them from DBus335relay # [13783.511625] relay dnsmasq[396]: read /etc/hosts - 9 names336client # [13783.537175] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...337client # [13783.538567] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'338client # [13783.538567] client dbus-broker-launch[325]: Invalid user-name in /nix/store/hxpsm3bnqlhm74a81cmd7dmp88rc8hak-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"339client # [13783.539304] client systemd[1]: Started D-Bus System Message Bus.340client # [13783.539562] client systemd[1]: Startup finished in 4.230s.341client # [13783.545936] client dbus-broker-launch[325]: Ready342agent # [13783.971718] agent systemd[1]: Reloading finished in 321 ms.343agent # [13784.047764] agent systemd[1]: Started app v1.344agent # [13784.051762] agent systemd[1]: Starting flakelet-agent...345agent # [13784.094949] agent systemd-logind[409]: New seat seat0.346agent # [13784.103935] agent systemd[1]: Starting other v1...347agent # [13784.104131] agent systemd[1]: Started User Login Management.348agent # [13784.119977] agent systemd[1]: Started other v1.349agent # [13784.121938] agent systemd[1]: Starting D-Bus System Message Bus...350agent # [13784.122898] agent systemd[1]: Starting linger-users.service...351agent # [13784.127552] agent flakelet[307]: app: updated to generation 1352agent # [13784.129058] agent systemd[1]: Finished Update flakelet service app.353agent # [13784.135609] agent flakelet[309]: other: updated to generation 1354agent # [13784.137141] agent systemd[1]: Finished Update flakelet service other.355agent # [13784.137451] agent systemd[1]: linger-users.service: Deactivated successfully.356agent # [13784.137572] agent systemd[1]: Finished linger-users.service.357agent # [13784.193213] agent systemd[1]: Started flakelet-agent.358agent # [13784.196368] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:22.157986Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}359agent # [13784.209023] agent flakelet[308]: flakelet-agent: updated to generation 1360agent # [13784.210172] agent systemd[1]: Finished Update flakelet service flakelet-agent.361agent # [13784.212127] agent systemd[1]: Reached target flakelet managed services.362agent # [13784.212170] agent systemd[1]: Reached target Multi-User System.363relay # [13784.353723] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:22.315369Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}364relay # [13784.354604] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:22.316088Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}365relay # [13784.354414] relay systemd[1]: Started flakelet-relay.366relay # [13784.363964] relay systemd[1]: Starting health for flakelet-relay...367agent # [13784.596364] agent dbus-broker-launch[670]: Looking up NSS user entry for 'systemd-timesync'...368agent # [13784.597582] agent dbus-broker-launch[670]: NSS returned no entry for 'systemd-timesync'369agent # [13784.597582] agent dbus-broker-launch[670]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"370agent # [13784.598396] agent systemd[1]: Started D-Bus System Message Bus.371agent # [13784.598702] agent systemd[1]: Startup finished in 5.291s.372agent # [13784.604184] agent dbus-broker-launch[670]: Ready373relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)374relay: waiting for unit nginx.service375relay: (finished: waiting for unit nginx.service, in 0.02 seconds)376agent: waiting for unit flakelet.target377agent: (finished: waiting for unit flakelet.target, in 0.01 seconds)378agent: waiting for unit flakelet-agent.service379agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)380client: waiting for unit multi-user.target381client: (finished: waiting for unit multi-user.target, in 0.02 seconds)382relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'383relay # [13784.670075] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.384relay # [13784.670457] relay systemd[1]: Finished health for flakelet-relay.385relay # [13784.712756] relay flakelet[310]: flakelet-relay: updated to generation 1386relay # [13784.716158] relay systemd[1]: Finished Update flakelet service flakelet-relay.387relay # [13784.716704] relay systemd[1]: Reached target flakelet managed services.388relay # [13784.716887] relay systemd[1]: Reached target Multi-User System.389relay # [13784.717161] relay systemd[1]: Startup finished in 5.408s.390relay # [13786.216354] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:24.178118Z","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"}391agent # [13786.216108] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:24.177757Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}392relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)393agent: must succeed: systemctl is-active app.service other.service394agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)395subtest: deploy with client certificate, relay found via SRV396agent: 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.json397agent: (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.02 seconds)398client: 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>&1399agent # [13787.123692] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:25.085409Z","level":"INFO","message":"start","id":"227a864ccfa28d2ecb018f5f289bafcf","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}400agent # [13787.124618] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:25.086419Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"227a864ccfa28d2ecb018f5f289bafcf\"]","target":"flakelet_relay::agent::jobs"}401agent # [13787.191895] agent systemd[1]: Starting flakelet update app (via relay)...402agent # [13787.223026] agent systemd[1]: Started flakelet update app (via relay).403agent # [13787.227748] agent flakelet[962]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2404agent # [13787.228446] agent flakelet[962]: app: activating generation 2405agent # [13787.241803] agent systemd[1]: Stopping app v1...406agent # [13787.242307] agent systemd[1]: app.service: Deactivated successfully.407agent # [13787.242588] agent systemd[1]: Stopped app v1.408agent # [13787.259640] agent systemd[1]: Reload requested from client PID 969 ('systemctl') (unit flakelet-relay-job-app.service)...409agent # [13787.259708] agent systemd[1]: Reloading...410relay # [13787.122844] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:25.084617Z","level":"INFO","message":"deploy accepted","job":"709c2bd7e751ca0e797473fae9dbe115","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}411agent # [13787.590257] agent systemd[1]: Reloading finished in 329 ms.412agent # [13787.679496] agent systemd[1]: Reload requested from client PID 999 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [13787.679539] agent systemd[1]: Reloading...414agent # [13788.001781] agent systemd[1]: Reloading finished in 321 ms.415agent # [13788.085828] agent systemd[1]: Reload requested from client PID 1028 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [13788.085870] agent systemd[1]: Reloading...417agent # [13788.407057] agent systemd[1]: Reloading finished in 320 ms.418agent # [13788.498446] agent systemd[1]: Reload requested from client PID 1062 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [13788.498482] agent systemd[1]: Reloading...420agent # [13788.816717] agent systemd[1]: Reloading finished in 317 ms.421agent # [13788.895779] agent systemd[1]: Starting app v2...422agent # [13788.926242] agent systemd[1]: Started app v2.423agent # [13788.940746] agent flakelet[962]: app: updated to generation 2424agent # [13788.941864] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.425client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.97 seconds)426agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'427agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)428agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'429agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)430(finished: subtest: deploy with client certificate, relay found via SRV, in 3.01 seconds)431subtest: deploy with OIDC token, sub principal432agent: 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.json433agent: (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)434client: 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)435client: (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)436client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSMlk0VjVMV1dMSE1PPT09IiwibmJmIjoxNzg4NjkyMDY4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.BjaQ7iUof7avjxG8XAigNhY3Ul7AFi-rv_Rh9y8bLiELSPEjQhGBVuzw9gCsO0dI33b0YWpMboh-ObHh77UyAQ' push --relay https://relay:7443 deploy agent/app 2>&1437agent # [13790.062456] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:28.024225Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}438agent # [13790.201069] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:28.162839Z","level":"INFO","message":"start","id":"2106b14872dd5cb43f025237819292bc","flakelet":"app","rule":"ci","relay":"relay","caller_name":"Some(\"repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}439agent # [13790.201517] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:28.163340Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2106b14872dd5cb43f025237819292bc\"]","target":"flakelet_relay::agent::jobs"}440agent # [13790.277156] agent systemd[1]: Starting flakelet update app (via relay)...441agent # [13790.310046] agent systemd[1]: Started flakelet update app (via relay).442relay # [13790.064262] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:28.025952Z","level":"INFO","message":"deploy finished","job":"709c2bd7e751ca0e797473fae9dbe115","ok":true,"target":"flakelet_relay::relay::api"}443relay # [13790.200847] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:28.162609Z","level":"INFO","message":"deploy accepted","job":"a51a7dd2ea78427e565f708e35e88100","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}444agent # [13790.314694] agent flakelet[1160]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1445agent # [13790.315404] agent flakelet[1160]: app: activating generation 3446agent # [13790.323649] agent systemd[1]: Stopping app v2...447agent # [13790.324357] agent systemd[1]: app.service: Deactivated successfully.448agent # [13790.324484] agent systemd[1]: Stopped app v2.449agent # [13790.334890] agent systemd[1]: Reload requested from client PID 1170 ('systemctl') (unit flakelet-relay-job-app.service)...450agent # [13790.334926] agent systemd[1]: Reloading...451agent # [13790.657605] agent systemd[1]: Reloading finished in 322 ms.452agent # [13790.741879] agent systemd[1]: Reload requested from client PID 1200 ('systemctl') (unit flakelet-relay-job-app.service)...453agent # [13790.741918] agent systemd[1]: Reloading...454agent # [13791.064143] agent systemd[1]: Reloading finished in 321 ms.455agent # [13791.158401] agent systemd[1]: Reload requested from client PID 1229 ('systemctl') (unit flakelet-relay-job-app.service)...456agent # [13791.158442] agent systemd[1]: Reloading...457agent # [13791.482651] agent systemd[1]: Reloading finished in 323 ms.458agent # [13791.566889] agent systemd[1]: Reload requested from client PID 1260 ('systemctl') (unit flakelet-relay-job-app.service)...459agent # [13791.566927] agent systemd[1]: Reloading...460agent # [13791.892484] agent systemd[1]: Reloading finished in 325 ms.461agent # [13791.977765] agent systemd[1]: Starting app v1...462agent # [13792.010323] agent systemd[1]: Started app v1.463agent # [13792.023028] agent flakelet[1160]: app: updated to generation 3464agent # [13792.025277] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.465client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSMlk0VjVMV1dMSE1PPT09IiwibmJmIjoxNzg4NjkyMDY4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.BjaQ7iUof7avjxG8XAigNhY3Ul7AFi-rv_Rh9y8bLiELSPEjQhGBVuzw9gCsO0dI33b0YWpMboh-ObHh77UyAQ' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.97 seconds)466(finished: subtest: deploy with OIDC token, sub principal, in 3.04 seconds)467subtest: policy denies uncovered target468client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSMlk0VjVMV1dMSE1PPT09IiwibmJmIjoxNzg4NjkyMDY4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.BjaQ7iUof7avjxG8XAigNhY3Ul7AFi-rv_Rh9y8bLiELSPEjQhGBVuzw9gCsO0dI33b0YWpMboh-ObHh77UyAQ' push --relay https://relay:7443 deploy agent/other 2>&1469client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSMlk0VjVMV1dMSE1PPT09IiwibmJmIjoxNzg4NjkyMDY4LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.BjaQ7iUof7avjxG8XAigNhY3Ul7AFi-rv_Rh9y8bLiELSPEjQhGBVuzw9gCsO0dI33b0YWpMboh-ObHh77UyAQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.03 seconds)470(finished: subtest: policy denies uncovered target, in 0.03 seconds)471subtest: claim principal from groups, unchanged counts as success472client: 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)473client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)474client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM3MSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY5MjA3MSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVlhLTlZFWjQySkdKVT09PSIsIm5iZiI6MTc4ODY5MjA3MSwic3ViIjoic29tZW9uZSJ9.lmpZcAGqeprecUDfDQgvFmkasyuuW1qqFyhEb30-sifrZrxxBi6FETL3v-kJaJ6gZTFEqOV0x6TTEf52m2ScDQ' push --relay https://relay:7443 deploy agent/other 2>&1475agent # [13793.130758] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:31.092546Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}476agent # [13793.234451] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:31.196212Z","level":"INFO","message":"start","id":"c0e2243eb434b6fb48c8d767962385c6","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"someone\")","target":"flakelet_relay::agent::conn"}477agent # [13793.234783] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:31.196612Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"c0e2243eb434b6fb48c8d767962385c6\"]","target":"flakelet_relay::agent::jobs"}478agent # [13793.302961] agent systemd[1]: Starting flakelet update other (via relay)...479agent # [13793.329979] agent systemd[1]: Started flakelet update other (via relay).480agent # [13793.334473] agent flakelet[1341]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1481agent # [13793.335046] agent flakelet[1341]: other: up to date482agent # [13793.337745] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.483relay # [13793.132028] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:31.093771Z","level":"INFO","message":"deploy finished","job":"a51a7dd2ea78427e565f708e35e88100","ok":true,"target":"flakelet_relay::relay::api"}484relay # [13793.234191] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:31.195947Z","level":"INFO","message":"deploy accepted","job":"efef3df319f84b27f9c75bed85956ee8","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}485client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM3MSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY5MjA3MSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVlhLTlZFWjQySkdKVT09PSIsIm5iZiI6MTc4ODY5MjA3MSwic3ViIjoic29tZW9uZSJ9.lmpZcAGqeprecUDfDQgvFmkasyuuW1qqFyhEb30-sifrZrxxBi6FETL3v-kJaJ6gZTFEqOV0x6TTEf52m2ScDQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.68 seconds)486(finished: subtest: claim principal from groups, unchanged counts as success, in 0.73 seconds)487subtest: push login via device flow, cached token used afterwards488client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1489agent # [13793.888268] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:31.850014Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}490relay # [13793.889671] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:31.851430Z","level":"INFO","message":"deploy finished","job":"efef3df319f84b27f9c75bed85956ee8","ok":true,"target":"flakelet_relay::relay::api"}491relay # [13793.912301] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:54:31] "POST /device HTTP/1.1" 200 -492relay # [13794.917901] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:54:32] "POST /token HTTP/1.1" 400 -493client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)494client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600495client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)496client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1497agent # [13795.997687] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:33.959441Z","level":"INFO","message":"start","id":"6fc83c9167596291f2712efb4f0ce21e","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}498agent # [13795.998566] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:33.960211Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"6fc83c9167596291f2712efb4f0ce21e\"]","target":"flakelet_relay::agent::jobs"}499agent # [13796.068606] agent systemd[1]: Starting flakelet update other (via relay)...500agent # [13796.098940] agent systemd[1]: Started flakelet update other (via relay).501agent # [13796.103754] agent flakelet[1391]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1502agent # [13796.104323] agent flakelet[1391]: other: up to date503agent # [13796.107095] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.504relay # [13795.966171] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:54:33] "POST /token HTTP/1.1" 200 -505relay # [13795.997386] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:33.959158Z","level":"INFO","message":"deploy accepted","job":"0e086139e747de660a3aa9240843a874","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}506client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.69 seconds)507client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1508agent # [13796.667654] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:34.629376Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}509agent # [13796.691761] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:34.653567Z","level":"INFO","message":"start","id":"dee8aad028d72a7ae0916e45620bf1ae","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}510agent # [13796.692191] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:34.654010Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"dee8aad028d72a7ae0916e45620bf1ae\"]","target":"flakelet_relay::agent::jobs"}511agent # [13796.749325] agent systemd[1]: Starting flakelet update other (via relay)...512agent # [13796.781963] agent systemd[1]: Started flakelet update other (via relay).513agent # [13796.787496] agent flakelet[1441]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1514agent # [13796.788217] agent flakelet[1441]: other: up to date515agent # [13796.788747] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.516relay # [13796.669333] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:34.631067Z","level":"INFO","message":"deploy finished","job":"0e086139e747de660a3aa9240843a874","ok":true,"target":"flakelet_relay::relay::api"}517relay # [13796.691519] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:34.653326Z","level":"INFO","message":"deploy accepted","job":"fbf92ca58b2c04c4998aa284fe8200f2","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}518client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 1.68 seconds)519(finished: subtest: push login via device flow, cached token used afterwards, in 4.46 seconds)520subtest: waves: failing first wave skips the second521agent: 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.json522agent: (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)523client: 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>&1524agent # [13798.344774] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:36.306555Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}525agent # [13798.382439] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:36.344236Z","level":"INFO","message":"start","id":"9735ea118ceae5b70f4ad0f9d783d5cb","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}526agent # [13798.382865] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:36.344684Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"9735ea118ceae5b70f4ad0f9d783d5cb\"]","target":"flakelet_relay::agent::jobs"}527agent # [13798.430370] agent systemd[1]: Starting flakelet update app (via relay)...528agent # [13798.463264] agent systemd[1]: Started flakelet update app (via relay).529agent # [13798.467641] agent flakelet[1495]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken530agent # [13798.468322] agent flakelet[1495]: app: activating generation 4531agent # [13798.479076] agent systemd[1]: Stopping app v1...532agent # [13798.479461] agent systemd[1]: app.service: Deactivated successfully.533agent # [13798.479684] agent systemd[1]: Stopped app v1.534agent # [13798.494166] agent systemd[1]: Reload requested from client PID 1502 ('systemctl') (unit flakelet-relay-job-app.service)...535agent # [13798.494223] agent systemd[1]: Reloading...536relay # [13798.346242] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:36.307998Z","level":"INFO","message":"deploy finished","job":"fbf92ca58b2c04c4998aa284fe8200f2","ok":true,"target":"flakelet_relay::relay::api"}537relay # [13798.382177] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:36.343977Z","level":"INFO","message":"deploy accepted","job":"a6b2e57da7350a73b57cc2ec347ac673","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}538agent # [13798.814739] agent systemd[1]: Reloading finished in 319 ms.539agent # [13798.903884] agent systemd[1]: Reload requested from client PID 1532 ('systemctl') (unit flakelet-relay-job-app.service)...540agent # [13798.903927] agent systemd[1]: Reloading...541agent # [13799.215247] agent systemd[1]: Reloading finished in 310 ms.542agent # [13799.299907] agent systemd[1]: Reload requested from client PID 1561 ('systemctl') (unit flakelet-relay-job-app.service)...543agent # [13799.299948] agent systemd[1]: Reloading...544agent # [13799.615088] agent systemd[1]: Reloading finished in 314 ms.545agent # [13799.690466] agent systemd[1]: Reload requested from client PID 1592 ('systemctl') (unit flakelet-relay-job-app.service)...546agent # [13799.690499] agent systemd[1]: Reloading...547agent # [13800.004888] agent systemd[1]: Reloading finished in 314 ms.548agent # [13800.075524] agent systemd[1]: Starting app broken...549agent # [13800.104381] agent (nonexistent)[1622]: app.service: Unable to locate executable '/nonexistent': No such file or directory550agent # [13800.104405] agent (nonexistent)[1622]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory551agent # [13800.105750] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC552agent # [13800.105864] agent systemd[1]: app.service: Failed with result 'exit-code'.553agent # [13800.106208] agent systemd[1]: Failed to start app broken.554agent # [13800.135969] agent systemd[1]: Reload requested from client PID 1629 ('systemctl') (unit flakelet-relay-job-app.service)...555agent # [13800.136017] agent systemd[1]: Reloading...556agent # [13800.453294] agent systemd[1]: Reloading finished in 316 ms.557agent # [13800.543268] agent systemd[1]: Reload requested from client PID 1662 ('systemctl') (unit flakelet-relay-job-app.service)...558agent # [13800.543305] agent systemd[1]: Reloading...559agent # [13800.863389] agent systemd[1]: Reloading finished in 319 ms.560agent # [13800.932986] agent systemd[1]: Reload requested from client PID 1693 ('systemctl') (unit flakelet-relay-job-app.service)...561agent # [13800.933030] agent systemd[1]: Reloading...562agent # [13801.242861] agent systemd[1]: Reloading finished in 309 ms.563agent # [13801.318698] agent systemd[1]: Reload requested from client PID 1725 ('systemctl') (unit flakelet-relay-job-app.service)...564agent # [13801.318737] agent systemd[1]: Reloading...565agent # [13801.631892] agent systemd[1]: Reloading finished in 312 ms.566agent # [13801.700017] agent systemd[1]: Starting app v1...567agent # [13801.729974] agent systemd[1]: Started app v1.568agent # [13801.731197] agent flakelet[1495]: app: deploy failed, rolled back: systemctl start app.service failed:569agent # [13801.731197] agent flakelet[1495]: failed units: app.service. See journalctl -u app.service570agent # [13801.731737] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE571agent # [13801.731826] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.572client: (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.13 seconds)573agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'574agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.01 seconds)575(finished: subtest: waves: failing first wave skips the second, in 4.16 seconds)576subtest: host patterns expand on the relay577agent: 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.json578agent: (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)579client: 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>&1580agent # [13802.489204] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:40.450946Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}581agent # [13802.538898] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:40.500648Z","level":"INFO","message":"start","id":"ab7fe2d1210fa65d378328137413e9a0","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}582agent # [13802.539340] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:40.501159Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ab7fe2d1210fa65d378328137413e9a0\"]","target":"flakelet_relay::agent::jobs"}583agent # [13802.588169] agent systemd[1]: Starting flakelet update app (via relay)...584agent # [13802.595387] agent systemd[1]: Started flakelet update app (via relay).585agent # [13802.599535] agent flakelet[1819]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1586agent # [13802.600080] agent flakelet[1819]: app: up to date587agent # [13802.602059] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.588relay # [13802.490539] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:40.452278Z","level":"INFO","message":"deploy finished","job":"a6b2e57da7350a73b57cc2ec347ac673","ok":false,"target":"flakelet_relay::relay::api"}589relay # [13802.538646] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:40.500424Z","level":"INFO","message":"deploy accepted","job":"72555c88214a681d769521bd20966e93","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}590client: (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.65 seconds)591client: 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>&1592agent # [13803.168409] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:41.130158Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}593agent # [13803.196352] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:41.158136Z","level":"INFO","message":"start","id":"343eebcb69e76104b72681c31a13c3eb","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}594agent # [13803.196709] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:41.158533Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"343eebcb69e76104b72681c31a13c3eb\"]","target":"flakelet_relay::agent::jobs"}595agent # [13803.259694] agent systemd[1]: Starting flakelet update app (via relay)...596agent # [13803.288984] agent systemd[1]: Started flakelet update app (via relay).597relay # [13803.169635] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:41.131388Z","level":"INFO","message":"deploy finished","job":"72555c88214a681d769521bd20966e93","ok":true,"target":"flakelet_relay::relay::api"}598agent # [13803.293608] agent flakelet[1853]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1599relay # [13803.196097] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:41.157900Z","level":"INFO","message":"deploy accepted","job":"67ace821fadda5103842a3578999b5ce","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}600agent # [13803.294184] agent flakelet[1853]: app: up to date601agent # [13803.294613] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.602client: (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.70 seconds)603client: 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>&1604agent # [13804.872390] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:42.834122Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}605agent # [13804.898613] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:42.860424Z","level":"INFO","message":"start","id":"5023b90d89ea3e6edfd43c861dff56ba","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}606agent # [13804.898810] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:42.860638Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"5023b90d89ea3e6edfd43c861dff56ba\"]","target":"flakelet_relay::agent::jobs"}607agent # [13804.972028] agent systemd[1]: Starting flakelet update app (via relay)...608agent # [13805.011047] agent systemd[1]: Started flakelet update app (via relay).609agent # [13805.015553] agent flakelet[1905]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1610agent # [13805.016141] agent flakelet[1905]: app: up to date611agent # [13805.017428] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.612relay # [13804.873658] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:42.835404Z","level":"INFO","message":"deploy finished","job":"67ace821fadda5103842a3578999b5ce","ok":false,"target":"flakelet_relay::relay::api"}613relay # [13804.898389] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:42.860188Z","level":"INFO","message":"deploy accepted","job":"4d5bbe94d61b8466be65daa7066e1923","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}614client: (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.70 seconds)615client: 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>&1616client: (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)617(finished: subtest: host patterns expand on the relay, in 3.09 seconds)618subtest: detach returns once the job is accepted619agent: 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.json620agent: (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)621client: 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>&1622client: (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)623agent: waiting for success: systemctl is-active flakelet-relay-job-app.service624agent # [13805.574761] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:43.536545Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}625agent # [13805.632848] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:43.594619Z","level":"INFO","message":"start","id":"51856e597527c83ebc4e3192cdb556f2","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}626agent # [13805.633115] agent flakelet-agent[507]: {"timestamp":"2026-09-06T10:54:43.594942Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"51856e597527c83ebc4e3192cdb556f2\"]","target":"flakelet_relay::agent::jobs"}627agent # [13805.680196] agent systemd[1]: Starting flakelet update app (via relay)...628agent # [13805.712164] agent systemd[1]: Started flakelet update app (via relay).629relay # [13805.575969] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:43.537717Z","level":"INFO","message":"deploy finished","job":"4d5bbe94d61b8466be65daa7066e1923","ok":false,"target":"flakelet_relay::relay::api"}630agent # [13805.716331] agent flakelet[1946]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2631relay # [13805.632529] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:43.594336Z","level":"INFO","message":"deploy accepted","job":"3ea15e35cb7a7e7226366cf8fbf16862","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}632agent # [13805.717080] agent flakelet[1946]: app: activating generation 4633agent # [13805.727104] agent systemd[1]: Stopping app v1...634agent # [13805.727802] agent systemd[1]: app.service: Deactivated successfully.635agent # [13805.727933] agent systemd[1]: Stopped app v1.636agent # [13805.738930] agent systemd[1]: Reload requested from client PID 1953 ('systemctl') (unit flakelet-relay-job-app.service)...637agent # [13805.738965] agent systemd[1]: Reloading...638agent # [13806.077436] agent systemd[1]: Reloading finished in 338 ms.639agent # [13806.171166] agent systemd[1]: Reload requested from client PID 1983 ('systemctl') (unit flakelet-relay-job-app.service)...640agent # [13806.171204] agent systemd[1]: Reloading...641agent # [13806.493418] agent systemd[1]: Reloading finished in 321 ms.642agent # [13806.587028] agent systemd[1]: Reload requested from client PID 2014 ('systemctl') (unit flakelet-relay-job-app.service)...643agent # [13806.587063] agent systemd[1]: Reloading...644agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.34 seconds)645??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.646 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39647agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service648??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.649 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39650agent # [13806.898111] agent systemd[1]: Reloading finished in 310 ms.651agent # [13806.982360] agent systemd[1]: Reload requested from client PID 2048 ('systemctl') (unit flakelet-relay-job-app.service)...652agent # [13806.982397] agent systemd[1]: Reloading...653agent # [13807.311407] agent systemd[1]: Reloading finished in 328 ms.654agent # [13807.395187] agent systemd[1]: Starting app slow2...655agent # [13813.466361] agent systemd[1]: Started app slow2.656agent # [13813.486514] agent flakelet[1946]: app: updated to generation 4657agent # [13813.489497] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.658agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.52 seconds)659(finished: subtest: detach returns once the job is accepted, in 8.90 seconds)660subtest: unknown host is final, missing agent is retried, agents listing661client: 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>&1662client: (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)663agent: must succeed: systemctl stop flakelet-agent664agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.07 seconds)665relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'666relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)667client: 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 &668client: (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)669client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out670agent # [13814.535856] agent systemd[1]: Stopping flakelet-agent...671agent # [13814.567317] agent systemd[1]: flakelet-agent.service: Deactivated successfully.672agent # [13814.567690] agent systemd[1]: Stopped flakelet-agent.673agent # [13814.568033] agent systemd[1]: flakelet-agent.service: Consumed 2.800s CPU time over 30.515s wall clock time.674relay # [13814.536288] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:52.498006Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}675client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)676agent: must succeed: systemctl start flakelet-agent677agent: (finished: must succeed: systemctl start flakelet-agent, in 0.20 seconds)678??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.679 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39680client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out681agent # [13815.660994] agent systemd[1]: Starting flakelet-agent...682agent # [13815.725278] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:53.687062Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"51856e597527c83ebc4e3192cdb556f2\"]","target":"flakelet_relay::agent::jobs"}683agent # [13815.845097] agent systemd[1]: Started flakelet-agent.684agent # [13815.855532] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:53.817338Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}685relay # [13815.855692] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:53.817440Z","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"}686agent # [13816.304603] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:54.266339Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}687agent # [13817.643162] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:55.604831Z","level":"INFO","message":"start","id":"3c9fe0ed6281853c89a060b792a7f9d2","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}688agent # [13817.643998] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:55.605596Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3c9fe0ed6281853c89a060b792a7f9d2\"]","target":"flakelet_relay::agent::jobs"}689agent # [13817.745821] agent systemd[1]: Starting flakelet update other (via relay)...690agent # [13817.753756] agent systemd[1]: Started flakelet update other (via relay).691agent # [13817.757277] agent flakelet[2618]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1692agent # [13817.757819] agent flakelet[2618]: other: up to date693relay # [13817.642727] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:55.604499Z","level":"INFO","message":"deploy accepted","job":"77b2be0b0dd71a45113ed727bb0e46b9","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}694agent # [13817.760613] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.695agent # [13818.332532] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:54:56.294271Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}696relay # [13818.334206] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:54:56.295987Z","level":"INFO","message":"deploy finished","job":"77b2be0b0dd71a45113ed727bb0e46b9","ok":true,"target":"flakelet_relay::relay::api"}697client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.05 seconds)698client: 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 agents699client: (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)700client: 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)701client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)702client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDMkFSUVZFUTJQWkNFPT09IiwibmJmIjoxNzg4NjkyMDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ALRDP0Ao_KjtrjzsFskoQzFcfMKvbMV16fSpdSKjQF-uerQ2qey_crBtT-stPBlTib_tcmfxe5NHKEF8Hz41CQ' push --relay https://relay:7443 agents703client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjM5NiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMDk2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDMkFSUVZFUTJQWkNFPT09IiwibmJmIjoxNzg4NjkyMDk2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ALRDP0Ao_KjtrjzsFskoQzFcfMKvbMV16fSpdSKjQF-uerQ2qey_crBtT-stPBlTib_tcmfxe5NHKEF8Hz41CQ' push --relay https://relay:7443 agents, in 0.02 seconds)704(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.49 seconds)705subtest: out-of-band flakelet update reaches the relay without reconnect706agent: must succeed: flakelet status --json app | jq '.[0].generation'707agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.05 seconds)708agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true709agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)710agent: 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.json711agent: (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)712agent: must succeed: flakelet update app713app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2714app: activating generation 5715agent # [13819.082247] agent systemd[1]: Stopping app slow2...716agent # [13819.082720] agent systemd[1]: app.service: Deactivated successfully.717agent # [13819.082949] agent systemd[1]: Stopped app slow2.718agent # [13819.097992] agent systemd[1]: Reload requested from client PID 2678 ('systemctl')...719agent # [13819.098085] agent systemd[1]: Reloading...720agent # [13819.448099] agent systemd[1]: Reloading finished in 349 ms.721agent # [13819.549639] agent systemd[1]: Reload requested from client PID 2707 ('systemctl')...722agent # [13819.549681] agent systemd[1]: Reloading...723agent # [13819.889007] agent systemd[1]: Reloading finished in 338 ms.724agent # [13819.989763] agent systemd[1]: Reload requested from client PID 2737 ('systemctl')...725agent # [13819.989806] agent systemd[1]: Reloading...726agent # [13820.303632] agent systemd[1]: Reloading finished in 313 ms.727agent # [13820.399772] agent systemd[1]: Reload requested from client PID 2767 ('systemctl')...728agent # [13820.399807] agent systemd[1]: Reloading...729agent: (finished: must succeed: flakelet update app, in 1.81 seconds)730client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'731agent # [13820.729543] agent systemd[1]: Reloading finished in 329 ms.732agent # [13820.825857] agent systemd[1]: Starting app v2...733agent # [13820.859224] agent systemd[1]: Started app v2.734client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.09 seconds)735agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true736agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)737agent: 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.json738agent: (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)739agent: must succeed: flakelet update app740app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1741app: activating generation 6742agent # [13823.011193] agent systemd[1]: Stopping app v2...743agent # [13823.011649] agent systemd[1]: app.service: Deactivated successfully.744agent # [13823.019179] agent systemd[1]: Stopped app v2.745agent # [13823.044482] agent systemd[1]: Reload requested from client PID 2835 ('systemctl')...746agent # [13823.044552] agent systemd[1]: Reloading...747agent # [13823.393683] agent systemd[1]: Reloading finished in 348 ms.748agent # [13823.470930] agent systemd[1]: Reload requested from client PID 2864 ('systemctl')...749agent # [13823.470969] agent systemd[1]: Reloading...750agent # [13823.785138] agent systemd[1]: Reloading finished in 313 ms.751agent # [13823.913589] agent systemd[1]: Reload requested from client PID 2894 ('systemctl')...752agent # [13823.913628] agent systemd[1]: Reloading...753agent # [13824.236316] agent systemd[1]: Reloading finished in 322 ms.754agent # [13824.334532] agent systemd[1]: Reload requested from client PID 2925 ('systemctl')...755agent # [13824.334571] agent systemd[1]: Reloading...756agent: (finished: must succeed: flakelet update app, in 1.80 seconds)757client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'758agent # [13824.668849] agent systemd[1]: Reloading finished in 333 ms.759agent # [13824.761451] agent systemd[1]: Starting app v1...760agent # [13824.769911] agent systemd[1]: Started app v1.761client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.07 seconds)762(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.86 seconds)763subtest: certificate not listed under agents cannot connect as agent764client: 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/agent765client: (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)766(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)767subtest: metrics768relay: must succeed: curl -sf http://127.0.0.1:7400/metrics769relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)770(finished: subtest: metrics, in 0.01 seconds)771subtest: agent link drop mid-run replays missed lines once772agent: 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.json773agent: (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)774agent: must succeed: date +%s775agent: (finished: must succeed: date +%s, in 0.01 seconds)776client: 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 &777client: (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)778agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692104 | grep -q 'app-slow'779relay # [13826.874022] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:04.835639Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}780relay # [13826.930083] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:04.891882Z","level":"INFO","message":"deploy accepted","job":"ccfd2b06ce8ff9b6ab7cdc543fb73b2f","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}781agent # [13826.930458] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:04.892229Z","level":"INFO","message":"start","id":"65a2f0668530130017d2b93c589a2596","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}782agent # [13826.931110] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:04.892931Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"65a2f0668530130017d2b93c589a2596\"]","target":"flakelet_relay::agent::jobs"}783agent # [13827.000827] agent systemd[1]: Starting flakelet update app (via relay)...784agent # [13827.007596] agent systemd[1]: Started flakelet update app (via relay).785agent # [13827.011656] agent flakelet[2998]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow786agent # [13827.012370] agent flakelet[2998]: app: activating generation 7787agent # [13827.026215] agent systemd[1]: Stopping app v1...788agent # [13827.026660] agent systemd[1]: app.service: Deactivated successfully.789agent # [13827.026914] agent systemd[1]: Stopped app v1.790agent # [13827.043325] agent systemd[1]: Reload requested from client PID 3005 ('systemctl') (unit flakelet-relay-job-app.service)...791agent # [13827.043393] agent systemd[1]: Reloading...792agent # [13827.369417] agent systemd[1]: Reloading finished in 325 ms.793agent # [13827.451496] agent systemd[1]: Reload requested from client PID 3035 ('systemctl') (unit flakelet-relay-job-app.service)...794agent # [13827.451537] agent systemd[1]: Reloading...795agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692104 | grep -q 'app-slow', in 1.02 seconds)796agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done797agent: (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)798relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done799relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)800agent: must succeed: ss -K dport = 7443801agent # [13827.767801] agent systemd[1]: Reloading finished in 315 ms.802agent # [13827.851165] agent systemd[1]: Reload requested from client PID 3064 ('systemctl') (unit flakelet-relay-job-app.service)...803agent # [13827.851205] agent systemd[1]: Reloading...804agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)805agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692104 | grep -q 'updated to generation'806agent # [13828.044502] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:06.006059Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}807agent # [13828.168640] agent systemd[1]: Reloading finished in 317 ms.808agent # [13828.247824] agent systemd[1]: Reload requested from client PID 3112 ('systemctl') (unit flakelet-relay-job-app.service)...809agent # [13828.247859] agent systemd[1]: Reloading...810relay # [13828.014508] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:05.976251Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}811agent # [13828.570053] agent systemd[1]: Reloading finished in 321 ms.812agent # [13828.670927] agent systemd[1]: Starting app slow...813agent # [13829.046539] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:07.008288Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}814agent # [13831.048427] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:09.010138Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}815agent # [13834.715177] agent systemd[1]: Started app slow.816agent # [13834.735062] agent flakelet[2998]: app: updated to generation 7817agent # [13834.737700] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.818agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692104 | grep -q 'updated to generation', in 7.11 seconds)819agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done820agent: (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)821client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out822agent # [13835.050657] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:13.012247Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}823agent # [13835.863605] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:13.825360Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}824client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.09 seconds)825client: must succeed: cat /tmp/slow.out826client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)827(finished: subtest: agent link drop mid-run replays missed lines once, in 16.39 seconds)828subtest: agent restart mid-run reattaches to the unit829agent: 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.json830agent: (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)831client: 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 &832client: (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)833agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'834relay # [13843.055334] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:21.017081Z","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"}835relay # [13843.056802] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:21.018613Z","level":"INFO","message":"deploy finished","job":"ccfd2b06ce8ff9b6ab7cdc543fb73b2f","ok":true,"target":"flakelet_relay::relay::api"}836agent # [13843.055305] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:21.017010Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}837agent # [13843.056523] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:21.018270Z","level":"INFO","message":"start","id":"65a2f0668530130017d2b93c589a2596","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}838agent # [13843.317445] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:21.279071Z","level":"INFO","message":"start","id":"a2fffa1dd335346c8c84e9a88b52fe6c","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}839agent # [13843.317883] agent flakelet-agent[2169]: {"timestamp":"2026-09-06T10:55:21.279704Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"a2fffa1dd335346c8c84e9a88b52fe6c\"]","target":"flakelet_relay::agent::jobs"}840agent # [13843.390410] agent systemd[1]: Starting flakelet update app (via relay)...841agent # [13843.415044] agent systemd[1]: Started flakelet update app (via relay).842agent # [13843.419433] agent flakelet[3331]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2843agent # [13843.420136] agent flakelet[3331]: app: activating generation 8844agent # [13843.431031] agent systemd[1]: Stopping app slow...845agent # [13843.431758] agent systemd[1]: app.service: Deactivated successfully.846agent # [13843.431890] agent systemd[1]: Stopped app slow.847agent # [13843.441742] agent systemd[1]: Reload requested from client PID 3338 ('systemctl') (unit flakelet-relay-job-app.service)...848agent # [13843.441780] agent systemd[1]: Reloading...849agent # [13843.776501] agent systemd[1]: Reloading finished in 334 ms.850agent # [13843.889817] agent systemd[1]: Reload requested from client PID 3371 ('systemctl') (unit flakelet-relay-job-app.service)...851agent # [13843.889852] agent systemd[1]: Reloading...852agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)853agent: must succeed: systemctl restart flakelet-agent854agent # [13844.208945] agent systemd[1]: Reloading finished in 318 ms.855agent # [13844.295661] agent systemd[1]: Reload requested from client PID 3402 ('systemctl') (unit flakelet-relay-job-app.service)...856agent # [13844.295696] agent systemd[1]: Reloading...857agent # [13844.613560] agent systemd[1]: Reloading finished in 317 ms.858agent # [13844.699687] agent systemd[1]: Stopping flakelet-agent...859agent # [13844.703668] agent systemd[1]: Reload requested from client PID 3439 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [13844.703706] agent systemd[1]: Reloading...861relay # [13843.317138] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:21.278711Z","level":"INFO","message":"deploy accepted","job":"38ae229ab76e201521bb6f4046c6addd","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}862relay # [13844.699809] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:22.661562Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}863agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.92 seconds)864agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"865agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)866client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out867agent # [13845.038294] agent systemd[1]: Reloading finished in 334 ms.868agent # [13845.097598] agent systemd[1]: flakelet-agent.service: Deactivated successfully.869agent # [13845.097777] agent systemd[1]: Stopped flakelet-agent.870agent # [13845.097792] agent systemd[1]: flakelet-agent.service: Consumed 2.187s CPU time over 29.436s wall clock time.871agent # [13845.116203] agent systemd[1]: Starting app slow2...872agent # [13845.117319] agent systemd[1]: Starting flakelet-agent...873agent # [13845.167572] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:23.129368Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"a2fffa1dd335346c8c84e9a88b52fe6c\"]","target":"flakelet_relay::agent::jobs"}874agent # [13845.249934] agent systemd[1]: Started flakelet-agent.875agent # [13845.263920] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:23.225724Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}876agent # [13845.265194] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:23.227016Z","level":"INFO","message":"start","id":"a2fffa1dd335346c8c84e9a88b52fe6c","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}877relay # [13845.264067] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:23.225809Z","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"}878agent # [13851.186132] agent systemd[1]: Started app slow2.879agent # [13851.207163] agent flakelet[3331]: app: updated to generation 8880agent # [13851.209954] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.881agent # [13851.781159] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:29.742940Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}882relay # [13851.782221] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:29.744003Z","level":"INFO","message":"deploy finished","job":"38ae229ab76e201521bb6f4046c6addd","ok":true,"target":"flakelet_relay::relay::api"}883client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)884client: must succeed: cat /tmp/restart.out885client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)886agent: must succeed: systemctl is-active app.service887agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)888(finished: subtest: agent restart mid-run reattaches to the unit, in 9.09 seconds)889subtest: relay restart mid-run, push resumes via /v1/jobs890agent: 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.json891agent: (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)892agent: must succeed: date +%s893agent: (finished: must succeed: date +%s, in 0.01 seconds)894client: 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 &895client: (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)896agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692130 | grep -q 'app-slow'897agent # [13852.415278] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:30.377014Z","level":"INFO","message":"start","id":"a9a4a742d504cfbe5806e69307de7fe5","flakelet":"app","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}898agent # [13852.415808] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:30.377625Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"a9a4a742d504cfbe5806e69307de7fe5\"]","target":"flakelet_relay::agent::jobs"}899agent # [13852.497589] agent systemd[1]: Starting flakelet update app (via relay)...900agent # [13852.504227] agent systemd[1]: Started flakelet update app (via relay).901agent # [13852.508809] agent flakelet[3983]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow902agent # [13852.509530] agent flakelet[3983]: app: activating generation 9903agent # [13852.523095] agent systemd[1]: Stopping app slow2...904agent # [13852.524792] agent systemd[1]: app.service: Deactivated successfully.905agent # [13852.525124] agent systemd[1]: Stopped app slow2.906agent # [13852.540455] agent systemd[1]: Reload requested from client PID 3990 ('systemctl') (unit flakelet-relay-job-app.service)...907agent # [13852.540520] agent systemd[1]: Reloading...908agent # [13852.867719] agent systemd[1]: Reloading finished in 326 ms.909relay # [13852.414979] relay flakelet-relay[402]: {"timestamp":"2026-09-06T10:55:30.376734Z","level":"INFO","message":"deploy accepted","job":"e2d0a825b695f0f0a63f82f59f24ccf7","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}910agent # [13852.953248] agent systemd[1]: Reload requested from client PID 4020 ('systemctl') (unit flakelet-relay-job-app.service)...911agent # [13852.953290] agent systemd[1]: Reloading...912agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788692130 | grep -q 'app-slow', in 1.02 seconds)913relay: must succeed: systemctl restart flakelet-relay914agent # [13853.270159] agent systemd[1]: Reloading finished in 316 ms.915agent # [13853.367160] agent systemd[1]: Reload requested from client PID 4051 ('systemctl') (unit flakelet-relay-job-app.service)...916agent # [13853.367202] agent systemd[1]: Reloading...917agent # [13853.437902] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:31.399692Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}918relay # [13853.437530] relay systemd[1]: Stopping flakelet-relay...919relay # [13853.472966] relay systemd[1]: flakelet-relay.service: Deactivated successfully.920relay # [13853.473252] relay systemd[1]: Stopped flakelet-relay.921relay # [13853.473275] relay systemd[1]: flakelet-relay.service: Consumed 2.814s CPU time over 1min 11.132s wall clock time.922relay # [13853.490565] relay systemd[1]: Starting flakelet-relay...923agent # [13853.686725] agent systemd[1]: Reloading finished in 319 ms.924agent # [13853.786437] agent systemd[1]: Reload requested from client PID 4086 ('systemctl') (unit flakelet-relay-job-app.service)...925agent # [13853.786473] agent systemd[1]: Reloading...926agent # [13854.110294] agent systemd[1]: Reloading finished in 323 ms.927agent # [13854.191181] agent systemd[1]: Starting app slow...928agent # [13854.441476] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:32.403230Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}929relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.70 seconds)930client: waiting for success: grep -q '» ok' /tmp/resume.out931relay # [13855.120048] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:33.081783Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}932relay # [13855.120783] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:33.082290Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}933relay # [13855.120594] relay systemd[1]: Started flakelet-relay.934agent # [13856.454904] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:34.416647Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}935relay # [13856.457452] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:34.419220Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}936agent # [13860.257977] agent systemd[1]: Started app slow.937agent # [13860.277306] agent flakelet[3983]: app: updated to generation 9938agent # [13860.280104] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.939relay # [13860.462105] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:38.423738Z","level":"INFO","message":"job reattached","job":"e2d0a825b695f0f0a63f82f59f24ccf7","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}940agent # [13861.397650] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:39.359405Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}941client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.07 seconds)942client: must succeed: cat /tmp/resume.out943client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)944(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.84 seconds)945subtest: job history comes from the agents and survives a relay restart946client: 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>&1947agent # [13862.225891] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:40.187678Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}948agent # [13862.226370] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:40.188198Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}949agent # [13862.305705] agent systemd[1]: Starting flakelet update other (via relay)...950agent # [13862.312485] agent systemd[1]: Started flakelet update other (via relay).951agent # [13862.317572] agent flakelet[4228]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1952agent # [13862.318248] agent flakelet[4228]: other: up to date953agent # [13862.320441] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.954relay # [13862.225547] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:40.187253Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}955client: (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.69 seconds)956relay: must succeed: systemctl restart flakelet-relay957agent # [13862.889871] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:40.851660Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}958agent # [13862.907291] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:40.869105Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}959relay # [13862.891372] relay flakelet-relay[935]: {"timestamp":"2026-09-06T10:55:40.853123Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}960relay # [13862.907045] relay systemd[1]: Stopping flakelet-relay...961relay # [13862.946718] relay systemd[1]: flakelet-relay.service: Deactivated successfully.962relay # [13862.947189] relay systemd[1]: Stopped flakelet-relay.963relay # [13862.947228] relay systemd[1]: flakelet-relay.service: Consumed 2.413s CPU time over 9.456s wall clock time.964relay # [13862.983215] relay systemd[1]: Starting flakelet-relay...965agent # [13863.910223] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:41.871970Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}966relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.55 seconds)967relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'968relay # [13864.445876] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:42.407663Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}969relay # [13864.446424] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:42.408194Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}970relay # [13864.446581] relay systemd[1]: Started flakelet-relay.971agent # [13865.924911] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:43.886654Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}972relay # [13865.925056] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:43.886781Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}973relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)974client: 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 jobs975client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)976client: must succeed: echo '{"groups": [], "repository": "example/app"}' | 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)977client: (finished: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)978client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjQ0NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMTQ0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJXSFZRQVg1NzNSSlIyPT09IiwibmJmIjoxNzg4NjkyMTQ0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HhKbBMYUCf-fwPTUPQzpuyV7fbYFNVM0pLtyDwdISzM-dwLOUk432ZNAvz1wrxj7AgWw3H3iG8wWbjhbSlW-DQ' push --relay https://relay:7443 deploy --id hist2 agent/app979» job 6a239dbf87cfec796e49404c351d787f via relay 0.1.0 (agents: agent 0.1.0)980» wave 0981agent/app | Starting flakelet update app (via relay)...982agent/app | Started flakelet update app (via relay).983agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow984agent/app | app: up to date985agent # [13866.597499] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:44.559245Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"Some(\"example/app\")","target":"flakelet_relay::agent::conn"}986agent # [13866.598165] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:44.559981Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}987agent # [13866.666442] agent systemd[1]: Starting flakelet update app (via relay)...988agent/appagent # [13866.697165] agent systemd[1]: Started flakelet update app (via relay).989 | agent # [13866.701194] agent flakelet[4292]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow990flakelet-relay-job-app.service: Deactivated successfully.agent # [13866.701683] agent flakelet[4292]: app: up to date991992agent # [13866.704331] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.993relay # [13866.596983] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:44.558753Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}994» agent/app: unchanged (generation 9)995» ok996client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjQ0NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMTQ0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJXSFZRQVg1NzNSSlIyPT09IiwibmJmIjoxNzg4NjkyMTQ0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HhKbBMYUCf-fwPTUPQzpuyV7fbYFNVM0pLtyDwdISzM-dwLOUk432ZNAvz1wrxj7AgWw3H3iG8wWbjhbSlW-DQ' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.70 seconds)997client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjQ0NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMTQ0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJXSFZRQVg1NzNSSlIyPT09IiwibmJmIjoxNzg4NjkyMTQ0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HhKbBMYUCf-fwPTUPQzpuyV7fbYFNVM0pLtyDwdISzM-dwLOUk432ZNAvz1wrxj7AgWw3H3iG8wWbjhbSlW-DQ' push --relay https://relay:7443 jobs998client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY5MjQ0NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjkyMTQ0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJXSFZRQVg1NzNSSlIyPT09IiwibmJmIjoxNzg4NjkyMTQ0LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.HhKbBMYUCf-fwPTUPQzpuyV7fbYFNVM0pLtyDwdISzM-dwLOUk432ZNAvz1wrxj7AgWw3H3iG8wWbjhbSlW-DQ' push --relay https://relay:7443 jobs, in 0.02 seconds)999(finished: subtest: job history comes from the agents and survives a relay restart, in 5.09 seconds)1000subtest: dashboard login via authorization code flow1001client: 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'1002client: (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)1003client: 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/login1004client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.09 seconds)1005client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs1006client: (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.03 seconds)1007client: 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 hist11008client: (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)1009client: 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 || true1010client: (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)1011client: 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 4031012client: (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)1013client: 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'1014client: (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)1015client: 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/bf07407f1598eaa93f702d9a2acdbe89/events || true1016relay # [13867.277283] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:45.239026Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1017relay # [13867.355017] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:55:45] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=kF1gQ5hCUaQvi1-QkC72TWNy2GLVXWxDQH9BYotosPo&code_challenge=UJBXRVmqS_ceSuD65G-bmw3J660uAwr7AVfVr8PeMzM&code_challenge_method=S256 HTTP/1.1" 302 -1018relay # [13867.405980] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 10:55:45] "POST /token HTTP/1.1" 200 -1019relay # [13867.407485] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:45.369286Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1020relay # [13867.479364] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:45.441155Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1021relay # [13867.520764] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:45.482549Z","level":"INFO","message":"deploy accepted","job":"dffaf53aeeba14d4889b0c9f277f030d","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1022relay # [13867.541139] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:45.502870Z","level":"INFO","message":"job reattached","job":"dffaf53aeeba14d4889b0c9f277f030d","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1023agent # [13867.276293] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:45.238077Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}1024agent # [13867.521037] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:45.482818Z","level":"INFO","message":"start","id":"69101171e8c290f0efba69759f5c8a1f","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"dev@example.org\")","target":"flakelet_relay::agent::conn"}1025agent # [13867.521475] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:45.483301Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"69101171e8c290f0efba69759f5c8a1f\"]","target":"flakelet_relay::agent::jobs"}1026agent # [13867.567528] agent systemd[1]: Starting flakelet update other (via relay)...1027agent # [13867.604204] agent systemd[1]: Started flakelet update other (via relay).1028agent # [13867.608912] agent flakelet[4342]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11029agent # [13867.609548] agent flakelet[4342]: other: up to date1030agent # [13867.609916] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1031client: (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/bf07407f1598eaa93f702d9a2acdbe89/events || true, in 0.66 seconds)1032client: 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/bf07407f1598eaa93f702d9a2acdbe891033client: (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/bf07407f1598eaa93f702d9a2acdbe89, in 0.02 seconds)1034client: 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.js1035client: (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)1036client: 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'1037client: (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)1038client: 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/other1039client: (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)1040client: 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'1041client: (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)1042client: 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=bf07407f1598eaa93f702d9a2acdbe89' | grep -q 4001043client: (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=bf07407f1598eaa93f702d9a2acdbe89' | grep -q 400, in 0.02 seconds)1044client: 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 &1045client: (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)1046client: 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/other1047» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)1048» wave 01049agent/other | Starting flakelet update other (via relay)...1050agent/other | Started flakelet update other (via relay).1051agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11052agent/other | other: up to date1053agent # [13868.179552] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:46.141306Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1054agent # [13868.323423] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:46.285182Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller_name":"Some(\"admin@example.org\")","target":"flakelet_relay::agent::conn"}1055agent # [13868.323904] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:46.285588Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}1056agent # [13868.391443] agent systemd[1]: Starting flakelet update other (via relay)...1057agent # [13868.421120] agent systemd[1]: Started flakelet update other (via relay).1058agent # [13868.425548] agent flakelet[4378]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v11059agent # [13868.426125] agent flakelet[4378]: other: up to date1060agent # [13868.428261] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.1061agent/other | flakelet-relay-job-other.service: Deactivated successfully.1062relay # [13868.323117] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:46.284869Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}1063» agent/other: unchanged (generation 1)1064» ok1065client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 0.69 seconds)1066client: waiting for success: grep -q live1 /tmp/ev.out1067client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)1068client: 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/logout1069client: (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)1070client: 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 3031071client: (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)1072(finished: subtest: dashboard login via authorization code flow, in 1.75 seconds)1073(finished: run the VM test script, in 90.27 seconds)1074agent # [13868.993388] agent flakelet-agent[3471]: {"timestamp":"2026-09-06T10:55:46.955137Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}1075relay # [13868.994565] relay flakelet-relay[1325]: {"timestamp":"2026-09-06T10:55:46.956313Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}1076test script finished in 90.96s1077cleanup1078kill NspawnMachine (pid 52)1079kill NspawnMachine (pid 54)1080Container agent terminated by signal KILL.1081kill NspawnMachine (pid 56)1082Container client terminated by signal KILL.1083Container relay terminated by signal KILL.1084(finished: cleanup, in 0.39 seconds)1085additionally exposed symbols:1086 agent, client, relay,1087 vlan1,1088 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_ssh1089» job 709c2bd7e751ca0e797473fae9dbe115 via relay 0.1.0 (agents: agent 0.1.0)1090» wave 01091agent/app | Starting flakelet update app (via relay)...1092agent/app | Started flakelet update app (via relay).1093agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v21094agent/app | app: activating generation 21095agent/app | app: updated to generation 21096agent/app | flakelet-relay-job-app.service: Deactivated successfully.1097» agent/app: updated (generation 2)1098» ok10991100» job a6b2e57da7350a73b57cc2ec347ac673 via relay 0.1.0 (agents: agent 0.1.0)1101» wave 01102agent/app | Starting flakelet update app (via relay)...1103agent/app | Started flakelet update app (via relay).1104agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken1105agent/app | app: activating generation 41106agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1107agent/app | failed units: app.service. See journalctl -u app.service1108agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1109agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1110» agent/app: rolled-back (generation 3)1111agent/app │ Starting app v1...1112agent/app │ Started app v1.1113agent/app │ Stopping app v1...1114agent/app │ app.service: Deactivated successfully.1115agent/app │ Stopped app v1.1116agent/app │ Starting app v2...1117agent/app │ Started app v2.1118agent/app │ Stopping app v2...1119agent/app │ app.service: Deactivated successfully.1120agent/app │ Stopped app v2.1121agent/app │ Starting app v1...1122agent/app │ Started app v1.1123agent/app │ Stopping app v1...1124agent/app │ app.service: Deactivated successfully.1125agent/app │ Stopped app v1.1126agent/app │ Starting app broken...1127agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1128agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1129agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1130agent/app │ app.service: Failed with result 'exit-code'.1131agent/app │ Failed to start app broken.1132agent/app │ Starting app v1...1133agent/app │ Started app v1.1134» skipped: agent/other1135» failed11361137» job ccfd2b06ce8ff9b6ab7cdc543fb73b2f via relay 0.1.0 (agents: agent 0.1.0)1138» wave 01139agent/app | Starting flakelet update app (via relay)...1140agent/app | Started flakelet update app (via relay).1141agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1142agent/app | app: activating generation 71143agent/app | app: updated to generation 71144agent/app | flakelet-relay-job-app.service: Deactivated successfully.1145» agent/app: updated (generation 7)1146» ok11471148» job 38ae229ab76e201521bb6f4046c6addd via relay 0.1.0 (agents: agent 0.1.0)1149» wave 01150agent/app | Starting flakelet update app (via relay)...1151agent/app | Started flakelet update app (via relay).1152agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow21153agent/app | app: activating generation 81154agent/app | app: updated to generation 81155agent/app | flakelet-relay-job-app.service: Deactivated successfully.1156» agent/app: updated (generation 8)1157» ok11581159» job e2d0a825b695f0f0a63f82f59f24ccf7 via relay 0.1.0 (agents: agent 0.1.0)1160» wave 01161agent/app | Starting flakelet update app (via relay)...1162agent/app | Started flakelet update app (via relay).1163agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow1164agent/app | app: activating generation 91165flakelet-push: stream: error reading a body from connection, resuming job c2c287850fdb7de11828404ab13e6a481166flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1167flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1168flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1169» job e2d0a825b695f0f0a63f82f59f24ccf7 via relay 0.1.0 (agents: agent 0.1.0)1170» wave 01171agent/app | app: updated to generation 91172agent/app | flakelet-relay-job-app.service: Deactivated successfully.1173» agent/app: updated (generation 9)1174» ok117511761788692140 hist1 admin@example.org agent/other:unchanged11771788692130 c2c287850fdb7de11828404ab13e6a48 admin@example.org agent/app:updated11781788692121 4c296c1443262f1e88dbe00726be407a admin@example.org agent/app:updated11791788692104 6b316ad33958d7fbf29ad747232e19e3 admin@example.org agent/app:updated11801788692095 9d07645779b22e56606718e0e6b55e12 admin@example.org agent/other:unchanged11811788692083 06424286e0d538bf7f4e4758dd27ae22 admin@example.org agent/app:updated11821788692082 653799fff305669e311074d03779dcd0 admin@example.org agent/app:unchanged11831788692081 3a3d09aa1a05fad0265c6670a721ade8 admin@example.org agent/app:unchanged11841788692080 d02f77bef7741cd426dceb5d33fa62f9 admin@example.org agent/app:unchanged11851788692076 a04cceb60083fcca1a93dd4d757088e1 admin@example.org agent/app:rolled-back11861788692074 72285518dced8768c8bd732098788ba4 dev@example.org agent/other:unchanged11871788692073 40be619d7555a6175d5b5a39bc007711 dev@example.org agent/other:unchanged11881788692071 0d3f26da8060adc440b15e84effa27ce someone agent/other:unchanged11891788692068 c40e1e483ad49d8ac264044519b2ef17 repo:github:example/app:ref:refs/heads/main agent/app:updated11901788692065 9ab879d72e64275b03c417f2785e8f31 admin@example.org agent/app:updated1191