tribuchet: building on jamie
Machine state will be reset. To keep it, pass --keep-machine-state
start all VLans
(finished: start all VLans, in 0.00 seconds)
Initializing machine ID from random generator.
Test will time out and terminate in 3600.0 seconds
run the VM test script
start all VMs
agent: systemd-nspawn running (pid 51)
client: systemd-nspawn running (pid 53)
agent: Waiting for journal at /build/vm-state-agent/var/log/journal...
relay: systemd-nspawn running (pid 55)
client: Waiting for journal at /build/vm-state-client/var/log/journal...
relay: Waiting for journal at /build/vm-state-relay/var/log/journal...
(finished: start all VMs, in 0.00 seconds)
relay: waiting for unit flakelet-relay.service
nixos-nspawn(client): TAP vde-tap1 not found; container will be isolated from VDE
nixos-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.
nixos-nspawn(relay): TAP vde-tap1 not found; container will be isolated from VDE
nixos-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.
nixos-nspawn(agent): TAP vde-tap1 not found; container will be isolated from VDE
nixos-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.
Note: 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.
Note: 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.
░ Spawning container client on /build/vm-state-client.
░ Spawning container relay on /build/vm-state-relay.
Note: 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.
░ Spawning container agent on /build/vm-state-agent.
agent # No journal files were found.
agent # No journal boot entry found for the specified boot (+0).
client # No journal files were found.
client # No journal boot entry found for the specified boot (+0).
relay # No journal files were found.
relay # No journal boot entry found for the specified boot (+0).
agent # [ 4267.426784] agent systemd-journald[57]: Journal started
agent # [ 4267.426824] agent systemd-journald[57]: Runtime Journal (/run/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db) is 8M, max 4G, 3.9G free.
agent # [ 4267.437808] agent systemd[1]: Finished Apply Kernel Variables.
agent # [ 4267.449695] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
agent # [ 4267.463774] agent systemd[1]: Starting Flush Journal to Persistent Storage...
agent # [ 4267.464491] agent systemd[1]: Starting Create Static Device Nodes in /dev...
agent # [ 4267.494688] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db is 1.631ms for 6 entries.
agent # [ 4267.494688] agent systemd-journald[57]: System Journal (/var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db) is 512B, max 4G, 3.9G free.
agent # [ 4267.504351] agent systemd[1]: Finished Create Static Device Nodes in /dev.
agent # [ 4267.505031] agent systemd[1]: Reached target Preparation for Local File Systems.
agent # [ 4267.505152] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
agent # [ 4267.517663] agent systemd[1]: Finished Flush Journal to Persistent Storage.
agent # [ 4267.579965] agent systemd[1]: Finished Firewall.
client # [ 4267.427257] client systemd-journald[57]: Journal started
client # [ 4267.427297] client systemd-journald[57]: Runtime Journal (/run/log/journal/feb4e24c6a0e4855b5669cee0f098a4e) is 8M, max 4G, 3.9G free.
client # [ 4267.438687] client systemd[1]: Finished Apply Kernel Variables.
client # [ 4267.450966] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
client # [ 4267.465224] client systemd[1]: Starting Flush Journal to Persistent Storage...
client # [ 4267.465775] client systemd[1]: Starting Create Static Device Nodes in /dev...
client # [ 4267.495249] client systemd-journald[57]: Time spent on flushing to /var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e is 1.398ms for 6 entries.
client # [ 4267.495249] client systemd-journald[57]: System Journal (/var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e) is 512B, max 4G, 3.9G free.
client # [ 4267.504152] client systemd[1]: Finished Create Static Device Nodes in /dev.
client # [ 4267.504857] client systemd[1]: Reached target Preparation for Local File Systems.
client # [ 4267.504979] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
client # [ 4267.519974] client systemd[1]: Finished Flush Journal to Persistent Storage.
client # [ 4267.584362] client systemd[1]: Finished Firewall.
relay # [ 4267.434405] relay systemd-journald[57]: Journal started
relay # [ 4267.434447] relay systemd-journald[57]: Runtime Journal (/run/log/journal/b251195dba4843849f56bd16da8cc57a) is 8M, max 4G, 3.9G free.
relay # [ 4267.443527] relay systemd[1]: Finished Apply Kernel Variables.
relay # [ 4267.454811] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
relay # [ 4267.489551] relay systemd[1]: Starting Flush Journal to Persistent Storage...
relay # [ 4267.490184] relay systemd[1]: Starting Create Static Device Nodes in /dev...
relay # [ 4267.498449] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/b251195dba4843849f56bd16da8cc57a is 1.650ms for 6 entries.
relay # [ 4267.498449] relay systemd-journald[57]: System Journal (/var/log/journal/b251195dba4843849f56bd16da8cc57a) is 512B, max 4G, 3.9G free.
relay # [ 4267.507176] relay systemd[1]: Finished Create Static Device Nodes in /dev.
relay # [ 4267.507847] relay systemd[1]: Reached target Preparation for Local File Systems.
relay # [ 4267.507941] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
relay # [ 4267.522923] relay systemd[1]: Finished Flush Journal to Persistent Storage.
relay # [ 4267.602278] relay systemd[1]: Finished Firewall.
relay # [ 4268.434409] relay systemd[1]: Mounting /run/wrappers...
agent # [ 4268.437228] agent systemd[1]: Mounting /run/wrappers...
agent # [ 4268.500815] agent systemd[1]: Mounted /run/wrappers.
agent # [ 4268.501952] agent systemd[1]: Reached target Local File Systems.
agent # [ 4268.503287] agent systemd[1]: Listening on Boot Loader Control Service Socket.
agent # [ 4268.504710] agent systemd[1]: Starting Create SUID/SGID Wrappers...
agent # [ 4268.504754] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
agent # [ 4268.505697] agent systemd[1]: Starting Save Transient machine-id to Disk...
agent # [ 4268.506836] agent systemd[1]: Starting Create System Files and Directories...
agent # [ 4268.525239] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
agent # [ 4268.525645] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted
agent # [ 4268.525970] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/a8b5d2f187fb4bd1ab3bc06370b553db failed: Operation not permitted
agent # [ 4268.526330] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted
client # [ 4268.437699] client systemd[1]: Mounting /run/wrappers...
client # [ 4268.500827] client systemd[1]: Mounted /run/wrappers.
client # [ 4268.501883] client systemd[1]: Reached target Local File Systems.
client # [ 4268.503191] client systemd[1]: Listening on Boot Loader Control Service Socket.
client # [ 4268.504565] client systemd[1]: Starting Create SUID/SGID Wrappers...
client # [ 4268.504635] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
client # [ 4268.506087] client systemd[1]: Starting Save Transient machine-id to Disk...
client # [ 4268.507286] client systemd[1]: Starting Create System Files and Directories...
client # [ 4268.526375] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
client # [ 4268.526769] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted
client # [ 4268.527074] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/feb4e24c6a0e4855b5669cee0f098a4e failed: Operation not permitted
client # [ 4268.527182] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.gpk2Bu8h3K/chsh': Operation not permitted
client # [ 4268.527404] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted
relay # [ 4268.499730] relay systemd[1]: Mounted /run/wrappers.
relay # [ 4268.500791] relay systemd[1]: Reached target Local File Systems.
relay # [ 4268.502171] relay systemd[1]: Listening on Boot Loader Control Service Socket.
relay # [ 4268.503763] relay systemd[1]: Starting Create SUID/SGID Wrappers...
relay # [ 4268.503802] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
relay # [ 4268.504908] relay systemd[1]: Starting Save Transient machine-id to Disk...
relay # [ 4268.506101] relay systemd[1]: Starting Create System Files and Directories...
relay # [ 4268.527793] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
relay # [ 4268.528204] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted
relay # [ 4268.528511] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/b251195dba4843849f56bd16da8cc57a failed: Operation not permitted
relay # [ 4268.528839] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted
relay # [ 4268.529962] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.ZfGkMZzrPJ/chsh': Operation not permitted
relay # [ 4268.584171] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
relay # [ 4268.595663] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
relay # [ 4268.595755] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
relay # [ 4268.595937] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.
relay # [ 4268.596184] relay systemd[1]: Finished Save Transient machine-id to Disk.
relay # [ 4268.596726] relay systemd[1]: Finished Create System Files and Directories.
relay # [ 4268.611588] relay systemd[1]: Starting Rebuild Journal Catalog...
relay # [ 4268.612493] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...
relay # [ 4268.645649] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.
relay # [ 4268.651984] relay systemd[1]: Finished Rebuild Journal Catalog.
relay # [ 4268.652956] relay systemd[1]: Starting Update is Completed...
relay # [ 4268.660984] relay systemd[1]: Finished Update is Completed.
relay # [ 4268.661074] relay systemd[1]: Reached target System Initialization.
relay # [ 4268.661147] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
relay # [ 4268.661167] relay systemd[1]: Started Daily Cleanup of Temporary Directories.
relay # [ 4268.661179] relay systemd[1]: Reached target Timer Units.
relay # [ 4268.661276] relay systemd[1]: Listening on D-Bus System Message Bus Socket.
relay # [ 4268.661441] relay systemd[1]: Listening on Nix Daemon Socket.
relay # [ 4268.661540] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
relay # [ 4268.661556] relay systemd[1]: Reached target Socket Units.
relay # [ 4268.661581] relay systemd[1]: Reached target Basic System.
relay # [ 4268.663464] relay systemd[1]: Started device-mock.service.
relay # [ 4268.664199] relay systemd[1]: Starting Re-link flakelet services at boot...
relay # [ 4268.665082] relay systemd[1]: Starting Import lastlog data into lastlog2 database...
relay # [ 4268.666060] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 4268.666678] relay systemd[1]: Starting resolvconf update...
relay # [ 4268.680063] relay systemd[1]: Finished Re-link flakelet services at boot.
relay # [ 4268.681037] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...
client # [ 4268.591159] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
agent # [ 4268.530051] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.QoDBIPEiI7/chsh': Operation not permitted
client # [ 4268.604736] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
agent # [ 4268.612009] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
client # [ 4268.604771] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
client # [ 4268.604824] client systemd[1]: Failed to start Create SUID/SGID Wrappers.
agent # [ 4268.612650] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
agent # [ 4268.612686] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
client # [ 4268.604969] client systemd[1]: Finished Save Transient machine-id to Disk.
client # [ 4268.605453] client systemd[1]: Finished Create System Files and Directories.
client # [ 4268.636528] client systemd[1]: Starting Rebuild Journal Catalog...
client # [ 4268.637492] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...
client # [ 4268.650920] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.
client # [ 4268.656109] client systemd[1]: Finished Rebuild Journal Catalog.
client # [ 4268.657468] client systemd[1]: Starting Update is Completed...
client # [ 4268.665448] client systemd[1]: Finished Update is Completed.
client # [ 4268.666264] client systemd[1]: Reached target System Initialization.
client # [ 4268.666427] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
client # [ 4268.666493] client systemd[1]: Started Daily Cleanup of Temporary Directories.
client # [ 4268.666520] client systemd[1]: Reached target Timer Units.
client # [ 4268.666712] client systemd[1]: Listening on D-Bus System Message Bus Socket.
agent # [ 4268.612740] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.
client # [ 4268.666995] client systemd[1]: Listening on Nix Daemon Socket.
agent # [ 4268.612885] agent systemd[1]: Finished Save Transient machine-id to Disk.
client # [ 4268.667184] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
agent # [ 4268.613381] agent systemd[1]: Finished Create System Files and Directories.
client # [ 4268.667210] client systemd[1]: Reached target Socket Units.
agent # [ 4268.636652] agent systemd[1]: Starting Rebuild Journal Catalog...
client # [ 4268.667256] client systemd[1]: Reached target Basic System.
agent # [ 4268.637533] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...
client # [ 4268.668985] client systemd[1]: Starting Import lastlog data into lastlog2 database...
agent # [ 4268.650171] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.
client # [ 4268.670172] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 4268.657723] agent systemd[1]: Finished Rebuild Journal Catalog.
client # [ 4268.671276] client systemd[1]: Starting resolvconf update...
agent # [ 4268.658618] agent systemd[1]: Starting Update is Completed...
client # [ 4268.688178] client systemd[1]: Finished Import lastlog data into lastlog2 database.
agent # [ 4268.667254] agent systemd[1]: Finished Update is Completed.
agent # [ 4268.667326] agent systemd[1]: Reached target System Initialization.
agent # [ 4268.667390] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
agent # [ 4268.667412] agent systemd[1]: Started Daily Cleanup of Temporary Directories.
agent # [ 4268.667424] agent systemd[1]: Reached target Timer Units.
agent # [ 4268.667513] agent systemd[1]: Listening on D-Bus System Message Bus Socket.
agent # [ 4268.667699] agent systemd[1]: Listening on Nix Daemon Socket.
agent # [ 4268.667791] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
agent # [ 4268.667803] agent systemd[1]: Reached target Socket Units.
agent # [ 4268.667830] agent systemd[1]: Reached target Basic System.
agent # [ 4268.668894] agent systemd[1]: Starting Re-link flakelet services at boot...
agent # [ 4268.669606] agent systemd[1]: Starting Import lastlog data into lastlog2 database...
agent # [ 4268.670315] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 4268.671010] agent systemd[1]: Starting resolvconf update...
agent # [ 4268.683141] agent systemd[1]: Finished Re-link flakelet services at boot.
agent # [ 4268.684645] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...
agent # [ 4268.688149] agent systemd[1]: Finished Import lastlog data into lastlog2 database.
agent # [ 4268.697046] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.
agent # [ 4268.740898] agent systemd[1]: Finished resolvconf update.
agent # [ 4268.741526] agent systemd[1]: Reached target Preparation for Network.
agent # [ 4268.742497] agent systemd[1]: Starting Address configuration of eth1...
agent # [ 4268.743099] agent systemd[1]: Starting Extra networking commands....
agent # [ 4268.781330] agent systemd[1]: nscd.service: Deactivated successfully.
agent # [ 4268.781394] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).
agent # [ 4268.784311] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 4268.798915] agent network-addresses-eth1-start[237]: adding address 192.168.1.1/24... done
agent # [ 4268.802405] agent network-addresses-eth1-start[237]: adding address 2001:db8:1::1/64... done
agent # [ 4268.806994] agent systemd[1]: Finished Address configuration of eth1.
agent # [ 4268.850070] agent systemd[1]: Finished Extra networking commands..
agent # [ 4268.850196] agent systemd[1]: Reached target Network.
agent # [ 4268.851248] agent systemd[1]: Starting flakelet-agent...
agent # [ 4268.883801] agent systemd[1]: Starting Update flakelet service app...
agent # [ 4268.885661] agent systemd[1]: Starting Update flakelet service other...
agent # [ 4268.886283] agent systemd[1]: nscd.service: Deactivated successfully.
agent # [ 4268.886501] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).
agent # [ 4268.892100] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 4268.895500] agent flakelet[305]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 4268.896057] agent flakelet[305]: app: activating generation 1
agent # [ 4268.896919] agent flakelet[307]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4268.897437] agent flakelet[307]: other: activating generation 1
agent # [ 4268.899359] agent systemd[1]: Reload requested from client PID 391 ('systemctl') (unit flakelet-app.service)...
agent # [ 4268.899399] agent systemd[1]: Reloading...
agent # [ 4268.922173] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:46.883741Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}
relay # [ 4268.686952] relay systemd[1]: Finished Import lastlog data into lastlog2 database.
relay # [ 4268.692230] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.
relay # [ 4268.740225] relay systemd[1]: Finished resolvconf update.
relay # [ 4268.740353] relay systemd[1]: Reached target Preparation for Network.
relay # [ 4268.741371] relay systemd[1]: Starting Address configuration of eth1...
relay # [ 4268.742306] relay systemd[1]: Starting Extra networking commands....
relay # [ 4268.768561] relay systemd[1]: nscd.service: Deactivated successfully.
relay # [ 4268.781344] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).
relay # [ 4268.784245] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 4268.797859] relay network-addresses-eth1-start[246]: adding address 192.168.1.3/24... done
relay # [ 4268.802103] relay network-addresses-eth1-start[246]: adding address 2001:db8:1::3/64... done
relay # [ 4268.806376] relay systemd[1]: Finished Address configuration of eth1.
relay # [ 4268.846216] relay systemd[1]: Finished Extra networking commands..
relay # [ 4268.846313] relay systemd[1]: Reached target Network.
relay # [ 4268.847709] relay systemd[1]: Starting Dnsmasq Daemon...
relay # [ 4268.848642] relay systemd[1]: Starting Nginx Web Server...
relay # [ 4268.849453] relay systemd[1]: Starting Update flakelet service flakelet-relay...
relay # [ 4268.891988] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/zhnlcnggdn7ymdlwkz9j9s4dkxd6v5g7-flakelet-flakelet-relay
relay # [ 4268.892629] relay flakelet[311]: flakelet-relay: activating generation 1
relay # [ 4268.896804] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...
relay # [ 4268.896847] relay systemd[1]: Reloading...
client # [ 4268.743989] client systemd[1]: Finished resolvconf update.
client # [ 4268.744125] client systemd[1]: Reached target Preparation for Network.
client # [ 4268.781627] client systemd[1]: Starting Address configuration of eth1...
client # [ 4268.782532] client systemd[1]: Starting Extra networking commands....
client # [ 4268.782665] client systemd[1]: nscd.service: Deactivated successfully.
client # [ 4268.782717] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).
client # [ 4268.786601] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
client # [ 4268.803924] client network-addresses-eth1-start[233]: adding address 192.168.1.2/24... done
client # [ 4268.807443] client network-addresses-eth1-start[233]: adding address 2001:db8:1::2/64... done
client # [ 4268.812401] client systemd[1]: Finished Address configuration of eth1.
client # [ 4268.883550] client systemd[1]: Finished Extra networking commands..
client # [ 4268.883960] client systemd[1]: nscd.service: Deactivated successfully.
client # [ 4268.884199] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).
client # [ 4268.887767] client systemd[1]: Reached target Network.
client # [ 4268.889604] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 4269.219986] relay nsncd[251]: Sep 06 08:15:47.181 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
relay # [ 4269.314795] relay systemd[1]: Reloading finished in 417 ms.
relay # [ 4269.441523] relay systemd[1]: Started Name Service Cache Daemon (nsncd).
relay # [ 4269.442545] relay systemd[1]: Reached target Host and Network Name Lookups.
relay # [ 4269.442631] relay systemd[1]: Reached target User and Group Name Lookups.
relay # [ 4269.444015] relay systemd[1]: Starting User Login Management...
relay # [ 4269.444896] relay systemd[1]: Starting Permit User Sessions...
relay # [ 4269.459626] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...
relay # [ 4269.459660] relay systemd[1]: Reloading...
agent # [ 4269.230762] agent nsncd[311]: Sep 06 08:15:47.192 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
agent # [ 4269.307136] agent systemd[1]: Reloading finished in 407 ms.
agent # [ 4269.440787] agent systemd[1]: Started flakelet-agent.
agent # [ 4269.440901] agent systemd[1]: Started Name Service Cache Daemon (nsncd).
agent # [ 4269.443033] agent systemd[1]: Reached target Host and Network Name Lookups.
agent # [ 4269.443146] agent systemd[1]: Reached target User and Group Name Lookups.
agent # [ 4269.444498] agent systemd[1]: Starting User Login Management...
agent # [ 4269.445304] agent systemd[1]: Starting Permit User Sessions...
agent # [ 4269.445587] agent systemd[1]: Reload requested from client PID 421 ('systemctl') (unit flakelet-other.service)...
agent # [ 4269.445616] agent systemd[1]: Reloading...
client # [ 4269.212236] client systemd[1]: Started Name Service Cache Daemon (nsncd).
client # [ 4269.212530] client nsncd[303]: Sep 06 08:15:47.174 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
client # [ 4269.212332] client systemd[1]: Reached target Host and Network Name Lookups.
client # [ 4269.212429] client systemd[1]: Reached target User and Group Name Lookups.
client # [ 4269.214920] client systemd[1]: Starting User Login Management...
client # [ 4269.219009] client systemd[1]: Starting Permit User Sessions...
client # [ 4269.250106] client systemd[1]: Finished Permit User Sessions.
client # [ 4269.251944] client systemd[1]: Started Console Getty.
client # [ 4269.251997] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
client # [ 4269.252044] client systemd[1]: Reached target Login Prompts.
relay # [ 4269.503541] relay dnsmasq-pre-start[375]: dnsmasq: syntax check OK.
agent # [ 4269.863561] agent systemd[1]: Reloading finished in 417 ms.
agent # [ 4269.998197] agent systemd[1]: Finished Permit User Sessions.
agent # [ 4270.004535] agent systemd[1]: Started Console Getty.
agent # [ 4270.004561] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
agent # [ 4270.004572] agent systemd[1]: Reached target Login Prompts.
agent # [ 4270.010471] agent systemd[1]: Reload requested from client PID 778 ('systemctl') (unit flakelet-app.service)...
agent # [ 4270.010502] agent systemd[1]: Reloading...
relay # [ 4269.856397] relay systemd[1]: Reloading finished in 396 ms.
relay # [ 4270.001542] relay systemd[1]: Finished Permit User Sessions.
relay # [ 4270.043653] relay systemd[1]: Started Console Getty.
relay # [ 4270.043709] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
relay # [ 4270.043732] relay systemd[1]: Reached target Login Prompts.
relay # [ 4270.048537] relay systemd[1]: Starting flakelet-relay...
agent # [ 4270.390469] agent systemd[1]: Reloading finished in 379 ms.
agent # [ 4270.468940] agent systemd[1]: Reload requested from client PID 779 ('systemctl') (unit flakelet-other.service)...
agent # [ 4270.468980] agent systemd[1]: Reloading...
relay # [ 4270.504057] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok
relay # [ 4270.504748] relay nginx-pre-start[402]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful
relay # [ 4270.521587] relay systemd[1]: Started Nginx Web Server.
relay # [ 4270.665290] relay systemd[1]: Starting D-Bus System Message Bus...
client # [ 4270.614986] client systemd-logind[315]: New seat seat0.
client # [ 4270.615459] client systemd[1]: Started User Login Management.
client # [ 4270.617646] client systemd[1]: Starting D-Bus System Message Bus...
client # [ 4270.618920] client systemd[1]: Starting linger-users.service...
client # [ 4270.650888] client systemd[1]: linger-users.service: Deactivated successfully.
client # [ 4270.651230] client systemd[1]: Finished linger-users.service.
client # [ 4270.651564] client systemd[1]: Reached target Multi-User System.
agent # [ 4270.842883] agent systemd[1]: Reloading finished in 373 ms.
agent # [ 4270.924266] agent systemd[1]: Starting other v1...
agent # [ 4270.926902] agent systemd[1]: Starting app v1...
agent # [ 4270.953858] agent systemd[1]: Started other v1.
agent # [ 4270.954443] agent systemd[1]: Started app v1.
agent # [ 4270.972094] agent flakelet[307]: other: updated to generation 1
agent # [ 4270.973040] agent systemd[1]: Finished Update flakelet service other.
agent # [ 4270.974112] agent systemd-logind[740]: New seat seat0.
agent # [ 4270.974906] agent systemd[1]: Started User Login Management.
agent # [ 4270.975875] agent flakelet[305]: app: updated to generation 1
agent # [ 4270.976360] agent systemd[1]: Finished Update flakelet service app.
agent # [ 4270.976981] agent systemd[1]: Reached target flakelet managed services.
agent # [ 4270.978155] agent systemd[1]: Starting D-Bus System Message Bus...
agent # [ 4270.979243] agent systemd[1]: Starting linger-users.service...
agent # [ 4270.991741] agent systemd[1]: linger-users.service: Deactivated successfully.
agent # [ 4270.991943] agent systemd[1]: Finished linger-users.service.
agent # [ 4270.992088] agent systemd[1]: Reached target Multi-User System.
relay # [ 4271.063373] relay systemd-logind[354]: New seat seat0.
relay # [ 4271.063783] relay systemd[1]: Started User Login Management.
relay # [ 4271.066123] relay systemd[1]: Starting linger-users.service...
relay # [ 4271.105786] relay systemd[1]: linger-users.service: Deactivated successfully.
relay # [ 4271.106165] relay systemd[1]: Finished linger-users.service.
relay # [ 4271.184980] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'...
relay # [ 4271.186417] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync'
relay # [ 4271.186417] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
relay # [ 4271.187615] relay systemd[1]: Started D-Bus System Message Bus.
relay # [ 4271.194700] relay dbus-broker-launch[408]: Ready
relay # [ 4271.198113] relay systemd[1]: Started Dnsmasq Daemon.
relay # [ 4271.199597] relay dnsmasq[394]: started, version 2.93 cachesize 150
relay # [ 4271.199614] 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 dumpfile
relay # [ 4271.199628] relay dnsmasq[394]: DBus support enabled: connected to system bus
relay # [ 4271.199645] relay dnsmasq[394]: no upstream servers configured - please set them from DBus
relay # [ 4271.199791] relay dnsmasq[394]: read /etc/hosts - 9 names
client # [ 4271.156345] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...
client # [ 4271.157806] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'
client # [ 4271.157806] client dbus-broker-launch[325]: Invalid user-name in /nix/store/kl0xf3n3ac6xk287l1j4isggl96cyhax-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
client # [ 4271.158757] client systemd[1]: Started D-Bus System Message Bus.
client # [ 4271.159230] client systemd[1]: Startup finished in 4.201s.
client # [ 4271.164362] client dbus-broker-launch[325]: Ready
agent # [ 4271.399072] agent dbus-broker-launch[846]: Looking up NSS user entry for 'systemd-timesync'...
agent # [ 4271.400682] agent dbus-broker-launch[846]: NSS returned no entry for 'systemd-timesync'
agent # [ 4271.400682] agent dbus-broker-launch[846]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
agent # [ 4271.401672] agent systemd[1]: Started D-Bus System Message Bus.
agent # [ 4271.402143] agent systemd[1]: Startup finished in 4.453s.
agent # [ 4271.406731] agent dbus-broker-launch[846]: Ready
relay # [ 4271.958749] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:49.920360Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 4271.959636] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:49.921027Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 4271.959429] relay systemd[1]: Started flakelet-relay.
relay # [ 4271.970174] relay systemd[1]: Starting health for flakelet-relay...
relay # [ 4272.213411] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.
relay # [ 4272.213758] relay systemd[1]: Finished health for flakelet-relay.
relay # [ 4272.255128] relay flakelet[311]: flakelet-relay: updated to generation 1
relay # [ 4272.257487] relay systemd[1]: Finished Update flakelet service flakelet-relay.
relay # [ 4272.258060] relay systemd[1]: Reached target flakelet managed services.
relay # [ 4272.258234] relay systemd[1]: Reached target Multi-User System.
relay # [ 4272.258491] relay systemd[1]: Startup finished in 5.311s.
relay: (finished: waiting for unit flakelet-relay.service, in 6.16 seconds)
relay: waiting for unit nginx.service
relay: (finished: waiting for unit nginx.service, in 0.02 seconds)
agent: waiting for unit flakelet.target
agent: (finished: waiting for unit flakelet.target, in 0.02 seconds)
agent: waiting for unit flakelet-agent.service
agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds)
client: waiting for unit multi-user.target
client: (finished: waiting for unit multi-user.target, in 0.02 seconds)
relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'
agent # [ 4273.943557] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:51.905292Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
relay # [ 4273.943947] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:51.905666Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(1), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)
agent: must succeed: systemctl is-active app.service other.service
agent: (finished: must succeed: systemctl is-active app.service other.service, in 0.01 seconds)
subtest: deploy with client certificate, relay found via SRV
agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1
relay # [ 4274.761704] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:52.723430Z","level":"INFO","message":"deploy accepted","job":"b08899e4f5d9448ad0e62beee8dfb372","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4274.762409] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:52.724130Z","level":"INFO","message":"start","id":"6c8a2b22b9b638ee3bca1842049c9483","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4274.763355] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:52.725174Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6c8a2b22b9b638ee3bca1842049c9483\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4274.817525] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4274.847968] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4274.852758] agent flakelet[875]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2
agent # [ 4274.853409] agent flakelet[875]: app: activating generation 2
agent # [ 4274.867213] agent systemd[1]: Stopping app v1...
agent # [ 4274.867671] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4274.867936] agent systemd[1]: Stopped app v1.
agent # [ 4274.886902] agent systemd[1]: Reload requested from client PID 882 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4274.886970] agent systemd[1]: Reloading...
agent # [ 4275.229893] agent systemd[1]: Reloading finished in 342 ms.
agent # [ 4275.320871] agent systemd[1]: Reload requested from client PID 915 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4275.320906] agent systemd[1]: Reloading...
agent # [ 4275.649235] agent systemd[1]: Reloading finished in 327 ms.
agent # [ 4275.730516] agent systemd[1]: Reload requested from client PID 945 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4275.730555] agent systemd[1]: Reloading...
agent # [ 4276.059021] agent systemd[1]: Reloading finished in 328 ms.
agent # [ 4276.140833] agent systemd[1]: Reload requested from client PID 978 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4276.140874] agent systemd[1]: Reloading...
agent # [ 4276.468935] agent systemd[1]: Reloading finished in 327 ms.
agent # [ 4276.532855] agent systemd[1]: Starting app v2...
agent # [ 4276.557961] agent systemd[1]: Started app v2.
agent # [ 4276.570851] agent flakelet[875]: app: updated to generation 2
agent # [ 4276.573188] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
client: (finished: must succeed: push --relay-srv test --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.96 seconds)
agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2'
agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds)
agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2'
agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds)
(finished: subtest: deploy with client certificate, relay found via SRV, in 3.00 seconds)
subtest: deploy with OIDC token, sub principal
agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)
client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)
client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/app 2>&1
agent # [ 4277.690429] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.652167Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}
agent # [ 4277.823543] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.785284Z","level":"INFO","message":"start","id":"1c39184043568d292bfd3e5893d98b5e","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}
agent # [ 4277.823886] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:55.785659Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"1c39184043568d292bfd3e5893d98b5e\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4277.865259] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4277.910109] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4277.914334] agent flakelet[1060]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 4277.914970] agent flakelet[1060]: app: activating generation 3
agent # [ 4277.929123] agent systemd[1]: Stopping app v2...
agent # [ 4277.929608] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4277.929875] agent systemd[1]: Stopped app v2.
agent # [ 4277.948068] agent systemd[1]: Reload requested from client PID 1067 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4277.948136] agent systemd[1]: Reloading...
relay # [ 4277.691795] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:55.653552Z","level":"INFO","message":"deploy finished","job":"b08899e4f5d9448ad0e62beee8dfb372","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4277.823175] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:55.784948Z","level":"INFO","message":"deploy accepted","job":"4c9fe352143f106bd900e5e8de900986","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4278.286357] agent systemd[1]: Reloading finished in 337 ms.
agent # [ 4278.350940] agent systemd[1]: Reload requested from client PID 1097 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4278.350976] agent systemd[1]: Reloading...
agent # [ 4278.676325] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4278.748935] agent systemd[1]: Reload requested from client PID 1126 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4278.748975] agent systemd[1]: Reloading...
agent # [ 4279.074537] agent systemd[1]: Reloading finished in 325 ms.
agent # [ 4279.144770] agent systemd[1]: Reload requested from client PID 1160 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4279.144804] agent systemd[1]: Reloading...
agent # [ 4279.467780] agent systemd[1]: Reloading finished in 322 ms.
agent # [ 4279.536359] agent systemd[1]: Starting app v1...
agent # [ 4279.578163] agent systemd[1]: Started app v1.
agent # [ 4279.589462] agent flakelet[1060]: app: updated to generation 3
agent # [ 4279.591585] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.90 seconds)
(finished: subtest: deploy with OIDC token, sub principal, in 2.97 seconds)
subtest: policy denies uncovered target
client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/other 2>&1
client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1NSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTU1LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJFUFozWjJXWUk0Q1RRPT09IiwibmJmIjoxNzg4NjgyNTU1LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.eU6P3Q7FueynD5Ujut-lwWLcvfOIJ7WLsoHfdlY1DJ8ZnEpuHcEk9GYk8dvB8iwMb8QBnOQHOzX-JhlZTfYpBA' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.02 seconds)
(finished: subtest: policy denies uncovered target, in 0.02 seconds)
subtest: claim principal from groups, unchanged counts as success
client: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)
client: (finished: must succeed: echo '{"groups": ["wheel"]}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)
client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1OCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjU1OCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiT1YyNllRRUdCUVNMUT09PSIsIm5iZiI6MTc4ODY4MjU1OCwic3ViIjoic29tZW9uZSJ9.i5FVG64l7WxjnSghL_f_U8B8MrvTWdGmI707t5p3ZKjGeQFuH1qPUnfYelGEBwPoGGDO12Qa4Ch5i9sf6EViCw' push --relay https://relay:7443 deploy agent/other 2>&1
agent # [ 4280.686107] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.647836Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 4280.784962] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.746717Z","level":"INFO","message":"start","id":"57dfb8dca462d7707e252cbe917ec54c","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 4280.785309] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:58.747140Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"57dfb8dca462d7707e252cbe917ec54c\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4280.835065] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4280.869914] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4280.874258] agent flakelet[1226]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4280.874766] agent flakelet[1226]: other: up to date
agent # [ 4280.877998] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 4280.687217] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:58.648945Z","level":"INFO","message":"deploy finished","job":"4c9fe352143f106bd900e5e8de900986","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4280.784718] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:58.746482Z","level":"INFO","message":"deploy accepted","job":"c72b2526c5a009580f877a245aeaa6b7","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg1OCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjU1OCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiT1YyNllRRUdCUVNMUT09PSIsIm5iZiI6MTc4ODY4MjU1OCwic3ViIjoic29tZW9uZSJ9.i5FVG64l7WxjnSghL_f_U8B8MrvTWdGmI707t5p3ZKjGeQFuH1qPUnfYelGEBwPoGGDO12Qa4Ch5i9sf6EViCw' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.67 seconds)
(finished: subtest: claim principal from groups, unchanged counts as success, in 0.72 seconds)
subtest: push login via device flow, cached token used afterwards
client: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1
agent # [ 4281.430233] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:15:59.391960Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
relay # [ 4281.431450] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:15:59.393201Z","level":"INFO","message":"deploy finished","job":"c72b2526c5a009580f877a245aeaa6b7","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4281.457803] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:15:59] "POST /device HTTP/1.1" 200 -
relay # [ 4282.463803] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:16:00] "POST /token HTTP/1.1" 400 -
client: (finished: must succeed: push login --issuer https://relay:8443 --client-id flakelet-relay 2>&1, in 2.08 seconds)
client: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600
client: (finished: must succeed: test "$(stat -c %a /root/.local/state/flakelet-push/token.json)" = 600, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1
relay # [ 4283.513907] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:16:01] "POST /token HTTP/1.1" 200 -
relay # [ 4283.544224] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:01.506024Z","level":"INFO","message":"deploy accepted","job":"3846f68305ba7a8c5b66e0a9ffbe9e58","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 4283.544575] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:01.506319Z","level":"INFO","message":"start","id":"d0a18a8bb985692c8cb008a99a08b77c","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 4283.545302] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:01.507120Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"d0a18a8bb985692c8cb008a99a08b77c\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4283.596662] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4283.628037] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4283.632847] agent flakelet[1274]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4283.633361] agent flakelet[1274]: other: up to date
agent # [ 4283.636501] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.66 seconds)
client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1
agent # [ 4284.187441] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.149182Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 4284.209255] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.171068Z","level":"INFO","message":"start","id":"679f3221e08f81b35983e4943b6e1de4","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 4284.209470] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.171300Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"679f3221e08f81b35983e4943b6e1de4\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4284.268286] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4284.303993] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4284.308373] agent flakelet[1302]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4284.308910] agent flakelet[1302]: other: up to date
agent # [ 4284.310588] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 4284.188708] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.150456Z","level":"INFO","message":"deploy finished","job":"3846f68305ba7a8c5b66e0a9ffbe9e58","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4284.209066] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.170884Z","level":"INFO","message":"deploy accepted","job":"3fb621a90d1c4fe8d6c02115accb8284","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.67 seconds)
(finished: subtest: push login via device flow, cached token used afterwards, in 3.43 seconds)
subtest: waves: failing first wave skips the second
agent: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1
agent # [ 4284.861167] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.822904Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 4284.897668] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.859436Z","level":"INFO","message":"start","id":"60864decd9bfe1bb743beff185731eb3","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4284.897913] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:02.859690Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"60864decd9bfe1bb743beff185731eb3\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4284.957928] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4285.004193] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4285.008301] agent flakelet[1339]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken
agent # [ 4285.008956] agent flakelet[1339]: app: activating generation 4
agent # [ 4285.018688] agent systemd[1]: Stopping app v1...
agent # [ 4285.019423] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4285.019553] agent systemd[1]: Stopped app v1.
agent # [ 4285.029235] agent systemd[1]: Reload requested from client PID 1350 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4285.029270] agent systemd[1]: Reloading...
relay # [ 4284.862234] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.824006Z","level":"INFO","message":"deploy finished","job":"3fb621a90d1c4fe8d6c02115accb8284","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4284.897491] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:02.859309Z","level":"INFO","message":"deploy accepted","job":"8419c3ef1200ac1a3b2918807efb1372","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 4285.355562] agent systemd[1]: Reloading finished in 325 ms.
agent # [ 4285.428381] agent systemd[1]: Reload requested from client PID 1380 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4285.428418] agent systemd[1]: Reloading...
agent # [ 4285.753667] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4285.821643] agent systemd[1]: Reload requested from client PID 1409 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4285.821680] agent systemd[1]: Reloading...
agent # [ 4286.146370] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4286.210573] agent systemd[1]: Reload requested from client PID 1440 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4286.210607] agent systemd[1]: Reloading...
agent # [ 4286.537537] agent systemd[1]: Reloading finished in 326 ms.
agent # [ 4286.599997] agent systemd[1]: Starting app broken...
agent # [ 4286.635452] agent (nonexistent)[1470]: app.service: Unable to locate executable '/nonexistent': No such file or directory
agent # [ 4286.635475] agent (nonexistent)[1470]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory
agent # [ 4286.636856] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC
agent # [ 4286.636962] agent systemd[1]: app.service: Failed with result 'exit-code'.
agent # [ 4286.637332] agent systemd[1]: Failed to start app broken.
agent # [ 4286.669082] agent systemd[1]: Reload requested from client PID 1477 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4286.669119] agent systemd[1]: Reloading...
agent # [ 4286.995429] agent systemd[1]: Reloading finished in 325 ms.
agent # [ 4287.072509] agent systemd[1]: Reload requested from client PID 1510 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4287.072541] agent systemd[1]: Reloading...
agent # [ 4287.397221] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4287.457311] agent systemd[1]: Reload requested from client PID 1541 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4287.457342] agent systemd[1]: Reloading...
agent # [ 4287.784621] agent systemd[1]: Reloading finished in 326 ms.
agent # [ 4287.870345] agent systemd[1]: Reload requested from client PID 1573 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4287.870381] agent systemd[1]: Reloading...
agent # [ 4288.198166] agent systemd[1]: Reloading finished in 327 ms.
agent # [ 4288.262729] agent systemd[1]: Starting app v1...
agent # [ 4288.288954] agent systemd[1]: Started app v1.
agent # [ 4288.290067] agent flakelet[1339]: app: deploy failed, rolled back: systemctl start app.service failed:
agent # [ 4288.290067] agent flakelet[1339]: failed units: app.service. See journalctl -u app.service
agent # [ 4288.292140] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE
agent # [ 4288.292233] agent systemd[1]: flakelet-relay-job-app.service: Failed with result 'exit-code'.
client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.55 seconds)
agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1'
agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds)
(finished: subtest: waves: failing first wave skips the second, in 4.58 seconds)
subtest: host patterns expand on the relay
agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1
agent # [ 4289.421899] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.383644Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 4289.478271] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.440025Z","level":"INFO","message":"start","id":"f1b32e63c63b348f6bcaa4dd85b44f1b","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4289.478711] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:07.440531Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"f1b32e63c63b348f6bcaa4dd85b44f1b\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4289.529511] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4289.561021] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4289.565340] agent flakelet[1651]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 4289.565820] agent flakelet[1651]: app: up to date
agent # [ 4289.568937] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 4289.423477] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:07.385244Z","level":"INFO","message":"deploy finished","job":"8419c3ef1200ac1a3b2918807efb1372","ok":false,"target":"flakelet_relay::relay::api"}
relay # [ 4289.477893] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:07.439686Z","level":"INFO","message":"deploy accepted","job":"54e64c0c23a29bd77f9ed013b2ca24de","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1, in 0.67 seconds)
client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1
agent # [ 4290.121774] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.083507Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 4290.144718] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.106518Z","level":"INFO","message":"start","id":"59ff063568ac4f65946781e56e050ce3","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4290.145117] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.106937Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"59ff063568ac4f65946781e56e050ce3\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4290.202398] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4290.235007] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4290.239365] agent flakelet[1679]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 4290.239923] agent flakelet[1679]: app: up to date
agent # [ 4290.242509] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 4290.123259] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.085025Z","level":"INFO","message":"deploy finished","job":"54e64c0c23a29bd77f9ed013b2ca24de","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4290.144480] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.106300Z","level":"INFO","message":"deploy accepted","job":"beb907435b71cafa934c3fbf2377abc0","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}
client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.67 seconds)
client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1
agent # [ 4290.791811] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.753551Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 4290.815252] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.777055Z","level":"INFO","message":"start","id":"a2fdbb9d6d5be999afc01028db739d51","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4290.815635] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:08.777456Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"a2fdbb9d6d5be999afc01028db739d51\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4290.876208] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4290.906953] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4290.911245] agent flakelet[1707]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 4290.911734] agent flakelet[1707]: app: up to date
agent # [ 4290.914181] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 4290.793271] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.755048Z","level":"INFO","message":"deploy finished","job":"beb907435b71cafa934c3fbf2377abc0","ok":false,"target":"flakelet_relay::relay::api"}
relay # [ 4290.815041] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:08.776856Z","level":"INFO","message":"deploy accepted","job":"d4e529abb3e862d24c8b30e1f7400bc7","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}
client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.67 seconds)
client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1
client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1, in 0.02 seconds)
(finished: subtest: host patterns expand on the relay, in 2.04 seconds)
subtest: detach returns once the job is accepted
agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1
client: (finished: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --detach agent/app 2>&1, in 0.02 seconds)
agent: waiting for success: systemctl is-active flakelet-relay-job-app.service
agent # [ 4291.464705] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.426445Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 4291.521924] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.483686Z","level":"INFO","message":"start","id":"cafe9eb7933849ac787c87a8e3aa3227","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4291.522385] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:16:09.484204Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cafe9eb7933849ac787c87a8e3aa3227\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4291.571039] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4291.599916] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4291.604208] agent flakelet[1749]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2
agent # [ 4291.604864] agent flakelet[1749]: app: activating generation 4
agent # [ 4291.618338] agent systemd[1]: Stopping app v1...
agent # [ 4291.618784] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4291.619057] agent systemd[1]: Stopped app v1.
agent # [ 4291.637189] agent systemd[1]: Reload requested from client PID 1756 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4291.637257] agent systemd[1]: Reloading...
relay # [ 4291.466311] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:09.428079Z","level":"INFO","message":"deploy finished","job":"d4e529abb3e862d24c8b30e1f7400bc7","ok":false,"target":"flakelet_relay::relay::api"}
relay # [ 4291.521638] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:09.483434Z","level":"INFO","message":"deploy accepted","job":"54bf4db2326752f10b4c3da9a1be148e","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4291.970935] agent systemd[1]: Reloading finished in 332 ms.
agent # [ 4292.042489] agent systemd[1]: Reload requested from client PID 1786 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4292.042526] agent systemd[1]: Reloading...
agent # [ 4292.367840] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4292.431553] agent systemd[1]: Reload requested from client PID 1815 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4292.431591] agent systemd[1]: Reloading...
agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.29 seconds)
??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39
agent: waiting for failure: systemctl is-active flakelet-relay-job-app.service
??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39
agent # [ 4292.756463] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4292.820893] agent systemd[1]: Reload requested from client PID 1848 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4292.820928] agent systemd[1]: Reloading...
agent # [ 4293.145495] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4293.207787] agent systemd[1]: Starting app slow2...
agent # [ 4299.285035] agent systemd[1]: Started app slow2.
agent # [ 4299.302953] agent flakelet[1749]: app: updated to generation 4
agent # [ 4299.306097] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.49 seconds)
(finished: subtest: detach returns once the job is accepted, in 8.81 seconds)
subtest: unknown host is final, missing agent is retried, agents listing
client: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1
client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1, in 0.02 seconds)
agent: must succeed: systemctl stop flakelet-agent
agent: (finished: must succeed: systemctl stop flakelet-agent, in 0.04 seconds)
relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0'
relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/other > /tmp/retry.out 2>&1 &, in 0.01 seconds)
client: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out
agent # [ 4300.332911] agent systemd[1]: Stopping flakelet-agent...
agent # [ 4300.361332] agent systemd[1]: flakelet-agent.service: Deactivated successfully.
agent # [ 4300.361777] agent systemd[1]: Stopped flakelet-agent.
agent # [ 4300.362230] agent systemd[1]: flakelet-agent.service: Consumed 2.572s CPU time over 31.510s wall clock time.
relay # [ 4300.332932] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:18.294715Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}
client: (finished: waiting for success: grep -q 'agent_unavailable.*retrying' /tmp/retry.out, in 1.02 seconds)
agent: must succeed: systemctl start flakelet-agent
agent: (finished: must succeed: systemctl start flakelet-agent, in 0.15 seconds)
??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39
client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out
agent # [ 4301.423397] agent systemd[1]: Starting flakelet-agent...
agent # [ 4301.475367] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.437142Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"cafe9eb7933849ac787c87a8e3aa3227\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4301.556960] agent systemd[1]: Started flakelet-agent.
agent # [ 4301.570257] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.532048Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
relay # [ 4301.570325] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:19.532090Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 4302.036750] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:19.998470Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}
agent # [ 4303.406426] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:21.368154Z","level":"INFO","message":"start","id":"9a950a093acee1c7eca217400075cae1","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4303.407376] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:21.368812Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"9a950a093acee1c7eca217400075cae1\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4303.461664] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4303.495045] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4303.501049] agent flakelet[2375]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4303.501594] agent flakelet[2375]: other: up to date
agent # [ 4303.502320] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 4303.405965] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:21.367730Z","level":"INFO","message":"deploy accepted","job":"91cdeb537d902f2bbfda54be7f1ee2de","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 4304.055200] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:22.016933Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
relay # [ 4304.056677] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:22.018445Z","level":"INFO","message":"deploy finished","job":"91cdeb537d902f2bbfda54be7f1ee2de","ok":true,"target":"flakelet_relay::relay::api"}
client: (finished: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out, in 3.04 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds)
client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)
client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.05 seconds)
client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg4MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTgyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSNTRGUFpWUUhNTlNHPT09IiwibmJmIjoxNzg4NjgyNTgyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Iq3sKhHaBl7eLGLznpjPigr9cVJ0rexH0GsOepbDjdaEhadAE1AhgnFtlsKAIEW4uKWo867afXQc6ZpWPKlLDA' push --relay https://relay:7443 agents
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4Mjg4MiwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNTgyLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJSNTRGUFpWUUhNTlNHPT09IiwibmJmIjoxNzg4NjgyNTgyLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Iq3sKhHaBl7eLGLznpjPigr9cVJ0rexH0GsOepbDjdaEhadAE1AhgnFtlsKAIEW4uKWo867afXQc6ZpWPKlLDA' push --relay https://relay:7443 agents, in 0.02 seconds)
(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.40 seconds)
subtest: out-of-band flakelet update reaches the relay without reconnect
agent: must succeed: flakelet status --json app | jq '.[0].generation'
agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.05 seconds)
agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true
agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)
agent: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
agent: must succeed: flakelet update app
app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2
app: activating generation 5
agent # [ 4304.792147] agent systemd[1]: Stopping app slow2...
agent # [ 4304.792681] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4304.792952] agent systemd[1]: Stopped app slow2.
agent # [ 4304.810191] agent systemd[1]: Reload requested from client PID 2423 ('systemctl')...
agent # [ 4304.810259] agent systemd[1]: Reloading...
agent # [ 4305.157074] agent systemd[1]: Reloading finished in 346 ms.
agent # [ 4305.244680] agent systemd[1]: Reload requested from client PID 2452 ('systemctl')...
agent # [ 4305.244719] agent systemd[1]: Reloading...
agent # [ 4305.572999] agent systemd[1]: Reloading finished in 327 ms.
agent # [ 4305.672977] agent systemd[1]: Reload requested from client PID 2482 ('systemctl')...
agent # [ 4305.673029] agent systemd[1]: Reloading...
agent # [ 4305.997803] agent systemd[1]: Reloading finished in 324 ms.
agent # [ 4306.075944] agent systemd[1]: Reload requested from client PID 2514 ('systemctl')...
agent # [ 4306.075976] agent systemd[1]: Reloading...
agent # [ 4306.402060] agent systemd[1]: Reloading finished in 325 ms.
agent: (finished: must succeed: flakelet update app, in 1.77 seconds)
client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5'
agent # [ 4306.488699] agent systemd[1]: Starting app v2...
agent # [ 4306.518999] agent systemd[1]: Started app v2.
client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.06 seconds)
agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true
agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds)
agent: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
agent: must succeed: flakelet update app
app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
app: activating generation 6
agent # [ 4308.648174] agent systemd[1]: Stopping app v2...
agent # [ 4308.648676] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4308.648941] agent systemd[1]: Stopped app v2.
agent # [ 4308.666170] agent systemd[1]: Reload requested from client PID 2572 ('systemctl')...
agent # [ 4308.666238] agent systemd[1]: Reloading...
agent # [ 4309.011072] agent systemd[1]: Reloading finished in 344 ms.
agent # [ 4309.082523] agent systemd[1]: Reload requested from client PID 2601 ('systemctl')...
agent # [ 4309.082560] agent systemd[1]: Reloading...
agent # [ 4309.406690] agent systemd[1]: Reloading finished in 323 ms.
agent # [ 4309.474463] agent systemd[1]: Reload requested from client PID 2629 ('systemctl')...
agent # [ 4309.474501] agent systemd[1]: Reloading...
agent # [ 4309.796919] agent systemd[1]: Reloading finished in 321 ms.
agent # [ 4309.876130] agent systemd[1]: Reload requested from client PID 2661 ('systemctl')...
agent # [ 4309.876168] agent systemd[1]: Reloading...
agent # [ 4310.200994] agent systemd[1]: Reloading finished in 324 ms.
agent: (finished: must succeed: flakelet update app, in 1.70 seconds)
client: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6'
agent # [ 4310.272799] agent systemd[1]: Starting app v1...
agent # [ 4310.311188] agent systemd[1]: Started app v1.
client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.06 seconds)
(finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.69 seconds)
subtest: certificate not listed under agents cannot connect as agent
client: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent
client: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.02 seconds)
(finished: subtest: certificate not listed under agents cannot connect as agent, in 0.02 seconds)
subtest: metrics
relay: must succeed: curl -sf http://127.0.0.1:7400/metrics
relay: (finished: must succeed: curl -sf http://127.0.0.1:7400/metrics, in 0.01 seconds)
(finished: subtest: metrics, in 0.01 seconds)
subtest: agent link drop mid-run replays missed lines once
agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
agent: must succeed: date +%s
agent: (finished: must succeed: date +%s, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/slow.out 2>&1 &, in 0.01 seconds)
agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'app-slow'
agent # [ 4312.467100] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:30.428813Z","level":"INFO","message":"start","id":"b21bacf6c84543d38b3547c2e8da39c8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4312.467938] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:30.429553Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"b21bacf6c84543d38b3547c2e8da39c8\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4312.523642] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4312.656465] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4312.661740] agent flakelet[2725]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent # [ 4312.662797] agent flakelet[2725]: app: activating generation 7
agent # [ 4312.676055] agent systemd[1]: Stopping app v1...
agent # [ 4312.676509] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4312.676774] agent systemd[1]: Stopped app v1.
agent # [ 4312.693137] agent systemd[1]: Reload requested from client PID 2732 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4312.693201] agent systemd[1]: Reloading...
relay # [ 4312.409581] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:30.371345Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}
relay # [ 4312.466669] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:30.428477Z","level":"INFO","message":"deploy accepted","job":"f3469a74f8927189fefb099655270820","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4313.033255] agent systemd[1]: Reloading finished in 339 ms.
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'app-slow', in 1.02 seconds)
agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route add unreachable $a; done
agent: (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)
relay: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done
relay: (finished: must succeed: for a in $(getent ahosts agent | cut -d' ' -f1 | sort -u); do ss -K dst "[$a]"; done, in 0.05 seconds)
agent: must succeed: ss -K dport = 7443
agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)
agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'updated to generation'
agent # [ 4313.393152] agent systemd[1]: Reload requested from client PID 2762 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4313.393194] agent systemd[1]: Reloading...
agent # [ 4313.581895] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:31.543621Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
relay # [ 4313.548842] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:31.510585Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}
agent # [ 4313.884646] agent systemd[1]: Reloading finished in 491 ms.
agent # [ 4313.960977] agent systemd[1]: Reload requested from client PID 2808 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4313.961035] agent systemd[1]: Reloading...
agent # [ 4314.286509] agent systemd[1]: Reloading finished in 325 ms.
agent # [ 4314.405909] agent systemd[1]: Reload requested from client PID 2841 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4314.405945] agent systemd[1]: Reloading...
agent # [ 4314.584905] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:32.546475Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 4314.737292] agent systemd[1]: Reloading finished in 330 ms.
agent # [ 4314.820191] agent systemd[1]: Starting app slow...
agent # [ 4316.587400] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:34.549117Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 4320.589391] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:38.551036Z","level":"WARN","message":"connect failed: connect relay:7443: No route to host (os error 113)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 4320.889861] agent systemd[1]: Started app slow.
agent # [ 4320.907599] agent flakelet[2725]: app: updated to generation 7
agent # [ 4320.910667] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682590 | grep -q 'updated to generation', in 8.12 seconds)
agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done
agent: (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)
client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out
agent # [ 4321.548254] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:39.509966Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"}
client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 7.08 seconds)
client: must succeed: cat /tmp/slow.out
client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds)
(finished: subtest: agent link drop mid-run replays missed lines once, in 16.38 seconds)
subtest: agent restart mid-run reattaches to the unit
agent: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/restart.out 2>&1 &, in 0.01 seconds)
agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2'
relay # [ 4328.595391] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.557075Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 4328.595281] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.557000Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
relay # [ 4328.596802] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.558623Z","level":"INFO","message":"deploy finished","job":"f3469a74f8927189fefb099655270820","ok":true,"target":"flakelet_relay::relay::api"}
agent # [ 4328.596434] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.558251Z","level":"INFO","message":"start","id":"b21bacf6c84543d38b3547c2e8da39c8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
relay # [ 4328.846747] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:46.808343Z","level":"INFO","message":"deploy accepted","job":"0ddb9ea36fecb7d694381f79aeaf2b0e","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4328.847131] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.808668Z","level":"INFO","message":"start","id":"e5ae731e6705b9b81318c5da1e1a833c","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4328.847502] agent flakelet-agent[1942]: {"timestamp":"2026-09-06T08:16:46.809320Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e5ae731e6705b9b81318c5da1e1a833c\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4328.902266] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4328.935993] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4328.941244] agent flakelet[3021]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2
agent # [ 4328.941873] agent flakelet[3021]: app: activating generation 8
agent # [ 4328.954753] agent systemd[1]: Stopping app slow...
agent # [ 4328.956555] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4328.956866] agent systemd[1]: Stopped app slow.
agent # [ 4328.971824] agent systemd[1]: Reload requested from client PID 3028 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4328.971890] agent systemd[1]: Reloading...
agent # [ 4329.312712] agent systemd[1]: Reloading finished in 340 ms.
agent # [ 4329.383755] agent systemd[1]: Reload requested from client PID 3058 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4329.383791] agent systemd[1]: Reloading...
agent # [ 4329.712869] agent systemd[1]: Reloading finished in 328 ms.
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds)
agent: must succeed: systemctl restart flakelet-agent
agent # [ 4329.778184] agent systemd[1]: Reload requested from client PID 3089 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4329.778218] agent systemd[1]: Reloading...
agent # [ 4330.112241] agent systemd[1]: Reloading finished in 333 ms.
agent # [ 4330.189481] agent systemd[1]: Stopping flakelet-agent...
agent # [ 4330.196049] agent systemd[1]: Reload requested from client PID 3126 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4330.196091] agent systemd[1]: Reloading...
relay # [ 4330.189811] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:48.151552Z","level":"INFO","message":"agent disconnected: websocket closed","host":"agent","target":"flakelet_relay::relay::agent_conn"}
agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.86 seconds)
agent: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)"
agent: (finished: must succeed: test -n "$(ls /var/lib/flakelet-agent/jobs)", in 0.01 seconds)
client: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out
agent # [ 4330.532183] agent systemd[1]: Reloading finished in 335 ms.
agent # [ 4330.596410] agent systemd[1]: flakelet-agent.service: Deactivated successfully.
agent # [ 4330.596588] agent systemd[1]: Stopped flakelet-agent.
agent # [ 4330.596605] agent systemd[1]: flakelet-agent.service: Consumed 1.814s CPU time over 29.173s wall clock time.
agent # [ 4330.600941] agent systemd[1]: Starting flakelet-agent...
agent # [ 4330.603443] agent systemd[1]: Starting app slow2...
agent # [ 4330.656259] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.618046Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"e5ae731e6705b9b81318c5da1e1a833c\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4330.722965] agent systemd[1]: Started flakelet-agent.
agent # [ 4330.736828] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.698620Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 4330.738101] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:48.699918Z","level":"INFO","message":"start","id":"e5ae731e6705b9b81318c5da1e1a833c","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
relay # [ 4330.736939] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:48.698690Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 4336.666944] agent systemd[1]: Started app slow2.
agent # [ 4336.682207] agent flakelet[3021]: app: updated to generation 8
agent # [ 4336.684105] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 4337.262883] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:55.224631Z","level":"INFO","message":"deploy finished","job":"0ddb9ea36fecb7d694381f79aeaf2b0e","ok":true,"target":"flakelet_relay::relay::api"}
agent # [ 4337.261305] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.223014Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"}
client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.08 seconds)
client: must succeed: cat /tmp/restart.out
client: (finished: must succeed: cat /tmp/restart.out, in 0.01 seconds)
agent: must succeed: systemctl is-active app.service
agent: (finished: must succeed: systemctl is-active app.service, in 0.01 seconds)
(finished: subtest: agent restart mid-run reattaches to the unit, in 9.03 seconds)
subtest: relay restart mid-run, push resumes via /v1/jobs
agent: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json
agent: (finished: must succeed: jq '.services.app.prebuilt="/nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds)
agent: must succeed: date +%s
agent: (finished: must succeed: date +%s, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy agent/app > /tmp/resume.out 2>&1 &, in 0.01 seconds)
agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682615 | grep -q 'app-slow'
agent # [ 4337.884309] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.846047Z","level":"INFO","message":"start","id":"519f6601f6d4802b65e1d410940f29e2","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4337.884934] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:55.846756Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"519f6601f6d4802b65e1d410940f29e2\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4337.936600] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 4337.968056] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 4337.972713] agent flakelet[3642]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent # [ 4337.973341] agent flakelet[3642]: app: activating generation 9
agent # [ 4337.986602] agent systemd[1]: Stopping app slow2...
agent # [ 4337.987064] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 4337.987327] agent systemd[1]: Stopped app slow2.
agent # [ 4338.006261] agent systemd[1]: Reload requested from client PID 3649 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4338.006325] agent systemd[1]: Reloading...
relay # [ 4337.883861] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:16:55.845613Z","level":"INFO","message":"deploy accepted","job":"8ab76c92a77a0c8f36dc064757064de6","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4338.348044] agent systemd[1]: Reloading finished in 340 ms.
agent # [ 4338.456095] agent systemd[1]: Reload requested from client PID 3679 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4338.456132] agent systemd[1]: Reloading...
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682615 | grep -q 'app-slow', in 1.02 seconds)
relay: must succeed: systemctl restart flakelet-relay
agent # [ 4338.788286] agent systemd[1]: Reloading finished in 331 ms.
agent # [ 4338.875545] agent systemd[1]: Reload requested from client PID 3710 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4338.875577] agent systemd[1]: Reloading...
agent # [ 4338.906740] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:56.868524Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
relay # [ 4338.906320] relay systemd[1]: Stopping flakelet-relay...
relay # [ 4338.942125] relay systemd[1]: flakelet-relay.service: Deactivated successfully.
relay # [ 4338.942603] relay systemd[1]: Stopped flakelet-relay.
relay # [ 4338.942644] relay systemd[1]: flakelet-relay.service: Consumed 2.750s CPU time over 1min 8.893s wall clock time.
relay # [ 4338.981339] relay systemd[1]: Starting flakelet-relay...
agent # [ 4339.229836] agent systemd[1]: Reloading finished in 353 ms.
agent # [ 4339.318674] agent systemd[1]: Reload requested from client PID 3746 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 4339.318714] agent systemd[1]: Reloading...
agent # [ 4339.651864] agent systemd[1]: Reloading finished in 332 ms.
agent # [ 4339.736248] agent systemd[1]: Starting app slow...
agent # [ 4339.909881] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:57.871524Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.53 seconds)
client: waiting for success: grep -q '» ok' /tmp/resume.out
relay # [ 4340.421999] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:58.383741Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 4340.422952] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:58.384141Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 4340.422629] relay systemd[1]: Started flakelet-relay.
agent # [ 4341.924082] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:16:59.885791Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
relay # [ 4341.924266] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:59.886013Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
relay # [ 4341.926334] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:16:59.888146Z","level":"INFO","message":"job reattached","job":"8ab76c92a77a0c8f36dc064757064de6","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 4345.808957] agent systemd[1]: Started app slow.
agent # [ 4345.826799] agent flakelet[3642]: app: updated to generation 9
agent # [ 4345.829471] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
agent # [ 4346.913189] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:04.874927Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"}
client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.08 seconds)
client: must succeed: cat /tmp/resume.out
client: (finished: must succeed: cat /tmp/resume.out, in 0.01 seconds)
(finished: subtest: relay restart mid-run, push resumes via /v1/jobs, in 9.67 seconds)
subtest: job history comes from the agents and survives a relay restart
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1
agent # [ 4347.533732] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:05.495468Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 4347.534375] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:05.496192Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4347.586363] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4347.620523] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4347.625902] agent flakelet[3859]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4347.626471] agent flakelet[3859]: other: up to date
agent # [ 4347.627523] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 4347.533408] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:17:05.495083Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.67 seconds)
relay: must succeed: systemctl restart flakelet-relay
agent # [ 4348.179049] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:06.140782Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 4348.194408] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:06.156190Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
relay # [ 4348.180392] relay flakelet-relay[934]: {"timestamp":"2026-09-06T08:17:06.142147Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 4348.193883] relay systemd[1]: Stopping flakelet-relay...
relay # [ 4348.247150] relay systemd[1]: flakelet-relay.service: Deactivated successfully.
relay # [ 4348.247627] relay systemd[1]: Stopped flakelet-relay.
relay # [ 4348.247669] relay systemd[1]: flakelet-relay.service: Consumed 2.041s CPU time over 9.265s wall clock time.
relay # [ 4348.284052] relay systemd[1]: Starting flakelet-relay...
agent # [ 4349.197493] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:07.159215Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.49 seconds)
relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'
relay # [ 4349.670608] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:07.632343Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 4349.671578] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:07.632774Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 4349.671194] relay systemd[1]: Started flakelet-relay.
agent # [ 4351.207200] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.168973Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
relay # [ 4351.207343] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.169084Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.05 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds)
client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32)
client: (finished: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/r7sclamg09v434w8zjlfnrcrn1w79wh6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds)
client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjkyOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNjI5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDWVlZNlNTWUtRTklVPT09IiwibmJmIjoxNzg4NjgyNjI5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.0owOCgV_QvciKpjEZKBBXoa003pIKLx7Zmn79daCm8V4sI_R3_IXjw7wXVY3O05mD-JR3OxrdWTroHcGVTKADg' push --relay https://relay:7443 jobs
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjkyOSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyNjI5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJDWVlZNlNTWUtRTklVPT09IiwibmJmIjoxNzg4NjgyNjI5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.0owOCgV_QvciKpjEZKBBXoa003pIKLx7Zmn79daCm8V4sI_R3_IXjw7wXVY3O05mD-JR3OxrdWTroHcGVTKADg' push --relay https://relay:7443 jobs, in 0.02 seconds)
(finished: subtest: job history comes from the agents and survives a relay restart, in 4.31 seconds)
subtest: dashboard login via authorization code flow
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login'
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code} %{redirect_url}' https://relay:7443/ui/ | grep -q '303 https://relay:7443/ui/login', in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -f https://relay:7443/v1/jobs | grep -q hist1, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 10 https://relay:7443/ui/jobs/hist1/events || true, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -X POST 'https://relay:7443/ui/deploy?arg=other' | grep -q 403, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other'
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -D - -o /dev/null -H 'HX-Request: true' -X POST 'https://relay:7443/ui/deploy?arg=other', in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/2898b2a8a520ce1b90ca229229d36749/events || true
relay # [ 4351.874698] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:17:09] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=1KNzVBibdSVyboEPGKl-PdCIoQ7vehYyMPDFmNFtdyg&code_challenge=inwqMeyxARzYBCBF6Vy2xsmxYhCMss1bokJP7YYmnLs&code_challenge_method=S256 HTTP/1.1" 302 -
relay # [ 4351.920465] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[186]: 127.0.0.1 - - [06/Sep/2026 08:17:09] "POST /token HTTP/1.1" 200 -
relay # [ 4351.921726] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.883527Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}
relay # [ 4351.985154] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.946909Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
relay # [ 4352.027165] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:09.988930Z","level":"INFO","message":"deploy accepted","job":"67e1fdd469ec58d1a761e0b3128acbe3","caller":"oidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
relay # [ 4352.046918] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:10.008722Z","level":"INFO","message":"job reattached","job":"67e1fdd469ec58d1a761e0b3128acbe3","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 4352.027413] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.989169Z","level":"INFO","message":"start","id":"ece355ae42cccaa7c0b1a99716e07372","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}
agent # [ 4352.027856] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:09.989674Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"ece355ae42cccaa7c0b1a99716e07372\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 4352.079999] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 4352.112998] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4352.118496] agent flakelet[3907]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4352.118986] agent flakelet[3907]: other: up to date
agent # [ 4352.121850] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 30 https://relay:7443/ui/jobs/2898b2a8a520ce1b90ca229229d36749/events || true, in 0.65 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/2898b2a8a520ce1b90ca229229d36749
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs/2898b2a8a520ce1b90ca229229d36749, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -sf -o /dev/null https://relay:7443/ui/static/htmx.min.js, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth'
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/?q=status%3Ahealthy+oth', in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/flakelets/other, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected'
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar 'https://relay:7443/ui/hosts?q=status%3Adisconnected', in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=2898b2a8a520ce1b90ca229229d36749' | grep -q 400
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' -H 'HX-Request: true' -X POST 'https://relay:7443/ui/retry?arg=2898b2a8a520ce1b90ca229229d36749' | grep -q 400, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -N --max-time 15 'https://relay:7443/ui/events?path=jobs' > /tmp/ev.out 2>&1 &, in 0.01 seconds)
client: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other
» job 38796a7ba508eadfe82a1cd5def000bc via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/other | Starting flakelet update other (via relay)...
agent/other | Started flakelet update other (via relay).
agent/other | other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent/other | other: up to date
agent # [ 4352.672228] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.633970Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent/otheragent # [ 4352.821123] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.782776Z","level":"INFO","message":"start","id":"5e317fc57863c2a7c03ebe1bdacd1356","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
 | agent # [ 4352.821345] agent flakelet-agent[3157]: {"timestamp":"2026-09-06T08:17:10.783148Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}
