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
client: systemd-nspawn running (pid 53)
agent: systemd-nspawn running (pid 52)
client: Waiting for journal at /build/vm-state-client/var/log/journal...
relay: systemd-nspawn running (pid 54)
agent: Waiting for journal at /build/vm-state-agent/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(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.
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(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.
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 relay on /build/vm-state-relay.
░ Spawning container agent on /build/vm-state-agent.
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.
client # No journal files were found.
client # No journal boot entry found for the specified boot (+0).
relay # No journal files were found.
agent # No journal files were found.
agent # No journal boot entry found for the specified boot (+0).
relay # No journal boot entry found for the specified boot (+0).
client # [ 3743.809698] client systemd-journald[57]: Journal started
client # [ 3743.809743] client systemd-journald[57]: Runtime Journal (/run/log/journal/c4ba3fec4895401e9c3f374f828bae1e) is 8M, max 4G, 3.9G free.
client # [ 3743.831514] client systemd[1]: Listening on Journal Log Access Socket.
client # [ 3743.831783] client systemd[1]: Finished Apply Kernel Variables.
client # [ 3743.856021] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
client # [ 3743.873094] client systemd[1]: Starting Flush Journal to Persistent Storage...
client # [ 3743.873872] client systemd[1]: Starting Create Static Device Nodes in /dev...
client # [ 3743.882927] client systemd-journald[57]: Time spent on flushing to /var/log/journal/c4ba3fec4895401e9c3f374f828bae1e is 1.365ms for 7 entries.
client # [ 3743.882927] client systemd-journald[57]: System Journal (/var/log/journal/c4ba3fec4895401e9c3f374f828bae1e) is 512B, max 4G, 3.9G free.
client # [ 3743.896633] client systemd[1]: Finished Create Static Device Nodes in /dev.
client # [ 3743.897366] client systemd[1]: Reached target Preparation for Local File Systems.
client # [ 3743.897473] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
client # [ 3743.908380] client systemd[1]: Finished Flush Journal to Persistent Storage.
client # [ 3744.046159] client systemd[1]: Finished Firewall.
agent # [ 3743.809528] agent systemd-journald[57]: Journal started
agent # [ 3743.809575] agent systemd-journald[57]: Runtime Journal (/run/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd) is 8M, max 4G, 3.9G free.
agent # [ 3743.831110] agent systemd[1]: Listening on Journal Log Access Socket.
agent # [ 3743.831484] agent systemd[1]: Finished Apply Kernel Variables.
agent # [ 3743.853216] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
agent # [ 3743.872162] agent systemd[1]: Starting Flush Journal to Persistent Storage...
agent # [ 3743.873039] agent systemd[1]: Starting Create Static Device Nodes in /dev...
agent # [ 3743.881371] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd is 1.684ms for 7 entries.
agent # [ 3743.881371] agent systemd-journald[57]: System Journal (/var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd) is 512B, max 4G, 3.9G free.
agent # [ 3743.896736] agent systemd[1]: Finished Create Static Device Nodes in /dev.
agent # [ 3743.897403] agent systemd[1]: Reached target Preparation for Local File Systems.
agent # [ 3743.897508] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
agent # [ 3743.906961] agent systemd[1]: Finished Flush Journal to Persistent Storage.
agent # [ 3744.018789] agent systemd[1]: Finished Firewall.
relay # [ 3743.821016] relay systemd-journald[57]: Journal started
relay # [ 3743.821058] relay systemd-journald[57]: Runtime Journal (/run/log/journal/0c0eb96cc45e46c1a72a47abcc336c10) is 8M, max 4G, 3.9G free.
relay # [ 3743.865824] relay systemd[1]: Finished Apply Kernel Variables.
relay # [ 3743.884482] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
relay # [ 3743.900359] relay systemd[1]: Starting Flush Journal to Persistent Storage...
relay # [ 3743.901219] relay systemd[1]: Starting Create Static Device Nodes in /dev...
relay # [ 3743.909921] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10 is 2.386ms for 6 entries.
relay # [ 3743.909921] relay systemd-journald[57]: System Journal (/var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10) is 512B, max 4G, 3.9G free.
relay # [ 3743.942842] relay systemd[1]: Finished Create Static Device Nodes in /dev.
relay # [ 3743.943094] relay systemd[1]: Finished Flush Journal to Persistent Storage.
relay # [ 3743.944353] relay systemd[1]: Reached target Preparation for Local File Systems.
relay # [ 3743.944460] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys
relay # [ 3744.047415] relay systemd[1]: Finished Firewall.
relay # [ 3744.821679] relay systemd[1]: Mounting /run/wrappers...
relay # [ 3744.845321] relay systemd[1]: Mounted /run/wrappers.
relay # [ 3744.846107] relay systemd[1]: Reached target Local File Systems.
relay # [ 3744.846923] relay systemd[1]: Listening on Boot Loader Control Service Socket.
relay # [ 3744.847853] relay systemd[1]: Starting Create SUID/SGID Wrappers...
relay # [ 3744.847881] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
relay # [ 3744.848793] relay systemd[1]: Starting Save Transient machine-id to Disk...
relay # [ 3744.849714] relay systemd[1]: Starting Create System Files and Directories...
relay # [ 3744.869040] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
relay # [ 3744.869468] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted
relay # [ 3744.869795] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/0c0eb96cc45e46c1a72a47abcc336c10 failed: Operation not permitted
relay # [ 3744.869862] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.xVJFhvaATa/chsh': Operation not permitted
relay # [ 3744.870148] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted
client # [ 3744.825805] client systemd[1]: Mounting /run/wrappers...
client # [ 3744.861941] client systemd[1]: Mounted /run/wrappers.
client # [ 3744.863035] client systemd[1]: Reached target Local File Systems.
agent # [ 3744.822724] agent systemd[1]: Mounting /run/wrappers...
client # [ 3744.864292] client systemd[1]: Listening on Boot Loader Control Service Socket.
agent # [ 3744.857096] agent systemd[1]: Mounted /run/wrappers.
client # [ 3744.865491] client systemd[1]: Starting Create SUID/SGID Wrappers...
agent # [ 3744.858104] agent systemd[1]: Reached target Local File Systems.
client # [ 3744.865539] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
agent # [ 3744.859245] agent systemd[1]: Listening on Boot Loader Control Service Socket.
client # [ 3744.866756] client systemd[1]: Starting Save Transient machine-id to Disk...
agent # [ 3744.860310] agent systemd[1]: Starting Create SUID/SGID Wrappers...
client # [ 3744.867711] client systemd[1]: Starting Create System Files and Directories...
agent # [ 3744.860358] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container
client # [ 3744.889571] client suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.AjO7qj4Bwy/chsh': Operation not permitted
agent # [ 3744.861191] agent systemd[1]: Starting Save Transient machine-id to Disk...
client # [ 3744.896805] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
agent # [ 3744.861844] agent systemd[1]: Starting Create System Files and Directories...
client # [ 3744.897251] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted
agent # [ 3744.881491] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.SSEwFYwbZj/chsh': Operation not permitted
client # [ 3744.897560] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/c4ba3fec4895401e9c3f374f828bae1e failed: Operation not permitted
agent # [ 3744.894989] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
agent # [ 3744.895091] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
client # [ 3744.897912] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted
agent # [ 3744.895225] agent systemd[1]: Failed to start Create SUID/SGID Wrappers.
agent # [ 3744.897095] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted
agent # [ 3744.897534] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted
agent # [ 3744.897848] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/f1b11bc949224d2b8cc0515a62cdb4dd failed: Operation not permitted
agent # [ 3744.898205] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted
relay # [ 3744.870494] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
relay # [ 3744.870746] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
relay # [ 3744.870934] relay systemd[1]: Failed to start Create SUID/SGID Wrappers.
relay # [ 3744.885278] relay systemd[1]: Finished Create System Files and Directories.
relay # [ 3744.902215] relay systemd[1]: Starting Rebuild Journal Catalog...
relay # [ 3744.902958] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP...
relay # [ 3744.915437] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP.
relay # [ 3744.920950] relay systemd[1]: Finished Rebuild Journal Catalog.
relay # [ 3744.922551] relay systemd[1]: Starting Update is Completed...
relay # [ 3744.936288] relay systemd[1]: Finished Update is Completed.
relay # [ 3744.936442] relay systemd[1]: Reached target System Initialization.
relay # [ 3744.936516] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
relay # [ 3744.936541] relay systemd[1]: Started Daily Cleanup of Temporary Directories.
relay # [ 3744.936557] relay systemd[1]: Reached target Timer Units.
relay # [ 3744.936650] relay systemd[1]: Listening on D-Bus System Message Bus Socket.
relay # [ 3744.936837] relay systemd[1]: Listening on Nix Daemon Socket.
relay # [ 3744.936934] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
relay # [ 3744.936950] relay systemd[1]: Reached target Socket Units.
relay # [ 3744.936976] relay systemd[1]: Reached target Basic System.
relay # [ 3744.938381] relay systemd[1]: Started device-mock.service.
relay # [ 3744.939205] relay systemd[1]: Starting Re-link flakelet services at boot...
relay # [ 3744.940068] relay systemd[1]: Starting Import lastlog data into lastlog2 database...
relay # [ 3744.941482] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 3744.942808] relay systemd[1]: Starting resolvconf update...
relay # [ 3744.950158] relay systemd[1]: Finished Re-link flakelet services at boot.
relay # [ 3744.951752] relay systemd[1]: Starting Reconcile flakelet services with the host configuration...
relay # [ 3744.959054] relay systemd[1]: Finished Import lastlog data into lastlog2 database.
relay # [ 3744.962238] relay systemd[1]: Finished Reconcile flakelet services with the host configuration.
relay # [ 3745.034503] relay systemd[1]: Finished resolvconf update.
relay # [ 3745.034666] relay systemd[1]: Reached target Preparation for Network.
relay # [ 3745.035890] relay systemd[1]: Starting Address configuration of eth1...
relay # [ 3745.037192] relay systemd[1]: Starting Extra networking commands....
relay # [ 3745.053563] relay network-addresses-eth1-start[245]: adding address 192.168.1.3/24... done
relay # [ 3745.056555] relay network-addresses-eth1-start[245]: adding address 2001:db8:1::3/64... done
agent # [ 3744.899900] agent systemd[1]: Finished Create System Files and Directories.
agent # [ 3744.913957] agent systemd[1]: Starting Rebuild Journal Catalog...
agent # [ 3744.914581] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP...
agent # [ 3744.926167] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP.
agent # [ 3744.937142] agent systemd[1]: Finished Rebuild Journal Catalog.
agent # [ 3744.939428] agent systemd[1]: Starting Update is Completed...
agent # [ 3744.950424] agent systemd[1]: Finished Update is Completed.
agent # [ 3744.950529] agent systemd[1]: Reached target System Initialization.
agent # [ 3744.950609] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
agent # [ 3744.950636] agent systemd[1]: Started Daily Cleanup of Temporary Directories.
agent # [ 3744.950650] agent systemd[1]: Reached target Timer Units.
agent # [ 3744.950751] agent systemd[1]: Listening on D-Bus System Message Bus Socket.
agent # [ 3744.950936] agent systemd[1]: Listening on Nix Daemon Socket.
agent # [ 3744.951041] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
agent # [ 3744.951056] agent systemd[1]: Reached target Socket Units.
agent # [ 3744.951084] agent systemd[1]: Reached target Basic System.
agent # [ 3744.952178] agent systemd[1]: Starting Re-link flakelet services at boot...
agent # [ 3744.952794] agent systemd[1]: Starting Import lastlog data into lastlog2 database...
agent # [ 3744.953568] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 3744.954177] agent systemd[1]: Starting resolvconf update...
agent # [ 3744.963787] agent systemd[1]: Finished Re-link flakelet services at boot.
agent # [ 3744.965296] agent systemd[1]: Starting Reconcile flakelet services with the host configuration...
agent # [ 3744.971635] agent systemd[1]: Finished Import lastlog data into lastlog2 database.
agent # [ 3744.986575] agent systemd[1]: Finished Reconcile flakelet services with the host configuration.
agent # [ 3745.120011] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
client # [ 3744.906023] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE
client # [ 3744.906061] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.
client # [ 3744.906111] client systemd[1]: Failed to start Create SUID/SGID Wrappers.
client # [ 3744.906754] client systemd[1]: Finished Create System Files and Directories.
client # [ 3744.922403] client systemd[1]: Starting Rebuild Journal Catalog...
client # [ 3744.923042] client systemd[1]: Starting Record System Boot/Shutdown in UTMP...
client # [ 3744.939995] client systemd[1]: Finished Record System Boot/Shutdown in UTMP.
client # [ 3744.947068] client systemd[1]: Finished Rebuild Journal Catalog.
client # [ 3744.948250] client systemd[1]: Starting Update is Completed...
client # [ 3744.958704] client systemd[1]: Finished Update is Completed.
client # [ 3744.958793] client systemd[1]: Reached target System Initialization.
client # [ 3744.958858] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container
client # [ 3744.958887] client systemd[1]: Started Daily Cleanup of Temporary Directories.
client # [ 3744.958903] client systemd[1]: Reached target Timer Units.
client # [ 3744.959010] client systemd[1]: Listening on D-Bus System Message Bus Socket.
client # [ 3744.959207] client systemd[1]: Listening on Nix Daemon Socket.
client # [ 3744.959307] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
client # [ 3744.959320] client systemd[1]: Reached target Socket Units.
client # [ 3744.959349] client systemd[1]: Reached target Basic System.
client # [ 3744.960351] client systemd[1]: Starting Import lastlog data into lastlog2 database...
client # [ 3744.961520] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
client # [ 3744.962130] client systemd[1]: Starting resolvconf update...
client # [ 3744.971619] client systemd[1]: lastlog2-import.service: Failed to spawn executor: No such file or directory
client # [ 3744.971729] client systemd[1]: lastlog2-import.service: Failed to spawn 'start-post' task: No such file or directory
client # [ 3744.971770] client systemd[1]: lastlog2-import.service: Failed with result 'resources'.
client # [ 3744.971812] client systemd[1]: Failed to start Import lastlog data into lastlog2 database.
client # [ 3745.134612] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
agent # [ 3745.120941] agent systemd[1]: Finished Save Transient machine-id to Disk.
agent # [ 3745.153109] agent systemd[1]: nscd.service: Deactivated successfully.
agent # [ 3745.153230] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).
agent # [ 3745.175745] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 3745.176338] agent systemd[1]: Finished resolvconf update.
agent # [ 3745.177100] agent systemd[1]: Reached target Preparation for Network.
agent # [ 3745.178259] agent systemd[1]: Starting Address configuration of eth1...
agent # [ 3745.179296] agent systemd[1]: Starting Extra networking commands....
agent # [ 3745.199071] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done
agent # [ 3745.201893] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done
agent # [ 3745.205716] agent systemd[1]: Finished Address configuration of eth1.
agent # [ 3745.250496] agent systemd[1]: Finished Extra networking commands..
agent # [ 3745.251984] agent systemd[1]: Reached target Network.
agent # [ 3745.254500] agent systemd[1]: Starting flakelet-agent...
agent # [ 3745.256190] agent systemd[1]: Starting Update flakelet service app...
agent # [ 3745.258641] agent systemd[1]: Starting Update flakelet service other...
agent # [ 3745.269284] agent flakelet[305]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 3745.270871] agent flakelet[305]: app: activating generation 1
agent # [ 3745.275056] agent flakelet[306]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3745.275584] agent flakelet[306]: other: activating generation 1
agent # [ 3745.276197] agent systemd[1]: Reload requested from client PID 308 ('systemctl') (unit flakelet-app.service)...
agent # [ 3745.276267] agent systemd[1]: Reloading...
agent # [ 3745.338613] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:03.300333Z","level":"WARN","message":"SRV _flakelet-relay._tcp.test: lookup failed","target":"flakelet_agent"}
relay # [ 3745.135628] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
relay # [ 3745.137304] relay systemd[1]: Finished Save Transient machine-id to Disk.
relay # [ 3745.137659] relay systemd[1]: nscd.service: Deactivated successfully.
relay # [ 3745.137854] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd).
relay # [ 3745.141133] relay systemd[1]: Finished Address configuration of eth1.
relay # [ 3745.141507] relay systemd[1]: Finished Extra networking commands..
relay # [ 3745.153430] relay systemd[1]: Reached target Network.
relay # [ 3745.175713] relay systemd[1]: Starting Dnsmasq Daemon...
relay # [ 3745.177232] relay systemd[1]: Starting Nginx Web Server...
relay # [ 3745.177977] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 3745.179209] relay systemd[1]: Starting Update flakelet service flakelet-relay...
relay # [ 3745.191263] relay flakelet[310]: flakelet-relay: using prebuilt artifact /nix/store/f1v78vfk8kx4d0k813cb79kbav5dag0q-flakelet-flakelet-relay
relay # [ 3745.191879] relay flakelet[310]: flakelet-relay: activating generation 1
relay # [ 3745.196941] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)...
relay # [ 3745.197035] relay systemd[1]: Reloading...
client # [ 3745.136034] client systemd[1]: Finished Save Transient machine-id to Disk.
client # [ 3745.162382] client systemd[1]: nscd.service: Deactivated successfully.
client # [ 3745.175476] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).
client # [ 3745.177757] client systemd[1]: Finished resolvconf update.
client # [ 3745.178656] client systemd[1]: Reached target Preparation for Network.
client # [ 3745.179733] client systemd[1]: Starting Address configuration of eth1...
client # [ 3745.180484] client systemd[1]: Starting Extra networking commands....
client # [ 3745.181364] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
client # [ 3745.200319] client network-addresses-eth1-start[235]: adding address 192.168.1.2/24... done
client # [ 3745.203340] client network-addresses-eth1-start[235]: adding address 2001:db8:1::2/64... done
client # [ 3745.207928] client systemd[1]: Finished Address configuration of eth1.
client # [ 3745.254470] client systemd[1]: Finished Extra networking commands..
client # [ 3745.255407] client systemd[1]: Reached target Network.
client # [ 3745.294497] client systemd[1]: nscd.service: Deactivated successfully.
client # [ 3745.294658] client systemd[1]: Stopped Name Service Cache Daemon (nsncd).
client # [ 3745.297280] client systemd[1]: Starting Name Service Cache Daemon (nsncd)...
relay # [ 3745.675734] relay nsncd[309]: Sep 06 08:07:03.637 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
relay # [ 3745.760336] relay systemd[1]: Reloading finished in 562 ms.
relay # [ 3745.908063] relay systemd[1]: Started Name Service Cache Daemon (nsncd).
relay # [ 3745.909075] relay systemd[1]: Reached target Host and Network Name Lookups.
relay # [ 3745.909123] relay systemd[1]: Reached target User and Group Name Lookups.
relay # [ 3745.910133] relay systemd[1]: Starting User Login Management...
relay # [ 3745.910998] relay systemd[1]: Starting Permit User Sessions...
relay # [ 3745.918110] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)...
relay # [ 3745.918145] relay systemd[1]: Reloading...
client # [ 3745.800184] client nsncd[302]: Sep 06 08:07:03.761 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
client # [ 3745.800330] client systemd[1]: Started Name Service Cache Daemon (nsncd).
client # [ 3745.800415] client systemd[1]: Reached target Host and Network Name Lookups.
client # [ 3745.800504] client systemd[1]: Reached target User and Group Name Lookups.
client # [ 3745.802761] client systemd[1]: Starting User Login Management...
client # [ 3745.804184] client systemd[1]: Starting Permit User Sessions...
client # [ 3745.836406] client systemd[1]: Finished Permit User Sessions.
client # [ 3745.838192] client systemd[1]: Started Console Getty.
client # [ 3745.838243] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
client # [ 3745.838274] client systemd[1]: Reached target Login Prompts.
agent # [ 3745.766963] agent systemd[1]: Reloading finished in 489 ms.
agent # [ 3745.907482] agent systemd[1]: Started flakelet-agent.
agent # [ 3745.907740] agent systemd[1]: nscd.service: Deactivated successfully.
agent # [ 3745.907851] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd).
agent # [ 3745.913965] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)...
agent # [ 3745.914144] agent systemd[1]: Reload requested from client PID 309 ('systemctl') (unit flakelet-other.service)...
agent # [ 3745.914185] agent systemd[1]: Reloading...
relay # [ 3746.298049] relay dnsmasq-pre-start[393]: dnsmasq: syntax check OK.
relay # [ 3746.372128] relay systemd[1]: Reloading finished in 453 ms.
relay # [ 3746.486243] relay systemd[1]: Finished Permit User Sessions.
relay # [ 3746.492506] relay systemd[1]: Started Console Getty.
relay # [ 3746.492571] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
relay # [ 3746.492637] relay systemd[1]: Reached target Login Prompts.
relay # [ 3746.494292] relay systemd[1]: Starting flakelet-relay...
agent # [ 3746.308274] agent nsncd[724]: Sep 06 08:07:04.270 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
agent # [ 3746.353145] agent systemd[1]: Reloading finished in 438 ms.
agent # [ 3746.485941] agent systemd[1]: Started Name Service Cache Daemon (nsncd).
agent # [ 3746.489837] agent systemd[1]: Reached target Host and Network Name Lookups.
agent # [ 3746.489889] agent systemd[1]: Reached target User and Group Name Lookups.
agent # [ 3746.490971] agent systemd[1]: Starting User Login Management...
agent # [ 3746.492768] agent systemd[1]: Starting Permit User Sessions...
agent # [ 3746.495705] agent systemd[1]: Reload requested from client PID 762 ('systemctl') (unit flakelet-app.service)...
agent # [ 3746.495741] agent systemd[1]: Reloading...
agent # [ 3746.890776] agent systemd[1]: Reloading finished in 394 ms.
agent # [ 3746.962648] agent systemd[1]: Finished Permit User Sessions.
agent # [ 3746.968056] agent systemd[1]: Started Console Getty.
agent # [ 3746.968147] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0
agent # [ 3746.968252] agent systemd[1]: Reached target Login Prompts.
agent # [ 3746.969908] agent systemd[1]: Reload requested from client PID 767 ('systemctl') (unit flakelet-other.service)...
agent # [ 3746.969935] agent systemd[1]: Reloading...
relay # [ 3747.258229] relay systemd[1]: Starting D-Bus System Message Bus...
agent # [ 3747.316682] agent systemd[1]: Reloading finished in 346 ms.
agent # [ 3747.395350] agent systemd[1]: Starting app v1...
agent # [ 3747.402761] agent systemd[1]: Started app v1.
agent # [ 3747.404800] agent systemd[1]: Starting other v1...
agent # [ 3747.412912] agent systemd[1]: Started other v1.
agent # [ 3747.415914] agent flakelet[305]: app: updated to generation 1
agent # [ 3747.418932] agent systemd[1]: Finished Update flakelet service app.
agent # [ 3747.426202] agent flakelet[306]: other: updated to generation 1
agent # [ 3747.427813] agent systemd[1]: Finished Update flakelet service other.
agent # [ 3747.427946] agent systemd[1]: Reached target flakelet managed services.
relay # [ 3748.151887] relay nginx-pre-start[403]: nginx: the configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf syntax is ok
relay # [ 3748.152670] relay nginx-pre-start[403]: nginx: configuration file /nix/store/01avjj26wcihp926xgasszcj5s0k7cbs-nginx.conf test is successful
relay # [ 3748.165812] relay systemd[1]: Started Nginx Web Server.
relay # [ 3748.247097] relay dbus-broker-launch[402]: Looking up NSS user entry for 'systemd-timesync'...
relay # [ 3748.248025] relay dbus-broker-launch[402]: NSS returned no entry for 'systemd-timesync'
relay # [ 3748.248063] relay dbus-broker-launch[402]: Invalid user-name in /nix/store/27h4g2jdw18vrabfh6p1l0n8ss5dhbp5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
relay # [ 3748.249071] relay systemd[1]: Started D-Bus System Message Bus.
relay # [ 3748.254198] relay dbus-broker-launch[402]: Ready
relay # [ 3748.256558] relay systemd[1]: Started Dnsmasq Daemon.
relay # [ 3748.258221] relay dnsmasq[394]: started, version 2.93 cachesize 150
relay # [ 3748.258228] 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 # [ 3748.258235] relay dnsmasq[394]: DBus support enabled: connected to system bus
relay # [ 3748.258241] relay dnsmasq[394]: no upstream servers configured - please set them from DBus
relay # [ 3748.258327] relay dnsmasq[394]: read /etc/hosts - 9 names
relay # [ 3748.264891] relay systemd-logind[355]: New seat seat0.
relay # [ 3748.265090] relay systemd[1]: Started User Login Management.
relay # [ 3748.279658] relay systemd[1]: Starting linger-users.service...
relay # [ 3748.330039] relay systemd[1]: linger-users.service: Deactivated successfully.
relay # [ 3748.330131] relay systemd[1]: Finished linger-users.service.
client # [ 3748.248155] client systemd-logind[314]: New seat seat0.
client # [ 3748.249300] client systemd[1]: Starting D-Bus System Message Bus...
client # [ 3748.249379] client systemd[1]: Started User Login Management.
client # [ 3748.251827] client systemd[1]: Starting linger-users.service...
client # [ 3748.287820] client systemd[1]: linger-users.service: Deactivated successfully.
client # [ 3748.288030] client systemd[1]: Finished linger-users.service.
client # [ 3748.288246] client systemd[1]: Reached target Multi-User System.
agent # [ 3748.796198] agent systemd-logind[764]: New seat seat0.
agent # [ 3748.799411] agent systemd[1]: Starting D-Bus System Message Bus...
agent # [ 3748.799482] agent systemd[1]: Started User Login Management.
agent # [ 3748.800281] agent systemd[1]: Starting linger-users.service...
agent # [ 3748.813871] agent systemd[1]: linger-users.service: Deactivated successfully.
agent # [ 3748.814041] agent systemd[1]: Finished linger-users.service.
agent # [ 3748.814184] agent systemd[1]: Reached target Multi-User System.
client # [ 3748.989479] client dbus-broker-launch[324]: Looking up NSS user entry for 'systemd-timesync'...
client # [ 3748.990427] client dbus-broker-launch[324]: NSS returned no entry for 'systemd-timesync'
client # [ 3748.990427] client dbus-broker-launch[324]: Invalid user-name in /nix/store/hw5jayq2v1cfs4spsqadln3i0wyayl63-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
client # [ 3748.991230] client systemd[1]: Started D-Bus System Message Bus.
client # [ 3748.991517] client systemd[1]: Startup finished in 5.621s.
client # [ 3748.996166] client dbus-broker-launch[324]: Ready
agent # [ 3749.427217] agent dbus-broker-launch[839]: Looking up NSS user entry for 'systemd-timesync'...
agent # [ 3749.428187] agent dbus-broker-launch[839]: NSS returned no entry for 'systemd-timesync'
agent # [ 3749.428231] agent dbus-broker-launch[839]: Invalid user-name in /nix/store/q3c2gxfm178wqgzv8m87na4aa72wxc04-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
agent # [ 3749.428839] agent systemd[1]: Started D-Bus System Message Bus.
agent # [ 3749.430081] agent systemd[1]: Startup finished in 6.052s.
agent # [ 3749.433961] agent dbus-broker-launch[839]: Ready
relay # [ 3749.590401] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:07.552103Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 3749.591122] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:07.552924Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 3749.591214] relay systemd[1]: Started flakelet-relay.
relay # [ 3749.597571] relay systemd[1]: Starting health for flakelet-relay...
relay # [ 3749.972963] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully.
relay # [ 3749.973189] relay systemd[1]: Finished health for flakelet-relay.
relay # [ 3749.997611] relay flakelet[310]: flakelet-relay: updated to generation 1
relay # [ 3749.999491] relay systemd[1]: Finished Update flakelet service flakelet-relay.
relay # [ 3749.999756] relay systemd[1]: Reached target flakelet managed services.
relay # [ 3749.999837] relay systemd[1]: Reached target Multi-User System.
relay # [ 3749.999976] relay systemd[1]: Startup finished in 6.639s.
relay: (finished: waiting for unit flakelet-relay.service, in 7.66 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.01 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.01 seconds)
relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'
relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 0.01 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.02 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 # [ 3750.431880] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:08.393613Z","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 # [ 3750.561451] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:08.523245Z","level":"INFO","message":"deploy accepted","job":"7c688899f50c54534670dd507aceef9c","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3750.431495] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.393269Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 3750.561987] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.523762Z","level":"INFO","message":"start","id":"58bc565a1d56a34acfac5475878adc6a","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3750.563011] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:08.524826Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"58bc565a1d56a34acfac5475878adc6a\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3750.622374] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3750.630247] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3750.634260] agent flakelet[868]: app: using prebuilt artifact /nix/store/6ili1vxjlag9d7dy0bxrbxk6bpi5qh9p-flakelet-app-v2
agent # [ 3750.634911] agent flakelet[868]: app: activating generation 2
agent # [ 3750.647976] agent systemd[1]: Stopping app v1...
agent # [ 3750.648456] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3750.648716] agent systemd[1]: Stopped app v1.
agent # [ 3750.671541] agent systemd[1]: Reload requested from client PID 875 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3750.671607] agent systemd[1]: Reloading...
agent # [ 3751.031016] agent systemd[1]: Reloading finished in 358 ms.
agent # [ 3751.111158] agent systemd[1]: Reload requested from client PID 905 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3751.111196] agent systemd[1]: Reloading...
agent # [ 3751.459109] agent systemd[1]: Reloading finished in 347 ms.
agent # [ 3751.547817] agent systemd[1]: Reload requested from client PID 934 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3751.547859] agent systemd[1]: Reloading...
agent # [ 3751.930763] agent systemd[1]: Reloading finished in 382 ms.
agent # [ 3752.035829] agent systemd[1]: Reload requested from client PID 965 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3752.035871] agent systemd[1]: Reloading...
agent # [ 3752.403539] agent systemd[1]: Reloading finished in 367 ms.
agent # [ 3752.465371] agent systemd[1]: Starting app v2...
agent # [ 3752.504597] agent systemd[1]: Started app v2.
agent # [ 3752.518062] agent flakelet[868]: app: updated to generation 2
agent # [ 3752.520321] 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 3.06 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.01 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.10 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/app 2>&1
agent # [ 3753.597303] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.559100Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"}
agent # [ 3753.725607] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.687397Z","level":"INFO","message":"start","id":"d9cda3c4f0e6c78c5c401c1407920d75","flakelet":"app","rule":"ci","relay":"relay","caller":"Some(\"oidc:mock:repo:github:example/app:ref:refs/heads/main\")","target":"flakelet_relay::agent::conn"}
agent # [ 3753.726443] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:11.688263Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"d9cda3c4f0e6c78c5c401c1407920d75\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3753.785777] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3753.814075] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3753.817521] agent flakelet[1023]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 3753.818140] agent flakelet[1023]: app: activating generation 3
agent # [ 3753.832187] agent systemd[1]: Stopping app v2...
agent # [ 3753.832645] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3753.832922] agent systemd[1]: Stopped app v2.
agent # [ 3753.852667] agent systemd[1]: Reload requested from client PID 1030 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3753.852732] agent systemd[1]: Reloading...
relay # [ 3753.597940] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:11.559735Z","level":"INFO","message":"deploy finished","job":"7c688899f50c54534670dd507aceef9c","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3753.725212] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:11.687022Z","level":"INFO","message":"deploy accepted","job":"4406421f3677d1bf43da05a5e71aa9ae","caller":"oidc:mock:repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3754.213895] agent systemd[1]: Reloading finished in 360 ms.
agent # [ 3754.306525] agent systemd[1]: Reload requested from client PID 1060 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3754.306566] agent systemd[1]: Reloading...
agent # [ 3754.673009] agent systemd[1]: Reloading finished in 366 ms.
agent # [ 3754.759313] agent systemd[1]: Reload requested from client PID 1089 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3754.759355] agent systemd[1]: Reloading...
agent # [ 3755.199125] agent systemd[1]: Reloading finished in 439 ms.
agent # [ 3755.284504] agent systemd[1]: Reload requested from client PID 1120 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3755.284540] agent systemd[1]: Reloading...
agent # [ 3755.647334] agent systemd[1]: Reloading finished in 362 ms.
agent # [ 3755.745163] agent systemd[1]: Starting app v1...
agent # [ 3755.752206] agent systemd[1]: Started app v1.
agent # [ 3755.765721] agent flakelet[1023]: app: updated to generation 3
agent # [ 3755.767555] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/app 2>&1, in 3.15 seconds)
(finished: subtest: deploy with OIDC token, sub principal, in 3.22 seconds)
subtest: policy denies uncovered target
client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' push --relay https://relay:7443 deploy agent/other 2>&1
client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzMSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDMxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJVVkFBS1pKTVRCTTJRPT09IiwibmJmIjoxNzg4NjgyMDMxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.FTzOZnJ6Pu9iW14931gKsorUM2w1fqfmdt2kphEqaNDSb_NWGjDccIOwjbCujKUw7KMUPPxAccDhEpoofvSnCA' 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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzNCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAzNCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVDM0TEtGMlFOSlRISz09PSIsIm5iZiI6MTc4ODY4MjAzNCwic3ViIjoic29tZW9uZSJ9.jlusJ4UCZzWGuXNbNFccZeVsr56DAZMRu9s754iXN67hDsRNwiVZB9_hYs58oILw0HkjYVWe3oPGEnB6e_4nBg' push --relay https://relay:7443 deploy agent/other 2>&1
agent # [ 3756.840044] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.801777Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 3756.940716] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.902429Z","level":"INFO","message":"start","id":"f2b2879a34126884d5b4227259cd78bb","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 3756.941346] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:14.903162Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f2b2879a34126884d5b4227259cd78bb\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3756.995474] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3757.028429] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3757.032192] agent flakelet[1169]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3757.032688] agent flakelet[1169]: other: up to date
agent # [ 3757.034941] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 3756.841247] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:14.802992Z","level":"INFO","message":"deploy finished","job":"4406421f3677d1bf43da05a5e71aa9ae","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3756.940179] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:14.901979Z","level":"INFO","message":"deploy accepted","job":"5e9352d3fc0a3133dcc1a2f1e52ba2bb","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjMzNCwiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc4ODY4MjAzNCwiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiVDM0TEtGMlFOSlRISz09PSIsIm5iZiI6MTc4ODY4MjAzNCwic3ViIjoic29tZW9uZSJ9.jlusJ4UCZzWGuXNbNFccZeVsr56DAZMRu9s754iXN67hDsRNwiVZB9_hYs58oILw0HkjYVWe3oPGEnB6e_4nBg' 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 # [ 3757.585934] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:15.547695Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
relay # [ 3757.586855] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:15.548617Z","level":"INFO","message":"deploy finished","job":"5e9352d3fc0a3133dcc1a2f1e52ba2bb","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3757.607722] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:15] "POST /device HTTP/1.1" 200 -
relay # [ 3758.612980] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:16] "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 # [ 3759.662966] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:07:17] "POST /token HTTP/1.1" 200 -
relay # [ 3759.696440] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:17.658213Z","level":"INFO","message":"deploy accepted","job":"182f2c18e9f14519b24ac69b33adc951","caller":"oidc:mock:groups:wheel","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 3759.696874] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:17.658629Z","level":"INFO","message":"start","id":"3993301ca6447c91a65ccaacb495413a","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 3759.697636] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:17.659431Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3993301ca6447c91a65ccaacb495413a\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3759.741287] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3759.747747] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3759.752570] agent flakelet[1187]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3759.753061] agent flakelet[1187]: other: up to date
agent # [ 3759.754909] 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 1.63 seconds)
client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1
agent # [ 3761.304892] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.266682Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 3761.324705] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.286527Z","level":"INFO","message":"start","id":"f17c730293f26852e031868e720d3c9f","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:groups:wheel\\noidc:mock:someone\")","target":"flakelet_relay::agent::conn"}
agent # [ 3761.325735] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.287564Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"f17c730293f26852e031868e720d3c9f\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3761.372872] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3761.382092] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3761.387788] agent flakelet[1206]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3761.388301] agent flakelet[1206]: other: up to date
agent # [ 3761.388915] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 3761.305552] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.267323Z","level":"INFO","message":"deploy finished","job":"182f2c18e9f14519b24ac69b33adc951","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3761.324403] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.286207Z","level":"INFO","message":"deploy accepted","job":"d22d70a5f872386985f2c47fe927d858","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.63 seconds)
(finished: subtest: push login via device flow, cached token used afterwards, in 4.34 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
relay # [ 3761.931729] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.893512Z","level":"INFO","message":"deploy finished","job":"d22d70a5f872386985f2c47fe927d858","ok":true,"target":"flakelet_relay::relay::api"}
agent # [ 3761.930784] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.892524Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
relay # [ 3761.962438] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:19.924249Z","level":"INFO","message":"deploy accepted","job":"6c70740948a858850d4649517ab7ca16","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 3761.962621] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.924418Z","level":"INFO","message":"start","id":"befecff353fb8d9f60ad1ccd94a20840","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3761.963045] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:19.924864Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"befecff353fb8d9f60ad1ccd94a20840\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3762.018994] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3762.046956] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3762.052572] agent flakelet[1227]: app: using prebuilt artifact /nix/store/8282rnbvyk847q4l4zby3zwcq3jpzrvw-flakelet-app-broken
agent # [ 3762.053234] agent flakelet[1227]: app: activating generation 4
agent # [ 3762.061010] agent systemd[1]: Stopping app v1...
agent # [ 3762.061723] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3762.061925] agent systemd[1]: Stopped app v1.
agent # [ 3762.073495] agent systemd[1]: Reload requested from client PID 1234 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3762.073530] agent systemd[1]: Reloading...
agent # [ 3762.412010] agent systemd[1]: Reloading finished in 338 ms.
agent # [ 3762.499330] agent systemd[1]: Reload requested from client PID 1264 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3762.499372] agent systemd[1]: Reloading...
agent # [ 3762.857971] agent systemd[1]: Reloading finished in 358 ms.
agent # [ 3762.936464] agent systemd[1]: Reload requested from client PID 1293 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3762.936506] agent systemd[1]: Reloading...
agent # [ 3763.325738] agent systemd[1]: Reloading finished in 388 ms.
agent # [ 3763.423901] agent systemd[1]: Reload requested from client PID 1324 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3763.423938] agent systemd[1]: Reloading...
agent # [ 3763.778548] agent systemd[1]: Reloading finished in 354 ms.
agent # [ 3763.853840] agent systemd[1]: Starting app broken...
agent # [ 3763.860705] agent (nonexistent)[1354]: app.service: Unable to locate executable '/nonexistent': No such file or directory
agent # [ 3763.860727] agent (nonexistent)[1354]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory
agent # [ 3763.862180] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC
agent # [ 3763.862315] agent systemd[1]: app.service: Failed with result 'exit-code'.
agent # [ 3763.862662] agent systemd[1]: Failed to start app broken.
agent # [ 3763.897507] agent systemd[1]: Reload requested from client PID 1361 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3763.897558] agent systemd[1]: Reloading...
agent # [ 3764.314619] agent systemd[1]: Reloading finished in 416 ms.
agent # [ 3764.426664] agent systemd[1]: Reload requested from client PID 1392 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3764.426701] agent systemd[1]: Reloading...
agent # [ 3764.789486] agent systemd[1]: Reloading finished in 362 ms.
agent # [ 3764.870096] agent systemd[1]: Reload requested from client PID 1421 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3764.870140] agent systemd[1]: Reloading...
agent # [ 3765.219428] agent systemd[1]: Reloading finished in 348 ms.
agent # [ 3765.315159] agent systemd[1]: Reload requested from client PID 1451 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3765.315197] agent systemd[1]: Reloading...
agent # [ 3765.656905] agent systemd[1]: Reloading finished in 341 ms.
agent # [ 3765.746323] agent systemd[1]: Starting app v1...
agent # [ 3765.753379] agent systemd[1]: Started app v1.
agent # [ 3765.754412] agent flakelet[1227]: app: deploy failed, rolled back: systemctl start app.service failed:
agent # [ 3765.754412] agent flakelet[1227]: failed units: app.service. See journalctl -u app.service
agent # [ 3765.756519] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE
agent # [ 3765.756631] 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 5.39 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.01 seconds)
(finished: subtest: waves: failing first wave skips the second, in 5.41 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
relay # [ 3767.331120] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.292919Z","level":"INFO","message":"deploy finished","job":"6c70740948a858850d4649517ab7ca16","ok":false,"target":"flakelet_relay::relay::api"}
agent # [ 3767.330315] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.292086Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
relay # [ 3767.380995] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.342795Z","level":"INFO","message":"deploy accepted","job":"931b1963a1932ac92f57717607d7f2dc","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3767.381402] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.343190Z","level":"INFO","message":"start","id":"cbda194542977b6644e340cec3225c61","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3767.381896] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.343716Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cbda194542977b6644e340cec3225c61\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3767.441662] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3767.449460] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3767.453935] agent flakelet[1506]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 3767.454452] agent flakelet[1506]: app: up to date
agent # [ 3767.456913] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
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.65 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
relay # [ 3768.009253] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.971027Z","level":"INFO","message":"deploy finished","job":"931b1963a1932ac92f57717607d7f2dc","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3768.034268] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:25.996063Z","level":"INFO","message":"deploy accepted","job":"51343228cba2fcdf38b2ee932146f68c","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3768.008375] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.970117Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 3768.034557] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.996322Z","level":"INFO","message":"start","id":"e321a3293adff274198f74518a9ca5e8","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3768.034914] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:25.996733Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e321a3293adff274198f74518a9ca5e8\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3768.111200] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3768.118747] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3768.123427] agent flakelet[1524]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 3768.123972] agent flakelet[1524]: app: up to date
agent # [ 3768.126678] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
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
relay # [ 3768.676913] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:26.638683Z","level":"INFO","message":"deploy finished","job":"51343228cba2fcdf38b2ee932146f68c","ok":false,"target":"flakelet_relay::relay::api"}
relay # [ 3768.698209] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:26.660028Z","level":"INFO","message":"deploy accepted","job":"dca13ad2193f05d9432a859f2f42f93f","caller":"x509:email:admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3768.676173] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.637846Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 3768.698482] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.660288Z","level":"INFO","message":"start","id":"6e1e092362a0e6efc71bf980fc867dca","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3768.698834] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:26.660656Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"6e1e092362a0e6efc71bf980fc867dca\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3768.750772] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3768.757592] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3768.761990] agent flakelet[1542]: app: using prebuilt artifact /nix/store/hysydfr96ds875vr0jgw5rjxi4p39h2j-flakelet-app-v1
agent # [ 3768.762492] agent flakelet[1542]: app: up to date
agent # [ 3768.762872] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
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.64 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 1.99 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 # [ 3769.314079] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.275763Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"}
agent # [ 3769.371692] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.333459Z","level":"INFO","message":"start","id":"9fd6f38666d05977f29e134860f0c787","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3769.371897] agent flakelet-agent[304]: {"timestamp":"2026-09-06T08:07:27.333726Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"9fd6f38666d05977f29e134860f0c787\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3769.427611] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3769.436650] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3769.440890] agent flakelet[1564]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2
agent # [ 3769.441562] agent flakelet[1564]: app: activating generation 4
agent # [ 3769.455401] agent systemd[1]: Stopping app v1...
agent # [ 3769.455871] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3769.456157] agent systemd[1]: Stopped app v1.
agent # [ 3769.473214] agent systemd[1]: Reload requested from client PID 1571 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3769.473281] agent systemd[1]: Reloading...
relay # [ 3769.314805] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:27.276558Z","level":"INFO","message":"deploy finished","job":"dca13ad2193f05d9432a859f2f42f93f","ok":false,"target":"flakelet_relay::relay::api"}
relay # [ 3769.371423] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:27.333209Z","level":"INFO","message":"deploy accepted","job":"9c2aba91fb4cd62fb4fca17792527552","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3769.825546] agent systemd[1]: Reloading finished in 351 ms.
agent # [ 3769.921527] agent systemd[1]: Reload requested from client PID 1601 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3769.921568] agent systemd[1]: Reloading...
agent # [ 3770.267452] agent systemd[1]: Reloading finished in 345 ms.
agent # [ 3770.352439] agent systemd[1]: Reload requested from client PID 1630 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3770.352476] agent systemd[1]: Reloading...
agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.41 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 # [ 3770.695549] agent systemd[1]: Reloading finished in 342 ms.
agent # [ 3770.788448] agent systemd[1]: Reload requested from client PID 1662 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3770.788485] agent systemd[1]: Reloading...
agent # [ 3771.126298] agent systemd[1]: Reloading finished in 337 ms.
agent # [ 3771.208576] agent systemd[1]: Starting app slow2...
agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 6.49 seconds)
(finished: subtest: detach returns once the job is accepted, in 7.94 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.05 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.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/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 # [ 3777.249072] agent systemd[1]: Started app slow2.
agent # [ 3777.272112] agent flakelet[1564]: app: updated to generation 4
agent # [ 3777.275109] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
agent # [ 3777.309333] agent systemd[1]: Stopping flakelet-agent...
agent # [ 3777.340432] agent systemd[1]: flakelet-agent.service: Deactivated successfully.
agent # [ 3777.340829] agent systemd[1]: Stopped flakelet-agent.
agent # [ 3777.341386] agent systemd[1]: flakelet-agent.service: Consumed 1.544s CPU time over 32.086s wall clock time.
relay # [ 3777.310342] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:35.272106Z","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.06 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
relay # [ 3778.533632] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:36.495384Z","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 # [ 3778.407609] agent systemd[1]: Starting flakelet-agent...
agent # [ 3778.440817] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.402623Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"9fd6f38666d05977f29e134860f0c787\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3778.440980] agent systemd[1]: Started flakelet-agent.
agent # [ 3778.533597] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.495319Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 3779.000983] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:36.962763Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"}
relay # [ 3780.384894] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:38.346672Z","level":"INFO","message":"deploy accepted","job":"efe873aaaa91f693354a5a999eae6d01","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 3780.385339] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:38.347099Z","level":"INFO","message":"start","id":"4391afa6b9ee1ed547162380d3717185","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3780.387112] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:38.347772Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"4391afa6b9ee1ed547162380d3717185\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3780.453332] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3780.494174] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3780.498744] agent flakelet[2127]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3780.499319] agent flakelet[2127]: other: up to date
agent # [ 3780.501720] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 3781.049800] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.011592Z","level":"INFO","message":"deploy finished","job":"efe873aaaa91f693354a5a999eae6d01","ok":true,"target":"flakelet_relay::relay::api"}
agent # [ 3781.049058] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.010819Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
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.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM1OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDU5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzWUxPUVZFVlMyNzdVPT09IiwibmJmIjoxNzg4NjgyMDU5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.nmaaHzYddW4DRKAi63aIkHDB2OW48MEWBXoufS74CMTkxfqP2nPeTy8GtcWrZBvNnmYGtwudB9EZC0HcUMDiCg' push --relay https://relay:7443 agents
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM1OSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDU5LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiIzWUxPUVZFVlMyNzdVPT09IiwibmJmIjoxNzg4NjgyMDU5LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.nmaaHzYddW4DRKAi63aIkHDB2OW48MEWBXoufS74CMTkxfqP2nPeTy8GtcWrZBvNnmYGtwudB9EZC0HcUMDiCg' push --relay https://relay:7443 agents, in 0.02 seconds)
(finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.30 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.03 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.02 seconds)
(finished: subtest: metrics, in 0.02 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=@1788682059 | grep -q 'app-slow'
relay # [ 3781.597885] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.559679Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"}
relay # [ 3781.660577] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:39.622385Z","level":"INFO","message":"deploy accepted","job":"e85a1e72998985266f7693bf3126a7ce","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3781.660960] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.622729Z","level":"INFO","message":"start","id":"927eee0d36bffe1a2541d72efa0bd0cf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3781.661569] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:39.623393Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"927eee0d36bffe1a2541d72efa0bd0cf\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3781.696458] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3781.730132] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3781.734471] agent flakelet[2152]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent # [ 3781.735128] agent flakelet[2152]: app: activating generation 5
agent # [ 3781.743021] agent systemd[1]: Stopping app slow2...
agent # [ 3781.743740] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3781.743877] agent systemd[1]: Stopped app slow2.
agent # [ 3781.752934] agent systemd[1]: Reload requested from client PID 2159 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3781.752970] agent systemd[1]: Reloading...
agent # [ 3782.084038] agent systemd[1]: Reloading finished in 330 ms.
agent # [ 3782.175131] agent systemd[1]: Reload requested from client PID 2189 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3782.175167] agent systemd[1]: Reloading...
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | 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.06 seconds)
agent: must succeed: ss -K dport = 7443
agent # [ 3782.511536] agent systemd[1]: Reloading finished in 335 ms.
agent # [ 3782.596846] agent systemd[1]: Reload requested from client PID 2218 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3782.596891] agent systemd[1]: Reloading...
agent: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds)
agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'updated to generation'
agent # [ 3782.769406] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:40.731061Z","level":"INFO","message":"disconnected: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 3782.939149] agent systemd[1]: Reloading finished in 341 ms.
relay # [ 3782.738057] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:40.699826Z","level":"INFO","message":"agent disconnected: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"}
agent # [ 3783.032204] agent systemd[1]: Reload requested from client PID 2263 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3783.032241] agent systemd[1]: Reloading...
agent # [ 3783.367799] agent systemd[1]: Reloading finished in 335 ms.
agent # [ 3783.452131] agent systemd[1]: Starting app slow...
agent # [ 3783.859985] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:41.821786Z","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 # [ 3785.950633] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:43.912432Z","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: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682059 | grep -q 'updated to generation', in 7.10 seconds)
agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done
agent # [ 3789.520817] agent systemd[1]: Started app slow.
agent # [ 3789.544615] agent flakelet[2152]: app: updated to generation 5
agent # [ 3789.545437] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
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
relay # [ 3790.036990] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:47.998779Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 3790.036950] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:47.998742Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 3790.038049] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:47.999876Z","level":"INFO","message":"start","id":"927eee0d36bffe1a2541d72efa0bd0cf","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 1.02 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 9.30 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 # [ 3790.630954] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:48.592740Z","level":"INFO","message":"deploy finished","job":"e85a1e72998985266f7693bf3126a7ce","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3790.955535] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:48.917258Z","level":"INFO","message":"deploy accepted","job":"012d36b9186571825180908984710eb8","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3790.629999] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.591780Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(5)","target":"flakelet_relay::agent::jobs"}
agent # [ 3790.955974] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.917635Z","level":"INFO","message":"start","id":"98c6067a4d342c1e9cb764dc3857f5ef","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3790.956301] agent flakelet-agent[1714]: {"timestamp":"2026-09-06T08:07:48.918129Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"98c6067a4d342c1e9cb764dc3857f5ef\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3791.013103] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3791.040975] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3791.044203] agent flakelet[2384]: app: using prebuilt artifact /nix/store/ln47rsd5km8a04hd5zlkz4q1v352zqh3-flakelet-app-slow2
agent # [ 3791.044805] agent flakelet[2384]: app: activating generation 6
agent # [ 3791.059764] agent systemd[1]: Stopping app slow...
agent # [ 3791.061574] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3791.061906] agent systemd[1]: Stopped app slow.
agent # [ 3791.080379] agent systemd[1]: Reload requested from client PID 2391 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3791.080450] agent systemd[1]: Reloading...
agent # [ 3791.443896] agent systemd[1]: Reloading finished in 362 ms.
agent # [ 3791.540933] agent systemd[1]: Reload requested from client PID 2421 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3791.540974] agent systemd[1]: Reloading...
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.02 seconds)
agent: must succeed: systemctl restart flakelet-agent
agent # [ 3791.888690] agent systemd[1]: Reloading finished in 347 ms.
agent # [ 3791.971222] agent systemd[1]: Reload requested from client PID 2453 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3791.971264] agent systemd[1]: Reloading...
agent # [ 3792.302871] agent systemd[1]: Reloading finished in 331 ms.
agent # [ 3792.375922] agent systemd[1]: Stopping flakelet-agent...
agent # [ 3792.386475] agent systemd[1]: Reload requested from client PID 2485 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3792.386513] agent systemd[1]: Reloading...
relay # [ 3792.376212] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:50.337952Z","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.90 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 # [ 3792.727143] agent systemd[1]: Reloading finished in 340 ms.
agent # [ 3792.796730] agent systemd[1]: flakelet-agent.service: Deactivated successfully.
agent # [ 3792.796928] agent systemd[1]: Stopped flakelet-agent.
agent # [ 3792.796946] agent systemd[1]: flakelet-agent.service: Consumed 1.014s CPU time over 14.389s wall clock time.
agent # [ 3792.801252] agent systemd[1]: Starting flakelet-agent...
agent # [ 3792.803572] agent systemd[1]: Starting app slow2...
agent # [ 3792.862381] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.824189Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"98c6067a4d342c1e9cb764dc3857f5ef\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3792.862469] agent systemd[1]: Started flakelet-agent.
agent # [ 3792.930517] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.892306Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 3792.931676] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:50.893498Z","level":"INFO","message":"start","id":"98c6067a4d342c1e9cb764dc3857f5ef","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
relay # [ 3792.930551] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:50.892321Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(5), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 3798.884052] agent systemd[1]: Started app slow2.
agent # [ 3798.902287] agent flakelet[2384]: app: updated to generation 6
agent # [ 3798.905451] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 3799.463510] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:57.425256Z","level":"INFO","message":"deploy finished","job":"012d36b9186571825180908984710eb8","ok":true,"target":"flakelet_relay::relay::api"}
agent # [ 3799.462565] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.424317Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(6)","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.05 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=@1788682077 | grep -q 'app-slow'
relay # [ 3800.013550] relay flakelet-relay[400]: {"timestamp":"2026-09-06T08:07:57.975318Z","level":"INFO","message":"deploy accepted","job":"7ec8ea76b10475faaf72f0ea8b7fe5ae","caller":"x509:email:admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3800.013983] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.975746Z","level":"INFO","message":"start","id":"11c1679a0541c468bc55e7684cdfff1f","flakelet":"app","rule":"admins","relay":"relay","caller":"Some(\"x509:email:admin@example.org\")","target":"flakelet_relay::agent::conn"}
agent # [ 3800.014841] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:57.976659Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"11c1679a0541c468bc55e7684cdfff1f\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3800.067729] agent systemd[1]: Starting flakelet update app (via relay)...
agent # [ 3800.098259] agent systemd[1]: Started flakelet update app (via relay).
agent # [ 3800.103166] agent flakelet[2951]: app: using prebuilt artifact /nix/store/c67jj8kx3m50nyj874aqmdqf21w5iznd-flakelet-app-slow
agent # [ 3800.104232] agent flakelet[2951]: app: activating generation 7
agent # [ 3800.117131] agent systemd[1]: Stopping app slow2...
agent # [ 3800.117599] agent systemd[1]: app.service: Deactivated successfully.
agent # [ 3800.117919] agent systemd[1]: Stopped app slow2.
agent # [ 3800.136855] agent systemd[1]: Reload requested from client PID 2958 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3800.136933] agent systemd[1]: Reloading...
agent # [ 3800.487508] agent systemd[1]: Reloading finished in 349 ms.
agent # [ 3800.561093] agent systemd[1]: Reload requested from client PID 2988 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3800.561132] agent systemd[1]: Reloading...
agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1788682077 | grep -q 'app-slow', in 1.02 seconds)
relay: must succeed: systemctl restart flakelet-relay
relay # [ 3801.042274] relay systemd[1]: Stopping flakelet-relay...
relay # [ 3801.077561] relay systemd[1]: flakelet-relay.service: Deactivated successfully.
relay # [ 3801.077847] relay systemd[1]: Stopped flakelet-relay.
relay # [ 3801.077873] relay systemd[1]: flakelet-relay.service: Consumed 2.657s CPU time over 54.583s wall clock time.
relay # [ 3801.096499] relay systemd[1]: Starting flakelet-relay...
agent # [ 3800.899852] agent systemd[1]: Reloading finished in 338 ms.
agent # [ 3800.986368] agent systemd[1]: Reload requested from client PID 3017 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3800.986410] agent systemd[1]: Reloading...
agent # [ 3801.042724] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:07:59.004504Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 3801.335720] agent systemd[1]: Reloading finished in 348 ms.
agent # [ 3801.430582] agent systemd[1]: Reload requested from client PID 3051 ('systemctl') (unit flakelet-relay-job-app.service)...
agent # [ 3801.430619] agent systemd[1]: Reloading...
agent # [ 3801.768962] agent systemd[1]: Reloading finished in 338 ms.
agent # [ 3801.858284] agent systemd[1]: Starting app slow...
agent # [ 3802.115670] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:00.077295Z","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.52 seconds)
client: waiting for success: grep -q '» ok' /tmp/resume.out
relay # [ 3802.546877] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:00.508665Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 3802.547516] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:00.509183Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 3802.547582] relay systemd[1]: Started flakelet-relay.
relay # [ 3804.194186] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:02.155934Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(6), revision: Some(\"prebuilt:app\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"}
agent # [ 3804.194130] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:02.155819Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
agent # [ 3807.925084] agent systemd[1]: Started app slow.
agent # [ 3807.942986] agent flakelet[2951]: app: updated to generation 7
agent # [ 3807.946459] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully.
relay # [ 3808.061470] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:06.023250Z","level":"INFO","message":"job reattached","job":"7ec8ea76b10475faaf72f0ea8b7fe5ae","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"}
agent # [ 3809.025645] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:06.987426Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","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.66 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
relay # [ 3809.652906] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:07.614683Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"x509:email:admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 3809.653356] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:07.615138Z","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 # [ 3809.653865] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:07.615687Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3809.695682] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3809.727045] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3809.732276] agent flakelet[3128]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3809.732826] agent flakelet[3128]: other: up to date
agent # [ 3809.734516] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
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.64 seconds)
relay: must succeed: systemctl restart flakelet-relay
relay # [ 3810.277732] relay flakelet-relay[927]: {"timestamp":"2026-09-06T08:08:08.239479Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"}
relay # [ 3810.290834] relay systemd[1]: Stopping flakelet-relay...
relay # [ 3810.321087] relay systemd[1]: flakelet-relay.service: Deactivated successfully.
relay # [ 3810.321354] relay systemd[1]: Stopped flakelet-relay.
relay # [ 3810.321382] relay systemd[1]: flakelet-relay.service: Consumed 2.322s CPU time over 9.224s wall clock time.
relay # [ 3810.338409] relay systemd[1]: Starting flakelet-relay...
agent # [ 3810.277141] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:08.238921Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 3810.291174] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:08.252995Z","level":"INFO","message":"disconnected: websocket closed","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"}
agent # [ 3811.367986] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:09.329739Z","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.47 seconds)
relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1'
relay # [ 3811.746630] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:09.708348Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"}
relay # [ 3811.747634] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:09.708716Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"}
relay # [ 3811.747109] relay systemd[1]: Started flakelet-relay.
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
relay # [ 3813.447331] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.409075Z","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"}
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.05 seconds)
client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM5MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDkxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI0TUY0Q0JSQVhJWkc0PT09IiwibmJmIjoxNzg4NjgyMDkxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.v02-ELbxgX1trFtP61qGGWw757G5NN9G456hpQw1fZomw9yxwmu5cGH5rtLXhkqVIZn76Nn7mwZxRyufoGgnAg' push --relay https://relay:7443 jobs
agent # [ 3813.447271] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:11.409015Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"}
client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc4ODY4MjM5MSwiZ3JvdXBzIjpbXSwiaWF0IjoxNzg4NjgyMDkxLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI0TUY0Q0JSQVhJWkc0PT09IiwibmJmIjoxNzg4NjgyMDkxLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.v02-ELbxgX1trFtP61qGGWw757G5NN9G456hpQw1fZomw9yxwmu5cGH5rtLXhkqVIZn76Nn7mwZxRyufoGgnAg' 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.25 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.07 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/4c8237dfd41d407bd078b97634ba27eb/events || true
relay # [ 3813.932329] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:11] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=Xa3zpcZvDxfAKZpBIZg7Zv8e48ayIlIdRYT8F6y9tng&code_challenge=F33_-EYEdqsIM0kTV_mSP6uky2IkvuBH8YoASLM7DVw&code_challenge_method=S256 HTTP/1.1" 302 -
relay # [ 3813.977319] relay 93sn3sv24fj26ksccpppzwg6kbf10s4w-device-mock[185]: 127.0.0.1 - - [06/Sep/2026 08:08:11] "POST /token HTTP/1.1" 200 -
relay # [ 3813.978138] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.939946Z","level":"INFO","message":"login","name":"someone","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"}
relay # [ 3814.035470] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:11.997264Z","level":"INFO","message":"job reattached","job":"188b06c4636b65849b3ba8daac22dc7c","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
relay # [ 3814.074742] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.036527Z","level":"INFO","message":"deploy accepted","job":"c9e0f6181e1bb1cf4da2954b1c66fa7e","caller":"oidc:mock:someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
relay # [ 3814.094035] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.055827Z","level":"INFO","message":"job reattached","job":"c9e0f6181e1bb1cf4da2954b1c66fa7e","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"}
agent # [ 3814.075042] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.036823Z","level":"INFO","message":"start","id":"b5f453e8397a7ee21f389aa846be5180","flakelet":"other","rule":"admins","relay":"relay","caller":"Some(\"oidc:mock:someone\\noidc:mock:groups:wheel\")","target":"flakelet_relay::agent::conn"}
agent # [ 3814.075373] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.037207Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"b5f453e8397a7ee21f389aa846be5180\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3814.115210] agent systemd[1]: Starting flakelet update other (via relay)...
agent # [ 3814.157738] agent systemd[1]: Started flakelet update other (via relay).
agent # [ 3814.162219] agent flakelet[3166]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
agent # [ 3814.162699] agent flakelet[3166]: other: up to date
agent # [ 3814.163655] 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/4c8237dfd41d407bd078b97634ba27eb/events || true, in 0.64 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/4c8237dfd41d407bd078b97634ba27eb
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/4c8237dfd41d407bd078b97634ba27eb, 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=4c8237dfd41d407bd078b97634ba27eb' | 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=4c8237dfd41d407bd078b97634ba27eb' | 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 # [ 3814.711704] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.673425Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"}
agent # [ 3814.865179] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.826824Z","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 # [ 3814.865713] agent flakelet-agent[2516]: {"timestamp":"2026-09-06T08:08:12.827531Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5e317fc57863c2a7c03ebe1bdacd1356\"]","target":"flakelet_relay::agent::jobs"}
agent # [ 3814.905917] agent systemd[1]: Starting flakelet update other (via relay)...
agent/otheragent # [ 3814.939115] agent systemd[1]: Started flakelet update other (via relay).
 | agent # [ 3814.943916] agent flakelet[3184]: other: using prebuilt artifact /nix/store/hmr990n0b4v6rpzrcpyyw738r9xi7z95-flakelet-other-v1
