tribuchet: building on jamie Machine state will be reset. To keep it, pass --keep-machine-state start all VLans (finished: start all VLans, in 0.00 seconds) Initializing machine ID from random generator. Test will time out and terminate in 3600.0 seconds run the VM test script start all VMs agent: systemd-nspawn running (pid 51) agent: Waiting for journal at /build/vm-state-agent/var/log/journal... client: systemd-nspawn running (pid 55) relay: systemd-nspawn running (pid 56) client: Waiting for journal at /build/vm-state-client/var/log/journal... relay: Waiting for journal at /build/vm-state-relay/var/log/journal... (finished: start all VMs, in 0.00 seconds) relay: waiting for unit flakelet-relay.service nixos-nspawn(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. ░ 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. 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 client on /build/vm-state-client. agent # No journal files were found. agent # No journal boot entry found for the specified boot (+0). client # No journal files were found. client # No journal boot entry found for the specified boot (+0). relay # No journal files were found. relay # No journal boot entry found for the specified boot (+0). agent # [1723876.723584] agent systemd-journald[57]: Journal started agent # [1723876.723628] agent systemd-journald[57]: Runtime Journal (/run/log/journal/ea8a77b338724dfeb30912c983fb4987) is 8M, max 4G, 3.9G free. agent # [1723876.733542] agent systemd[1]: Finished Apply Kernel Variables. agent # [1723876.745651] agent systemd[1]: Finished Create Static Device Nodes in /dev gracefully. agent # [1723876.760250] agent systemd[1]: Starting Flush Journal to Persistent Storage... agent # [1723876.760828] agent systemd[1]: Starting Create Static Device Nodes in /dev... agent # [1723876.794654] agent systemd-journald[57]: Time spent on flushing to /var/log/journal/ea8a77b338724dfeb30912c983fb4987 is 1.623ms for 6 entries. agent # [1723876.794654] agent systemd-journald[57]: System Journal (/var/log/journal/ea8a77b338724dfeb30912c983fb4987) is 512B, max 4G, 3.9G free. agent # [1723876.802694] agent systemd[1]: Finished Create Static Device Nodes in /dev. agent # [1723876.803484] agent systemd[1]: Reached target Preparation for Local File Systems. agent # [1723876.803631] agent systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys agent # [1723876.817281] agent systemd[1]: Finished Flush Journal to Persistent Storage. agent # [1723876.881744] agent systemd[1]: Finished Firewall. agent # [1723877.745776] agent systemd[1]: Mounting /run/wrappers... client # [1723876.730924] client systemd-journald[57]: Journal started client # [1723876.730967] client systemd-journald[57]: Runtime Journal (/run/log/journal/0e8c16792dcd41359486fb1a282938f5) is 8M, max 4G, 3.9G free. client # [1723876.741708] client systemd[1]: Finished Apply Kernel Variables. client # [1723876.753945] client systemd[1]: Finished Create Static Device Nodes in /dev gracefully. client # [1723876.788590] client systemd[1]: Starting Flush Journal to Persistent Storage... client # [1723876.789330] client systemd[1]: Starting Create Static Device Nodes in /dev... client # [1723876.798326] client systemd-journald[57]: Time spent on flushing to /var/log/journal/0e8c16792dcd41359486fb1a282938f5 is 1.549ms for 6 entries. client # [1723876.798326] client systemd-journald[57]: System Journal (/var/log/journal/0e8c16792dcd41359486fb1a282938f5) is 512B, max 4G, 3.9G free. client # [1723876.808599] client systemd[1]: Finished Create Static Device Nodes in /dev. client # [1723876.809540] client systemd[1]: Reached target Preparation for Local File Systems. relay # [1723876.721241] relay systemd-journald[57]: Journal started relay # [1723876.721282] relay systemd-journald[57]: Runtime Journal (/run/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342) is 8M, max 4G, 3.9G free. client # [1723876.809686] client systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys relay # [1723876.732065] relay systemd[1]: Finished Apply Kernel Variables. client # [1723876.821708] client systemd[1]: Finished Flush Journal to Persistent Storage. relay # [1723876.744757] relay systemd[1]: Finished Create Static Device Nodes in /dev gracefully. client # [1723876.892230] client systemd[1]: Finished Firewall. relay # [1723876.759271] relay systemd[1]: Starting Flush Journal to Persistent Storage... client # [1723877.745745] client systemd[1]: Mounting /run/wrappers... relay # [1723876.760092] relay systemd[1]: Starting Create Static Device Nodes in /dev... relay # [1723876.794126] relay systemd-journald[57]: Time spent on flushing to /var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342 is 3.268ms for 6 entries. relay # [1723876.794126] relay systemd-journald[57]: System Journal (/var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342) is 512B, max 4G, 3.9G free. relay # [1723876.802752] relay systemd[1]: Finished Create Static Device Nodes in /dev. relay # [1723876.803474] relay systemd[1]: Reached target Preparation for Local File Systems. relay # [1723876.803594] relay systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys relay # [1723876.823442] relay systemd[1]: Finished Flush Journal to Persistent Storage. relay # [1723876.892499] relay systemd[1]: Finished Firewall. relay # [1723877.720242] relay systemd[1]: Mounting /run/wrappers... client # [1723877.767699] client systemd[1]: Mounted /run/wrappers. client # [1723877.768561] client systemd[1]: Reached target Local File Systems. client # [1723877.769454] client systemd[1]: Listening on Boot Loader Control Service Socket. client # [1723877.770484] client systemd[1]: Starting Create SUID/SGID Wrappers... client # [1723877.770514] client systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container client # [1723877.771250] client systemd[1]: Starting Save Transient machine-id to Disk... client # [1723877.771968] client systemd[1]: Starting Create System Files and Directories... client # [1723877.788917] client systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted client # [1723877.789325] client systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted client # [1723877.789635] client systemd-tmpfiles[161]: fchmod() of /var/log/journal/0e8c16792dcd41359486fb1a282938f5 failed: Operation not permitted client # [1723877.789963] client systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted relay # [1723877.777457] relay systemd[1]: Mounted /run/wrappers. relay # [1723877.778552] relay systemd[1]: Reached target Local File Systems. relay # [1723877.779823] relay systemd[1]: Listening on Boot Loader Control Service Socket. relay # [1723877.781128] relay systemd[1]: Starting Create SUID/SGID Wrappers... relay # [1723877.781159] relay systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container relay # [1723877.782058] relay systemd[1]: Starting Save Transient machine-id to Disk... relay # [1723877.782936] relay systemd[1]: Starting Create System Files and Directories... relay # [1723877.799690] relay systemd-tmpfiles[169]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted relay # [1723877.800127] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal failed: Operation not permitted relay # [1723877.800431] relay systemd-tmpfiles[169]: fchmod() of /var/log/journal/f8d9c0a1a610453f8009d5c9ba0e5342 failed: Operation not permitted relay # [1723877.800764] relay systemd-tmpfiles[169]: fchmod() of /run/log/journal failed: Operation not permitted agent # [1723877.777582] agent systemd[1]: Mounted /run/wrappers. agent # [1723877.778888] agent systemd[1]: Reached target Local File Systems. agent # [1723877.780345] agent systemd[1]: Listening on Boot Loader Control Service Socket. agent # [1723877.781516] agent systemd[1]: Starting Create SUID/SGID Wrappers... agent # [1723877.781562] agent systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container agent # [1723877.782620] agent systemd[1]: Starting Save Transient machine-id to Disk... agent # [1723877.783798] agent systemd[1]: Starting Create System Files and Directories... agent # [1723877.802512] agent systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted agent # [1723877.802898] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted agent # [1723877.803198] agent systemd-tmpfiles[161]: fchmod() of /var/log/journal/ea8a77b338724dfeb30912c983fb4987 failed: Operation not permitted agent # [1723877.803527] agent systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted relay # [1723877.803998] relay suid-sgid-wrappers-start[176]: chmod: changing permissions of '/run/wrappers/wrappers.Z82M0ZL3Ow/chsh': Operation not permitted relay # [1723877.868480] relay systemd[1]: etc-machine\x2did.mount: Deactivated successfully. relay # [1723877.883546] relay systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE relay # [1723877.883584] relay systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'. relay # [1723877.908213] relay systemd[1]: Failed to start Create SUID/SGID Wrappers. relay # [1723877.908449] relay systemd[1]: Finished Save Transient machine-id to Disk. relay # [1723877.908764] relay systemd[1]: Finished Create System Files and Directories. relay # [1723877.924213] relay systemd[1]: Starting Rebuild Journal Catalog... relay # [1723877.925203] relay systemd[1]: Starting Record System Boot/Shutdown in UTMP... relay # [1723877.937879] relay systemd[1]: Finished Record System Boot/Shutdown in UTMP. relay # [1723877.943754] relay systemd[1]: Finished Rebuild Journal Catalog. relay # [1723877.945629] relay systemd[1]: Starting Update is Completed... relay # [1723877.956296] relay systemd[1]: Finished Update is Completed. relay # [1723877.956383] relay systemd[1]: Reached target System Initialization. relay # [1723877.956477] relay systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container relay # [1723877.956506] relay systemd[1]: Started Daily Cleanup of Temporary Directories. relay # [1723877.956524] relay systemd[1]: Reached target Timer Units. relay # [1723877.956633] relay systemd[1]: Listening on D-Bus System Message Bus Socket. relay # [1723877.956808] relay systemd[1]: Listening on Nix Daemon Socket. relay # [1723877.956907] relay systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. relay # [1723877.956921] relay systemd[1]: Reached target Socket Units. relay # [1723877.956948] relay systemd[1]: Reached target Basic System. relay # [1723877.958047] relay systemd[1]: Started device-mock.service. relay # [1723877.958747] relay systemd[1]: Starting Re-link flakelet services at boot... relay # [1723877.959738] relay systemd[1]: Starting Import lastlog data into lastlog2 database... relay # [1723877.960768] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)... relay # [1723877.961650] relay systemd[1]: Starting resolvconf update... client # [1723877.792805] client systemd[1]: Finished Create System Files and Directories. client # [1723877.795579] client suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.bcp1gwo66l/chsh': Operation not permitted client # [1723877.860215] client systemd[1]: etc-machine\x2did.mount: Deactivated successfully. client # [1723877.871615] client systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE client # [1723877.871712] client systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'. client # [1723877.871885] client systemd[1]: Failed to start Create SUID/SGID Wrappers. client # [1723877.872112] client systemd[1]: Finished Save Transient machine-id to Disk. client # [1723877.874894] client systemd[1]: Starting Rebuild Journal Catalog... client # [1723877.876058] client systemd[1]: Starting Record System Boot/Shutdown in UTMP... client # [1723877.918168] client systemd[1]: Finished Record System Boot/Shutdown in UTMP. client # [1723877.924890] client systemd[1]: Finished Rebuild Journal Catalog. client # [1723877.926326] client systemd[1]: Starting Update is Completed... client # [1723877.936853] client systemd[1]: Finished Update is Completed. client # [1723877.936943] client systemd[1]: Reached target System Initialization. client # [1723877.937025] client systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container client # [1723877.937048] client systemd[1]: Started Daily Cleanup of Temporary Directories. client # [1723877.937061] client systemd[1]: Reached target Timer Units. client # [1723877.937160] client systemd[1]: Listening on D-Bus System Message Bus Socket. client # [1723877.937372] client systemd[1]: Listening on Nix Daemon Socket. client # [1723877.937467] client systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. client # [1723877.937481] client systemd[1]: Reached target Socket Units. client # [1723877.937510] client systemd[1]: Reached target Basic System. client # [1723877.938646] client systemd[1]: Starting Import lastlog data into lastlog2 database... client # [1723877.939815] client systemd[1]: Starting Name Service Cache Daemon (nsncd)... client # [1723877.940555] client systemd[1]: Starting resolvconf update... client # [1723877.954388] client systemd[1]: Finished Import lastlog data into lastlog2 database. client # [1723878.018651] client systemd[1]: Finished resolvconf update. agent # [1723877.803875] agent suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.8IlBaCviYc/chsh': Operation not permitted agent # [1723877.869076] agent systemd[1]: etc-machine\x2did.mount: Deactivated successfully. agent # [1723877.882770] agent systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE agent # [1723877.882806] agent systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'. agent # [1723877.882859] agent systemd[1]: Failed to start Create SUID/SGID Wrappers. agent # [1723877.883053] agent systemd[1]: Finished Save Transient machine-id to Disk. agent # [1723877.908523] agent systemd[1]: Finished Create System Files and Directories. agent # [1723877.924235] agent systemd[1]: Starting Rebuild Journal Catalog... agent # [1723877.925567] agent systemd[1]: Starting Record System Boot/Shutdown in UTMP... agent # [1723877.938379] agent systemd[1]: Finished Record System Boot/Shutdown in UTMP. agent # [1723877.942526] agent systemd[1]: Finished Rebuild Journal Catalog. agent # [1723877.943548] agent systemd[1]: Starting Update is Completed... agent # [1723877.952068] agent systemd[1]: Finished Update is Completed. agent # [1723877.952193] agent systemd[1]: Reached target System Initialization. agent # [1723877.952255] agent systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container agent # [1723877.952276] agent systemd[1]: Started Daily Cleanup of Temporary Directories. agent # [1723877.952289] agent systemd[1]: Reached target Timer Units. agent # [1723877.952381] agent systemd[1]: Listening on D-Bus System Message Bus Socket. agent # [1723877.952565] agent systemd[1]: Listening on Nix Daemon Socket. agent # [1723877.952657] agent systemd[1]: Listening on Virtual Machine and Container Registration Service Socket. agent # [1723877.952670] agent systemd[1]: Reached target Socket Units. agent # [1723877.952699] agent systemd[1]: Reached target Basic System. agent # [1723877.953739] agent systemd[1]: Starting Re-link flakelet services at boot... agent # [1723877.954373] agent systemd[1]: Starting Import lastlog data into lastlog2 database... agent # [1723877.955182] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)... agent # [1723877.955831] agent systemd[1]: Starting resolvconf update... agent # [1723877.963647] agent systemd[1]: Finished Re-link flakelet services at boot. agent # [1723877.965172] agent systemd[1]: Starting Reconcile flakelet services with the host configuration... agent # [1723877.974733] agent systemd[1]: Finished Import lastlog data into lastlog2 database. agent # [1723877.975077] agent systemd[1]: Finished Reconcile flakelet services with the host configuration. relay # [1723877.971294] relay systemd[1]: Finished Re-link flakelet services at boot. relay # [1723877.972700] relay systemd[1]: Starting Reconcile flakelet services with the host configuration... relay # [1723877.978470] relay systemd[1]: Finished Import lastlog data into lastlog2 database. relay # [1723877.984964] relay systemd[1]: Finished Reconcile flakelet services with the host configuration. relay # [1723878.046182] relay systemd[1]: nscd.service: Deactivated successfully. relay # [1723878.046306] relay systemd[1]: Stopped Name Service Cache Daemon (nsncd). relay # [1723878.048648] relay systemd[1]: Starting Name Service Cache Daemon (nsncd)... relay # [1723878.084344] relay systemd[1]: Finished resolvconf update. relay # [1723878.084565] relay systemd[1]: Reached target Preparation for Network. relay # [1723878.085423] relay systemd[1]: Starting Address configuration of eth1... relay # [1723878.086176] relay systemd[1]: Starting Extra networking commands.... relay # [1723878.107315] relay network-addresses-eth1-start[251]: adding address 192.168.1.3/24... done relay # [1723878.110418] relay network-addresses-eth1-start[251]: adding address 2001:db8:1::3/64... done relay # [1723878.114405] relay systemd[1]: Finished Address configuration of eth1. relay # [1723878.154887] relay systemd[1]: Finished Extra networking commands.. relay # [1723878.154975] relay systemd[1]: Reached target Network. relay # [1723878.160357] relay systemd[1]: Starting Dnsmasq Daemon... relay # [1723878.166964] relay systemd[1]: Starting Nginx Web Server... relay # [1723878.167727] relay systemd[1]: Starting Update flakelet service flakelet-relay... relay # [1723878.209815] relay flakelet[311]: flakelet-relay: using prebuilt artifact /nix/store/jfcc1waibf4w5cwgizlwlq212x74y7c1-flakelet-flakelet-relay relay # [1723878.210471] relay flakelet[311]: flakelet-relay: activating generation 1 relay # [1723878.215558] relay systemd[1]: Reload requested from client PID 316 ('systemctl') (unit flakelet-flakelet-relay.service)... relay # [1723878.215597] relay systemd[1]: Reloading... client # [1723878.019483] client systemd[1]: Reached target Preparation for Network. client # [1723878.046288] client systemd[1]: Starting Address configuration of eth1... client # [1723878.047303] client systemd[1]: Starting Extra networking commands.... client # [1723878.055783] client systemd[1]: nscd.service: Deactivated successfully. client # [1723878.084289] client systemd[1]: Stopped Name Service Cache Daemon (nsncd). client # [1723878.087610] client systemd[1]: Starting Name Service Cache Daemon (nsncd)... client # [1723878.102569] client network-addresses-eth1-start[233]: adding address 192.168.1.2/24... done client # [1723878.106238] client network-addresses-eth1-start[233]: adding address 2001:db8:1::2/64... done client # [1723878.110214] client systemd[1]: Finished Address configuration of eth1. client # [1723878.166899] client systemd[1]: nscd.service: Deactivated successfully. client # [1723878.167056] client systemd[1]: Stopped Name Service Cache Daemon (nsncd). client # [1723878.168490] client systemd[1]: Finished Extra networking commands.. client # [1723878.169224] client systemd[1]: Reached target Network. client # [1723878.200578] client systemd[1]: Starting Name Service Cache Daemon (nsncd)... agent # [1723878.046790] agent systemd[1]: nscd.service: Deactivated successfully. agent # [1723878.047019] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd). agent # [1723878.084647] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)... agent # [1723878.084882] agent systemd[1]: Finished resolvconf update. agent # [1723878.086121] agent systemd[1]: Reached target Preparation for Network. agent # [1723878.087719] agent systemd[1]: Starting Address configuration of eth1... agent # [1723878.088847] agent systemd[1]: Starting Extra networking commands.... agent # [1723878.109017] agent network-addresses-eth1-start[241]: adding address 192.168.1.1/24... done agent # [1723878.112252] agent network-addresses-eth1-start[241]: adding address 2001:db8:1::1/64... done agent # [1723878.117192] agent systemd[1]: Finished Address configuration of eth1. agent # [1723878.171959] agent systemd[1]: nscd.service: Deactivated successfully. agent # [1723878.200227] agent systemd[1]: Stopped Name Service Cache Daemon (nsncd). agent # [1723878.202069] agent systemd[1]: Finished Extra networking commands.. agent # [1723878.202862] agent systemd[1]: Reached target Network. agent # [1723878.204091] agent systemd[1]: Starting Name Service Cache Daemon (nsncd)... agent # [1723878.204920] agent systemd[1]: Starting Update flakelet service app... agent # [1723878.205953] agent systemd[1]: Starting Update flakelet service flakelet-agent... agent # [1723878.206953] agent systemd[1]: Starting Update flakelet service other... agent # [1723878.216236] agent flakelet[308]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 agent # [1723878.216774] agent flakelet[308]: app: activating generation 1 agent # [1723878.217902] agent flakelet[309]: flakelet-agent: using prebuilt artifact /nix/store/aj0lf71lc5h1sqimklbn8wyidli7z0sx-flakelet-flakelet-agent agent # [1723878.218437] agent flakelet[309]: flakelet-agent: activating generation 1 agent # [1723878.219835] agent systemd[1]: Reload requested from client PID 312 ('systemctl') (unit flakelet-app.service)... agent # [1723878.219872] agent systemd[1]: Reloading... agent # [1723878.220174] agent flakelet[310]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723878.220672] agent flakelet[310]: other: activating generation 1 relay # [1723878.499890] relay nsncd[242]: Oct 01 12:03:06.787 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" relay # [1723878.624707] relay systemd[1]: Reloading finished in 408 ms. client # [1723878.549727] client nsncd[303]: Oct 01 12:03:06.837 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" client # [1723878.549728] client systemd[1]: Started Name Service Cache Daemon (nsncd). client # [1723878.549813] client systemd[1]: Reached target Host and Network Name Lookups. client # [1723878.549930] client systemd[1]: Reached target User and Group Name Lookups. client # [1723878.552540] client systemd[1]: Starting User Login Management... client # [1723878.554030] client systemd[1]: Starting Permit User Sessions... client # [1723878.590210] client systemd[1]: Finished Permit User Sessions. client # [1723878.591559] client systemd[1]: Started Console Getty. client # [1723878.591583] client systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 client # [1723878.591595] client systemd[1]: Reached target Login Prompts. agent # [1723878.556045] agent nsncd[307]: Oct 01 12:03:06.843 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket" agent # [1723878.628845] agent systemd[1]: Reloading finished in 408 ms. agent # [1723878.763904] agent systemd[1]: Started Name Service Cache Daemon (nsncd). agent # [1723878.767011] agent systemd[1]: Reload requested from client PID 313 ('systemctl') (unit flakelet-flakelet-agent.service)... agent # [1723878.767056] agent systemd[1]: Reloading... relay # [1723878.763380] relay systemd[1]: Started Name Service Cache Daemon (nsncd). relay # [1723878.763867] relay systemd[1]: Reached target Host and Network Name Lookups. relay # [1723878.763950] relay systemd[1]: Reached target User and Group Name Lookups. relay # [1723878.765112] relay systemd[1]: Starting User Login Management... relay # [1723878.765865] relay systemd[1]: Starting Permit User Sessions... relay # [1723878.786978] relay systemd[1]: Reload requested from client PID 357 ('systemctl') (unit flakelet-flakelet-relay.service)... relay # [1723878.787052] relay systemd[1]: Reloading... relay # [1723878.850348] relay dnsmasq-pre-start[375]: dnsmasq: syntax check OK. agent # [1723879.154383] agent systemd[1]: Reloading finished in 386 ms. agent # [1723879.297154] agent systemd[1]: Reload requested from client PID 314 ('systemctl') (unit flakelet-other.service)... agent # [1723879.297203] agent systemd[1]: Reloading... relay # [1723879.148110] relay systemd[1]: Reloading finished in 360 ms. relay # [1723879.268603] relay systemd[1]: Finished Permit User Sessions. relay # [1723879.272616] relay systemd[1]: Started Console Getty. relay # [1723879.272684] relay systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 relay # [1723879.272749] relay systemd[1]: Reached target Login Prompts. relay # [1723879.296471] relay systemd[1]: Starting flakelet-relay... agent # [1723879.641572] agent systemd[1]: Reloading finished in 343 ms. agent # [1723879.717699] agent systemd[1]: Reached target Host and Network Name Lookups. agent # [1723879.717761] agent systemd[1]: Reached target User and Group Name Lookups. agent # [1723879.719144] agent systemd[1]: Starting User Login Management... agent # [1723879.720149] agent systemd[1]: Starting Permit User Sessions... agent # [1723879.724172] agent systemd[1]: Reload requested from client PID 405 ('systemctl') (unit flakelet-flakelet-agent.service)... agent # [1723879.724204] agent systemd[1]: Reloading... relay # [1723879.768125] relay nginx-pre-start[402]: nginx: the configuration file /nix/store/rwna8pp008by3mwnv5bx8ims12jy7ca2-nginx.conf syntax is ok relay # [1723879.768746] relay nginx-pre-start[402]: nginx: configuration file /nix/store/rwna8pp008by3mwnv5bx8ims12jy7ca2-nginx.conf test is successful relay # [1723879.801300] relay systemd[1]: Started Nginx Web Server. relay # [1723879.889896] relay systemd[1]: Starting D-Bus System Message Bus... client # [1723879.959131] client systemd-logind[315]: New seat seat0. client # [1723879.959672] client systemd[1]: Started User Login Management. client # [1723879.961888] client systemd[1]: Starting D-Bus System Message Bus... client # [1723879.963485] client systemd[1]: Starting linger-users.service... client # [1723880.002489] client systemd[1]: linger-users.service: Deactivated successfully. client # [1723880.002862] client systemd[1]: Finished linger-users.service. client # [1723880.003217] client systemd[1]: Reached target Multi-User System. relay # [1723880.188223] relay systemd-logind[354]: New seat seat0. relay # [1723880.188657] relay systemd[1]: Started User Login Management. relay # [1723880.192438] relay systemd[1]: Starting linger-users.service... relay # [1723880.232257] relay systemd[1]: linger-users.service: Deactivated successfully. relay # [1723880.232611] relay systemd[1]: Finished linger-users.service. relay # [1723880.434403] relay dbus-broker-launch[408]: Looking up NSS user entry for 'systemd-timesync'... relay # [1723880.435970] relay dbus-broker-launch[408]: NSS returned no entry for 'systemd-timesync' relay # [1723880.435970] relay dbus-broker-launch[408]: Invalid user-name in /nix/store/95gfk1imjmlbwin4q78zl8gp4aam6lf4-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" relay # [1723880.436921] relay systemd[1]: Started D-Bus System Message Bus. agent # [1723880.130145] agent systemd[1]: Reloading finished in 405 ms. agent # [1723880.195147] agent systemd[1]: Finished Permit User Sessions. agent # [1723880.220628] agent systemd[1]: Started Console Getty. agent # [1723880.220696] agent systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0 agent # [1723880.220768] agent systemd[1]: Reached target Login Prompts. agent # [1723880.225208] agent systemd[1]: Reload requested from client PID 409 ('systemctl') (unit flakelet-app.service)... agent # [1723880.225237] agent systemd[1]: Reloading... relay # [1723880.441963] relay dbus-broker-launch[408]: Ready relay # [1723880.445384] relay systemd[1]: Started Dnsmasq Daemon. relay # [1723880.448058] relay dnsmasq[394]: started, version 2.93 cachesize 150 relay # [1723880.448124] 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 # [1723880.448138] relay dnsmasq[394]: DBus support enabled: connected to system bus relay # [1723880.448154] relay dnsmasq[394]: no upstream servers configured - please set them from DBus relay # [1723880.448314] relay dnsmasq[394]: read /etc/hosts - 9 names client # [1723880.498887] client dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'... client # [1723880.500079] client dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync' client # [1723880.500079] client dbus-broker-launch[325]: Invalid user-name in /nix/store/87clbw76nins7jrhaxxqysv9xs5dc1i5-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" client # [1723880.500644] client systemd[1]: Started D-Bus System Message Bus. client # [1723880.501126] client systemd[1]: Startup finished in 4.216s. client # [1723880.507060] client dbus-broker-launch[325]: Ready agent # [1723880.578920] agent systemd[1]: Reloading finished in 353 ms. agent # [1723880.653394] agent systemd[1]: Starting flakelet-agent... agent # [1723880.653605] agent systemd[1]: Reload requested from client PID 444 ('systemctl') (unit flakelet-other.service)... agent # [1723880.653653] agent systemd[1]: Reloading... agent # [1723880.718663] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:09.006123Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"} agent # [1723880.992112] agent systemd[1]: Reloading finished in 338 ms. agent # [1723881.075430] agent systemd[1]: Started flakelet-agent. agent # [1723881.081371] agent systemd[1]: Starting app v1... agent # [1723881.083060] agent systemd[1]: Starting other v1... agent # [1723881.087475] agent flakelet[309]: flakelet-agent: updated to generation 1 agent # [1723881.113202] agent systemd[1]: Finished Update flakelet service flakelet-agent. agent # [1723881.117680] agent systemd[1]: Started other v1. agent # [1723881.117825] agent systemd-logind[407]: New seat seat0. agent # [1723881.117830] agent systemd[1]: Started app v1. agent # [1723881.117980] agent systemd[1]: Started User Login Management. agent # [1723881.120533] agent systemd[1]: Starting D-Bus System Message Bus... agent # [1723881.121423] agent systemd[1]: Starting linger-users.service... agent # [1723881.124820] agent flakelet[310]: other: updated to generation 1 agent # [1723881.125290] agent flakelet[308]: app: updated to generation 1 agent # [1723881.127591] agent systemd[1]: Finished Update flakelet service app. agent # [1723881.127812] agent systemd[1]: Finished Update flakelet service other. agent # [1723881.128618] agent systemd[1]: Reached target flakelet managed services. agent # [1723881.134759] agent systemd[1]: linger-users.service: Deactivated successfully. agent # [1723881.134904] agent systemd[1]: Finished linger-users.service. agent # [1723881.135076] agent systemd[1]: Reached target Multi-User System. relay # [1723881.274174] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:09.561605Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"} relay # [1723881.274962] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:09.562144Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"} relay # [1723881.274767] relay systemd[1]: Started flakelet-relay. relay # [1723881.285630] relay systemd[1]: Starting health for flakelet-relay... relay # [1723881.549120] relay systemd[1]: flakelet-relay-health.service: Deactivated successfully. relay # [1723881.549543] relay systemd[1]: Finished health for flakelet-relay. relay # [1723881.568036] relay flakelet[311]: flakelet-relay: updated to generation 1 relay # [1723881.570873] relay systemd[1]: Finished Update flakelet service flakelet-relay. relay # [1723881.571472] relay systemd[1]: Reached target flakelet managed services. relay # [1723881.571659] relay systemd[1]: Reached target Multi-User System. relay # [1723881.571906] relay systemd[1]: Startup finished in 5.288s. relay: (finished: waiting for unit flakelet-relay.service, in 6.17 seconds) relay: waiting for unit nginx.service relay: (finished: waiting for unit nginx.service, in 0.02 seconds) agent: waiting for unit flakelet.target agent: (finished: waiting for unit flakelet.target, in 0.02 seconds) agent: waiting for unit flakelet-agent.service agent # [1723881.569581] agent dbus-broker-launch[897]: Looking up NSS user entry for 'systemd-timesync'... agent # [1723881.571148] agent dbus-broker-launch[897]: NSS returned no entry for 'systemd-timesync' agent # [1723881.571148] agent dbus-broker-launch[897]: Invalid user-name in /nix/store/jg4hdwp4bn0pbiqkxaybjr51bdgpqjb9-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync" agent # [1723881.571649] agent systemd[1]: Started D-Bus System Message Bus. agent # [1723881.577077] agent systemd[1]: Startup finished in 5.293s. agent # [1723881.577718] agent dbus-broker-launch[897]: Ready agent: (finished: waiting for unit flakelet-agent.service, in 0.02 seconds) client: waiting for unit multi-user.target client: (finished: waiting for unit multi-user.target, in 0.02 seconds) relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1' relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 1.03 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/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-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/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1 relay # [1723882.733071] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:11.020496Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: None, revision: None }, Named { name: \"flakelet-agent\", generation: None, revision: None }, Named { name: \"other\", generation: None, revision: None }]","target":"flakelet_relay::relay::agent_conn"} relay # [1723883.077487] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:11.364813Z","level":"INFO","message":"deploy accepted","job":"86a81216942784b0ee6f88e96d36cd9e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723882.733036] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.020444Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} agent # [1723882.744954] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.032437Z","level":"INFO","message":"local change","flakelet":"app","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"} agent # [1723882.745389] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.032883Z","level":"INFO","message":"local change","flakelet":"flakelet-agent","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"} agent # [1723882.745585] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.033073Z","level":"INFO","message":"local change","flakelet":"other","generation":1,"by":"host activation","target":"flakelet_relay::agent::jobs"} agent # [1723883.077874] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.365130Z","level":"INFO","message":"start","id":"ec90ace156c268c796fbd51fd41b4977","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723883.078126] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:11.365484Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"ec90ace156c268c796fbd51fd41b4977\"]","target":"flakelet_relay::agent::jobs"} agent # [1723883.116284] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723883.145241] agent systemd[1]: Started flakelet update app (via relay). agent # [1723883.150068] agent flakelet[921]: app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2 agent # [1723883.150780] agent flakelet[921]: app: activating generation 2 agent # [1723883.169063] agent systemd[1]: Stopping app v1... agent # [1723883.170731] agent systemd[1]: app.service: Deactivated successfully. agent # [1723883.171014] agent systemd[1]: Stopped app v1. agent # [1723883.188121] agent systemd[1]: Reload requested from client PID 928 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723883.188190] agent systemd[1]: Reloading... agent # [1723883.537029] agent systemd[1]: Reloading finished in 348 ms. agent # [1723883.613711] agent systemd[1]: Reload requested from client PID 958 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723883.613750] agent systemd[1]: Reloading... agent # [1723883.949132] agent systemd[1]: Reloading finished in 334 ms. agent # [1723884.035079] agent systemd[1]: Reload requested from client PID 987 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723884.035120] agent systemd[1]: Reloading... agent # [1723884.368965] agent systemd[1]: Reloading finished in 333 ms. agent # [1723884.441795] agent systemd[1]: Reload requested from client PID 1018 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723884.441832] agent systemd[1]: Reloading... agent # [1723884.777238] agent systemd[1]: Reloading finished in 335 ms. agent # [1723884.846899] agent systemd[1]: Starting app v2... agent # [1723884.885344] agent systemd[1]: Started app v2. agent # [1723884.891404] agent flakelet[921]: app: updated to generation 2 agent # [1723884.894453] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. client: (finished: must succeed: push --relay-srv test --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app 2>&1, in 2.92 seconds) agent: must succeed: systemctl show app.service -p Description | grep -q 'app v2' agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v2', in 0.02 seconds) agent: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2' agent: (finished: must succeed: journalctl -u flakelet-relay-job-app.service | grep -q 'generation 2', in 0.01 seconds) agent: must succeed: flakelet status --json app | jq -c '.[0].changed.by' agent: (finished: must succeed: flakelet status --json app | jq -c '.[0].changed.by', in 0.02 seconds) (finished: subtest: deploy with client certificate, relay found via SRV, in 2.99 seconds) subtest: deploy with OIDC token, sub principal agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-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/cqj0khcw75fy7djy7y554bcgxi50911r-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds) client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/app 2>&1 agent # [1723885.970134] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.257563Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(2)","target":"flakelet_relay::agent::jobs"} agent # [1723886.132581] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.419923Z","level":"INFO","message":"start","id":"71272a98b77e554d9fda8f48706b143d","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"repo:github:example/app:ref:refs/heads/main\"","target":"flakelet_relay::agent::conn"} agent # [1723886.132797] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:14.420298Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"71272a98b77e554d9fda8f48706b143d\"]","target":"flakelet_relay::agent::jobs"} agent # [1723886.170616] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723886.199166] agent systemd[1]: Started flakelet update app (via relay). agent # [1723886.203025] agent flakelet[1087]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 agent # [1723886.203669] agent flakelet[1087]: app: activating generation 3 agent # [1723886.218367] agent systemd[1]: Stopping app v2... agent # [1723886.218814] agent systemd[1]: app.service: Deactivated successfully. agent # [1723886.219085] agent systemd[1]: Stopped app v2. agent # [1723886.236503] agent systemd[1]: Reload requested from client PID 1094 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723886.236575] agent systemd[1]: Reloading... relay # [1723885.971381] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:14.258794Z","level":"INFO","message":"deploy finished","job":"86a81216942784b0ee6f88e96d36cd9e","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723886.132238] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:14.419692Z","level":"INFO","message":"deploy accepted","job":"34297ea70f89701d7d9bb78619ec8d12","caller":"repo:github:example/app:ref:refs/heads/main","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723886.584759] agent systemd[1]: Reloading finished in 347 ms. agent # [1723886.659521] agent systemd[1]: Reload requested from client PID 1124 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723886.659562] agent systemd[1]: Reloading... agent # [1723886.991834] agent systemd[1]: Reloading finished in 331 ms. agent # [1723887.081330] agent systemd[1]: Reload requested from client PID 1156 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723887.081367] agent systemd[1]: Reloading... agent # [1723887.421640] agent systemd[1]: Reloading finished in 339 ms. agent # [1723887.517180] agent systemd[1]: Reload requested from client PID 1188 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723887.517216] agent systemd[1]: Reloading... agent # [1723887.853373] agent systemd[1]: Reloading finished in 335 ms. agent # [1723887.937618] agent systemd[1]: Starting app v1... agent # [1723887.969215] agent systemd[1]: Started app v1. agent # [1723887.974052] agent flakelet[1087]: app: updated to generation 3 agent # [1723887.976411] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/app 2>&1, in 2.96 seconds) (finished: subtest: deploy with OIDC token, sub principal, in 3.03 seconds) subtest: policy denies uncovered target client: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' push --relay https://relay:7443 deploy agent/other 2>&1 client: (finished: must fail: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MTk0LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJUSVVYTk1ZSEVNMjRPPT09IiwibmJmIjoxNzkwODU2MTk0LCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.SDkxuITth6KpfptbLERW9EUEItWvFqkJn4XfLfg_hn2ZiG4m0SaCJZPoWw5nH0EgoFJoicunMT_PQ2z-e7IxAg' 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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'someone' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds) client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDg1NjE5NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMjVHQTJUSTJRM0ZPND09PSIsIm5iZiI6MTc5MDg1NjE5Nywic3ViIjoic29tZW9uZSJ9.qTwWmVDFk7U2Z5X5yNOBB8po7yAJuJD6msGKcbThh73ecXMNGENJZbvM4PZxFgIncZMB6uTGtxCOwQjNUEI1CQ' push --relay https://relay:7443 deploy agent/other 2>&1 relay # [1723889.055603] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:17.343012Z","level":"INFO","message":"deploy finished","job":"34297ea70f89701d7d9bb78619ec8d12","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723889.158574] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:17.446032Z","level":"INFO","message":"deploy accepted","job":"87ef92a677acc0f8f4b6a914fbf1987c","caller":"someone","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"} agent # [1723889.054216] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.341627Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(3)","target":"flakelet_relay::agent::jobs"} agent # [1723889.159108] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.446428Z","level":"INFO","message":"start","id":"1bc1ae54859c737c0bfe42337f68e065","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"someone\"","target":"flakelet_relay::agent::conn"} agent # [1723889.159432] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:17.446926Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"1bc1ae54859c737c0bfe42337f68e065\"]","target":"flakelet_relay::agent::jobs"} agent # [1723889.201420] agent systemd[1]: Starting flakelet update other (via relay)... agent # [1723889.234259] agent systemd[1]: Started flakelet update other (via relay). agent # [1723889.239208] agent flakelet[1242]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723889.239671] agent flakelet[1242]: other: up to date agent # [1723889.242207] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully. client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjQ5NywiZ3JvdXBzIjpbIndoZWVsIl0sImlhdCI6MTc5MDg1NjE5NywiaXNzIjoiaHR0cHM6Ly9yZWxheTo4NDQzIiwianRpIjoiMjVHQTJUSTJRM0ZPND09PSIsIm5iZiI6MTc5MDg1NjE5Nywic3ViIjoic29tZW9uZSJ9.qTwWmVDFk7U2Z5X5yNOBB8po7yAJuJD6msGKcbThh73ecXMNGENJZbvM4PZxFgIncZMB6uTGtxCOwQjNUEI1CQ' push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds) (finished: subtest: claim principal from groups, unchanged counts as success, in 0.70 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 relay # [1723889.783788] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:18.071195Z","level":"INFO","message":"deploy finished","job":"87ef92a677acc0f8f4b6a914fbf1987c","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723889.807359] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:18] "POST /device HTTP/1.1" 200 - agent # [1723889.782418] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:18.069827Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"} relay # [1723890.812459] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:19] "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 agent # [1723891.891794] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.179245Z","level":"INFO","message":"start","id":"3e233ab2eb367d8740e8b7a62d9933ee","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723891.892640] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.179961Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"3e233ab2eb367d8740e8b7a62d9933ee\"]","target":"flakelet_relay::agent::jobs"} agent # [1723891.935492] agent systemd[1]: Starting flakelet update other (via relay)... agent # [1723891.969612] agent systemd[1]: Started flakelet update other (via relay). agent # [1723891.974923] agent flakelet[1266]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723891.975467] agent flakelet[1266]: other: up to date agent # [1723891.976924] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully. relay # [1723891.859922] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:03:20] "POST /token HTTP/1.1" 200 - relay # [1723891.891378] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.178832Z","level":"INFO","message":"deploy accepted","job":"95053516e55514095bfa17b77df7c77e","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"} client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.65 seconds) client: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1 relay # [1723892.517312] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.804722Z","level":"INFO","message":"deploy finished","job":"95053516e55514095bfa17b77df7c77e","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723892.535968] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:20.823415Z","level":"INFO","message":"deploy accepted","job":"84cc3b1f030bc93248646e4b449d2570","caller":"dev@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"} agent # [1723892.516306] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.803738Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"} agent # [1723892.536291] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.823779Z","level":"INFO","message":"start","id":"fff8bfaab99afe8c63d44872308c7058","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"dev@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723892.536494] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:20.823995Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"fff8bfaab99afe8c63d44872308c7058\"]","target":"flakelet_relay::agent::jobs"} agent # [1723892.575795] agent systemd[1]: Starting flakelet update other (via relay)... agent # [1723892.604249] agent systemd[1]: Started flakelet update other (via relay). agent # [1723892.608709] agent flakelet[1286]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723892.609277] agent flakelet[1286]: other: up to date agent # [1723892.612581] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully. client: (finished: must succeed: push --relay https://relay:7443 deploy agent/other 2>&1, in 0.64 seconds) (finished: subtest: push login via device flow, cached token used afterwards, in 3.37 seconds) subtest: waves: failing first wave skips the second agent: must succeed: jq '.services.app.prebuilt="/nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-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/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1 agent # [1723893.154690] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.442153Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"} agent # [1723893.192083] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.479564Z","level":"INFO","message":"start","id":"cc564c1f4cf1d674dd817f94d316c731","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723893.192305] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:21.479805Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"cc564c1f4cf1d674dd817f94d316c731\"]","target":"flakelet_relay::agent::jobs"} agent # [1723893.230165] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723893.263187] agent systemd[1]: Started flakelet update app (via relay). agent # [1723893.267771] agent flakelet[1313]: app: using prebuilt artifact /nix/store/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-flakelet-app-broken agent # [1723893.268446] agent flakelet[1313]: app: activating generation 4 agent # [1723893.286282] agent systemd[1]: Stopping app v1... agent # [1723893.286735] agent systemd[1]: app.service: Deactivated successfully. agent # [1723893.286996] agent systemd[1]: Stopped app v1. agent # [1723893.304176] agent systemd[1]: Reload requested from client PID 1320 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723893.304244] agent systemd[1]: Reloading... relay # [1723893.155538] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:21.442959Z","level":"INFO","message":"deploy finished","job":"84cc3b1f030bc93248646e4b449d2570","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723893.191801] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:21.479242Z","level":"INFO","message":"deploy accepted","job":"1c2a28ffb5c770daeba76919b2dbd4b1","caller":"admin@example.org","targets":"[\"agent/app\", \"agent/other\"]","target":"flakelet_relay::relay::api"} agent # [1723893.648933] agent systemd[1]: Reloading finished in 343 ms. agent # [1723893.717845] agent systemd[1]: Reload requested from client PID 1350 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723893.717884] agent systemd[1]: Reloading... agent # [1723894.050214] agent systemd[1]: Reloading finished in 331 ms. agent # [1723894.116983] agent systemd[1]: Reload requested from client PID 1379 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723894.117029] agent systemd[1]: Reloading... agent # [1723894.448309] agent systemd[1]: Reloading finished in 330 ms. agent # [1723894.513401] agent systemd[1]: Reload requested from client PID 1410 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723894.513439] agent systemd[1]: Reloading... agent # [1723894.844652] agent systemd[1]: Reloading finished in 330 ms. agent # [1723894.921725] agent systemd[1]: Starting app broken... agent # [1723894.929309] agent (nonexistent)[1443]: app.service: Unable to locate executable '/nonexistent': No such file or directory agent # [1723894.929332] agent (nonexistent)[1443]: app.service: Failed at step EXEC spawning /nonexistent: No such file or directory agent # [1723894.930119] agent systemd[1]: app.service: Main process exited, code=exited, status=203/EXEC agent # [1723894.930215] agent systemd[1]: app.service: Failed with result 'exit-code'. agent # [1723894.930414] agent systemd[1]: Failed to start app broken. agent # [1723894.958940] agent systemd[1]: Reload requested from client PID 1450 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723894.959024] agent systemd[1]: Reloading... agent # [1723895.315091] agent systemd[1]: Reloading finished in 355 ms. agent # [1723895.382224] agent systemd[1]: Reload requested from client PID 1480 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723895.382262] agent systemd[1]: Reloading... agent # [1723895.723291] agent systemd[1]: Reloading finished in 340 ms. agent # [1723895.793040] agent systemd[1]: Reload requested from client PID 1510 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723895.793081] agent systemd[1]: Reloading... agent # [1723896.135200] agent systemd[1]: Reloading finished in 341 ms. agent # [1723896.225293] agent systemd[1]: Reload requested from client PID 1540 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723896.225332] agent systemd[1]: Reloading... agent # [1723896.564619] agent systemd[1]: Reloading finished in 338 ms. agent # [1723896.658242] agent systemd[1]: Starting app v1... agent # [1723896.666180] agent systemd[1]: Started app v1. agent # [1723896.667288] agent flakelet[1313]: app: deploy failed, rolled back: systemctl start app.service failed: agent # [1723896.667288] agent flakelet[1313]: failed units: app.service. See journalctl -u app.service agent # [1723896.670222] agent systemd[1]: flakelet-relay-job-app.service: Main process exited, code=exited, status=1/FAILURE agent # [1723896.670318] 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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave agent/other 2>&1, in 4.17 seconds) agent: must succeed: systemctl show app.service -p Description | grep -q 'app v1' agent: (finished: must succeed: systemctl show app.service -p Description | grep -q 'app v1', in 0.02 seconds) (finished: subtest: waves: failing first wave skips the second, in 4.21 seconds) subtest: host patterns expand on the relay agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-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/cqj0khcw75fy7djy7y554bcgxi50911r-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/app' 2>&1 agent # [1723897.338933] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.626379Z","level":"INFO","message":"update finished","flakelet":"app","status":"RolledBack","generation":"Some(3)","target":"flakelet_relay::agent::jobs"} agent # [1723897.404312] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.691746Z","level":"INFO","message":"start","id":"2dd0b0d037d467162fa1f1ee764747ba","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723897.404797] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:25.692289Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"2dd0b0d037d467162fa1f1ee764747ba\"]","target":"flakelet_relay::agent::jobs"} agent # [1723897.445551] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723897.478151] agent systemd[1]: Started flakelet update app (via relay). agent # [1723897.482442] agent flakelet[1600]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 agent # [1723897.482986] agent flakelet[1600]: app: up to date agent # [1723897.486542] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. relay # [1723897.340355] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:25.627786Z","level":"INFO","message":"deploy finished","job":"1c2a28ffb5c770daeba76919b2dbd4b1","ok":false,"target":"flakelet_relay::relay::api"} relay # [1723897.403955] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:25.691406Z","level":"INFO","message":"deploy accepted","job":"d5830c29e7096747f8d35e1896764a09","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1 relay # [1723898.026706] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.314151Z","level":"INFO","message":"deploy finished","job":"d5830c29e7096747f8d35e1896764a09","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723898.048244] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.335727Z","level":"INFO","message":"deploy accepted","job":"1c69bfa50585b5e8118fcb5919322db3","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"} agent # [1723898.025403] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.312859Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"} agent # [1723898.048538] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.336019Z","level":"INFO","message":"start","id":"b7d0c7772f3d115a6567d7f1550efcb1","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723898.048915] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.336411Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"b7d0c7772f3d115a6567d7f1550efcb1\"]","target":"flakelet_relay::agent::jobs"} agent # [1723898.087648] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723898.121277] agent systemd[1]: Started flakelet update app (via relay). agent # [1723898.126437] agent flakelet[1620]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 agent # [1723898.126951] agent flakelet[1620]: app: up to date agent # [1723898.128765] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '*/app' 2>&1, in 0.64 seconds) client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1 agent # [1723898.668519] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.955969Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"} agent # [1723898.694154] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.981631Z","level":"INFO","message":"start","id":"e3b0d0f5a8789ec5d400876e577add73","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723898.694526] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:26.982021Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"e3b0d0f5a8789ec5d400876e577add73\"]","target":"flakelet_relay::agent::jobs"} agent # [1723898.736038] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723898.766177] agent systemd[1]: Started flakelet update app (via relay). agent # [1723898.771359] agent flakelet[1643]: app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 agent # [1723898.771880] agent flakelet[1643]: app: up to date agent # [1723898.775015] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. relay # [1723898.670176] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.957618Z","level":"INFO","message":"deploy finished","job":"1c69bfa50585b5e8118fcb5919322db3","ok":false,"target":"flakelet_relay::relay::api"} relay # [1723898.693786] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:26.981276Z","level":"INFO","message":"deploy accepted","job":"0065dcf2edfacfd0037786fce8fc30f9","caller":"admin@example.org","targets":"[\"agent/app\", \"ghost/app\"]","target":"flakelet_relay::relay::api"} client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy agent/app --wave '*/app' 2>&1, in 0.65 seconds) client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy '@all/nope' 2>&1 client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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.98 seconds) subtest: detach returns once the job is accepted agent: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-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/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 seconds) client: must succeed: timeout 20 push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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 relay # [1723899.318566] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:27.606007Z","level":"INFO","message":"deploy finished","job":"0065dcf2edfacfd0037786fce8fc30f9","ok":false,"target":"flakelet_relay::relay::api"} relay # [1723899.383209] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:27.670657Z","level":"INFO","message":"deploy accepted","job":"3a95e3c37847f25eff8ecdb03448ba0a","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723899.316939] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.604386Z","level":"INFO","message":"update finished","flakelet":"app","status":"Unchanged","generation":"Some(3)","target":"flakelet_relay::agent::jobs"} agent # [1723899.383562] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.670996Z","level":"INFO","message":"start","id":"394442565fd8040c1ee18df9a37e0e98","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723899.384052] agent flakelet-agent[473]: {"timestamp":"2026-10-01T12:03:27.671546Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"394442565fd8040c1ee18df9a37e0e98\"]","target":"flakelet_relay::agent::jobs"} agent # [1723899.427069] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723899.457181] agent systemd[1]: Started flakelet update app (via relay). agent # [1723899.462652] agent flakelet[1668]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2 agent # [1723899.463303] agent flakelet[1668]: app: activating generation 4 agent # [1723899.476317] agent systemd[1]: Stopping app v1... agent # [1723899.478394] agent systemd[1]: app.service: Deactivated successfully. agent # [1723899.478818] agent systemd[1]: Stopped app v1. agent # [1723899.497250] agent systemd[1]: Reload requested from client PID 1675 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723899.497317] agent systemd[1]: Reloading... agent # [1723899.841570] agent systemd[1]: Reloading finished in 343 ms. agent # [1723899.908619] agent systemd[1]: Reload requested from client PID 1705 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723899.908657] agent systemd[1]: Reloading... agent # [1723900.242360] agent systemd[1]: Reloading finished in 333 ms. agent # [1723900.318595] agent systemd[1]: Reload requested from client PID 1734 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723900.318638] agent systemd[1]: Reloading... agent # [1723900.649728] agent systemd[1]: Reloading finished in 330 ms. agent: (finished: waiting for success: systemctl is-active flakelet-relay-job-app.service, in 1.33 seconds) ??? Warning (UserWarning): wait_until_fails(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-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/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 agent # [1723900.722734] agent systemd[1]: Reload requested from client PID 1768 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723900.722774] agent systemd[1]: Reloading... agent # [1723901.054818] agent systemd[1]: Reloading finished in 331 ms. agent # [1723901.131547] agent systemd[1]: Starting app slow2... agent # [1723907.202231] agent systemd[1]: Started app slow2. agent # [1723907.211323] agent flakelet[1668]: app: updated to generation 4 agent # [1723907.212038] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. agent: (finished: waiting for failure: systemctl is-active flakelet-relay-job-app.service, in 7.51 seconds) (finished: subtest: detach returns once the job is accepted, in 8.88 seconds) subtest: unknown host is final, missing agent is retried, agents listing client: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy nope/app 2>&1 client: (finished: must fail: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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.08 seconds) relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0' relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 0', in 0.02 seconds) client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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 relay # [1723908.258748] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:36.546168Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"} agent # [1723908.258784] agent systemd[1]: Stopping flakelet-agent... agent # [1723908.290411] agent systemd[1]: flakelet-agent.service: Deactivated successfully. agent # [1723908.290875] agent systemd[1]: Stopped flakelet-agent. agent # [1723908.291372] agent systemd[1]: flakelet-agent.service: Consumed 1.606s CPU time over 27.637s wall clock time. 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.10 seconds) ??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead. File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39 client: waiting for success: grep -q 'agent/other: unchanged' /tmp/retry.out agent # [1723909.388183] agent systemd[1]: Starting flakelet-agent... agent # [1723909.440957] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:37.728432Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"394442565fd8040c1ee18df9a37e0e98\"]","target":"flakelet_relay::agent::jobs"} agent # [1723909.469359] agent systemd[1]: Started flakelet-agent. agent # [1723909.479934] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:37.767405Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} relay # [1723909.480061] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:37.767478Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(4), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"} agent # [1723909.986661] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:38.274111Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(4)","target":"flakelet_relay::agent::jobs"} agent # [1723911.375231] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:39.662642Z","level":"INFO","message":"start","id":"92fb2595afad90c3633d2e58de95a460","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723911.376159] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:39.663233Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"92fb2595afad90c3633d2e58de95a460\"]","target":"flakelet_relay::agent::jobs"} agent # [1723911.416610] agent systemd[1]: Starting flakelet update other (via relay)... agent # [1723911.446310] agent systemd[1]: Started flakelet update other (via relay). agent # [1723911.452273] agent flakelet[2249]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723911.452797] agent flakelet[2249]: other: up to date agent # [1723911.453718] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully. relay # [1723911.374738] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:39.662157Z","level":"INFO","message":"deploy accepted","job":"af7c52be6d90f55ed3d2ccda74a6ab02","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"} relay # [1723911.989757] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:40.277200Z","level":"INFO","message":"deploy finished","job":"af7c52be6d90f55ed3d2ccda74a6ab02","ok":true,"target":"flakelet_relay::relay::api"} agent # [1723911.987989] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:40.275437Z","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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents, in 0.02 seconds) client: must succeed: echo '{"groups": []}' | step crypto jwt sign --key /nix/store/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds) client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjUyMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjIwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJETlNDSlhWNzc0VFpRPT09IiwibmJmIjoxNzkwODU2MjIwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.6DVP9prSfsBefadS7ChNErffEzyfcm6OE6GN2pnt0gafLsKB3zcdZQv7EFNJ2LIQl9QNyEvNeXA61jrgpm4AAA' push --relay https://relay:7443 agents client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjUyMCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjIwLCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiJETlNDSlhWNzc0VFpRPT09IiwibmJmIjoxNzkwODU2MjIwLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.6DVP9prSfsBefadS7ChNErffEzyfcm6OE6GN2pnt0gafLsKB3zcdZQv7EFNJ2LIQl9QNyEvNeXA61jrgpm4AAA' push --relay https://relay:7443 agents, in 0.02 seconds) (finished: subtest: unknown host is final, missing agent is retried, agents listing, in 4.38 seconds) subtest: out-of-band flakelet update reaches the relay without reconnect agent: must succeed: flakelet status --json app | jq '.[0].generation' agent: (finished: must succeed: flakelet status --json app | jq '.[0].generation', in 0.03 seconds) agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds) agent: must succeed: jq '.services.app.prebuilt="/nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-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/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds) agent: must succeed: flakelet update app app: using prebuilt artifact /nix/store/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-flakelet-app-v2 app: activating generation 5 agent # [1723912.700148] agent systemd[1]: Stopping app slow2... agent # [1723912.700609] agent systemd[1]: app.service: Deactivated successfully. agent # [1723912.700880] agent systemd[1]: Stopped app slow2. agent # [1723912.719331] agent systemd[1]: Reload requested from client PID 2283 ('systemctl')... agent # [1723912.719401] agent systemd[1]: Reloading... agent # [1723913.064664] agent systemd[1]: Reloading finished in 344 ms. agent # [1723913.153688] agent systemd[1]: Reload requested from client PID 2312 ('systemctl')... agent # [1723913.153730] agent systemd[1]: Reloading... agent # [1723913.484816] agent systemd[1]: Reloading finished in 330 ms. agent # [1723913.555543] agent systemd[1]: Reload requested from client PID 2342 ('systemctl')... agent # [1723913.555583] agent systemd[1]: Reloading... agent # [1723913.888718] agent systemd[1]: Reloading finished in 332 ms. agent # [1723913.953660] agent systemd[1]: Reload requested from client PID 2373 ('systemctl')... agent # [1723913.953709] agent systemd[1]: Reloading... agent: (finished: must succeed: flakelet update app, in 1.72 seconds) client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5' agent # [1723914.285554] agent systemd[1]: Reloading finished in 331 ms. agent # [1723914.352986] agent systemd[1]: Starting app v2... agent # [1723914.377095] agent systemd[1]: Started app v2. agent # [1723915.490290] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:43.777755Z","level":"INFO","message":"local change","flakelet":"app","generation":5,"by":"root (shell)","target":"flakelet_relay::agent::jobs"} client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@5', in 2.07 seconds) agent: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true agent: (finished: must succeed: journalctl -u flakelet-agent -o cat | grep -c '"connected"' || true, in 0.01 seconds) client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5- client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-5-, in 0.02 seconds) client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app- client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs | grep local-app-, in 0.02 seconds) agent: must succeed: jq '.services.app.prebuilt="/nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-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/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.01 seconds) agent: must succeed: flakelet update app app: using prebuilt artifact /nix/store/cqj0khcw75fy7djy7y554bcgxi50911r-flakelet-app-v1 app: activating generation 6 agent # [1723916.556997] agent systemd[1]: Stopping app v2... agent # [1723916.557477] agent systemd[1]: app.service: Deactivated successfully. agent # [1723916.557742] agent systemd[1]: Stopped app v2. agent # [1723916.577236] agent systemd[1]: Reload requested from client PID 2419 ('systemctl')... agent # [1723916.577308] agent systemd[1]: Reloading... agent # [1723916.926105] agent systemd[1]: Reloading finished in 348 ms. agent # [1723917.001090] agent systemd[1]: Reload requested from client PID 2448 ('systemctl')... agent # [1723917.001131] agent systemd[1]: Reloading... agent # [1723917.334265] agent systemd[1]: Reloading finished in 332 ms. agent # [1723917.404255] agent systemd[1]: Reload requested from client PID 2476 ('systemctl')... agent # [1723917.404298] agent systemd[1]: Reloading... agent # [1723917.735965] agent systemd[1]: Reloading finished in 331 ms. agent # [1723917.822857] agent systemd[1]: Reload requested from client PID 2509 ('systemctl')... agent # [1723917.822897] agent systemd[1]: Reloading... agent # [1723918.154670] agent systemd[1]: Reloading finished in 331 ms. agent: (finished: must succeed: flakelet update app, in 1.74 seconds) client: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6' agent # [1723918.229243] agent systemd[1]: Starting app v1... agent # [1723918.258057] agent systemd[1]: Started app v1. agent # [1723919.497516] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:47.784955Z","level":"INFO","message":"local change","flakelet":"app","generation":6,"by":"root (shell)","target":"flakelet_relay::agent::jobs"} client: (finished: waiting for success: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem agents | grep -q 'app@6', in 2.07 seconds) (finished: subtest: out-of-band flakelet update reaches the relay without reconnect, in 7.72 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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/cert.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/mallory/key.pem -H 'Upgrade: websocket' -H 'Connection: Upgrade' -H 'Sec-WebSocket-Version: 13' -H 'Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==' https://relay:7443/v1/agent, in 0.03 seconds) (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/lb9sxpw9lh5imz78256ba6b43w55pkww-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/lb9sxpw9lh5imz78256ba6b43w55pkww-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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=@1790856228 | grep -q 'app-slow' agent # [1723920.417562] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:48.704962Z","level":"INFO","message":"start","id":"7a249324f2f8dcc84d01cbaa339caaf3","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723920.418168] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:48.705655Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"7a249324f2f8dcc84d01cbaa339caaf3\"]","target":"flakelet_relay::agent::jobs"} agent # [1723920.458448] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723920.488239] agent systemd[1]: Started flakelet update app (via relay). agent # [1723920.492386] agent flakelet[2558]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent # [1723920.492976] agent flakelet[2558]: app: activating generation 7 agent # [1723920.516474] agent systemd[1]: Stopping app v1... agent # [1723920.518472] agent systemd[1]: app.service: Deactivated successfully. agent # [1723920.518838] agent systemd[1]: Stopped app v1. agent # [1723920.535326] agent systemd[1]: Reload requested from client PID 2565 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723920.535393] agent systemd[1]: Reloading... relay # [1723920.355021] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:48.642487Z","level":"INFO","message":"agent rejected: no agents entry matches","principals":"[\"x509:dns:mallory\"]","target":"flakelet_relay::relay::agent_conn"} relay # [1723920.417019] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:48.704493Z","level":"INFO","message":"deploy accepted","job":"0deea8b1fc66516c837f2aabf7092244","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723920.876693] agent systemd[1]: Reloading finished in 340 ms. agent # [1723920.961824] agent systemd[1]: Reload requested from client PID 2595 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723920.961866] agent systemd[1]: Reloading... agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856228 | 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: (finished: must succeed: ss -K dport = 7443, in 0.03 seconds) agent: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856228 | grep -q 'updated to generation' agent # [1723921.292084] agent systemd[1]: Reloading finished in 329 ms. agent # [1723921.359896] agent systemd[1]: Reload requested from client PID 2624 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723921.359934] agent systemd[1]: Reloading... agent # [1723921.530635] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:49.818053Z","level":"INFO","message":"disconnected: IO error: Software caused connection abort (os error 103)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"} relay # [1723921.499222] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:03:49.786634Z","level":"INFO","message":"agent disconnected: IO error: Software caused connection abort (os error 103)","host":"agent","target":"flakelet_relay::relay::agent_conn"} agent # [1723921.717860] agent systemd[1]: Reloading finished in 357 ms. agent # [1723921.813260] agent systemd[1]: Reload requested from client PID 2672 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723921.813301] agent systemd[1]: Reloading... agent # [1723922.150566] agent systemd[1]: Reloading finished in 336 ms. agent # [1723922.220771] agent systemd[1]: Starting app slow... agent # [1723922.533735] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:50.821155Z","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 # [1723924.536391] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:52.823800Z","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 # [1723928.286183] agent systemd[1]: Started app slow. agent # [1723928.294716] agent flakelet[2558]: app: updated to generation 7 agent # [1723928.295746] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856228 | grep -q 'updated to generation', in 7.11 seconds) agent: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done agent: (finished: must succeed: for a in $(getent ahosts relay | cut -d' ' -f1 | sort -u); do ip route del unreachable $a; done, in 0.02 seconds) client: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out agent # [1723928.539813] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:56.827066Z","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 # [1723929.399790] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:03:57.687232Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(7)","target":"flakelet_relay::agent::jobs"} client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/slow.out, in 8.09 seconds) client: must succeed: cat /tmp/slow.out client: (finished: must succeed: cat /tmp/slow.out, in 0.01 seconds) (finished: subtest: agent link drop mid-run replays missed lines once, in 16.40 seconds) subtest: agent restart mid-run reattaches to the unit agent: must succeed: jq '.services.app.prebuilt="/nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-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/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.03 seconds) client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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 # [1723936.544041] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:04.831454Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"} agent # [1723936.543947] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:04.831357Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} relay # [1723936.545537] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:04.833025Z","level":"INFO","message":"deploy finished","job":"0deea8b1fc66516c837f2aabf7092244","ok":true,"target":"flakelet_relay::relay::api"} agent # [1723936.545171] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:04.832661Z","level":"INFO","message":"start","id":"7a249324f2f8dcc84d01cbaa339caaf3","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} relay # [1723936.822498] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:05.109813Z","level":"INFO","message":"deploy accepted","job":"0214376e1376797b6231c8053fe3f06e","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723936.822872] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:05.110185Z","level":"INFO","message":"start","id":"3f24754a8f186d7529d273edef4c5d6d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723936.823412] agent flakelet-agent[1836]: {"timestamp":"2026-10-01T12:04:05.110898Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"3f24754a8f186d7529d273edef4c5d6d\"]","target":"flakelet_relay::agent::jobs"} agent # [1723936.862295] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723936.890207] agent systemd[1]: Started flakelet update app (via relay). agent # [1723936.910494] agent flakelet[2794]: app: using prebuilt artifact /nix/store/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2 agent # [1723936.911673] agent flakelet[2794]: app: activating generation 8 agent # [1723936.936940] agent systemd[1]: Stopping app slow... agent # [1723936.940787] agent systemd[1]: app.service: Deactivated successfully. agent # [1723936.942269] agent systemd[1]: Stopped app slow. agent # [1723936.969475] agent systemd[1]: Reload requested from client PID 2801 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723936.969543] agent systemd[1]: Reloading... agent # [1723937.314294] agent systemd[1]: Reloading finished in 344 ms. agent # [1723937.392853] agent systemd[1]: Reload requested from client PID 2831 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723937.392895] agent systemd[1]: Reloading... agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since -20s | grep -q 'app-slow2', in 1.03 seconds) agent: must succeed: systemctl restart flakelet-agent agent # [1723937.726287] agent systemd[1]: Reloading finished in 332 ms. agent # [1723937.808535] agent systemd[1]: Reload requested from client PID 2863 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723937.808572] agent systemd[1]: Reloading... agent # [1723938.141654] agent systemd[1]: Reloading finished in 332 ms. agent # [1723938.205788] agent systemd[1]: Stopping flakelet-agent... agent # [1723938.212401] agent systemd[1]: Reload requested from client PID 2899 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723938.212435] agent systemd[1]: Reloading... relay # [1723938.206480] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:06.493509Z","level":"INFO","message":"agent disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","host":"agent","target":"flakelet_relay::relay::agent_conn"} agent: (finished: must succeed: systemctl restart flakelet-agent, in 0.87 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 # [1723938.549989] agent systemd[1]: Reloading finished in 337 ms. agent # [1723938.618381] agent systemd[1]: flakelet-agent.service: Deactivated successfully. agent # [1723938.618546] agent systemd[1]: Stopped flakelet-agent. agent # [1723938.618560] agent systemd[1]: flakelet-agent.service: Consumed 1.250s CPU time over 29.230s wall clock time. agent # [1723938.637815] agent systemd[1]: Starting app slow2... agent # [1723938.638765] agent systemd[1]: Starting flakelet-agent... agent # [1723938.695313] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:06.982778Z","level":"INFO","message":"reattaching to running unit","flakelet":"app","ids":"[\"3f24754a8f186d7529d273edef4c5d6d\"]","target":"flakelet_relay::agent::jobs"} agent # [1723938.711672] agent systemd[1]: Started flakelet-agent. agent # [1723938.725100] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:07.012582Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} agent # [1723938.726380] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:07.013874Z","level":"INFO","message":"start","id":"3f24754a8f186d7529d273edef4c5d6d","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} relay # [1723938.725252] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:07.012678Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(7), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"} agent # [1723944.710113] agent systemd[1]: Started app slow2. agent # [1723944.719534] agent flakelet[2794]: app: updated to generation 8 agent # [1723944.723281] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. agent # [1723945.287531] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:13.575005Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(8)","target":"flakelet_relay::agent::jobs"} relay # [1723945.288594] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:13.576060Z","level":"INFO","message":"deploy finished","job":"0214376e1376797b6231c8053fe3f06e","ok":true,"target":"flakelet_relay::relay::api"} client: (finished: waiting for success: grep -q 'agent/app: updated' /tmp/restart.out, in 7.09 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.07 seconds) subtest: relay restart mid-run, push resumes via /v1/jobs agent: must succeed: jq '.services.app.prebuilt="/nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-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/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow"' /etc/flakelet/config.json > /tmp/config.json && cp --remove-destination /tmp/config.json /etc/flakelet/config.json, in 0.02 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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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=@1790856254 | grep -q 'app-slow' agent # [1723945.888502] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:14.175938Z","level":"INFO","message":"start","id":"79568b1870a18eddf3ff096c6fe2a72e","flakelet":"app","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723945.889149] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:14.176638Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"79568b1870a18eddf3ff096c6fe2a72e\"]","target":"flakelet_relay::agent::jobs"} agent # [1723945.926532] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723945.936942] agent systemd[1]: Started flakelet update app (via relay). agent # [1723945.941394] agent flakelet[3376]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent # [1723945.942049] agent flakelet[3376]: app: activating generation 9 agent # [1723945.953580] agent systemd[1]: Stopping app slow2... agent # [1723945.954300] agent systemd[1]: app.service: Deactivated successfully. agent # [1723945.954501] agent systemd[1]: Stopped app slow2. agent # [1723945.964613] agent systemd[1]: Reload requested from client PID 3383 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723945.964655] agent systemd[1]: Reloading... relay # [1723945.888134] relay flakelet-relay[400]: {"timestamp":"2026-10-01T12:04:14.175596Z","level":"INFO","message":"deploy accepted","job":"4618a827b932dcb3dae7b71cf2d16982","caller":"admin@example.org","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723946.345073] agent systemd[1]: Reloading finished in 380 ms. agent # [1723946.447935] agent systemd[1]: Reload requested from client PID 3413 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723946.447976] agent systemd[1]: Reloading... agent: (finished: waiting for success: journalctl -u flakelet-relay-job-app.service --since=@1790856254 | grep -q 'app-slow', in 1.03 seconds) relay: must succeed: systemctl restart flakelet-relay agent # [1723946.830841] agent systemd[1]: Reloading finished in 382 ms. agent # [1723946.916513] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:15.203977Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"} agent # [1723946.929600] agent systemd[1]: Reload requested from client PID 3448 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723946.929638] agent systemd[1]: Reloading... relay # [1723946.916108] relay systemd[1]: Stopping flakelet-relay... relay # [1723946.965660] relay systemd[1]: flakelet-relay.service: Deactivated successfully. relay # [1723946.967102] relay systemd[1]: Stopped flakelet-relay. relay # [1723946.967144] relay systemd[1]: flakelet-relay.service: Consumed 2.651s CPU time over 1min 7.669s wall clock time. relay # [1723947.041083] relay systemd[1]: Starting flakelet-relay... agent # [1723947.344205] agent systemd[1]: Reloading finished in 414 ms. agent # [1723947.426662] agent systemd[1]: Reload requested from client PID 3480 ('systemctl') (unit flakelet-relay-job-app.service)... agent # [1723947.426700] agent systemd[1]: Reloading... agent # [1723947.797458] agent systemd[1]: Reloading finished in 370 ms. agent # [1723947.856261] agent systemd[1]: Starting app slow... agent # [1723947.920109] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:16.207509Z","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.78 seconds) client: waiting for success: grep -q '» ok' /tmp/resume.out relay # [1723948.679314] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:16.966730Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"} relay # [1723948.680309] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:16.967180Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"} relay # [1723948.679813] relay systemd[1]: Started flakelet-relay. agent # [1723949.932878] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:18.220304Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} relay # [1723949.933094] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:18.220493Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(8), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"} relay # [1723949.934862] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:18.222360Z","level":"INFO","message":"job reattached","job":"4618a827b932dcb3dae7b71cf2d16982","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} agent # [1723953.895053] agent systemd[1]: Started app slow. agent # [1723953.903629] agent flakelet[3376]: app: updated to generation 9 agent # [1723953.907127] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. agent # [1723955.001338] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:23.288796Z","level":"INFO","message":"update finished","flakelet":"app","status":"Updated","generation":"Some(9)","target":"flakelet_relay::agent::jobs"} client: (finished: waiting for success: grep -q '» ok' /tmp/resume.out, in 7.07 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.93 seconds) subtest: job history comes from the agents and survives a relay restart client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1 relay # [1723955.787675] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:24.075083Z","level":"INFO","message":"deploy accepted","job":"188b06c4636b65849b3ba8daac22dc7c","caller":"admin@example.org","targets":"[\"agent/other\"]","target":"flakelet_relay::relay::api"} agent # [1723955.788046] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.075463Z","level":"INFO","message":"start","id":"5be20c693e5c0b60e3f85779794dfb86","flakelet":"other","rule":"admins","relay":"relay","caller_name":"\"admin@example.org\"","target":"flakelet_relay::agent::conn"} agent # [1723955.788736] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.076228Z","level":"INFO","message":"update starting","flakelet":"other","ids":"[\"5be20c693e5c0b60e3f85779794dfb86\"]","target":"flakelet_relay::agent::jobs"} agent # [1723955.828790] agent systemd[1]: Starting flakelet update other (via relay)... agent # [1723955.862227] agent systemd[1]: Started flakelet update other (via relay). agent # [1723955.866448] agent flakelet[3554]: other: using prebuilt artifact /nix/store/h4k7d4dqcfa4h9d48c0rm4x08qziqfaf-flakelet-other-v1 agent # [1723955.867009] agent flakelet[3554]: other: up to date agent # [1723955.869731] agent systemd[1]: flakelet-relay-job-other.service: Deactivated successfully. client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem deploy --id hist1 agent/other 2>&1, in 0.65 seconds) relay: must succeed: systemctl restart flakelet-relay agent # [1723956.409292] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.696695Z","level":"INFO","message":"update finished","flakelet":"other","status":"Unchanged","generation":"Some(1)","target":"flakelet_relay::agent::jobs"} agent # [1723956.428072] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:24.715472Z","level":"INFO","message":"disconnected: IO error: peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"} relay # [1723956.410575] relay flakelet-relay[929]: {"timestamp":"2026-10-01T12:04:24.697989Z","level":"INFO","message":"deploy finished","job":"188b06c4636b65849b3ba8daac22dc7c","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723956.427827] relay systemd[1]: Stopping flakelet-relay... relay # [1723956.479548] relay systemd[1]: flakelet-relay.service: Deactivated successfully. relay # [1723956.479861] relay systemd[1]: Stopped flakelet-relay. relay # [1723956.479903] relay systemd[1]: flakelet-relay.service: Consumed 2.453s CPU time over 9.438s wall clock time. relay # [1723956.498132] relay systemd[1]: Starting flakelet-relay... agent # [1723957.431712] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:25.719066Z","level":"WARN","message":"connect failed: connect relay:7443: Connection refused (os error 111)","relay":"https://relay:7443","target":"flakelet_relay::agent::conn"} relay: (finished: must succeed: systemctl restart flakelet-relay, in 1.53 seconds) relay: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1' relay # [1723957.940248] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:26.227696Z","level":"INFO","message":"listening on 127.0.0.1:7400","target":"flakelet_relay::relay::server"} relay # [1723957.940790] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:26.228109Z","level":"INFO","message":"listening on [::]:7443","target":"flakelet_relay::relay::server"} relay # [1723957.940961] relay systemd[1]: Started flakelet-relay. agent # [1723959.445164] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:27.732496Z","level":"INFO","message":"connected","relay":"https://relay:7443","relay_name":"relay","relay_version":"0.1.0","host":"agent","target":"flakelet_relay::agent::conn"} relay # [1723959.445318] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:27.732634Z","level":"INFO","message":"agent connected","host":"agent","version":"0.1.0","flakelets":"[Named { name: \"app\", generation: Some(9), revision: Some(\"prebuilt:app\") }, Named { name: \"flakelet-agent\", generation: Some(1), revision: Some(\"prebuilt:flakelet-agent\") }, Named { name: \"other\", generation: Some(1), revision: Some(\"prebuilt:other\") }]","target":"flakelet_relay::relay::agent_conn"} relay: (finished: waiting for success: curl -sf http://127.0.0.1:7400/metrics | grep -q 'agent_up{host="agent"} 1', in 2.06 seconds) client: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs client: (finished: must succeed: push --relay https://relay:7443 --cert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin.pem --key /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/admin-key.pem jobs, in 0.02 seconds) client: must succeed: echo '{"groups": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-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": [], "repository": "example/app"}' | step crypto jwt sign --key /nix/store/n5cr3hg7jccw59hghm19jvr8n3lj1kp6-flakelet-relay-test-issuer/jwk.json --iss https://relay:8443 --aud flakelet-relay --sub 'repo:github:example/app:ref:refs/heads/main' --exp $(( $(date +%s) + 300 )) --jti $(head -c8 /dev/urandom | base32), in 0.06 seconds) client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' push --relay https://relay:7443 deploy --id hist2 agent/app » job 6a239dbf87cfec796e49404c351d787f 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/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent/app | app: up to date agent # [1723960.101250] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:28.388678Z","level":"INFO","message":"start","id":"dce6faec8455f85321e72ee634888126","flakelet":"app","rule":"ci","relay":"relay","caller_name":"\"example/app\"","target":"flakelet_relay::agent::conn"} agent/appagent # [1723960.101757] agent flakelet-agent[2931]: {"timestamp":"2026-10-01T12:04:28.389249Z","level":"INFO","message":"update starting","flakelet":"app","ids":"[\"dce6faec8455f85321e72ee634888126\"]","target":"flakelet_relay::agent::jobs"} | flakelet-relay-job-app.service: Deactivated successfully.agent # [1723960.140264] agent systemd[1]: Starting flakelet update app (via relay)... agent # [1723960.172163] agent systemd[1]: Started flakelet update app (via relay). agent # [1723960.176501] agent flakelet[3582]: app: using prebuilt artifact /nix/store/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent # [1723960.177030] agent flakelet[3582]: app: up to date agent # [1723960.180458] agent systemd[1]: flakelet-relay-job-app.service: Deactivated successfully. relay # [1723960.100800] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:28.388251Z","level":"INFO","message":"deploy accepted","job":"6a239dbf87cfec796e49404c351d787f","caller":"example/app","targets":"[\"agent/app\"]","target":"flakelet_relay::relay::api"} » agent/app: unchanged (generation 9) » ok client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' push --relay https://relay:7443 deploy --id hist2 agent/app, in 0.65 seconds) client: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' push --relay https://relay:7443 jobs client: (finished: must succeed: FLAKELET_RELAY_TOKEN_COMMAND='echo eyJhbGciOiJFZERTQSIsImtpZCI6ImsxIiwidHlwIjoiSldUIn0.eyJhdWQiOiJmbGFrZWxldC1yZWxheSIsImV4cCI6MTc5MDg1NjU2OCwiZ3JvdXBzIjpbXSwiaWF0IjoxNzkwODU2MjY4LCJpc3MiOiJodHRwczovL3JlbGF5Ojg0NDMiLCJqdGkiOiI1UktSVUI0T0NFVUo2PT09IiwibmJmIjoxNzkwODU2MjY4LCJyZXBvc2l0b3J5IjoiZXhhbXBsZS9hcHAiLCJzdWIiOiJyZXBvOmdpdGh1YjpleGFtcGxlL2FwcDpyZWY6cmVmcy9oZWFkcy9tYWluIn0.LO5N2WtIRX6oGnlz1DzkldX5GvPaWUwaEBN2BZz4mB4rkOfrk_vrVaEq6zyZzlqp_AHknNymzkROGYGsgtl-Ag' 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.98 seconds) subtest: dashboard login via authorization code flow client: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar -L https://relay:7443/ui/login, in 0.08 seconds) client: must succeed: curl -sS --cacert /nix/store/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-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/1mmby7f9fvxprhygz7w9j1i4ks3vf5ms-flakelet-relay-test-certs/ca.pem -b /tmp/jar -c /tmp/jar https://relay:7443/ui/jobs, in 0.02 seconds) !!! Test "dashboard login via authorization code flow" failed with error: "" cleanup kill NspawnMachine (pid 51) kill NspawnMachine (pid 55) kill NspawnMachine (pid 56) Container agent terminated by signal KILL. relay # [1723960.725395] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:29.012810Z","level":"INFO","message":"deploy finished","job":"6a239dbf87cfec796e49404c351d787f","ok":true,"target":"flakelet_relay::relay::api"} relay # [1723960.800808] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:04:29] "GET /authorize?response_type=code&client_id=dashboard&redirect_uri=https%3A%2F%2Frelay%3A7443%2Fui%2Fcallback&scope=openid%20profile%20email%20groups&state=IpxheFPAMdF3Mu-o3N483ndWPgH7844rTX5m0F7nG5w&code_challenge=lqWB09musStEYFGyJaxO1fDnCUl3bAJplZ9JVAMoQ94&code_challenge_method=S256 HTTP/1.1" 302 - relay # [1723960.847743] relay gak3xiqx9spzgkhmirxzgiwy0qnzcmgk-device-mock[186]: 127.0.0.1 - - [01/Oct/2026 12:04:29] "POST /token HTTP/1.1" 200 - relay # [1723960.848615] relay flakelet-relay[1319]: {"timestamp":"2026-10-01T12:04:29.136086Z","level":"INFO","message":"login","name":"dev@example.org","principals":"[\"oidc:mock:someone\", \"oidc:mock:groups:wheel\"]","target":"flakelet_relay::relay::login"} Container client terminated by signal KILL. Container relay terminated by signal KILL. (finished: cleanup, in 0.39 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 86a81216942784b0ee6f88e96d36cd9e 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/1hhsfvlan5s6l308sr1yx2i20rkz1mdc-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 1c2a28ffb5c770daeba76919b2dbd4b1 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/qy8h9kkvfrxq0bc47vwjy6lfnk9i95ga-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 0deea8b1fc66516c837f2aabf7092244 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/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent/app | app: activating generation 7 agent/app | app: updated to generation 7 agent/app | flakelet-relay-job-app.service: Deactivated successfully. » agent/app: updated (generation 7) » ok » job 0214376e1376797b6231c8053fe3f06e 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/yqdz0mcr1b2ljpw9vli2zvbmm43j4gr2-flakelet-app-slow2 agent/app | app: activating generation 8 agent/app | app: updated to generation 8 agent/app | flakelet-relay-job-app.service: Deactivated successfully. » agent/app: updated (generation 8) » ok » job 4618a827b932dcb3dae7b71cf2d16982 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/lb9sxpw9lh5imz78256ba6b43w55pkww-flakelet-app-slow agent/app | app: activating generation 9 flakelet-push: stream: error reading a body from connection, resuming job 1a38fccf7b28c28d866ba8bc9e7c6977 flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 1s flakelet-push: https://relay:7443: connect relay:7443: Connection refused (os error 111), retrying in 2s » job 4618a827b932dcb3dae7b71cf2d16982 via relay 0.1.0 (agents: agent 0.1.0) » wave 0 agent/app | app: updated to generation 9 agent/app | flakelet-relay-job-app.service: Deactivated successfully. » agent/app: updated (generation 9) » ok 1790856264 hist1 admin@example.org agent/other:unchanged 1790856254 1a38fccf7b28c28d866ba8bc9e7c6977 admin@example.org agent/app:updated 1790856245 90ce4e731fcbf97478ecf3f0442a764c admin@example.org agent/app:updated 1790856228 27bf17ad835d2015286f125e806dff05 admin@example.org agent/app:updated 1790856226 local-app-6-1790856226 root (shell) agent/app:updated 1790856222 local-app-5-1790856222 root (shell) agent/app:updated 1790856219 fc16f53f0cf78bed20e0af5a9ffdccee admin@example.org agent/other:unchanged 1790856207 4fdb7f565417002cb3f5b08d720a6ff5 admin@example.org agent/app:updated 1790856206 81e74aaa63beab2823c0f5bd842cde46 admin@example.org agent/app:unchanged 1790856206 9bdbcb288ca52522e0fc351f8619314f admin@example.org agent/app:unchanged 1790856205 4926c124545383671a20fba52b46a705 admin@example.org agent/app:unchanged 1790856201 55fdd2109331f70eec8c21648e229c15 admin@example.org agent/app:rolled-back 1790856200 0675e922875e3d9b3f0bddc66361c4e8 dev@example.org agent/other:unchanged 1790856200 bc2258243445b7e4d129c6df071c96cb dev@example.org agent/other:unchanged 1790856197 7245dfc67cd00633cf815e33e9600288 someone agent/other:unchanged 1790856194 3b87149eb8229b251a73361fd9550610 repo:github:example/app:ref:refs/heads/main agent/app:updated 1790856191 76f43bd28a044ed969a4f30c05548526 admin@example.org agent/app:updated 1790856189 local-app-1-1790856189 host activation agent/app:updated 1790856189 local-flakelet-agent-1-1790856189 host activation agent/flakelet-agent:updated 1790856189 local-other-1-1790856189 host activation agent/other:updated Traceback (most recent call last): File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/bin/.nixos-test-driver-wrapped", line 9, in sys.exit(main()) ~~~~^^ File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/__init__.py", line 194, in main driver.run_tests() ~~~~~~~~~~~~~~~~^^ File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 437, in run_tests self.test_script() ~~~~~~~~~~~~~~~~^^ File "/nix/store/29sx6wcid88iz35qayaccsr67l3kdrpk-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/driver.py", line 395, in test_script exec(self.tests, symbols, None) ~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "", line 208, in AssertionError