flakelet-relay-job-other.service: Deactivated successfully.agent # [ 4352.868511] agent systemd[1]: Starting flakelet update other (via relay)...

agent # [ 4352.904098] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 4352.908518] agent flakelet[3945]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 4352.908977] agent flakelet[3945]: other: up to date
agent # [ 4352.911172] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 4352.820688] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:10.782440Z","level":"INFO","message":"deploy accepted","job":"38796a7ba508eadfe82a1cd5def000bc","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
» agent/other: unchanged (generation 1)
» ok
client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin.pem --key /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/admin-key.pem deploy --id live1 agent/other, in 0.66 seconds)
client: waiting for success: grep -q live1 /tmp/ev.out
client: (finished: waiting for success: grep -q live1 /tmp/ev.out, in 0.01 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -X POST -o /dev/null https://relay:7443/ui/logout, in 0.02 seconds)
client: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303
client: (finished: must succeed: curl -sS --cacert /nix/store/ydql3jgw8j7khsad67k605wlnywsd36n-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -o /dev/null -w '%{http_code}' https://relay:7443/ui/ | grep -q 303, in 0.02 seconds)
(finished: subtest: dashboard login via authorization code flow, in 1.70 seconds)
(finished: run the VM test script, in 87.10 seconds)
test script finished in 87.14s
cleanup
kill NspawnMachine (pid 51)
kill NspawnMachine (pid 53)
Container agent terminated by signal KILL.
kill NspawnMachine (pid 55)
relay # [ 4353.465686] relay flakelet-relay[1324]: {"timestamp":"2026-09-06T08:17:11.427442Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}
Container client terminated by signal KILL.
(finished: cleanup, in 0.34 seconds)
additionally exposed symbols:
    agent, client, relay,
    vlan1,
    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_ssh
» job b08899e4f5d9448ad0e62beee8dfb372 via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | Starting flakelet update app (via relay)...
agent/app | Started flakelet update app (via relay).
agent/app | app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2
agent/app | app: activating generation 2
agent/app | app: updated to generation 2
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 2)
» ok

» job 8419c3ef1200ac1a3b2918807efb1372 via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | Starting flakelet update app (via relay)...
agent/app | Started flakelet update app (via relay).
agent/app | app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken
agent/app | app: activating generation 4
agent/app | app: deploy failed, rolled back: systemctl start app.service failed:
agent/app | failed units: app.service. See journalctl -u app.service
agent/app | flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE
agent/app | flakelet-relay-job-app.service: Failed with result 'exit-code'.
» agent/app: rolled-back (generation 3)
agent/app │ Starting app v1...
agent/app │ Started app v1.
agent/app │ Stopping app v1...
agent/app │ app.service: Deactivated successfully.
agent/app │ Stopped app v1.
agent/app │ Starting app v2...
agent/app │ Started app v2.
agent/app │ Stopping app v2...
agent/app │ app.service: Deactivated successfully.
agent/app │ Stopped app v2.
agent/app │ Starting app v1...
agent/app │ Started app v1.
agent/app │ Stopping app v1...
agent/app │ app.service: Deactivated successfully.
agent/app │ Stopped app v1.
agent/app │ Starting app broken...
agent/app │ app.service: Unable to locate executable '/nonexistent': No such file or directory
agent/app │ app.service: Failed at step EXEC spawning /nonexistent: No such file or directory
agent/app │ app.service: Main process exited, code=exited, status=203/EXEC
agent/app │ app.service: Failed with result 'exit-code'.
agent/app │ Failed to start app broken.
agent/app │ Starting app v1...
agent/app │ Started app v1.
» skipped: agent/other
» failed

» job f3469a74f8927189fefb099655270820 via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | Starting flakelet update app (via relay)...
agent/app | Started flakelet update app (via relay).
agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent/app | app: activating generation 7
agent/app | app: updated to generation 7
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 7)
» ok

