container-test-run-flakelet-postgres-transfer
checks.x86_64-linux.transfer
· build #20
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.01 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all VMs9a: systemd-nspawn running (pid 51)10b: systemd-nspawn running (pid 52)11a: Waiting for journal at /build/vm-state-a/var/log/journal...12b: Waiting for journal at /build/vm-state-b/var/log/journal...13(finished: start all VMs, in 0.00 seconds)14a: waiting for unit postgresql.target15nixos-nspawn(b): TAP vde-tap1 not found; container will be isolated from VDE16nixos-nspawn(b): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.17nixos-nspawn(a): TAP vde-tap1 not found; container will be isolated from VDE18nixos-nspawn(a): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.19Note: 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.20Note: 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.21░ Spawning container a on /build/vm-state-a.22░ Spawning container b on /build/vm-state-b.23b # [713648.469592] b systemd-journald[57]: Journal started24a # [713648.461392] a systemd-journald[57]: Journal started25b # [713648.469638] b systemd-journald[57]: Runtime Journal (/run/log/journal/5ba668a63c124e2a98a49e0a9524ac9d) is 8M, max 4G, 3.9G free.26a # [713648.461489] a systemd-journald[57]: Runtime Journal (/run/log/journal/6b65a22701654660b33347fd757c6fb3) is 8M, max 4G, 3.9G free.27b # [713648.477948] b systemd[1]: Finished Create Static Device Nodes in /dev gracefully.28a # [713648.467328] a systemd[1]: Finished Apply Kernel Variables.29b # [713648.490507] b systemd[1]: Starting Flush Journal to Persistent Storage...30a # [713648.477648] a systemd[1]: Finished Create Static Device Nodes in /dev gracefully.31b # [713648.491099] b systemd[1]: Starting Create Static Device Nodes in /dev...32a # [713648.489959] a systemd[1]: Starting Flush Journal to Persistent Storage...33b # [713648.529339] b systemd-journald[57]: Time spent on flushing to /var/log/journal/5ba668a63c124e2a98a49e0a9524ac9d is 1.552ms for 5 entries.34a # [713648.490797] a systemd[1]: Starting Create Static Device Nodes in /dev...35b # [713648.529339] b systemd-journald[57]: System Journal (/var/log/journal/5ba668a63c124e2a98a49e0a9524ac9d) is 512B, max 4G, 3.9G free.36a # [713648.529341] a systemd-journald[57]: Time spent on flushing to /var/log/journal/6b65a22701654660b33347fd757c6fb3 is 1.552ms for 6 entries.37b # [713648.535494] b systemd[1]: Finished Create Static Device Nodes in /dev.38a # [713648.529341] a systemd-journald[57]: System Journal (/var/log/journal/6b65a22701654660b33347fd757c6fb3) is 512B, max 4G, 3.9G free.39b # [713648.536291] b systemd[1]: Reached target Preparation for Local File Systems.40a # [713648.535585] a systemd[1]: Finished Create Static Device Nodes in /dev.41b # [713648.536409] b systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys42a # [713648.536568] a systemd[1]: Reached target Preparation for Local File Systems.43b # [713648.555330] b systemd[1]: Finished Flush Journal to Persistent Storage.44a # [713648.536667] a systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys45a # [713648.553103] a systemd[1]: Finished Flush Journal to Persistent Storage.46a # [713648.630101] a systemd[1]: Finished Firewall.47b # [713648.628645] b systemd[1]: Finished Firewall.48a # [713649.457672] a systemd[1]: Mounting /run/wrappers...49a # [713649.522306] a systemd[1]: Mounted /run/wrappers.50a # [713649.523686] a systemd[1]: Reached target Local File Systems.51a # [713649.525266] a systemd[1]: Listening on Boot Loader Control Service Socket.52a # [713649.527082] a systemd[1]: Starting Create SUID/SGID Wrappers...53a # [713649.527130] a systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container54a # [713649.528218] a systemd[1]: Starting Save Transient machine-id to Disk...55a # [713649.529280] a systemd[1]: Starting Create System Files and Directories...56a # [713649.547804] a systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted57a # [713649.548293] a systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted58a # [713649.548611] a systemd-tmpfiles[161]: fchmod() of /var/log/journal/6b65a22701654660b33347fd757c6fb3 failed: Operation not permitted59a # [713649.548943] a systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted60b # [713649.492768] b systemd[1]: Mounting /run/wrappers...61b # [713649.525352] b systemd[1]: Mounted /run/wrappers.62b # [713649.526628] b systemd[1]: Reached target Local File Systems.63b # [713649.528123] b systemd[1]: Listening on Boot Loader Control Service Socket.64b # [713649.529664] b systemd[1]: Starting Create SUID/SGID Wrappers...65b # [713649.529722] b systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container66b # [713649.531063] b systemd[1]: Starting Save Transient machine-id to Disk...67b # [713649.532297] b systemd[1]: Starting Create System Files and Directories...68b # [713649.551642] b systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted69b # [713649.552052] b systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted70b # [713649.552346] b systemd-tmpfiles[161]: fchmod() of /var/log/journal/5ba668a63c124e2a98a49e0a9524ac9d failed: Operation not permitted71b # [713649.552670] b systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted72a # [713649.555898] a suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.zociZSDdKW/chsh': Operation not permitted73b # [713649.554778] b suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.TZPEtt1IKs/chsh': Operation not permitted74a # [713649.573126] a systemd[1]: Finished Create System Files and Directories.75b # [713649.609224] b systemd[1]: etc-machine\x2did.mount: Deactivated successfully.76a # [713649.592252] a systemd[1]: etc-machine\x2did.mount: Deactivated successfully.77b # [713649.609754] b systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE78a # [713649.602149] a systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE79b # [713649.609786] b systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.80a # [713649.602241] a systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.81b # [713649.609834] b systemd[1]: Failed to start Create SUID/SGID Wrappers.82a # [713649.602446] a systemd[1]: Failed to start Create SUID/SGID Wrappers.83b # [713649.609962] b systemd[1]: Finished Save Transient machine-id to Disk.84a # [713649.602686] a systemd[1]: Finished Save Transient machine-id to Disk.85b # [713649.610380] b systemd[1]: Finished Create System Files and Directories.86a # [713649.605919] a systemd[1]: Starting Rebuild Journal Catalog...87b # [713649.630628] b systemd[1]: Starting Rebuild Journal Catalog...88a # [713649.606704] a systemd[1]: Starting Record System Boot/Shutdown in UTMP...89b # [713649.631530] b systemd[1]: Starting Record System Boot/Shutdown in UTMP...90a # [713649.642941] a systemd[1]: Finished Record System Boot/Shutdown in UTMP.91b # [713649.644073] b systemd[1]: Finished Record System Boot/Shutdown in UTMP.92a # [713649.657897] a systemd[1]: Finished Rebuild Journal Catalog.93b # [713649.651114] b systemd[1]: Finished Rebuild Journal Catalog.94a # [713649.658765] a systemd[1]: Starting Update is Completed...95b # [713649.652074] b systemd[1]: Starting Update is Completed...96a # [713649.668890] a systemd[1]: Finished Update is Completed.97b # [713649.660271] b systemd[1]: Finished Update is Completed.98a # [713649.668994] a systemd[1]: Reached target System Initialization.99b # [713649.660368] b systemd[1]: Reached target System Initialization.100a # [713649.669084] a systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container101b # [713649.660451] b systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container102a # [713649.669121] a systemd[1]: Started Daily Cleanup of Temporary Directories.103b # [713649.660522] b systemd[1]: Started Daily Cleanup of Temporary Directories.104a # [713649.669139] a systemd[1]: Reached target Timer Units.105b # [713649.660544] b systemd[1]: Reached target Timer Units.106a # [713649.669234] a systemd[1]: Listening on D-Bus System Message Bus Socket.107b # [713649.660668] b systemd[1]: Listening on D-Bus System Message Bus Socket.108a # [713649.669406] a systemd[1]: Listening on Nix Daemon Socket.109b # [713649.660861] b systemd[1]: Listening on Nix Daemon Socket.110a # [713649.669506] a systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.111b # [713649.660959] b systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.112a # [713649.669519] a systemd[1]: Reached target Socket Units.113b # [713649.660971] b systemd[1]: Reached target Socket Units.114a # [713649.669547] a systemd[1]: Reached target Basic System.115b # [713649.660998] b systemd[1]: Reached target Basic System.116a # [713649.670523] a systemd[1]: Starting Re-link flakelet services at boot...117b # [713649.662037] b systemd[1]: Starting Re-link flakelet services at boot...118a # [713649.671512] a systemd[1]: Starting Import lastlog data into lastlog2 database...119b # [713649.662761] b systemd[1]: Starting Import lastlog data into lastlog2 database...120a # [713649.672352] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...121b # [713649.663847] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...122a # [713649.672938] a systemd[1]: Starting resolvconf update...123b # [713649.664611] b systemd[1]: Starting resolvconf update...124a # [713649.683843] a systemd[1]: Finished Re-link flakelet services at boot.125b # [713649.673378] b systemd[1]: Finished Re-link flakelet services at boot.126a # [713649.684643] a systemd[1]: lastlog2-import.service: Failed to spawn executor: No such file or directory127b # [713649.676207] b systemd[1]: Starting Reconcile flakelet services with the host configuration...128a # [713649.684680] a systemd[1]: lastlog2-import.service: Failed to spawn 'start-post' task: No such file or directory129b # [713649.683049] b systemd[1]: Finished Import lastlog data into lastlog2 database.130a # [713649.684716] a systemd[1]: lastlog2-import.service: Failed with result 'resources'.131b # [713649.687722] b systemd[1]: Finished Reconcile flakelet services with the host configuration.132a # [713649.684765] a systemd[1]: Failed to start Import lastlog data into lastlog2 database.133b # [713649.743445] b systemd[1]: nscd.service: Deactivated successfully.134a # [713649.686401] a systemd[1]: Starting Reconcile flakelet services with the host configuration...135b # [713649.743575] b systemd[1]: Stopped Name Service Cache Daemon (nsncd).136a # [713649.696737] a systemd[1]: Finished Reconcile flakelet services with the host configuration.137b # [713649.746278] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...138b # [713649.786389] b systemd[1]: Finished resolvconf update.139b # [713649.786632] b systemd[1]: Reached target Preparation for Network.140b # [713649.787888] b systemd[1]: Starting Address configuration of eth1...141b # [713649.788817] b systemd[1]: Starting Extra networking commands....142b # [713649.809750] b network-addresses-eth1-start[242]: adding address 192.168.1.2/24... done143b # [713649.812984] b network-addresses-eth1-start[242]: adding address 2001:db8:1::2/64... done144b # [713649.817903] b systemd[1]: Finished Address configuration of eth1.145b # [713649.861278] b systemd[1]: Finished Extra networking commands..146b # [713649.861383] b systemd[1]: Reached target Network.147b # [713649.862614] b systemd[1]: Starting PostgreSQL Server...148b # [713650.049045] b systemd[1]: Started Name Service Cache Daemon (nsncd).149a # [713649.752190] a systemd[1]: nscd.service: Deactivated successfully.150a # [713649.786377] a systemd[1]: Stopped Name Service Cache Daemon (nsncd).151a # [713649.788103] a systemd[1]: Finished resolvconf update.152a # [713649.788858] a systemd[1]: Reached target Preparation for Network.153a # [713649.790234] a systemd[1]: Starting Address configuration of eth1...154a # [713649.791484] a systemd[1]: Starting Extra networking commands....155a # [713649.792952] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...156a # [713649.815785] a network-addresses-eth1-start[238]: adding address 192.168.1.1/24... done157a # [713649.819510] a network-addresses-eth1-start[238]: adding address 2001:db8:1::1/64... done158a # [713649.824707] a systemd[1]: Finished Address configuration of eth1.159a # [713649.859199] a systemd[1]: Finished Extra networking commands..160a # [713649.859855] a systemd[1]: Reached target Network.161a # [713649.861397] a systemd[1]: Starting PostgreSQL Server...162a # [713650.052415] a nsncd[240]: Oct 22 15:37:22.862 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"163a # [713650.052351] a systemd[1]: Started Name Service Cache Daemon (nsncd).164a # [713650.052393] a systemd[1]: Reached target Host and Network Name Lookups.165a # [713650.052444] a systemd[1]: Reached target User and Group Name Lookups.166a # [713650.053607] a systemd[1]: Starting User Login Management...167a # [713650.054444] a systemd[1]: Starting Permit User Sessions...168a # [713650.088440] a systemd[1]: Finished Permit User Sessions.169a # [713650.090150] a systemd[1]: Started Console Getty.170a # [713650.090205] a systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0171a # [713650.090233] a systemd[1]: Reached target Login Prompts.172b # [713650.049111] b systemd[1]: Reached target Host and Network Name Lookups.173b # [713650.049182] b systemd[1]: Reached target User and Group Name Lookups.174b # [713650.049913] b nsncd[235]: Oct 22 15:37:22.860 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"175b # [713650.050868] b systemd[1]: Starting User Login Management...176b # [713650.051856] b systemd[1]: Starting Permit User Sessions...177b # [713650.088212] b systemd[1]: Finished Permit User Sessions.178b # [713650.089389] b systemd[1]: Started Console Getty.179b # [713650.089416] b systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0180b # [713650.089429] b systemd[1]: Reached target Login Prompts.181b # [713651.122824] b systemd-logind[314]: New seat seat0.182b # [713651.125087] b systemd[1]: Starting D-Bus System Message Bus...183b # [713651.125272] b systemd[1]: Started User Login Management.184b # [713651.148359] b postgresql-pre-start[327]: The files belonging to this database system will be owned by user "postgres".185b # [713651.148359] b postgresql-pre-start[327]: This user must also own the server process.186b # [713651.148924] b postgresql-pre-start[327]: The database cluster will be initialized with locale "en_US.UTF-8".187b # [713651.148924] b postgresql-pre-start[327]: The default database encoding has accordingly been set to "UTF8".188b # [713651.148924] b postgresql-pre-start[327]: The default text search configuration will be set to "english".189b # [713651.148924] b postgresql-pre-start[327]: Data page checksums are enabled.190b # [713651.148924] b postgresql-pre-start[327]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok191b # [713651.149666] b postgresql-pre-start[327]: creating subdirectories ... ok192b # [713651.149801] b postgresql-pre-start[327]: selecting dynamic shared memory implementation ... posix193b # [713651.156712] b systemd[1]: Starting linger-users.service...194b # [713651.170310] b postgresql-pre-start[327]: selecting default "max_connections" ... 100195b # [713651.192231] b systemd[1]: linger-users.service: Deactivated successfully.196b # [713651.192320] b systemd[1]: Finished linger-users.service.197b # [713651.199900] b postgresql-pre-start[327]: selecting default "shared_buffers" ... 128MB198a # [713651.118753] a systemd-logind[312]: New seat seat0.199a # [713651.120978] a systemd[1]: Starting D-Bus System Message Bus...200a # [713651.121175] a systemd[1]: Started User Login Management.201a # [713651.122546] a systemd[1]: Starting linger-users.service...202a # [713651.138591] a postgresql-pre-start[323]: The files belonging to this database system will be owned by user "postgres".203a # [713651.138591] a postgresql-pre-start[323]: This user must also own the server process.204a # [713651.139193] a postgresql-pre-start[323]: The database cluster will be initialized with locale "en_US.UTF-8".205a # [713651.139193] a postgresql-pre-start[323]: The default database encoding has accordingly been set to "UTF8".206a # [713651.139193] a postgresql-pre-start[323]: The default text search configuration will be set to "english".207a # [713651.139193] a postgresql-pre-start[323]: Data page checksums are enabled.208a # [713651.139193] a postgresql-pre-start[323]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok209a # [713651.140143] a postgresql-pre-start[323]: creating subdirectories ... ok210a # [713651.140280] a postgresql-pre-start[323]: selecting dynamic shared memory implementation ... posix211a # [713651.163772] a postgresql-pre-start[323]: selecting default "max_connections" ... 100212a # [713651.166291] a systemd[1]: linger-users.service: Deactivated successfully.213a # [713651.166622] a systemd[1]: Finished linger-users.service.214a # [713651.192334] a postgresql-pre-start[323]: selecting default "shared_buffers" ... 128MB215a # [713651.517625] a postgresql-pre-start[323]: selecting default time zone ... UTC216a # [713651.518720] a postgresql-pre-start[323]: creating configuration files ... ok217a # [713651.518921] a dbus-broker-launch[324]: Looking up NSS user entry for 'systemd-timesync'...218a # [713651.521738] a dbus-broker-launch[324]: NSS returned no entry for 'systemd-timesync'219a # [713651.521738] a dbus-broker-launch[324]: Invalid user-name in /nix/store/3n9kcp7440imf0349raradpc31y24gp4-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"220a # [713651.522783] a systemd[1]: Started D-Bus System Message Bus.221a # [713651.528586] a dbus-broker-launch[324]: Ready222a # [713651.644483] a postgresql-pre-start[323]: running bootstrap script ... ok223b # [713651.517870] b dbus-broker-launch[324]: Looking up NSS user entry for 'systemd-timesync'...224b # [713651.521621] b dbus-broker-launch[324]: NSS returned no entry for 'systemd-timesync'225b # [713651.521621] b dbus-broker-launch[324]: Invalid user-name in /nix/store/3n9kcp7440imf0349raradpc31y24gp4-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"226b # [713651.522783] b systemd[1]: Started D-Bus System Message Bus.227b # [713651.528067] b postgresql-pre-start[327]: selecting default time zone ... UTC228b # [713651.529166] b postgresql-pre-start[327]: creating configuration files ... ok229b # [713651.529692] b dbus-broker-launch[324]: Ready230b # [713651.657806] b postgresql-pre-start[327]: running bootstrap script ... ok231a # [713651.990912] a postgresql-pre-start[323]: performing post-bootstrap initialization ... ok232b # [713652.000945] b postgresql-pre-start[327]: performing post-bootstrap initialization ... ok233b # [713652.389365] b postgresql-pre-start[327]: syncing data to disk ... ok234b # [713652.389365] b postgresql-pre-start[327]: initdb: warning: enabling "trust" authentication for local connections235b # [713652.389365] b postgresql-pre-start[327]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.236b # [713652.389365] b postgresql-pre-start[327]: Success. You can now start the database server using:237b # [713652.389365] b postgresql-pre-start[327]: pg_ctl -D /var/lib/postgresql/18 -l logfile start238a # [713652.372891] a postgresql-pre-start[323]: syncing data to disk ... ok239a # [713652.372891] a postgresql-pre-start[323]: initdb: warning: enabling "trust" authentication for local connections240a # [713652.372891] a postgresql-pre-start[323]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.241a # [713652.372891] a postgresql-pre-start[323]: Success. You can now start the database server using:242a # [713652.372891] a postgresql-pre-start[323]: pg_ctl -D /var/lib/postgresql/18 -l logfile start243a # [713653.442476] a postgres[341]: [341] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit244a # [713653.444952] a postgres[341]: [341] LOG: listening on IPv6 address "::1", port 5432245a # [713653.444952] a postgres[341]: [341] LOG: listening on IPv4 address "127.0.0.1", port 5432246a # [713653.445550] a postgres[341]: [341] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"247a # [713653.451228] a postgres[350]: [350] LOG: database system was shut down at 2026-10-22 15:37:24 GMT248a # [713653.455305] a postgres[341]: [341] LOG: database system is ready to accept connections249a # [713653.456170] a systemd[1]: Started PostgreSQL Server.250a # [713653.458909] a systemd[1]: Starting PostgreSQL Setup Scripts...251a # [713653.521289] a systemd[1]: Finished PostgreSQL Setup Scripts.252a # [713653.522992] a systemd[1]: Reached target PostgreSQL.253a # [713653.523292] a systemd[1]: Reached target flakelet contract providers ready.254a # [713653.525111] a systemd[1]: Starting Update flakelet service web...255a # [713653.541730] a flakelet[359]: web: using prebuilt artifact /nix/store/m732qs5ppfnm3j1kcnh10ni5l6gxyy9m-flakelet-web256a # [713653.542824] a flakelet[359]: web: requires.postgres: provisioning via /nix/store/g4lhvdqwxy6vvyqah8vq1qff0xyschv1-flakelet-postgres-provision/bin/flakelet-postgres-provision257a # [713653.559138] a runuser[363]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)258a # [713653.653027] a runuser[363]: pam_unix(runuser:session): session closed for user postgres259a # [713653.655792] a flakelet[359]: web: activating generation 1260a # [713653.663303] a systemd[1]: Reload requested from client PID 366 ('systemctl') (unit flakelet-web.service)...261a # [713653.663397] a systemd[1]: Reloading...262b # [713653.454831] b postgres[343]: [343] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit263b # [713653.455832] b postgres[343]: [343] LOG: listening on IPv6 address "::1", port 5432264b # [713653.455832] b postgres[343]: [343] LOG: listening on IPv4 address "127.0.0.1", port 5432265b # [713653.456249] b postgres[343]: [343] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"266b # [713653.461237] b postgres[352]: [352] LOG: database system was shut down at 2026-10-22 15:37:24 GMT267b # [713653.464887] b postgres[343]: [343] LOG: database system is ready to accept connections268b # [713653.465450] b systemd[1]: Started PostgreSQL Server.269b # [713653.492945] b systemd[1]: Starting PostgreSQL Setup Scripts...270b # [713653.529462] b systemd[1]: Finished PostgreSQL Setup Scripts.271b # [713653.529790] b systemd[1]: Reached target PostgreSQL.272b # [713653.529884] b systemd[1]: Reached target flakelet contract providers ready.273b # [713653.531053] b systemd[1]: Starting Update flakelet service web...274b # [713653.544088] b flakelet[361]: web: using prebuilt artifact /nix/store/m732qs5ppfnm3j1kcnh10ni5l6gxyy9m-flakelet-web275b # [713653.544491] b flakelet[361]: web: requires.postgres: provisioning via /nix/store/g4lhvdqwxy6vvyqah8vq1qff0xyschv1-flakelet-postgres-provision/bin/flakelet-postgres-provision276b # [713653.562534] b runuser[365]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)277b # [713653.651538] b runuser[365]: pam_unix(runuser:session): session closed for user postgres278b # [713653.653616] b flakelet[361]: web: activating generation 1279b # [713653.659296] b systemd[1]: Reload requested from client PID 368 ('systemctl') (unit flakelet-web.service)...280b # [713653.659375] b systemd[1]: Reloading...281a # [713653.999522] a systemd[1]: Reloading finished in 335 ms.282a # [713654.098246] a systemd[1]: Reload requested from client PID 395 ('systemctl') (unit flakelet-web.service)...283a # [713654.098286] a systemd[1]: Reloading...284b # [713653.963250] b systemd[1]: Reloading finished in 303 ms.285b # [713654.079398] b systemd[1]: Reload requested from client PID 397 ('systemctl') (unit flakelet-web.service)...286b # [713654.079441] b systemd[1]: Reloading...287b # [713654.394984] b systemd[1]: Reloading finished in 315 ms.288b # [713654.515533] b systemd[1]: Starting web.service...289b # [713654.552980] b systemd[1]: Started web.service.290b # [713654.557514] b flakelet[361]: web: updated to generation 1291b # [713654.559088] b systemd[1]: Finished Update flakelet service web.292b # [713654.559527] b systemd[1]: Reached target flakelet managed services.293b # [713654.559662] b systemd[1]: Reached target Multi-User System.294b # [713654.559885] b systemd[1]: Startup finished in 6.498s.295a: (finished: waiting for unit postgresql.target, in 7.15 seconds)296??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.297 File "/nix/store/310kyvymdsg670fiyk6296s3m0fgyiqs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39298a: waiting for unit web.service299a: (finished: waiting for unit web.service, in 0.02 seconds)300a: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d postgres -c 'SELECT 1 FROM pg_database WHERE datname='\''web'\''' | grep -q 1301a # [713654.407967] a systemd[1]: Reloading finished in 309 ms.302a # [713654.543818] a systemd[1]: Starting web.service...303a # [713654.556026] a systemd[1]: Started web.service.304a # [713654.560946] a flakelet[359]: web: updated to generation 1305a # [713654.561694] a systemd[1]: Finished Update flakelet service web.306a # [713654.563537] a systemd[1]: Reached target flakelet managed services.307a # [713654.563947] a systemd[1]: Reached target Multi-User System.308a # [713654.564269] a systemd[1]: Startup finished in 6.499s.309a: (finished: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d postgres -c 'SELECT 1 FROM pg_database WHERE datname='\''web'\''' | grep -q 1, in 0.02 seconds)310a: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'CREATE TABLE t(v text); INSERT INTO t VALUES ('\''payload'\'')'311a: (finished: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'CREATE TABLE t(v text); INSERT INTO t VALUES ('\''payload'\'')', in 0.03 seconds)312a: must succeed: flakelet export web --dry-run >&2313{314 "version": 1,315 "flakelet_version": "0.1.0",316 "name": "web",317 "source_host": "a",318 "created": 1792683447,319 "flake": "",320 "output": "flakelets.default",321 "flake_url": "prebuilt:web",322 "flake_rev": "",323 "settings_hash": "44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a",324 "state": {325 "folders": [326 {327 "path": "/var/lib/web",328 "user": "web",329 "group": null,330 "dynamic": false331 }332 ],333 "dump": null,334 "restore": null335 },336 "exports": {337 "requires": {338 "postgres": {339 "database": "web"340 }341 }342 },343 "consistency": "stopped"344}345a: (finished: must succeed: flakelet export web --dry-run >&2, in 0.01 seconds)346a: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst347web: stopping units348requires.postgres: running /nix/store/4mjyafbw7x9sij3kn6rkm9p9knp47raw-flakelet-postgres-dump/bin/flakelet-postgres-dump349web: archiving /var/lib/web350a # [713654.745554] a runuser[431]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)351a # [713654.757217] a runuser[431]: pam_unix(runuser:session): session closed for user postgres352a # [713654.767243] a runuser[435]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)353a # [713654.784022] a runuser[435]: pam_unix(runuser:session): session closed for user web354a # [713654.817149] a systemd[1]: Stopping web.service...355a # [713654.817583] a systemd[1]: web.service: Deactivated successfully.356a # [713654.817800] a systemd[1]: Stopped web.service.357a # [713654.834695] a runuser[448]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)358a # [713654.886513] a runuser[448]: pam_unix(runuser:session): session closed for user postgres359a # [713654.930275] a systemd[1]: Reload requested from client PID 463 ('systemctl')...360a # [713654.930347] a systemd[1]: Reloading...361a # [713655.253319] a systemd[1]: Reloading finished in 322 ms.362a # [713655.335628] a systemd[1]: Reload requested from client PID 491 ('systemctl')...363a # [713655.335669] a systemd[1]: Reloading...364web: disabled here, 'flakelet enable web' undoes that365a: (finished: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst, in 0.93 seconds)366a: must fail: systemctl is-active web.service367a: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)368a: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump369a: (finished: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump, in 0.01 seconds)370b: waiting for unit postgresql.target371b: (finished: waiting for unit postgresql.target, in 0.02 seconds)372b: waiting for unit web.service373b: (finished: waiting for unit web.service, in 0.02 seconds)374??? Warning (UserWarning): succeed(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.375 File "/nix/store/310kyvymdsg670fiyk6296s3m0fgyiqs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39376b: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2377??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.378 File "/nix/store/310kyvymdsg670fiyk6296s3m0fgyiqs-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39379web: using prebuilt artifact /nix/store/m732qs5ppfnm3j1kcnh10ni5l6gxyy9m-flakelet-web380a # [713655.638747] a systemd[1]: Reloading finished in 302 ms.381b # [713655.819436] b systemd[1]: Stopping web.service...382b # [713655.820159] b systemd[1]: web.service: Deactivated successfully.383b # [713655.820305] b systemd[1]: Stopped web.service.384b # [713655.832015] b systemd[1]: Reload requested from client PID 445 ('systemctl')...385b # [713655.832056] b systemd[1]: Reloading...386b # [713656.131966] b systemd[1]: Reloading finished in 299 ms.387b # [713656.222479] b systemd[1]: Reload requested from client PID 473 ('systemctl')...388b # [713656.222520] b systemd[1]: Reloading...389web: restoring /var/lib/web390requires.postgres: running /nix/store/74qvb36qi4n2ggwmxas1sjr4lnply9zq-flakelet-postgres-restore/bin/flakelet-postgres-restore391web: requires.postgres: provisioning via /nix/store/g4lhvdqwxy6vvyqah8vq1qff0xyschv1-flakelet-postgres-provision/bin/flakelet-postgres-provision392web: activating generation 2393b # [713656.519541] b systemd[1]: Reloading finished in 296 ms.394b # [713656.637515] b runuser[508]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)395b # [713656.650014] b runuser[508]: pam_unix(runuser:session): session closed for user postgres396b # [713656.655348] b runuser[511]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)397b # [713656.669782] b runuser[511]: pam_unix(runuser:session): session closed for user postgres398b # [713656.674438] b runuser[514]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)399b # [713656.688244] b runuser[514]: pam_unix(runuser:session): session closed for user postgres400b # [713656.705237] b runuser[520]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)401b # [713656.716966] b runuser[520]: pam_unix(runuser:session): session closed for user postgres402b # [713656.722837] b systemd[1]: Reload requested from client PID 523 ('systemctl')...403b # [713656.722885] b systemd[1]: Reloading...404b # [713657.022742] b systemd[1]: Reloading finished in 299 ms.405b # [713657.108567] b systemd[1]: Reload requested from client PID 551 ('systemctl')...406b # [713657.108609] b systemd[1]: Reloading...407b # [713657.404593] b systemd[1]: Reloading finished in 295 ms.408web: imported as generation 2409b: (finished: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2, in 1.75 seconds)410b: must succeed: systemctl is-active web.service411b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)412b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload413b: (finished: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload, in 0.03 seconds)414b: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT tableowner FROM pg_tables WHERE tablename='\''t'\''' | grep -qx web415b: (finished: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT tableowner FROM pg_tables WHERE tablename='\''t'\''' | grep -qx web, in 0.02 seconds)416b: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d postgres -c 'SELECT shobj_description(oid, '\''pg_database'\'') FROM pg_database WHERE datname='\''web'\''' | grep -q flakelet417b: (finished: must succeed: runuser -u postgres -- psql -qtAX -v ON_ERROR_STOP=1 -d postgres -c 'SELECT shobj_description(oid, '\''pg_database'\'') FROM pg_database WHERE datname='\''web'\''' | grep -q flakelet, in 0.02 seconds)418b: must fail: flakelet import /tmp/shared/web.tar.zst >&2419web: using prebuilt artifact /nix/store/m732qs5ppfnm3j1kcnh10ni5l6gxyy9m-flakelet-web420b # [713657.496013] b systemd[1]: Starting web.service...421b # [713657.524752] b systemd[1]: Started web.service.422b # [713657.561519] b runuser[584]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)423b # [713657.574009] b runuser[584]: pam_unix(runuser:session): session closed for user web424b # [713657.586869] b runuser[589]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)425b # [713657.598625] b runuser[589]: pam_unix(runuser:session): session closed for user postgres426b # [713657.609051] b runuser[594]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)427b # [713657.620303] b runuser[594]: pam_unix(runuser:session): session closed for user postgres428b # [713657.653254] b systemd[1]: Stopping web.service...429b # [713657.653968] b systemd[1]: web.service: Deactivated successfully.430b # [713657.654117] b systemd[1]: Stopped web.service.431b # [713657.666434] b systemd[1]: Reload requested from client PID 610 ('systemctl')...432b # [713657.666473] b systemd[1]: Reloading...433b # [713657.967151] b systemd[1]: Reloading finished in 300 ms.434b # [713658.047844] b systemd[1]: Reload requested from client PID 638 ('systemctl')...435b # [713658.047884] b systemd[1]: Reloading...436b # [713658.342367] b systemd[1]: Reloading finished in 294 ms.437web: restoring /var/lib/web438requires.postgres: running /nix/store/74qvb36qi4n2ggwmxas1sjr4lnply9zq-flakelet-postgres-restore/bin/flakelet-postgres-restore439error: /nix/store/74qvb36qi4n2ggwmxas1sjr4lnply9zq-flakelet-postgres-restore/bin/flakelet-postgres-restore /var/cache/flakelet/.tmppdafdg/requires/postgres/claim.json /var/cache/flakelet/.tmppdafdg/requires/postgres failed:440flakelet-postgres-restore: database web is not empty, refusing441442b: (finished: must fail: flakelet import /tmp/shared/web.tar.zst >&2, in 0.87 seconds)443b: must fail: systemctl is-active web.service444b: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)445b: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2446web: using prebuilt artifact /nix/store/m732qs5ppfnm3j1kcnh10ni5l6gxyy9m-flakelet-web447b # [713658.445886] b runuser[673]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)448b # [713658.462225] b runuser[673]: pam_unix(runuser:session): session closed for user postgres449b # [713658.467893] b runuser[676]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)450b # [713658.480424] b runuser[676]: pam_unix(runuser:session): session closed for user postgres451b # [713658.534598] b systemd[1]: Reload requested from client PID 691 ('systemctl')...452b # [713658.534638] b systemd[1]: Reloading...453web: restoring /var/lib/web454requires.postgres: running /nix/store/74qvb36qi4n2ggwmxas1sjr4lnply9zq-flakelet-postgres-restore/bin/flakelet-postgres-restore455b # [713658.830765] b systemd[1]: Reloading finished in 295 ms.456b # [713658.938860] b runuser[723]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)457b # [713658.950694] b postgres[350]: [350] LOG: checkpoint starting: immediate force wait458b # [713658.960916] b postgres[350]: [350] LOG: checkpoint complete: wrote 14 buffers (0.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.004 s, total=0.011 s; sync files=14, longest=0.001 s, average=0.001 s; distance=4387 kB, estimate=4387 kB; lsn=0/1BAED90, redo lsn=0/1BAED38459b # [713658.977494] b runuser[723]: pam_unix(runuser:session): session closed for user postgres460b # [713658.994941] b runuser[729]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)461b # [713659.045987] b runuser[729]: pam_unix(runuser:session): session closed for user postgres462b # [713659.051942] b runuser[732]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)463b # [713659.067266] b runuser[732]: pam_unix(runuser:session): session closed for user postgres464b # [713659.072441] b runuser[735]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)465b # [713659.090736] b runuser[735]: pam_unix(runuser:session): session closed for user postgres466web: requires.postgres: provisioning via /nix/store/g4lhvdqwxy6vvyqah8vq1qff0xyschv1-flakelet-postgres-provision/bin/flakelet-postgres-provision467web: activating generation 3468b # [713659.108709] b runuser[741]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)469b # [713659.121455] b runuser[741]: pam_unix(runuser:session): session closed for user postgres470b # [713659.129067] b systemd[1]: Reload requested from client PID 744 ('systemctl')...471b # [713659.129119] b systemd[1]: Reloading...472b # [713659.426474] b systemd[1]: Reloading finished in 296 ms.473b # [713659.522951] b systemd[1]: Reload requested from client PID 772 ('systemctl')...474b # [713659.522992] b systemd[1]: Reloading...475web: imported as generation 3476b: (finished: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2, in 1.47 seconds)477b: must succeed: systemctl is-active web.service478b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)479b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload480b: (finished: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload, in 0.03 seconds)481(finished: run the VM test script, in 12.45 seconds)482test script finished in 12.47s483cleanup484kill NspawnMachine (pid 51)485kill NspawnMachine (pid 52)486b # [713659.821735] b systemd[1]: Reloading finished in 298 ms.487b # [713659.912790] b systemd[1]: Starting web.service...488b # [713659.957480] b systemd[1]: Started web.service.489b # [713659.994205] b runuser[805]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)490b # [713660.008089] b runuser[805]: pam_unix(runuser:session): session closed for user web491Container a terminated by signal KILL.492Container b terminated by signal KILL.493(finished: cleanup, in 0.28 seconds)494additionally exposed symbols:495 a, b,496 vlan1,497 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