flakelet-relay-job-other.service: Deactivated successfully.
agent # [ 3814.944423] agent flakelet[3184]: other: up to date
agent # [ 3814.945896] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully.
relay # [ 3814.864756] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:12.826499Z","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 1.65 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 2.66 seconds)
(finished: run the VM test script, in 73.77 seconds)
test script finished in 73.94s
cleanup
kill NspawnMachine (pid 52)
kill NspawnMachine (pid 53)
relay # [ 3816.498479] relay flakelet-relay[1317]: {"timestamp":"2026-09-06T08:08:14.460273Z","level":"INFO","message":"deploy finished","job":"38796a7ba508eadfe82a1cd5def000bc","ok":true,"target":"flakelet_relay::relay::api"}
kill NspawnMachine (pid 54)
Container agent terminated by signal KILL.
Container client terminated by signal KILL.
Container relay 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 7c688899f50c54534670dd507aceef9c 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 6c70740948a858850d4649517ab7ca16 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 e85a1e72998985266f7693bf3126a7ce 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 5
agent/app | app: updated to generation 5
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 5)
» ok

» job 012d36b9186571825180908984710eb8 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 6
agent/app | app: updated to generation 6
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 6)
» ok

» job 7ec8ea76b10475faaf72f0ea8b7fe5ae 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
flakelet-push: stream: error reading a body from connection, resuming job c5c29e4bc96eb35fa769432617e2a837
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
flakelet-push: https://relay:7443: 404 Not Found: unknown_job: no connected agent knows this job, retrying in 4s
» job 7ec8ea76b10475faaf72f0ea8b7fe5ae via relay 0.1.0 (agents: agent 0.1.0)
» wave 0
agent/app | app: updated to generation 7
agent/app | flakelet-relay-job-app.service: Deactivated successfully.
» agent/app: updated (generation 7)
» ok