» job 0ddb9ea36fecb7d694381f79aeaf2b0e via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | Starting flakelet update app (via relay)...
agent/app | Started flakelet update app (via relay).
agent/app | app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2
agent/app | app: activating generation 8
agent/app | app: updated to generation 8
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 8)
» ok

» job 8ab76c92a77a0c8f36dc064757064de6 via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | Starting flakelet update app (via relay)...
agent/app | Started flakelet update app (via relay).
agent/app | app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent/app | app: activating generation 9
flakelet-push: stream: error reading a body from connection, resuming job 05d4231c307cb1cbf07c6a9bdf207b94
flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s
flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s
» job 8ab76c92a77a0c8f36dc064757064de6 via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | app: updated to generation 9
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 9)
» ok

1788682625	hist1	x509:email:admin@example.org	agent/other:unchanged
1788682615	05d4231c307cb1cbf07c6a9bdf207b94	x509:email:admin@example.org	agent/app:updated
1788682606	23da240189104d19234d432efbf0057c	x509:email:admin@example.org	agent/app:updated
1788682590	bf8c5b2d59a0eb357752b8716c11533b	x509:email:admin@example.org	agent/app:updated
1788682581	ed963f79555867c956c14f32ad09afb0	x509:email:admin@example.org	agent/other:unchanged
1788682569	313fecae7846ea2661401f4ecb3ed8e4	x509:email:admin@example.org	agent/app:updated
1788682568	8c41e2d174f8f86377f9484d2d4de768	x509:email:admin@example.org	agent/app:unchanged
1788682568	f0dba552df68fb3bfa8da79a34b4b5ad	x509:email:admin@example.org	agent/app:unchanged
1788682567	88eb7e9f3367c33813834b7f2f43b527	x509:email:admin@example.org	agent/app:unchanged
1788682562	2115e6266c59c8f29486fc6de24a7806	x509:email:admin@example.org	agent/app:rolled-back
1788682562	a19f817a842695e2740b28dda6c7fe5f	oidc:mock:groups:wheel	agent/other:unchanged
1788682561	78f0ab79312d1634498aab8f76da8cf2	oidc:mock:groups:wheel	agent/other:unchanged
1788682558	963c04c021b1f0489e22438454ce0598	oidc:mock:groups:wheel	agent/other:unchanged
1788682555	2bf3cd2fd9539cc177c5e7413bc3abfd	oidc:mock:repo:github:example/app:ref:refs/heads/main	agent/app:updated
1788682552	cd6104c2a4dc8a780b83d81f54901226	x509:email:admin@example.org	agent/app:updated

Container relay terminated by signal KILL.