nixbot

builds

failed container-test-run-flakelet-relay checks.x86_64-linux.nixos-test · build #47 · 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 VMs9relay: systemd-nspawn running (pid 53)10agent: systemd-nspawn running (pid 52)11client: systemd-nspawn running (pid 54)12agent: Waiting for journal at /build/vm-state-agent/var/log/journal...13relay: Waiting for journal at /build/vm-state-relay/var/log/journal...14client: Waiting for journal at /build/vm-state-client/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16relay: waiting for unit flakelet-relay.service17nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.19nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE20nixos-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.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.24░ Spawning container relay on /build/vm-state-relay.25Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.26░ Spawning container client on /build/vm-state-client.27Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.28░ Spawning container agent on /build/vm-state-agent.29agent # No journal files were found.30agent # No journal boot entry found for the specified boot (+0).31client # No journal files were found.32relay # No journal files were found.33client # No journal boot entry found for the specified boot (+0).34relay # No journal boot entry found for the specified boot (+0).35agent # [2328488.674168] agent systemd-journald[57]: Journal started36relay # [2328488.676272] relay systemd-journald[57]: Journal started37agent # [2328488.674213] agent systemd-journald[57]: Runtime Journal (/run/log/journal/0ef09743fcfa49e8b217788b2d9bf504) is 8M, max 4G, 3.9G free.38relay # [2328488.676321] relay systemd-journald[57]: Runtime Journal (/run/log/journal/53d69d15b70b491a8c40fa8c8034cb34) is 8M, max 4G, 3.9G free.39agent # [2328488.687953] agent systemd[1]: Finished Apply Kernel Variables.40relay # [2328488.686930] relay systemd[1]: Finished Apply Kernel Variables.41agent # [2328488.700270] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.42relay # [2328488.699354] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.43agent # [2328488.714932] agent systemd[1]: Starting Flush Journal to Persistent Storage...44agent # [2328488.715760] agent systemd[1]: Starting Create Static Device Nodes in /dev...45relay # [2328488.713856] relay systemd[1]: Starting Flush Journal to Persistent Storage...46relay # [2328488.714404] relay systemd[1]: Starting Create Static Device Nodes in /dev...47agent # [2328488.752599] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/0ef09743fcfa49e8b217788b2d9bf504 is 2.324ms for 6 entries.48relay # [2328488.752752] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/53d69d15b70b491a8c40fa8c8034cb34 is 1.709ms for 6 entries.49agent # [2328488.752599] agent systemd-journald[57]: System Journal (/var/log/journal/0ef09743fcfa49e8b217788b2d9bf504) is 512B, max 4G, 3.9G free.50relay # [2328488.752752] relay systemd-journald[57]: System Journal (/var/log/journal/53d69d15b70b491a8c40fa8c8034cb34) is 512B, max 4G, 3.9G free.51agent # [2328488.762256] agent systemd[1]: Finished Create Static Device Nodes in /dev.52agent # [2328488.763015] agent systemd[1]: Reached target Preparation for Local File Systems.53agent # [2328488.763119] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys54agent # [2328488.779940] agent systemd[1]: Finished Flush Journal to Persistent Storage.55relay # [2328488.761775] relay systemd[1]: Finished Create Static Device Nodes in /dev.56agent # [2328488.828123] agent systemd[1]: Finished Firewall.57relay # [2328488.762506] relay systemd[1]: Reached target Preparation for Local File Systems.58agent # [2328489.708823] agent systemd[1]: Mounting /run/wrappers...59relay # [2328488.762631] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys60relay # [2328488.776594] relay systemd[1]: Finished Flush Journal to Persistent Storage.61relay # [2328488.856097] relay systemd[1]: Finished Firewall.62relay # [2328489.675410] relay systemd[1]: Mounting /run/wrappers...63client # [2328488.673963] client systemd-journald[57]: Journal started64client # [2328488.674013] client systemd-journald[57]: Runtime Journal (/run/log/journal/c2584356f6bd45d48159661e1105eac7) is 8M, max 4G, 3.9G free.65client # [2328488.686593] client systemd[1]: Finished Apply Kernel Variables.66client # [2328488.698840] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.67client # [2328488.713060] client systemd[1]: Starting Flush Journal to Persistent Storage...68client # [2328488.713766] client systemd[1]: Starting Create Static Device Nodes in /dev...69client # [2328488.752419] client systemd-journald[57]: Time spent on flushing to /var/log/journal/c2584356f6bd45d48159661e1105eac7 is 1.952ms for 6 entries.70client # [2328488.752419] client systemd-journald[57]: System Journal (/var/log/journal/c2584356f6bd45d48159661e1105eac7) is 512B, max 4G, 3.9G free.71client # [2328488.762152] client systemd[1]: Finished Create Static Device Nodes in /dev.72client # [2328488.762903] client systemd[1]: Reached target Preparation for Local File Systems.73client # [2328488.763023] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys74client # [2328488.779456] client systemd[1]: Finished Flush Journal to Persistent Storage.75client # [2328488.829433] client systemd[1]: Finished Firewall.76client # [2328489.673960] client systemd[1]: Mounting /run/wrappers...77client # [2328489.725903] client systemd[1]: Mounted /run/wrappers.78client # [2328489.726799] client systemd[1]: Reached target Local File Systems.79client # [2328489.727577] client systemd[1]: Listening on Boot Loader Control Service Socket.80client # [2328489.728568] client systemd[1]: Starting Create SUID/SGID Wrappers...81client # [2328489.728594] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container82client # [2328489.729412] client systemd[1]: Starting Save Transient machine-id to Disk...83client # [2328489.730349] client systemd[1]: Starting Create System Files and Directories...84client # [2328489.748890] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted85client # [2328489.749285] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted86client # [2328489.749581] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/c2584356f6bd45d48159661e1105eac7 failed: Operation not permitted87client # [2328489.749893] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted88relay # [2328489.741048] relay systemd[1]: Mounted /run/wrappers.89relay # [2328489.742387] relay systemd[1]: Reached target Local File Systems.90relay # [2328489.743600] relay systemd[1]: Listening on Boot Loader Control Service Socket.91relay # [2328489.744781] relay systemd[1]: Starting Create SUID/SGID Wrappers...92relay # [2328489.744829] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container93relay # [2328489.745769] relay systemd[1]: Starting Save Transient machine-id to Disk...94relay # [2328489.746634] relay systemd[1]: Starting Create System Files and Directories...95relay # [2328489.764647] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted96relay # [2328489.765049] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted97relay # [2328489.765345] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/53d69d15b70b491a8c40fa8c8034cb34 failed: Operation not permitted98relay # [2328489.765668] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted99agent # [2328489.745907] agent systemd[1]: Mounted /run/wrappers.100agent # [2328489.747198] agent systemd[1]: Reached target Local File Systems.101agent # [2328489.748465] agent systemd[1]: Listening on Boot Loader Control Service Socket.102agent # [2328489.749795] agent systemd[1]: Starting Create SUID/SGID Wrappers...103agent # [2328489.749845] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container104agent # [2328489.750942] agent systemd[1]: Starting Save Transient machine-id to Disk...105agent # [2328489.752063] agent systemd[1]: Starting Create System Files and Directories...106agent # [2328489.770578] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted107agent # [2328489.770970] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted108agent # [2328489.771283] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/0ef09743fcfa49e8b217788b2d9bf504 failed: Operation not permitted109agent # [2328489.771612] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted110client # [2328489.751737] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.A2jM3ucQhJ/chsh': Operation not permitted111client # [2328489.751726] client systemd[1]: Finished Create System Files and Directories.112client # [2328489.764129] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE113client # [2328489.764237] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.114client # [2328489.764412] client systemd[1]: Failed to start Create SUID/SGID Wrappers.115client # [2328489.766323] client systemd[1]: Starting Rebuild Journal Catalog...116client # [2328489.767078] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...117client # [2328489.779980] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.118client # [2328489.786862] client systemd[1]: Finished Rebuild Journal Catalog.119client # [2328489.788117] client systemd[1]: Starting Update is Completed...120client # [2328489.798424] client systemd[1]: Finished Update is Completed.121client # [2328489.798504] client systemd[1]: Reached target System Initialization.122client # [2328489.798581] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container123client # [2328489.798603] client systemd[1]: Started Daily Cleanup of Temporary Directories.124client # [2328489.798615] client systemd[1]: Reached target Timer Units.125client # [2328489.798715] client systemd[1]: Listening on D-Bus System Message Bus Socket.126client # [2328489.798895] client systemd[1]: Listening on Nix Daemon Socket.127client # [2328489.798993] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.128client # [2328489.799019] client systemd[1]: Reached target Socket Units.129client # [2328489.799046] client systemd[1]: Reached target Basic System.130client # [2328489.804936] client systemd[1]: Starting Import lastlog data into lastlog2 database...131client # [2328489.807851] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...132client # [2328489.817742] client systemd[1]: Starting resolvconf update...133client # [2328489.834744] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.134client # [2328489.853493] client systemd[1]: Finished Save Transient machine-id to Disk.135client # [2328489.870465] client systemd[1]: Finished Import lastlog data into lastlog2 database.136client # [2328489.924238] client systemd[1]: nscd.service: Deactivated successfully.137client # [2328489.924405] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).138relay # [2328489.766998] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.0K4ojZU51y/chsh': Operation not permitted139relay # [2328489.834485] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.140relay # [2328489.853526] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE141relay # [2328489.853561] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.142relay # [2328489.853611] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.143relay # [2328489.853756] relay systemd[1]: Finished Save Transient machine-id to Disk.144relay # [2328489.854205] relay systemd[1]: Finished Create System Files and Directories.145relay # [2328489.896587] relay systemd[1]: Starting Rebuild Journal Catalog...146relay # [2328489.897764] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...147relay # [2328489.919856] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.148agent # [2328489.774605] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.GXtsRVTZgH/chsh': Operation not permitted149agent # [2328489.838692] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.150agent # [2328489.854719] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE151agent # [2328489.854755] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.152agent # [2328489.854818] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.153agent # [2328489.854968] agent systemd[1]: Finished Save Transient machine-id to Disk.154agent # [2328489.855522] agent systemd[1]: Finished Create System Files and Directories.155agent # [2328489.898542] agent systemd[1]: Starting Rebuild Journal Catalog...156agent # [2328489.899184] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...157agent # [2328489.921240] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.158agent # [2328489.928271] agent systemd[1]: Finished Rebuild Journal Catalog.159agent # [2328489.929429] agent systemd[1]: Starting Update is Completed...160agent # [2328489.940914] agent systemd[1]: Finished Update is Completed.161agent # [2328489.941083] agent systemd[1]: Reached target System Initialization.162agent # [2328489.941152] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container163agent # [2328489.941177] agent systemd[1]: Started Daily Cleanup of Temporary Directories.164agent # [2328489.941193] agent systemd[1]: Reached target Timer Units.165agent # [2328489.941288] agent systemd[1]: Listening on D-Bus System Message Bus Socket.166agent # [2328489.941460] agent systemd[1]: Listening on Nix Daemon Socket.167agent # [2328489.941562] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.168agent # [2328489.941578] agent systemd[1]: Reached target Socket Units.169agent # [2328489.941606] agent systemd[1]: Reached target Basic System.170agent # [2328489.942724] agent systemd[1]: Starting Re-link flakelet services at boot...171agent # [2328489.943488] agent systemd[1]: Starting Import lastlog data into lastlog2 database...172agent # [2328489.944270] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...173agent # [2328489.945063] agent systemd[1]: Starting resolvconf update...174agent # [2328489.955428] agent systemd[1]: Finished Re-link flakelet services at boot.175agent # [2328489.958207] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...176client # [2328489.927068] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...177client # [2328489.934182] client systemd[1]: Finished resolvconf update.178client # [2328489.934291] client systemd[1]: Reached target Preparation for Network.179client # [2328489.935200] client systemd[1]: Starting Address configuration of eth1...180client # [2328489.936055] client systemd[1]: Starting Extra networking commands....181client # [2328489.954709] client network-addresses-eth1-start[238]: adding address 192.168.1.2/24... done182client # [2328489.957986] client network-addresses-eth1-start[238]: adding address 2001:db8:1::2/64... done183client # [2328489.962308] client systemd[1]: Finished Address configuration of eth1.184client # [2328490.041883] client systemd[1]: Finished Extra networking commands..185client # [2328490.042042] client systemd[1]: Reached target Network.186client # [2328490.048400] client systemd[1]: nscd.service: Deactivated successfully.187client # [2328490.073238] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).188client # [2328490.076032] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...189relay # [2328489.927867] relay systemd[1]: Finished Rebuild Journal Catalog.190relay # [2328489.929557] relay systemd[1]: Starting Update is Completed...191relay # [2328489.938718] relay systemd[1]: Finished Update is Completed.192relay # [2328489.938940] relay systemd[1]: Reached target System Initialization.193relay # [2328489.939055] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container194relay # [2328489.939093] relay systemd[1]: Started Daily Cleanup of Temporary Directories.195relay # [2328489.939123] relay systemd[1]: Reached target Timer Units.196relay # [2328489.939287] relay systemd[1]: Listening on D-Bus System Message Bus Socket.197relay # [2328489.939581] relay systemd[1]: Listening on Nix Daemon Socket.198relay # [2328489.939753] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.199relay # [2328489.939779] relay systemd[1]: Reached target Socket Units.200relay # [2328489.939833] relay systemd[1]: Reached target Basic System.201relay # [2328489.941571] relay systemd[1]: Started device-mock.service.202relay # [2328489.942409] relay systemd[1]: Starting Re-link flakelet services at boot...203relay # [2328489.943210] relay systemd[1]: Starting Import lastlog data into lastlog2 database...204relay # [2328489.944066] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...205relay # [2328489.944960] relay systemd[1]: Starting resolvconf update...206relay # [2328489.955150] relay systemd[1]: Finished Re-link flakelet services at boot.207relay # [2328489.956069] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...208relay # [2328489.962156] relay systemd[1]: Finished Import lastlog data into lastlog2 database.209relay # [2328489.966956] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.210relay # [2328490.038979] relay systemd[1]: nscd.service: Deactivated successfully.211relay # [2328490.039154] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).212relay # [2328490.041844] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...213relay # [2328490.045072] relay systemd[1]: Finished resolvconf update.214relay # [2328490.045209] relay systemd[1]: Reached target Preparation for Network.215relay # [2328490.045964] relay systemd[1]: Starting Address configuration of eth1...216relay # [2328490.073652] relay systemd[1]: Starting Extra networking commands....217relay # [2328490.091741] relay network-addresses-eth1-start[250]: adding address 192.168.1.3/24... done218relay # [2328490.095083] relay network-addresses-eth1-start[250]: adding address 2001:db8:1::3/64... done219relay # [2328490.099963] relay systemd[1]: Finished Address configuration of eth1.220relay # [2328490.139061] relay systemd[1]: Finished Extra networking commands..221relay # [2328490.139751] relay systemd[1]: Reached target Network.222relay # [2328490.141176] relay systemd[1]: Starting Dnsmasq Daemon...223relay # [2328490.142154] relay systemd[1]: Starting Nginx Web Server...224relay # [2328490.142941] relay systemd[1]: Starting Update flakelet service flakelet-relay...225relay # [2328490.157404] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/b9k6fp9n31l10v7g51g10x2j6m931y2q-flakelet-flakelet-relay226relay # [2328490.159173] relay flakelet[311]: flakelet-relay: activating generation 1227relay # [2328490.164550] relay systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-flakelet-relay.service)...228relay # [2328490.164584] relay systemd[1]: Reloading...229agent # [2328489.962205] agent systemd[1]: Finished Import lastlog data into lastlog2 database.230agent # [2328489.970566] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.231agent # [2328490.038965] agent systemd[1]: nscd.service: Deactivated successfully.232agent # [2328490.039117] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).233agent # [2328490.041852] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...234agent # [2328490.043285] agent systemd[1]: Finished resolvconf update.235agent # [2328490.043373] agent systemd[1]: Reached target Preparation for Network.236agent # [2328490.044269] agent systemd[1]: Starting Address configuration of eth1...237agent # [2328490.045160] agent systemd[1]: Starting Extra networking commands....238agent # [2328490.090852] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done239agent # [2328490.094226] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done240agent # [2328490.098798] agent systemd[1]: Finished Address configuration of eth1.241agent # [2328490.144066] agent systemd[1]: Finished Extra networking commands..242agent # [2328490.144177] agent systemd[1]: Reached target Network.243agent # [2328490.145398] agent systemd[1]: Starting Update flakelet service app...244agent # [2328490.146508] agent systemd[1]: Starting Update flakelet service flakelet-agent...245agent # [2328490.147369] agent systemd[1]: Starting Update flakelet service other...246agent # [2328490.163141] agent flakelet[305]: flakelet-agent: using prebuilt artifact /nix/store/34n1x01929ddbda2zc38va53604yzbhp-flakelet-flakelet-agent247agent # [2328490.163664] agent flakelet[304]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1248agent # [2328490.164124] agent flakelet[306]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1249agent # [2328490.164517] agent flakelet[305]: flakelet-agent: activating generation 1250agent # [2328490.164568] agent flakelet[304]: app: activating generation 1251agent # [2328490.164609] agent flakelet[306]: other: activating generation 1252agent # [2328490.168656] agent systemd[1]: Reload requested from client PID 307 ('systemctl') (unit flakelet-flakelet-agent.service)...253agent # [2328490.168687] agent systemd[1]: Reloading...254client # [2328490.425674] client nsncd[303]: Oct 08 11:59:58.713 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"255client # [2328490.425780] client systemd[1]: Started Name Service Cache Daemon (nsncd).256client # [2328490.425872] client systemd[1]: Reached target Host and Network Name Lookups.257client # [2328490.425977] client systemd[1]: Reached target User and Group Name Lookups.258client # [2328490.428373] client systemd[1]: Starting User Login Management...259client # [2328490.429882] client systemd[1]: Starting Permit User Sessions...260client # [2328490.465140] client systemd[1]: Finished Permit User Sessions.261client # [2328490.467156] client systemd[1]: Started Console Getty.262client # [2328490.467222] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0263client # [2328490.467251] client systemd[1]: Reached target Login Prompts.264relay # [2328490.464232] relay nsncd[247]: Oct 08 11:59:58.751 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"265relay # [2328490.541975] relay systemd[1]: Reloading finished in 376 ms.266relay # [2328490.672845] relay systemd[1]: Started Name Service Cache Daemon (nsncd).267relay # [2328490.673915] relay systemd[1]: Reached target Host and Network Name Lookups.268relay # [2328490.674014] relay systemd[1]: Reached target User and Group Name Lookups.269relay # [2328490.675321] relay systemd[1]: Starting User Login Management...270relay # [2328490.676384] relay systemd[1]: Starting Permit User Sessions...271relay # [2328490.693265] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...272relay # [2328490.693326] relay systemd[1]: Reloading...273agent # [2328490.547991] agent systemd[1]: Reloading finished in 378 ms.274agent # [2328490.676358] agent systemd[1]: nscd.service: Deactivated successfully.275agent # [2328490.676504] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).276agent # [2328490.678951] agent systemd[1]: Reload requested from client PID 308 ('systemctl') (unit flakelet-app.service)...277agent # [2328490.678995] agent systemd[1]: Reloading...278relay # [2328490.736513] relay dnsmasq-pre-start[373]: dnsmasq: syntax check OK.279relay # [2328491.060301] relay systemd[1]: Reloading finished in 366 ms.280relay # [2328491.184993] relay systemd[1]: Finished Permit User Sessions.281relay # [2328491.189644] relay systemd[1]: Started Console Getty.282relay # [2328491.189716] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0283relay # [2328491.189794] relay systemd[1]: Reached target Login Prompts.284relay # [2328491.212691] relay systemd[1]: Starting flakelet-relay...285agent # [2328491.053021] agent systemd[1]: Reloading finished in 373 ms.286agent # [2328491.190411] agent systemd[1]: Reload requested from client PID 309 ('systemctl') (unit flakelet-other.service)...287agent # [2328491.190453] agent systemd[1]: Reloading...288agent # [2328491.553769] agent systemd[1]: Reloading finished in 362 ms.289agent # [2328491.629708] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...290agent # [2328491.635655] agent systemd[1]: Reload requested from client PID 393 ('systemctl') (unit flakelet-flakelet-agent.service)...291agent # [2328491.635691] agent systemd[1]: Reloading...292relay # [2328491.823239] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/cxg067xx9kj6jimgw17hvankw9yihc9k-nginx.conf syntax is ok293relay # [2328491.823877] relay nginx-pre-start[402]: nginx: configuration file /nix/store/cxg067xx9kj6jimgw17hvankw9yihc9k-nginx.conf test is successful294relay # [2328491.849212] relay systemd[1]: Started Nginx Web Server.295relay # [2328491.853060] relay systemd[1]: Starting D-Bus System Message Bus...296client # [2328491.851812] client systemd-logind[315]: New seat seat0.297client # [2328491.852247] client systemd[1]: Started User Login Management.298client # [2328491.854277] client systemd[1]: Starting D-Bus System Message Bus...299client # [2328491.855744] client systemd[1]: Starting linger-users.service...300client # [2328491.885025] client systemd[1]: linger-users.service: Deactivated successfully.301client # [2328491.885390] client systemd[1]: Finished linger-users.service.302client # [2328491.885745] client systemd[1]: Reached target Multi-User System.303agent # [2328492.002137] agent systemd[1]: Reloading finished in 366 ms.304agent # [2328492.034887] agent nsncd[392]: Oct 08 12:00:00.322 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"305agent # [2328492.096958] agent systemd[1]: Started Name Service Cache Daemon (nsncd).306agent # [2328492.099883] agent systemd[1]: Reload requested from client PID 394 ('systemctl') (unit flakelet-app.service)...307agent # [2328492.099918] agent systemd[1]: Reloading...308relay # [2328492.180594] relay systemd-logind[354]: New seat seat0.309relay # [2328492.180913] relay systemd[1]: Started User Login Management.310relay # [2328492.182413] relay systemd[1]: Starting linger-users.service...311relay # [2328492.227353] relay systemd[1]: linger-users.service: Deactivated successfully.312relay # [2328492.227622] relay systemd[1]: Finished linger-users.service.313relay # [2328492.409151] relay dbus-broker-launch[405]: Looking up NSS user entry for 'systemd-timesync'...314relay # [2328492.410303] relay dbus-broker-launch[405]: NSS returned no entry for 'systemd-timesync'315relay # [2328492.410303] relay dbus-broker-launch[405]: Invalid user-name in /nix/store/40ryqckxvcy0k9xw1i3g5rddwf4rhnya-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"316relay # [2328492.411370] relay systemd[1]: Started D-Bus System Message Bus.317relay # [2328492.416515] relay dbus-broker-launch[405]: Ready318relay # [2328492.419991] relay systemd[1]: Started Dnsmasq Daemon.319relay # [2328492.422145] relay dnsmasq[394]: started, version 2.93 cachesize 150320relay # [2328492.422152] relay dnsmasq[394]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth DNSSEC loop-detect inotify dumpfile321relay # [2328492.422158] relay dnsmasq[394]: DBus support enabled: connected to system bus322relay # [2328492.422165] relay dnsmasq[394]: no upstream servers configured - please set them from DBus323relay # [2328492.422256] relay dnsmasq[394]: read /etc/hosts - 9 names324client # [2328492.370121] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...325client # [2328492.371329] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'326client # [2328492.371329] client dbus-broker-launch[325]: Invalid user-name in /nix/store/r6avdj42dpkd7m67x50h2pljx8qs8wvd-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"327client # [2328492.372407] client systemd[1]: Started D-Bus System Message Bus.328client # [2328492.372892] client systemd[1]: Startup finished in 4.126s.329client # [2328492.378531] client dbus-broker-launch[325]: Ready330agent # [2328492.458391] agent systemd[1]: Reloading finished in 358 ms.331agent # [2328492.534230] agent systemd[1]: Reached target Host and Network Name Lookups.332agent # [2328492.534392] agent systemd[1]: Reached target User and Group Name Lookups.333agent # [2328492.535820] agent systemd[1]: Starting User Login Management...334agent # [2328492.536942] agent systemd[1]: Starting Permit User Sessions...335agent # [2328492.539133] agent systemd[1]: Starting flakelet-agent...336agent # [2328492.566029] agent systemd[1]: Starting app v1...337agent # [2328492.566388] agent systemd[1]: Reload requested from client PID 461 ('systemctl') (unit flakelet-other.service)...338agent # [2328492.566425] agent systemd[1]: Reloading...339agent # [2328492.603096] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:00.890568Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}340agent # [2328492.920489] agent systemd[1]: Reloading finished in 353 ms.341agent # [2328493.017767] agent systemd[1]: Started app v1.342agent # [2328493.018047] agent systemd[1]: Started flakelet-agent.343agent # [2328493.018431] agent systemd[1]: Finished Permit User Sessions.344agent # [2328493.025810] agent flakelet[305]: flakelet-agent: updated to generation 1345agent # [2328493.025925] agent systemd[1]: Started Console Getty.346agent # [2328493.025982] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0347agent # [2328493.026058] agent systemd[1]: Reached target Login Prompts.348agent # [2328493.027071] agent systemd[1]: Starting other v1...349agent # [2328493.027421] agent systemd[1]: Finished Update flakelet service flakelet-agent.350agent # [2328493.031777] agent flakelet[304]: app: updated to generation 1351agent # [2328493.056334] agent systemd[1]: Finished Update flakelet service app.352agent # [2328493.060292] agent systemd[1]: Started other v1.353agent # [2328493.066628] agent flakelet[306]: other: updated to generation 1354agent # [2328493.068163] agent systemd[1]: Finished Update flakelet service other.355agent # [2328493.068306] agent systemd[1]: Reached target flakelet managed services.356relay # [2328493.212484] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:01.499940Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}357relay # [2328493.212954] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:01.500407Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}358relay # [2328493.212950] relay systemd[1]: Started flakelet-relay.359relay # [2328493.221550] relay systemd[1]: Starting health for flakelet-relay...360relay # [2328493.519306] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.361relay # [2328493.519648] relay systemd[1]: Finished health for flakelet-relay.362relay # [2328493.528828] relay flakelet[311]: flakelet-relay: updated to generation 1363relay # [2328493.530989] relay systemd[1]: Finished Update flakelet service flakelet-relay.364relay # [2328493.531732] relay systemd[1]: Reached target flakelet managed services.365relay # [2328493.531946] relay systemd[1]: Reached target Multi-User System.366relay # [2328493.532182] relay systemd[1]: Startup finished in 5.288s.367relay: (finished: waiting for unit flakelet-relay.service, in 6.17 seconds)368relay: waiting for unit nginx.service369relay: (finished: waiting for unit nginx.service, in 0.02 seconds)370agent: waiting for unit flakelet.target371agent # [2328493.666149] agent systemd-logind[459]: New seat seat0.372agent # [2328493.666931] agent systemd[1]: Started User Login Management.373agent # [2328493.668898] agent systemd[1]: Starting D-Bus System Message Bus...374agent # [2328493.670591] agent systemd[1]: Starting linger-users.service...375agent # [2328493.701347] agent systemd[1]: linger-users.service: Deactivated successfully.376agent # [2328493.701732] agent systemd[1]: Finished linger-users.service.377agent # [2328493.702113] agent systemd[1]: Reached target Multi-User System.378agent # [2328494.036936] agent dbus-broker-launch[898]: Looking up NSS user entry for 'systemd-timesync'...379agent: (finished: waiting for unit flakelet.target, in 0.17 seconds)380agent: waiting for unit flakelet-agent.service381agent: (finished: waiting for unit flakelet-agent.service, in 0.04 seconds)382client: waiting for unit multi-user.target383client: (finished: waiting for unit multi-user.target, in 0.02 seconds)384relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'385agent # [2328494.038160] agent dbus-broker-launch[898]: NSS returned no entry for 'systemd-timesync'386agent # [2328494.038160] agent dbus-broker-launch[898]: Invalid user-name in /nix/store/g6pprdd65qv8qsgizxsmz013f6jwwbn7-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"387agent # [2328494.038908] agent systemd[1]: Started D-Bus System Message Bus.388agent # [2328494.039471] agent systemd[1]: Startup finished in 5.799s.389agent # [2328494.045362] agent dbus-broker-launch[898]: Ready390relay # [2328494.617602] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:02.905050Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: None, revision: None }, Named { name: \"flakelet-agent\", generation: None, revision: None }, Named { name: \"other\", generation: None, revision: None }]","target":"flakelet_relay::relay::agent_conn"}391agent # [2328494.617575] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:02.904995Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}392agent # [2328494.626833] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:02.914320Z","level":"INFO","message":"local change","flakelet":"app","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}393agent # [2328494.627287] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:02.914780Z","level":"INFO","message":"local change","flakelet":"flakelet-agent","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}394agent # [2328494.627472] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:02.914971Z","level":"INFO","message":"local change","flakelet":"other","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"}395relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 1.03 seconds)396agent: must succeed: systemctl is-active app.service other.service397agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)398subtest: deploy with client certificate, relay found via SRV399agent: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json400agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)401client: must succeed: push --relay-srv test --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1402relay # [2328495.209685] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:03.497089Z","level":"INFO","message":"deploy accepted","job":"04cb31a43ff35a8e43a6ee19d4bc5b2e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}403agent # [2328495.210171] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:03.497583Z","level":"INFO","message":"start","id":"e365208392317ef40bbe4403536d66dd","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}404agent # [2328495.210651] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:03.498141Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e365208392317ef40bbe4403536d66dd\"]","target":"flakelet_relay::agent::jobs"}405agent # [2328495.250379] agent systemd[1]: Starting flakelet update app (via relay)...406agent # [2328495.283116] agent systemd[1]: Started flakelet update app (via relay).407agent # [2328495.287810] agent flakelet[920]: app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2408agent # [2328495.288461] agent flakelet[920]: app: activating generation 2409agent # [2328495.304451] agent systemd[1]: Stopping app v1...410agent # [2328495.306097] agent systemd[1]: app.service: Deactivated successfully.411agent # [2328495.306360] agent systemd[1]: Stopped app v1.412agent # [2328495.323630] agent systemd[1]: Reload requested from client PID 927 ('systemctl') (unit flakelet-relay-job-app.service)...413agent # [2328495.323696] agent systemd[1]: Reloading...414agent # [2328495.669589] agent systemd[1]: Reloading finished in 345 ms.415agent # [2328495.757902] agent systemd[1]: Reload requested from client PID 957 ('systemctl') (unit flakelet-relay-job-app.service)...416agent # [2328495.757938] agent systemd[1]: Reloading...417agent # [2328496.093659] agent systemd[1]: Reloading finished in 335 ms.418agent # [2328496.178166] agent systemd[1]: Reload requested from client PID 986 ('systemctl') (unit flakelet-relay-job-app.service)...419agent # [2328496.178204] agent systemd[1]: Reloading...420agent # [2328496.528614] agent systemd[1]: Reloading finished in 349 ms.421agent # [2328496.603159] agent systemd[1]: Reload requested from client PID 1017 ('systemctl') (unit flakelet-relay-job-app.service)...422agent # [2328496.603193] agent systemd[1]: Reloading...423agent # [2328496.935017] agent systemd[1]: Reloading finished in 331 ms.424agent # [2328497.001427] agent systemd[1]: Starting app v2...425agent # [2328497.030118] agent systemd[1]: Started app v2.426agent # [2328497.034639] agent flakelet[920]: app: updated to generation 2427agent # [2328497.035851] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.428client: (finished: must succeed: push --relay-srv test --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.96 seconds)429agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'430agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)431agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'432agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)433agent: must succeed: flakelet status --json app | jq -c '.[0].changed.by'434agent: (finished: must succeed: flakelet status --json app | jq -c '.[0].changed.by', in 0.03 seconds)435(finished: subtest: deploy with client certificate, relay found via SRV, in 3.04 seconds)436subtest: deploy with OIDC token, sub principal437agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json438agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)439client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)440client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)441client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODA2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWVUpIUUg3N1pNVlhBPT09IiwibmJmIjoxNzkxNDYwODA2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.D23hiHynP0DW6YSkirWjdZPNMlWCAFFPx0-gMLqtwvqtOHzi_uRO89tFkAdhjBY3VHv10YAHOhcSEwhIhuEvBA' push --relay https://relay:7443 deploy agent/app 2>&1442agent # [2328498.141053] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:06.428457Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}443agent # [2328498.326942] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:06.614372Z","level":"INFO","message":"start","id":"afbce17fd8d2e95fff5c4759f08299e4","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"}444agent # [2328498.327675] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:06.615161Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"afbce17fd8d2e95fff5c4759f08299e4\"]","target":"flakelet_relay::agent::jobs"}445agent # [2328498.367999] agent systemd[1]: Starting flakelet update app (via relay)...446agent # [2328498.374709] agent systemd[1]: Started flakelet update app (via relay).447agent # [2328498.378526] agent flakelet[1086]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1448agent # [2328498.379115] agent flakelet[1086]: app: activating generation 3449agent # [2328498.392163] agent systemd[1]: Stopping app v2...450relay # [2328498.143305] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:06.430705Z","level":"INFO","message":"deploy finished","job":"04cb31a43ff35a8e43a6ee19d4bc5b2e","ok":true,"target":"flakelet_relay::relay::api"}451relay # [2328498.326629] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:06.614062Z","level":"INFO","message":"deploy accepted","job":"7d3d1f638ae44b7ee49586e1592ba235","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}452agent # [2328498.393779] agent systemd[1]: app.service: Deactivated successfully.453agent # [2328498.394044] agent systemd[1]: Stopped app v2.454agent # [2328498.408949] agent systemd[1]: Reload requested from client PID 1093 ('systemctl') (unit flakelet-relay-job-app.service)...455agent # [2328498.409028] agent systemd[1]: Reloading...456agent # [2328498.756167] agent systemd[1]: Reloading finished in 346 ms.457agent # [2328498.828840] agent systemd[1]: Reload requested from client PID 1126 ('systemctl') (unit flakelet-relay-job-app.service)...458agent # [2328498.828871] agent systemd[1]: Reloading...459agent # [2328499.161933] agent systemd[1]: Reloading finished in 332 ms.460agent # [2328499.229449] agent systemd[1]: Reload requested from client PID 1156 ('systemctl') (unit flakelet-relay-job-app.service)...461agent # [2328499.229487] agent systemd[1]: Reloading...462agent # [2328499.562247] agent systemd[1]: Reloading finished in 332 ms.463agent # [2328499.643634] agent systemd[1]: Reload requested from client PID 1187 ('systemctl') (unit flakelet-relay-job-app.service)...464agent # [2328499.643668] agent systemd[1]: Reloading...465agent # [2328499.974239] agent systemd[1]: Reloading finished in 330 ms.466agent # [2328500.035012] agent systemd[1]: Starting app v1...467agent # [2328500.064313] agent systemd[1]: Started app v1.468agent # [2328500.071934] agent flakelet[1086]: app: updated to generation 3469agent # [2328500.073156] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.470client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODA2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWVUpIUUg3N1pNVlhBPT09IiwibmJmIjoxNzkxNDYwODA2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.D23hiHynP0DW6YSkirWjdZPNMlWCAFFPx0-gMLqtwvqtOHzi_uRO89tFkAdhjBY3VHv10YAHOhcSEwhIhuEvBA' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.89 seconds)471(finished: subtest: deploy with OIDC token, sub principal, in 2.97 seconds)472subtest: policy denies uncovered target473client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODA2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWVUpIUUg3N1pNVlhBPT09IiwibmJmIjoxNzkxNDYwODA2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.D23hiHynP0DW6YSkirWjdZPNMlWCAFFPx0-gMLqtwvqtOHzi_uRO89tFkAdhjBY3VHv10YAHOhcSEwhIhuEvBA' push --relay https://relay:7443 deploy agent/other 2>&1474client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwNiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODA2LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJWVUpIUUg3N1pNVlhBPT09IiwibmJmIjoxNzkxNDYwODA2LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.D23hiHynP0DW6YSkirWjdZPNMlWCAFFPx0-gMLqtwvqtOHzi_uRO89tFkAdhjBY3VHv10YAHOhcSEwhIhuEvBA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)475(finished: subtest: policy denies uncovered target, in 0.02 seconds)476subtest: claim principal from groups, unchanged counts as success477client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)478client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)479client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwOSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MTQ2MDgwOSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiQjVaNUQ2QkVHUzVJSz09PSIsIm5iZiI6MTc5MTQ2MDgwOSwic3ViIjoic29tZW9uZSJ9.EZnH8p6w-OllvuEwoFr5zaO2FjDbmQgiTIsY7jqBItyvIssM5LfLASlbhyPYqQzNTALyGTMuPNBRARvPg6IcCA' push --relay https://relay:7443 deploy agent/other 2>&1480relay # [2328501.178662] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:09.466052Z","level":"INFO","message":"deploy finished","job":"7d3d1f638ae44b7ee49586e1592ba235","ok":true,"target":"flakelet_relay::relay::api"}481relay # [2328501.280239] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:09.567707Z","level":"INFO","message":"deploy accepted","job":"d6c6fcd5526a3269eb536da8622a4c70","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}482agent # [2328501.176732] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:09.464136Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}483agent # [2328501.280596] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:09.568035Z","level":"INFO","message":"start","id":"ecc985fdbd8f5ca7018a4cc74cb12387","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"}484agent # [2328501.281083] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:09.568579Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"ecc985fdbd8f5ca7018a4cc74cb12387\"]","target":"flakelet_relay::agent::jobs"}485agent # [2328501.324782] agent systemd[1]: Starting flakelet update other (via relay)...486agent # [2328501.359251] agent systemd[1]: Started flakelet update other (via relay).487agent # [2328501.363350] agent flakelet[1241]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1488agent # [2328501.363907] agent flakelet[1241]: other: up to date489agent # [2328501.365707] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.490client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEwOSwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MTQ2MDgwOSwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiQjVaNUQ2QkVHUzVJSz09PSIsIm5iZiI6MTc5MTQ2MDgwOSwic3ViIjoic29tZW9uZSJ9.EZnH8p6w-OllvuEwoFr5zaO2FjDbmQgiTIsY7jqBItyvIssM5LfLASlbhyPYqQzNTALyGTMuPNBRARvPg6IcCA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds)491(finished: subtest: claim principal from groups, unchanged counts as success, in 0.71 seconds)492subtest: push login via device flow, cached token used afterwards493client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1494relay # [2328501.906925] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:10.194345Z","level":"INFO","message":"deploy finished","job":"d6c6fcd5526a3269eb536da8622a4c70","ok":true,"target":"flakelet_relay::relay::api"}495relay # [2328501.929998] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [08/Oct/2026 12:00:10] "POST /device HTTP/1.1" 200 -496agent # [2328501.905149] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:10.192551Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}497relay # [2328502.935795] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [08/Oct/2026 12:00:11] "POST /token HTTP/1.1" 400 -498client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.09 seconds)499client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600500client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)501client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1502relay # [2328503.995549] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [08/Oct/2026 12:00:12] "POST /token HTTP/1.1" 200 -503relay # [2328504.030484] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:12.317942Z","level":"INFO","message":"deploy accepted","job":"16a84ab1248ca211f11074255ef1276a","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}504agent # [2328504.030993] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:12.318398Z","level":"INFO","message":"start","id":"fe003e0f078ab0b855b8436148a37a2f","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}505agent # [2328504.031831] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:12.319225Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"fe003e0f078ab0b855b8436148a37a2f\"]","target":"flakelet_relay::agent::jobs"}506agent # [2328504.073213] agent systemd[1]: Starting flakelet update other (via relay)...507agent # [2328504.105144] agent systemd[1]: Started flakelet update other (via relay).508agent # [2328504.109839] agent flakelet[1265]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1509agent # [2328504.110398] agent flakelet[1265]: other: up to date510agent # [2328504.113033] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.511client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)512client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1513relay # [2328504.652556] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:12.939952Z","level":"INFO","message":"deploy finished","job":"16a84ab1248ca211f11074255ef1276a","ok":true,"target":"flakelet_relay::relay::api"}514relay # [2328504.675533] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:12.963011Z","level":"INFO","message":"deploy accepted","job":"c8099833d31fb344f4443b0c4db883b0","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}515agent # [2328504.650642] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:12.938040Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}516agent # [2328504.675890] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:12.963318Z","level":"INFO","message":"start","id":"e117afeb06c620ca5e621b168a928d79","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"}517agent # [2328504.676341] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:12.963827Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"e117afeb06c620ca5e621b168a928d79\"]","target":"flakelet_relay::agent::jobs"}518agent # [2328504.718570] agent systemd[1]: Starting flakelet update other (via relay)...519agent # [2328504.747221] agent systemd[1]: Started flakelet update other (via relay).520agent # [2328504.751301] agent flakelet[1289]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1521agent # [2328504.751846] agent flakelet[1289]: other: up to date522agent # [2328504.754090] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.523client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds)524(finished: subtest: push login via device flow, cached token used afterwards, in 3.39 seconds)525subtest: waves: failing first wave skips the second526agent: must succeed: jq '.services.app.prebuilt="/nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json527agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)528client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1529relay # [2328505.292973] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:13.580391Z","level":"INFO","message":"deploy finished","job":"c8099833d31fb344f4443b0c4db883b0","ok":true,"target":"flakelet_relay::relay::api"}530relay # [2328505.330820] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:13.618260Z","level":"INFO","message":"deploy accepted","job":"5edb477152b27b7226589eca431c6c19","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}531agent # [2328505.290885] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:13.578280Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}532agent # [2328505.331117] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:13.618579Z","level":"INFO","message":"start","id":"813406c4fa284fcfb3c32398e391bac4","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}533agent # [2328505.331579] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:13.619066Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"813406c4fa284fcfb3c32398e391bac4\"]","target":"flakelet_relay::agent::jobs"}534agent # [2328505.371152] agent systemd[1]: Starting flakelet update app (via relay)...535agent # [2328505.408291] agent systemd[1]: Started flakelet update app (via relay).536agent # [2328505.412844] agent flakelet[1312]: app: using prebuilt artifact /nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken537agent # [2328505.413471] agent flakelet[1312]: app: activating generation 4538agent # [2328505.423841] agent systemd[1]: Stopping app v1...539agent # [2328505.425296] agent systemd[1]: app.service: Deactivated successfully.540agent # [2328505.425498] agent systemd[1]: Stopped app v1.541agent # [2328505.435456] agent systemd[1]: Reload requested from client PID 1319 ('systemctl') (unit flakelet-relay-job-app.service)...542agent # [2328505.435491] agent systemd[1]: Reloading...543agent # [2328505.771251] agent systemd[1]: Reloading finished in 335 ms.544agent # [2328505.836407] agent systemd[1]: Reload requested from client PID 1349 ('systemctl') (unit flakelet-relay-job-app.service)...545agent # [2328505.836444] agent systemd[1]: Reloading...546agent # [2328506.167082] agent systemd[1]: Reloading finished in 330 ms.547agent # [2328506.227936] agent systemd[1]: Reload requested from client PID 1378 ('systemctl') (unit flakelet-relay-job-app.service)...548agent # [2328506.227975] agent systemd[1]: Reloading...549agent # [2328506.560359] agent systemd[1]: Reloading finished in 331 ms.550agent # [2328506.629680] agent systemd[1]: Reload requested from client PID 1412 ('systemctl') (unit flakelet-relay-job-app.service)...551agent # [2328506.629716] agent systemd[1]: Reloading...552agent # [2328506.965328] agent systemd[1]: Reloading finished in 335 ms.553agent # [2328507.028208] agent systemd[1]: Starting app broken...554agent # [2328507.057541] agent (nonexistent)[1443]: app.service: Unable to locate executable '/nonexistent': No such file or directory555agent # [2328507.057566] agent (nonexistent)[1443]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory556agent # [2328507.059058] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC557agent # [2328507.059172] agent systemd[1]: app.service: Failed with result 'exit-code'.558agent # [2328507.059507] agent systemd[1]: Failed to start app broken.559agent # [2328507.088175] agent systemd[1]: Reload requested from client PID 1449 ('systemctl') (unit flakelet-relay-job-app.service)...560agent # [2328507.088213] agent systemd[1]: Reloading...561agent # [2328507.422160] agent systemd[1]: Reloading finished in 333 ms.562agent # [2328507.495925] agent systemd[1]: Reload requested from client PID 1479 ('systemctl') (unit flakelet-relay-job-app.service)...563agent # [2328507.495963] agent systemd[1]: Reloading...564agent # [2328507.825265] agent systemd[1]: Reloading finished in 328 ms.565agent # [2328507.890740] agent systemd[1]: Reload requested from client PID 1509 ('systemctl') (unit flakelet-relay-job-app.service)...566agent # [2328507.890778] agent systemd[1]: Reloading...567agent # [2328508.225190] agent systemd[1]: Reloading finished in 333 ms.568agent # [2328508.303303] agent systemd[1]: Reload requested from client PID 1539 ('systemctl') (unit flakelet-relay-job-app.service)...569agent # [2328508.303339] agent systemd[1]: Reloading...570agent # [2328508.636123] agent systemd[1]: Reloading finished in 332 ms.571agent # [2328508.698771] agent systemd[1]: Starting app v1...572agent # [2328508.736223] agent systemd[1]: Started app v1.573agent # [2328508.737515] agent flakelet[1312]: app: deploy failed, rolled back: systemctl start app.service failed:574agent # [2328508.737515] agent flakelet[1312]: failed units: app.service. See journalctl -u app.service575agent # [2328508.738937] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE576agent # [2328508.739048] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.577client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.13 seconds)578agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'579agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds)580(finished: subtest: waves: failing first wave skips the second, in 4.17 seconds)581subtest: host patterns expand on the relay582agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json583agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)584client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1585relay # [2328509.439882] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:17.727303Z","level":"INFO","message":"deploy finished","job":"5edb477152b27b7226589eca431c6c19","ok":false,"target":"flakelet_relay::relay::api"}586relay # [2328509.498186] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:17.785608Z","level":"INFO","message":"deploy accepted","job":"3fb39b3d0a7bd2c89a90c225cdc71e6b","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}587agent # [2328509.438103] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:17.725494Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}588agent # [2328509.498504] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:17.785918Z","level":"INFO","message":"start","id":"008075b80e82f5c3b844cefae40c025c","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}589agent # [2328509.499083] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:17.786568Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"008075b80e82f5c3b844cefae40c025c\"]","target":"flakelet_relay::agent::jobs"}590agent # [2328509.539983] agent systemd[1]: Starting flakelet update app (via relay)...591agent # [2328509.574262] agent systemd[1]: Started flakelet update app (via relay).592agent # [2328509.578715] agent flakelet[1599]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1593agent # [2328509.579339] agent flakelet[1599]: app: up to date594agent # [2328509.581313] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.595client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.65 seconds)596client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1597relay # [2328510.126661] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:18.414075Z","level":"INFO","message":"deploy finished","job":"3fb39b3d0a7bd2c89a90c225cdc71e6b","ok":true,"target":"flakelet_relay::relay::api"}598relay # [2328510.148843] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:18.436322Z","level":"INFO","message":"deploy accepted","job":"6a9de204cfaef8b5d6c6f9af318e72a5","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}599agent # [2328510.125154] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:18.412573Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}600agent # [2328510.149178] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:18.436632Z","level":"INFO","message":"start","id":"fbe75db19c8c3c72e22aa2dbd486896e","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}601agent # [2328510.149368] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:18.436865Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"fbe75db19c8c3c72e22aa2dbd486896e\"]","target":"flakelet_relay::agent::jobs"}602agent # [2328510.187555] agent systemd[1]: Starting flakelet update app (via relay)...603agent # [2328510.194226] agent systemd[1]: Started flakelet update app (via relay).604agent # [2328510.198876] agent flakelet[1619]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1605agent # [2328510.199452] agent flakelet[1619]: app: up to date606agent # [2328510.201917] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.607client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.62 seconds)608client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1609relay # [2328510.743986] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:19.031404Z","level":"INFO","message":"deploy finished","job":"6a9de204cfaef8b5d6c6f9af318e72a5","ok":false,"target":"flakelet_relay::relay::api"}610relay # [2328510.766251] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:19.053722Z","level":"INFO","message":"deploy accepted","job":"c1c90b6ba3db0ab3498796af53f2b1b9","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}611agent # [2328510.741937] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.029333Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}612agent # [2328510.766548] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.054014Z","level":"INFO","message":"start","id":"d6a3b4179353abc1c9b76bd432cc693e","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}613agent # [2328510.766984] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.054472Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"d6a3b4179353abc1c9b76bd432cc693e\"]","target":"flakelet_relay::agent::jobs"}614agent # [2328510.807431] agent systemd[1]: Starting flakelet update app (via relay)...615agent # [2328510.846279] agent systemd[1]: Started flakelet update app (via relay).616agent # [2328510.851344] agent flakelet[1643]: app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1617agent # [2328510.851935] agent flakelet[1643]: app: up to date618agent # [2328510.853883] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.619client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.65 seconds)620client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1621client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)622(finished: subtest: host patterns expand on the relay, in 1.95 seconds)623subtest: detach returns once the job is accepted624agent: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json625agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds)626client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1627client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)628agent: waiting for success: systemctl is-active flakelet-relay-job-app.service629relay # [2328511.395700] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:19.683112Z","level":"INFO","message":"deploy finished","job":"c1c90b6ba3db0ab3498796af53f2b1b9","ok":false,"target":"flakelet_relay::relay::api"}630relay # [2328511.454714] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:19.742139Z","level":"INFO","message":"deploy accepted","job":"e7a8fd02228427d07fcb9a0ba8a1a078","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}631agent # [2328511.393696] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.681100Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}632agent # [2328511.455058] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.742470Z","level":"INFO","message":"start","id":"58b8da61b1cca2f8b513955fa63e0cd5","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}633agent # [2328511.455608] agent flakelet-agent[463]: {"timestamp":"2026-10-08T12:00:19.743092Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"58b8da61b1cca2f8b513955fa63e0cd5\"]","target":"flakelet_relay::agent::jobs"}634agent # [2328511.497847] agent systemd[1]: Starting flakelet update app (via relay)...635agent # [2328511.530198] agent systemd[1]: Started flakelet update app (via relay).636agent # [2328511.534830] agent flakelet[1667]: app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2637agent # [2328511.535483] agent flakelet[1667]: app: activating generation 4638agent # [2328511.548847] agent systemd[1]: Stopping app v1...639agent # [2328511.550696] agent systemd[1]: app.service: Deactivated successfully.640agent # [2328511.551061] agent systemd[1]: Stopped app v1.641agent # [2328511.568759] agent systemd[1]: Reload requested from client PID 1674 ('systemctl') (unit flakelet-relay-job-app.service)...642agent # [2328511.568826] agent systemd[1]: Reloading...643agent # [2328511.912714] agent systemd[1]: Reloading finished in 343 ms.644agent # [2328511.989278] agent systemd[1]: Reload requested from client PID 1704 ('systemctl') (unit flakelet-relay-job-app.service)...645agent # [2328511.989316] agent systemd[1]: Reloading...646agent # [2328512.320337] agent systemd[1]: Reloading finished in 330 ms.647agent # [2328512.387344] agent systemd[1]: Reload requested from client PID 1733 ('systemctl') (unit flakelet-relay-job-app.service)...648agent # [2328512.387382] agent systemd[1]: Reloading...649agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.32 seconds)650??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.651 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39652agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service653??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.654 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39655agent # [2328512.721868] agent systemd[1]: Reloading finished in 334 ms.656agent # [2328512.786684] agent systemd[1]: Reload requested from client PID 1768 ('systemctl') (unit flakelet-relay-job-app.service)...657agent # [2328512.786717] agent systemd[1]: Reloading...658agent # [2328513.117865] agent systemd[1]: Reloading finished in 330 ms.659agent # [2328513.194009] agent systemd[1]: Starting app slow2...660agent # [2328519.270580] agent systemd[1]: Started app slow2.661agent # [2328519.277285] agent flakelet[1667]: app: updated to generation 4662agent # [2328519.279374] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.663agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.50 seconds)664(finished: subtest: detach returns once the job is accepted, in 8.87 seconds)665subtest: unknown host is final, missing agent is retried, agents listing666client: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1667client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)668agent: must succeed: systemctl stop flakelet-agent669agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.07 seconds)670relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'671relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)672client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &673client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)674client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out675agent # [2328520.320137] agent systemd[1]: Stopping flakelet-agent...676agent # [2328520.349245] agent systemd[1]: flakelet-agent.service: Deactivated successfully.677agent # [2328520.349743] agent systemd[1]: Stopped flakelet-agent.678agent # [2328520.350170] agent systemd[1]: flakelet-agent.service: Consumed 1.579s CPU time over 27.810s wall clock time.679relay # [2328520.320219] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:28.607675Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"}680client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)681agent: must succeed: systemctl start flakelet-agent682agent: (finished: must succeed: systemctl start flakelet-agent, in 0.10 seconds)683??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.684 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39685client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out686relay # [2328521.536836] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:29.824269Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}687agent # [2328521.445290] agent systemd[1]: Starting flakelet-agent...688agent # [2328521.501349] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:29.788822Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"58b8da61b1cca2f8b513955fa63e0cd5\"]","target":"flakelet_relay::agent::jobs"}689agent # [2328521.527385] agent systemd[1]: Started flakelet-agent.690agent # [2328521.536761] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:29.824240Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}691agent # [2328522.045337] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:30.332756Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}692relay # [2328523.430087] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:31.717499Z","level":"INFO","message":"deploy accepted","job":"d725407863e887d4187059d5e0074d05","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}693agent # [2328523.430566] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:31.717963Z","level":"INFO","message":"start","id":"9c8da081e316db3c393557b94c9cfbda","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}694agent # [2328523.431514] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:31.718658Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"9c8da081e316db3c393557b94c9cfbda\"]","target":"flakelet_relay::agent::jobs"}695agent # [2328523.473239] agent systemd[1]: Starting flakelet update other (via relay)...696agent # [2328523.508222] agent systemd[1]: Started flakelet update other (via relay).697agent # [2328523.512851] agent flakelet[2248]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1698agent # [2328523.513376] agent flakelet[2248]: other: up to date699agent # [2328523.515605] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.700relay # [2328524.053350] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:32.340739Z","level":"INFO","message":"deploy finished","job":"d725407863e887d4187059d5e0074d05","ok":true,"target":"flakelet_relay::relay::api"}701agent # [2328524.051552] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:32.338993Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}702client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)703client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents704client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)705client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)706client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)707client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEzMiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODMyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTUzJVSFhGS0lDRjNVPT09IiwibmJmIjoxNzkxNDYwODMyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.yeHHq9VRiLzga2dmAfRjtKF2PKTFvuemXtxRsNpH4AflksOPneK9mwt4JyBAup8x4f90nBJjkQNrCDAoGm5lDw' push --relay https://relay:7443 agents708client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTEzMiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODMyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJTUzJVSFhGS0lDRjNVPT09IiwibmJmIjoxNzkxNDYwODMyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.yeHHq9VRiLzga2dmAfRjtKF2PKTFvuemXtxRsNpH4AflksOPneK9mwt4JyBAup8x4f90nBJjkQNrCDAoGm5lDw' push --relay https://relay:7443 agents, in 0.02 seconds)709(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.38 seconds)710subtest: out-of-band flakelet update reaches the relay without reconnect711agent: must succeed: flakelet status --json app | jq '.[0].generation'712agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.03 seconds)713agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true714agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)715agent: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json716agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)717agent: must succeed: flakelet update app718app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v2719app: activating generation 5720agent # [2328524.759818] agent systemd[1]: Stopping app slow2...721agent # [2328524.761497] agent systemd[1]: app.service: Deactivated successfully.722agent # [2328524.761780] agent systemd[1]: Stopped app slow2.723agent # [2328524.779746] agent systemd[1]: Reload requested from client PID 2282 ('systemctl')...724agent # [2328524.779812] agent systemd[1]: Reloading...725agent # [2328525.125853] agent systemd[1]: Reloading finished in 345 ms.726agent # [2328525.192173] agent systemd[1]: Reload requested from client PID 2311 ('systemctl')...727agent # [2328525.192211] agent systemd[1]: Reloading...728agent # [2328525.524326] agent systemd[1]: Reloading finished in 331 ms.729agent # [2328525.599621] agent systemd[1]: Reload requested from client PID 2341 ('systemctl')...730agent # [2328525.599656] agent systemd[1]: Reloading...731agent # [2328525.936614] agent systemd[1]: Reloading finished in 336 ms.732agent # [2328526.019170] agent systemd[1]: Reload requested from client PID 2372 ('systemctl')...733agent # [2328526.019205] agent systemd[1]: Reloading...734agent # [2328526.351966] agent systemd[1]: Reloading finished in 332 ms.735agent: (finished: must succeed: flakelet update app, in 1.74 seconds)736client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'737agent # [2328526.427077] agent systemd[1]: Starting app v2...738agent # [2328526.464295] agent systemd[1]: Started app v2.739agent # [2328527.549490] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:35.836898Z","level":"INFO","message":"local change","flakelet":"app","generation":5,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}740client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.07 seconds)741agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true742agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)743client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-744client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-, in 0.02 seconds)745client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-746client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-, in 0.02 seconds)747agent: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json748agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)749agent: must succeed: flakelet update app750app: using prebuilt artifact /nix/store/4ksi9bj3vq7a8k2k1kiyi6p5dgncxpjx-flakelet-app-v1751app: activating generation 6752agent # [2328528.638353] agent systemd[1]: Stopping app v2...753agent # [2328528.639068] agent systemd[1]: app.service: Deactivated successfully.754agent # [2328528.639204] agent systemd[1]: Stopped app v2.755agent # [2328528.649121] agent systemd[1]: Reload requested from client PID 2418 ('systemctl')...756agent # [2328528.649155] agent systemd[1]: Reloading...757agent # [2328528.978459] agent systemd[1]: Reloading finished in 328 ms.758agent # [2328529.059817] agent systemd[1]: Reload requested from client PID 2447 ('systemctl')...759agent # [2328529.059854] agent systemd[1]: Reloading...760agent # [2328529.391108] agent systemd[1]: Reloading finished in 330 ms.761agent # [2328529.464981] agent systemd[1]: Reload requested from client PID 2475 ('systemctl')...762agent # [2328529.465024] agent systemd[1]: Reloading...763agent # [2328529.796302] agent systemd[1]: Reloading finished in 330 ms.764agent # [2328529.874431] agent systemd[1]: Reload requested from client PID 2507 ('systemctl')...765agent # [2328529.874469] agent systemd[1]: Reloading...766agent: (finished: must succeed: flakelet update app, in 1.70 seconds)767client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'768agent # [2328530.206445] agent systemd[1]: Reloading finished in 331 ms.769agent # [2328530.269626] agent systemd[1]: Starting app v1...770agent # [2328530.306189] agent systemd[1]: Started app v1.771agent # [2328531.555433] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:39.842774Z","level":"INFO","message":"local change","flakelet":"app","generation":6,"by":"root (shell)","target":"flakelet_relay::agent::jobs"}772client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.07 seconds)773(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.71 seconds)774subtest: certificate not listed under agents cannot connect as agent775client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent776client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.03 seconds)777(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.03 seconds)778subtest: metrics779relay: must succeed: curl -sf http://127.0.0.1:7400/metrics780relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.02 seconds)781(finished: subtest: metrics, in 0.02 seconds)782subtest: agent link drop mid-run replays missed lines once783agent: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json784agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)785agent: must succeed: date +%s786agent: (finished: must succeed: date +%s, in 0.01 seconds)787client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &788client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)789agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460840 | grep -q 'app-slow'790relay # [2328532.407339] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:40.694667Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}791relay # [2328532.473538] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:40.760970Z","level":"INFO","message":"deploy accepted","job":"d149e9c00eed19555e206e6750dbd5b8","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}792agent # [2328532.473959] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:40.761372Z","level":"INFO","message":"start","id":"49af54efec991c8d3dd89a11d2075c4c","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}793agent # [2328532.474337] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:40.761826Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"49af54efec991c8d3dd89a11d2075c4c\"]","target":"flakelet_relay::agent::jobs"}794agent # [2328532.511781] agent systemd[1]: Starting flakelet update app (via relay)...795agent # [2328532.545256] agent systemd[1]: Started flakelet update app (via relay).796agent # [2328532.550651] agent flakelet[2557]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow797agent # [2328532.551295] agent flakelet[2557]: app: activating generation 7798agent # [2328532.568083] agent systemd[1]: Stopping app v1...799agent # [2328532.568526] agent systemd[1]: app.service: Deactivated successfully.800agent # [2328532.568782] agent systemd[1]: Stopped app v1.801agent # [2328532.584963] agent systemd[1]: Reload requested from client PID 2564 ('systemctl') (unit flakelet-relay-job-app.service)...802agent # [2328532.585042] agent systemd[1]: Reloading...803agent # [2328532.931674] agent systemd[1]: Reloading finished in 345 ms.804agent # [2328532.995272] agent systemd[1]: Reload requested from client PID 2594 ('systemctl') (unit flakelet-relay-job-app.service)...805agent # [2328532.995310] agent systemd[1]: Reloading...806agent # [2328533.325496] agent systemd[1]: Reloading finished in 329 ms.807agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460840 | grep -q 'app-slow', in 1.03 seconds)808agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done809agent: (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)810relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done811relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.06 seconds)812agent: must succeed: ss -K dport = 7443813agent # [2328533.383328] agent systemd[1]: Reload requested from client PID 2623 ('systemctl') (unit flakelet-relay-job-app.service)...814agent # [2328533.383364] agent systemd[1]: Reloading...815agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)816agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460840 | grep -q 'updated to generation'817agent # [2328533.599877] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:41.887154Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}818agent # [2328533.712748] agent systemd[1]: Reloading finished in 328 ms.819agent # [2328533.781071] agent systemd[1]: Reload requested from client PID 2671 ('systemctl') (unit flakelet-relay-job-app.service)...820agent # [2328533.781110] agent systemd[1]: Reloading...821relay # [2328533.564909] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:41.852334Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}822agent # [2328534.111769] agent systemd[1]: Reloading finished in 330 ms.823agent # [2328534.186202] agent systemd[1]: Starting app slow...824agent # [2328534.602473] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:42.889746Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}825agent # [2328536.605075] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:44.892477Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}826agent # [2328540.254273] agent systemd[1]: Started app slow.827agent # [2328540.264323] agent flakelet[2557]: app: updated to generation 7828agent # [2328540.266348] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.829agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460840 | grep -q 'updated to generation', in 7.11 seconds)830agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done831agent: (finished: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done, in 0.02 seconds)832client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out833agent # [2328540.607590] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:48.894875Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}834agent # [2328541.363389] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:49.650807Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}835client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.09 seconds)836client: must succeed: cat /tmp/slow.out837client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)838(finished: subtest: agent link drop mid-run replays missed lines once, in 16.41 seconds)839subtest: agent restart mid-run reattaches to the unit840agent: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json841agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)842client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &843client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)844agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'845relay # [2328548.611050] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:56.898477Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}846agent # [2328548.610967] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:56.898408Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}847relay # [2328548.611915] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:56.899034Z","level":"INFO","message":"deploy finished","job":"d149e9c00eed19555e206e6750dbd5b8","ok":true,"target":"flakelet_relay::relay::api"}848agent # [2328548.611708] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:56.898619Z","level":"INFO","message":"start","id":"49af54efec991c8d3dd89a11d2075c4c","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}849relay # [2328548.873809] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:57.161104Z","level":"INFO","message":"deploy accepted","job":"837e7595e4205c5521345f57477d8f7d","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}850agent # [2328548.874169] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:57.161478Z","level":"INFO","message":"start","id":"23a45f8695ca2339fe7dff52fede2868","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}851agent # [2328548.874641] agent flakelet-agent[1835]: {"timestamp":"2026-10-08T12:00:57.162131Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"23a45f8695ca2339fe7dff52fede2868\"]","target":"flakelet_relay::agent::jobs"}852agent # [2328548.910777] agent systemd[1]: Starting flakelet update app (via relay)...853agent # [2328548.942218] agent systemd[1]: Started flakelet update app (via relay).854agent # [2328548.946697] agent flakelet[2793]: app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow2855agent # [2328548.947350] agent flakelet[2793]: app: activating generation 8856agent # [2328548.963775] agent systemd[1]: Stopping app slow...857agent # [2328548.965552] agent systemd[1]: app.service: Deactivated successfully.858agent # [2328548.965864] agent systemd[1]: Stopped app slow.859agent # [2328548.981282] agent systemd[1]: Reload requested from client PID 2800 ('systemctl') (unit flakelet-relay-job-app.service)...860agent # [2328548.981348] agent systemd[1]: Reloading...861agent # [2328549.330207] agent systemd[1]: Reloading finished in 348 ms.862agent # [2328549.415713] agent systemd[1]: Reload requested from client PID 2830 ('systemctl') (unit flakelet-relay-job-app.service)...863agent # [2328549.415752] agent systemd[1]: Reloading...864agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)865agent: must succeed: systemctl restart flakelet-agent866agent # [2328549.748450] agent systemd[1]: Reloading finished in 332 ms.867agent # [2328549.836796] agent systemd[1]: Reload requested from client PID 2861 ('systemctl') (unit flakelet-relay-job-app.service)...868agent # [2328549.836829] agent systemd[1]: Reloading...869relay # [2328550.276070] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:58.563456Z","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"}870agent # [2328550.184921] agent systemd[1]: Reloading finished in 347 ms.871agent # [2328550.275813] agent systemd[1]: Stopping flakelet-agent...872agent # [2328550.282364] agent systemd[1]: Reload requested from client PID 2898 ('systemctl') (unit flakelet-relay-job-app.service)...873agent # [2328550.282400] agent systemd[1]: Reloading...874agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.91 seconds)875agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"876agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)877client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out878relay # [2328550.808992] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:00:59.096398Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}879agent # [2328550.641551] agent systemd[1]: Reloading finished in 358 ms.880agent # [2328550.728448] agent systemd[1]: flakelet-agent.service: Deactivated successfully.881agent # [2328550.728635] agent systemd[1]: Stopped flakelet-agent.882agent # [2328550.747450] agent systemd[1]: Starting app slow2...883agent # [2328550.748458] agent systemd[1]: Starting flakelet-agent...884agent # [2328550.779677] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:00:59.067160Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"23a45f8695ca2339fe7dff52fede2868\"]","target":"flakelet_relay::agent::jobs"}885agent # [2328550.799051] agent systemd[1]: Started flakelet-agent.886agent # [2328550.808806] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:00:59.096291Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}887agent # [2328550.810038] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:00:59.097541Z","level":"INFO","message":"start","id":"23a45f8695ca2339fe7dff52fede2868","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}888agent # [2328556.795883] agent systemd[1]: Started app slow2.889agent # [2328556.802566] agent flakelet[2793]: app: updated to generation 8890agent # [2328556.803890] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.891agent # [2328557.357999] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:05.645420Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}892relay # [2328557.360760] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:01:05.648166Z","level":"INFO","message":"deploy finished","job":"837e7595e4205c5521345f57477d8f7d","ok":true,"target":"flakelet_relay::relay::api"}893client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.07 seconds)894client: must succeed: cat /tmp/restart.out895client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)896agent: must succeed: systemctl is-active app.service897agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)898(finished: subtest: agent restart mid-run reattaches to the unit, in 9.07 seconds)899subtest: relay restart mid-run, push resumes via /v1/jobs900agent: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json901agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)902agent: must succeed: date +%s903agent: (finished: must succeed: date +%s, in 0.01 seconds)904client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &905client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)906agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460866 | grep -q 'app-slow'907relay # [2328557.957982] relay flakelet-relay[400]: {"timestamp":"2026-10-08T12:01:06.245408Z","level":"INFO","message":"deploy accepted","job":"20aea30ca682d19359b90aeaf3957397","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}908agent # [2328557.958370] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:06.245768Z","level":"INFO","message":"start","id":"34c419cef9a20030125bc88ff12635ec","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}909agent # [2328557.958917] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:06.246403Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"34c419cef9a20030125bc88ff12635ec\"]","target":"flakelet_relay::agent::jobs"}910agent # [2328557.994111] agent systemd[1]: Starting flakelet update app (via relay)...911agent # [2328558.022233] agent systemd[1]: Started flakelet update app (via relay).912agent # [2328558.026897] agent flakelet[3375]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow913agent # [2328558.027516] agent flakelet[3375]: app: activating generation 9914agent # [2328558.044180] agent systemd[1]: Stopping app slow2...915agent # [2328558.044631] agent systemd[1]: app.service: Deactivated successfully.916agent # [2328558.044888] agent systemd[1]: Stopped app slow2.917agent # [2328558.061559] agent systemd[1]: Reload requested from client PID 3382 ('systemctl') (unit flakelet-relay-job-app.service)...918agent # [2328558.061624] agent systemd[1]: Reloading...919agent # [2328558.413740] agent systemd[1]: Reloading finished in 351 ms.920agent # [2328558.497957] agent systemd[1]: Reload requested from client PID 3412 ('systemctl') (unit flakelet-relay-job-app.service)...921agent # [2328558.497995] agent systemd[1]: Reloading...922agent # [2328558.835269] agent systemd[1]: Reloading finished in 336 ms.923agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1791460866 | grep -q 'app-slow', in 1.03 seconds)924relay: must succeed: systemctl restart flakelet-relay925agent # [2328558.922669] agent systemd[1]: Reload requested from client PID 3443 ('systemctl') (unit flakelet-relay-job-app.service)...926agent # [2328558.922702] agent systemd[1]: Reloading...927agent # [2328558.984387] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:07.271811Z","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"}928relay # [2328558.983991] relay systemd[1]: Stopping flakelet-relay...929relay # [2328559.037345] relay systemd[1]: flakelet-relay.service: Deactivated successfully.930relay # [2328559.037747] relay systemd[1]: Stopped flakelet-relay.931relay # [2328559.037793] relay systemd[1]: flakelet-relay.service: Consumed 3.046s CPU time over 1min 7.824s wall clock time.932relay # [2328559.079965] relay systemd[1]: Starting flakelet-relay...933agent # [2328559.275564] agent systemd[1]: Reloading finished in 352 ms.934agent # [2328559.362828] agent systemd[1]: Reload requested from client PID 3479 ('systemctl') (unit flakelet-relay-job-app.service)...935agent # [2328559.362862] agent systemd[1]: Reloading...936agent # [2328559.701084] agent systemd[1]: Reloading finished in 337 ms.937agent # [2328559.784528] agent systemd[1]: Starting app slow...938agent # [2328559.986753] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:08.274096Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}939relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.53 seconds)940client: waiting for success: grep -q '» ok' /tmp/resume.out941relay # [2328560.500309] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:08.787724Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}942relay # [2328560.501195] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:08.788132Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}943relay # [2328560.500888] relay systemd[1]: Started flakelet-relay.944relay # [2328561.997156] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:10.284578Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}945agent # [2328561.997125] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:10.284534Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}946relay # [2328565.998599] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:14.286034Z","level":"INFO","message":"job reattached","job":"20aea30ca682d19359b90aeaf3957397","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}947agent # [2328565.859402] agent systemd[1]: Started app slow.948agent # [2328565.867702] agent flakelet[3375]: app: updated to generation 9949agent # [2328565.869871] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.950agent # [2328566.946055] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:15.233496Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}951client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)952client: must succeed: cat /tmp/resume.out953client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)954(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.68 seconds)955subtest: job history comes from the agents and survives a relay restart956client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1957relay # [2328567.610524] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:15.897940Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}958agent # [2328567.610811] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:15.898275Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"}959agent # [2328567.611470] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:15.898964Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}960agent # [2328567.645787] agent systemd[1]: Starting flakelet update other (via relay)...961agent # [2328567.682340] agent systemd[1]: Started flakelet update other (via relay).962agent # [2328567.686601] agent flakelet[3553]: other: using prebuilt artifact /nix/store/mrvv83l5ba0y6vj0n2zv9cwg8pjyd7wn-flakelet-other-v1963agent # [2328567.687151] agent flakelet[3553]: other: up to date964agent # [2328567.688495] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.965client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.63 seconds)966relay: must succeed: systemctl restart flakelet-relay967relay # [2328568.224056] relay flakelet-relay[929]: {"timestamp":"2026-10-08T12:01:16.511471Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}968relay # [2328568.240602] relay systemd[1]: Stopping flakelet-relay...969relay # [2328568.276579] relay systemd[1]: flakelet-relay.service: Deactivated successfully.970relay # [2328568.276996] relay systemd[1]: Stopped flakelet-relay.971relay # [2328568.277063] relay systemd[1]: flakelet-relay.service: Consumed 2.232s CPU time over 9.196s wall clock time.972relay # [2328568.313646] relay systemd[1]: Starting flakelet-relay...973agent # [2328568.222668] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:16.510121Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}974agent # [2328568.240642] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:16.528134Z","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"}975agent # [2328569.242969] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:17.530376Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}976relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.47 seconds)977relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'978relay # [2328569.699777] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:17.987219Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}979relay # [2328569.700295] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:17.987663Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}980relay # [2328569.700301] relay systemd[1]: Started flakelet-relay.981relay # [2328571.250370] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:19.537801Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}982agent # [2328571.250292] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:19.537726Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}983relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)984client: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs985client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin.pem --key /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)986client: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)987client: (finished: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/xn5876ymgfzb09rfhh9ixig9djhgdsb7-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)988client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTE4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVWFFCSFVTSzdKUVJPPT09IiwibmJmIjoxNzkxNDYwODgwLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.kISjj8RA94bwxPHr8UC87xlH-PItJagLfHJ7pHU5h08pQ25H7kDZbUXPw61UTxyAFg-o5vUPaDzsSKpd3WLZBg' push --relay https://relay:7443 deploy --id hist2 agent/app989» job 6a239dbf87cfec796e49404c351d787f via relay 0.1.0 (agents: agent 0.1.0)990» wave 0991agent/app | Starting flakelet update app (via relay)...992agent/app | Started flakelet update app (via relay).993agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow994agent/app | app: up to date995agent # [2328571.850312] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:20.137728Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"}996agent # [2328571.850766] agent flakelet-agent[2930]: {"timestamp":"2026-10-08T12:01:20.138255Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"}997agent/appagent # [2328571.890847] agent systemd[1]: Starting flakelet update app (via relay)...998agent # [2328571.921185] agent systemd[1]: Started flakelet update app (via relay).999 | agent # [2328571.924953] agent flakelet[3581]: app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1000flakelet-relay-job-app.service: Deactivated successfully.agent # [2328571.925511] agent flakelet[3581]: app: up to date10011002agent # [2328571.927552] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.1003relay # [2328571.849808] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:20.137273Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}1004» agent/app: unchanged (generation 9)1005» ok1006client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTE4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVWFFCSFVTSzdKUVJPPT09IiwibmJmIjoxNzkxNDYwODgwLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.kISjj8RA94bwxPHr8UC87xlH-PItJagLfHJ7pHU5h08pQ25H7kDZbUXPw61UTxyAFg-o5vUPaDzsSKpd3WLZBg' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.64 seconds)1007client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTE4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVWFFCSFVTSzdKUVJPPT09IiwibmJmIjoxNzkxNDYwODgwLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.kISjj8RA94bwxPHr8UC87xlH-PItJagLfHJ7pHU5h08pQ25H7kDZbUXPw61UTxyAFg-o5vUPaDzsSKpd3WLZBg' push --relay https://relay:7443 jobs1008client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MTQ2MTE4MCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkxNDYwODgwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVWFFCSFVTSzdKUVJPPT09IiwibmJmIjoxNzkxNDYwODgwLCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.kISjj8RA94bwxPHr8UC87xlH-PItJagLfHJ7pHU5h08pQ25H7kDZbUXPw61UTxyAFg-o5vUPaDzsSKpd3WLZBg' push --relay https://relay:7443 jobs, in 0.02 seconds)1009(finished: subtest: job history comes from the agents and survives a relay restart, in 4.90 seconds)1010subtest: dashboard login via authorization code flow1011client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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'1012client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-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)1013client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login1014client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds)1015client: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs1016client: (finished: must succeed: curl -sS --cacert /nix/store/ig7mkdabjd1ddkrfbc329795jl63n9zx-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)1017!!! Test "dashboard login via authorization code flow" failed with error: ""1018cleanup1019kill NspawnMachine (pid 52)1020kill NspawnMachine (pid 54)1021Container agent terminated by signal KILL.1022kill NspawnMachine (pid 53)1023relay # [2328572.465744] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:20.753186Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"}1024relay # [2328572.542971] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [08/Oct/2026 12:01:20] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=xY4gmZH698AMcQPSeUFdx6yCVUmDtaulK6cfdXA3j88&code_challenge=fJu8Yr4T9AB7msw3KsEtcQu921FyDVxPaAKFUl7uhYc&code_challenge_method=S256 HTTP/1.1" 302 -1025relay # [2328572.592988] relay ya2z5a0869r8miiipbsyg78ar3sqjnnp-device-mock[186]: 127.0.0.1 - - [08/Oct/2026 12:01:20] "POST /token HTTP/1.1" 200 -1026relay # [2328572.593677] relay flakelet-relay[1319]: {"timestamp":"2026-10-08T12:01:20.881162Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}1027Container client terminated by signal KILL.1028Container relay terminated by signal KILL.1029(finished: cleanup, in 0.39 seconds)1030additionally exposed symbols:1031 agent, client, relay,1032 vlan1,1033 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh1034» job 04cb31a43ff35a8e43a6ee19d4bc5b2e via relay 0.1.0 (agents: agent 0.1.0)1035» wave 01036agent/app | Starting flakelet update app (via relay)...1037agent/app | Started flakelet update app (via relay).1038agent/app | app: using prebuilt artifact /nix/store/svdd0ak6lxpmv7c3i747sganc69lpfsm-flakelet-app-v21039agent/app | app: activating generation 21040agent/app | app: updated to generation 21041agent/app | flakelet-relay-job-app.service: Deactivated successfully.1042» agent/app: updated (generation 2)1043» ok10441045» job 5edb477152b27b7226589eca431c6c19 via relay 0.1.0 (agents: agent 0.1.0)1046» wave 01047agent/app | Starting flakelet update app (via relay)...1048agent/app | Started flakelet update app (via relay).1049agent/app | app: using prebuilt artifact /nix/store/9dhh6vyjl69s1r5rpkgranrw6wmfb7rg-flakelet-app-broken1050agent/app | app: activating generation 41051agent/app | app: deploy failed, rolled back: systemctl start app.service failed:1052agent/app | failed units: app.service. See journalctl -u app.service1053agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE1054agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.1055» agent/app: rolled-back (generation 3)1056agent/app │ Starting app v1...1057agent/app │ Started app v1.1058agent/app │ Stopping app v1...1059agent/app │ app.service: Deactivated successfully.1060agent/app │ Stopped app v1.1061agent/app │ Starting app v2...1062agent/app │ Started app v2.1063agent/app │ Stopping app v2...1064agent/app │ app.service: Deactivated successfully.1065agent/app │ Stopped app v2.1066agent/app │ Starting app v1...1067agent/app │ Started app v1.1068agent/app │ Stopping app v1...1069agent/app │ app.service: Deactivated successfully.1070agent/app │ Stopped app v1.1071agent/app │ Starting app broken...1072agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory1073agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory1074agent/app │ app.service: Main process exited, code=exited, status=203/EXEC1075agent/app │ app.service: Failed with result 'exit-code'.1076agent/app │ Failed to start app broken.1077agent/app │ Starting app v1...1078agent/app │ Started app v1.1079» skipped: agent/other1080» failed10811082» job d149e9c00eed19555e206e6750dbd5b8 via relay 0.1.0 (agents: agent 0.1.0)1083» wave 01084agent/app | Starting flakelet update app (via relay)...1085agent/app | Started flakelet update app (via relay).1086agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1087agent/app | app: activating generation 71088agent/app | app: updated to generation 71089agent/app | flakelet-relay-job-app.service: Deactivated successfully.1090» agent/app: updated (generation 7)1091» ok10921093» job 837e7595e4205c5521345f57477d8f7d via relay 0.1.0 (agents: agent 0.1.0)1094» wave 01095agent/app | Starting flakelet update app (via relay)...1096agent/app | Started flakelet update app (via relay).1097agent/app | app: using prebuilt artifact /nix/store/16anj40wy6gl63z9fcn523i6vgwifqfv-flakelet-app-slow21098agent/app | app: activating generation 81099agent/app | app: updated to generation 81100agent/app | flakelet-relay-job-app.service: Deactivated successfully.1101» agent/app: updated (generation 8)1102» ok11031104» job 20aea30ca682d19359b90aeaf3957397 via relay 0.1.0 (agents: agent 0.1.0)1105» wave 01106agent/app | Starting flakelet update app (via relay)...1107agent/app | Started flakelet update app (via relay).1108agent/app | app: using prebuilt artifact /nix/store/r7zi1qmqbswlb5lyb7p60nqcxmcgs5vl-flakelet-app-slow1109agent/app | app: activating generation 91110flakelet-push: stream: error reading a body from connection, resuming job f4ced87bae47ee7f219169d69bca95081111flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s1112flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s1113flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s1114» job 20aea30ca682d19359b90aeaf3957397 via relay 0.1.0 (agents: agent 0.1.0)1115» wave 01116agent/app | app: updated to generation 91117agent/app | flakelet-relay-job-app.service: Deactivated successfully.1118» agent/app: updated (generation 9)1119» ok112011211791460875 hist1 admin@example.org agent/other:unchanged11221791460866 f4ced87bae47ee7f219169d69bca9508 admin@example.org agent/app:updated11231791460857 a77399393ae7b76082b408619ae04e0a admin@example.org agent/app:updated11241791460840 92616b0a05118a9ed0ac8f89588f9e72 admin@example.org agent/app:updated11251791460838 local-app-6-1791460838 root (shell) agent/app:updated11261791460834 local-app-5-1791460834 root (shell) agent/app:updated11271791460831 e806915dc3831c0cb6029414e8998db0 admin@example.org agent/other:unchanged11281791460819 25d2841472926cab2bcd638146fd4ea3 admin@example.org agent/app:unchanged11291791460819 c3a8ccc72dc392b8864994a2758c3f2e admin@example.org agent/app:updated11301791460818 a48d80b64140f40e54dfe9609ee0cd62 admin@example.org agent/app:unchanged11311791460817 3b96bfb7e74dcfc590b55fe62025a913 admin@example.org agent/app:unchanged11321791460813 4f2e77d60c3388e333ae8c23d6817928 admin@example.org agent/app:rolled-back11331791460812 607044300d363f6dfc6fe6c3f09f4947 dev@example.org agent/other:unchanged11341791460812 c49266ae4efcc8a079f6532873e32b11 dev@example.org agent/other:unchanged11351791460809 20e5a3e93ea0a7e456eacb54f5575920 someone agent/other:unchanged11361791460806 5ba18697da9847838d1f267454975a19 repo:github:example/app:ref:refs/heads/main agent/app:updated11371791460803 a971f99edb41376106ac0b1a932d9803 admin@example.org agent/app:updated11381791460801 local-app-1-1791460801 host activation agent/app:updated11391791460801 local-flakelet-agent-1-1791460801 host activation agent/flakelet-agent:updated11401791460801 local-other-1-1791460801 host activation agent/other:updated11411142Traceback (most recent call last):1143 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/bin/.nixos-test-driver-wrapped", line 9, in <module>1144 sys.exit(main())1145 ~~~~^^1146 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/__init__.py", line 194, in main1147 driver.run_tests()1148 ~~~~~~~~~~~~~~~~^^1149 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 437, in run_tests1150 self.test_script()1151 ~~~~~~~~~~~~~~~~^^1152 File "/nix/store/f499z2x8krpksz8cyfbq40djpw3i52nv-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 395, in test_script1153 exec(self.tests, symbols, None)1154 ~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^1155 File "<string>", line 208, in <module>1156AssertionError