1788682087	hist1	x509:email:admin@example.org	agent/other:unchanged
1788682077	c5c29e4bc96eb35fa769432617e2a837	x509:email:admin@example.org	agent/app:updated
1788682068	bab3f2e8a3cb4c3960692f9ef67203f1	x509:email:admin@example.org	agent/app:updated
1788682059	a83454a80b61350a2f72ab7ddd86a01f	x509:email:admin@example.org	agent/app:updated
1788682058	83bd2bbe2cb487fffd24afb4363bc00e	x509:email:admin@example.org	agent/other:unchanged
1788682047	7c35fd6467d21f215c54f5bb5228d614	x509:email:admin@example.org	agent/app:updated
1788682046	f880de0d3de4c5544110e91be18a057e	x509:email:admin@example.org	agent/app:unchanged
1788682045	084d281f1305a8789445510f9fdea61b	x509:email:admin@example.org	agent/app:unchanged
1788682045	5ff3958c58814053439e809bb2d814e0	x509:email:admin@example.org	agent/app:unchanged
1788682039	1d9861a7eec93459c511b111ce0fff03	x509:email:admin@example.org	agent/app:rolled-back
1788682039	6f0a33634dac65ab2b37cddc8a15ce1c	oidc:mock:groups:wheel	agent/other:unchanged
1788682037	f36fb5e34000c14e7c1aac2eae24837d	oidc:mock:groups:wheel	agent/other:unchanged
1788682034	9aed90bd01858acc6d3dd3cdba81df9b	oidc:mock:groups:wheel	agent/other:unchanged
1788682031	00fabb1fb0c04f844ed6e9a686dea144	oidc:mock:repo:github:example/app:ref:refs/heads/main	agent/app:updated
1788682028	cb301dd1dad98892fc40883a6d78404c	x509:email:admin@example.org	agent/app:updated