container-test-run-flakelet-postgres-transfer
checks.x86_64-linux.transfer
· build #10
· raw
1tribuchet: building on jamie2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Initializing machine ID from random generator.6Test will time out and terminate in 3600.0 seconds7run the VM test script8start all 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(a): TAP vde-tap1 not found; container will be isolated from VDE16nixos-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.17nixos-nspawn(b): TAP vde-tap1 not found; container will be isolated from VDE18nixos-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.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.20░ Spawning container a on /build/vm-state-a.21Note: 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.22░ Spawning container b on /build/vm-state-b.23a # No journal files were found.24a # No journal boot entry found for the specified boot (+0).25b # No journal files were found.26b # No journal boot entry found for the specified boot (+0).27a # [108556.998644] a systemd-journald[57]: Journal started28a # [108556.998689] a systemd-journald[57]: Runtime Journal (/run/log/journal/521765592d644be2811afa71c2aae8fd) is 8M, max 4G, 3.9G free.29a # [108557.007663] a systemd[1]: Finished Apply Kernel Variables.30a # [108557.018860] a systemd[1]: Finished Create Static Device Nodes in /dev gracefully.31a # [108557.054402] a systemd[1]: Starting Flush Journal to Persistent Storage...32a # [108557.055098] a systemd[1]: Starting Create Static Device Nodes in /dev...33a # [108557.063504] a systemd-journald[57]: Time spent on flushing to /var/log/journal/521765592d644be2811afa71c2aae8fd is 1.421ms for 6 entries.34a # [108557.063504] a systemd-journald[57]: System Journal (/var/log/journal/521765592d644be2811afa71c2aae8fd) is 512B, max 4G, 3.9G free.35a # [108557.071577] a systemd[1]: Finished Create Static Device Nodes in /dev.36a # [108557.072382] a systemd[1]: Reached target Preparation for Local File Systems.37a # [108557.072515] a systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys38a # [108557.091034] a systemd[1]: Finished Flush Journal to Persistent Storage.39a # [108557.165809] a systemd[1]: Finished Firewall.40a # [108558.017765] a systemd[1]: Mounting /run/wrappers...41b # [108556.990961] b systemd-journald[57]: Journal started42b # [108556.991007] b systemd-journald[57]: Runtime Journal (/run/log/journal/78ceaf3b91314e41b09587a93c2221a1) is 8M, max 4G, 3.9G free.43b # [108557.000443] b systemd[1]: Finished Apply Kernel Variables.44b # [108557.010841] b systemd[1]: Finished Create Static Device Nodes in /dev gracefully.45b # [108557.024017] b systemd[1]: Starting Flush Journal to Persistent Storage...46b # [108557.024699] b systemd[1]: Starting Create Static Device Nodes in /dev...47b # [108557.057395] b systemd-journald[57]: Time spent on flushing to /var/log/journal/78ceaf3b91314e41b09587a93c2221a1 is 2.554ms for 6 entries.48b # [108557.057395] b systemd-journald[57]: System Journal (/var/log/journal/78ceaf3b91314e41b09587a93c2221a1) is 512B, max 4G, 3.9G free.49b # [108557.064634] b systemd[1]: Finished Create Static Device Nodes in /dev.50b # [108557.065382] b systemd[1]: Reached target Preparation for Local File Systems.51b # [108557.065492] b systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys52b # [108557.086294] b systemd[1]: Finished Flush Journal to Persistent Storage.53b # [108557.152137] b systemd[1]: Finished Firewall.54b # [108557.992051] b systemd[1]: Mounting /run/wrappers...55b # [108558.046438] b systemd[1]: Mounted /run/wrappers.56b # [108558.047497] b systemd[1]: Reached target Local File Systems.57b # [108558.048703] b systemd[1]: Listening on Boot Loader Control Service Socket.58b # [108558.050274] b systemd[1]: Starting Create SUID/SGID Wrappers...59b # [108558.050321] b systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container60b # [108558.051572] b systemd[1]: Starting Save Transient machine-id to Disk...61b # [108558.052626] b systemd[1]: Starting Create System Files and Directories...62b # [108558.069689] b systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted63b # [108558.070124] b systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted64b # [108558.070440] b systemd-tmpfiles[161]: fchmod() of /var/log/journal/78ceaf3b91314e41b09587a93c2221a1 failed: Operation not permitted65b # [108558.070789] b systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted66a # [108558.051783] a systemd[1]: Mounted /run/wrappers.67a # [108558.052974] a systemd[1]: Reached target Local File Systems.68a # [108558.054573] a systemd[1]: Listening on Boot Loader Control Service Socket.69a # [108558.055803] a systemd[1]: Starting Create SUID/SGID Wrappers...70a # [108558.055864] a systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container71a # [108558.057126] a systemd[1]: Starting Save Transient machine-id to Disk...72a # [108558.058227] a systemd[1]: Starting Create System Files and Directories...73a # [108558.076702] a systemd-tmpfiles[161]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted74a # [108558.077128] a systemd-tmpfiles[161]: fchmod() of /var/log/journal failed: Operation not permitted75a # [108558.077444] a systemd-tmpfiles[161]: fchmod() of /var/log/journal/521765592d644be2811afa71c2aae8fd failed: Operation not permitted76a # [108558.077500] a suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.ossh0Bmmg3/chsh': Operation not permitted77a # [108558.077768] a systemd-tmpfiles[161]: fchmod() of /run/log/journal failed: Operation not permitted78b # [108558.072318] b suid-sgid-wrappers-start[168]: chmod: changing permissions of '/run/wrappers/wrappers.yGQ4UwV6zl/chsh': Operation not permitted79b # [108558.077894] b systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE80b # [108558.078130] b systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.81b # [108558.078266] b systemd[1]: Failed to start Create SUID/SGID Wrappers.82b # [108558.078687] b systemd[1]: Finished Create System Files and Directories.83b # [108558.090935] b systemd[1]: Starting Rebuild Journal Catalog...84b # [108558.091557] b systemd[1]: Starting Record System Boot/Shutdown in UTMP...85b # [108558.102671] b systemd[1]: Finished Record System Boot/Shutdown in UTMP.86b # [108558.109788] b systemd[1]: Finished Rebuild Journal Catalog.87b # [108558.110866] b systemd[1]: Starting Update is Completed...88b # [108558.119919] b systemd[1]: Finished Update is Completed.89b # [108558.120022] b systemd[1]: Reached target System Initialization.90b # [108558.120082] b systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container91b # [108558.120104] b systemd[1]: Started Daily Cleanup of Temporary Directories.92b # [108558.120117] b systemd[1]: Reached target Timer Units.93b # [108558.120204] b systemd[1]: Listening on D-Bus System Message Bus Socket.94b # [108558.120380] b systemd[1]: Listening on Nix Daemon Socket.95b # [108558.120475] b systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.96b # [108558.120489] b systemd[1]: Reached target Socket Units.97b # [108558.120514] b systemd[1]: Reached target Basic System.98b # [108558.121531] b systemd[1]: Starting Re-link flakelet services at boot...99b # [108558.122234] b systemd[1]: Starting Import lastlog data into lastlog2 database...100b # [108558.123222] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...101b # [108558.123937] b systemd[1]: Starting resolvconf update...102b # [108558.132579] b systemd[1]: Finished Re-link flakelet services at boot.103b # [108558.133532] b systemd[1]: Starting Reconcile flakelet services with the host configuration...104b # [108558.138780] b systemd[1]: Finished Import lastlog data into lastlog2 database.105b # [108558.145996] b systemd[1]: Finished Reconcile flakelet services with the host configuration.106b # [108558.190906] b systemd[1]: nscd.service: Deactivated successfully.107b # [108558.191791] b systemd[1]: Stopped Name Service Cache Daemon (nsncd).108b # [108558.217707] b systemd[1]: etc-machine\x2did.mount: Deactivated successfully.109b # [108558.224143] b systemd[1]: Finished Save Transient machine-id to Disk.110b # [108558.224362] b systemd[1]: Finished resolvconf update.111b # [108558.225608] b systemd[1]: Reached target Preparation for Network.112b # [108558.226486] b systemd[1]: Starting Address configuration of eth1...113b # [108558.227263] b systemd[1]: Starting Extra networking commands....114b # [108558.228475] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...115a # [108558.085025] a systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE116a # [108558.085063] a systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.117a # [108558.085116] a systemd[1]: Failed to start Create SUID/SGID Wrappers.118a # [108558.085595] a systemd[1]: Finished Create System Files and Directories.119a # [108558.098201] a systemd[1]: Starting Rebuild Journal Catalog...120a # [108558.099077] a systemd[1]: Starting Record System Boot/Shutdown in UTMP...121a # [108558.110176] a systemd[1]: Finished Record System Boot/Shutdown in UTMP.122a # [108558.117528] a systemd[1]: Finished Rebuild Journal Catalog.123a # [108558.118452] a systemd[1]: Starting Update is Completed...124a # [108558.128744] a systemd[1]: Finished Update is Completed.125a # [108558.128880] a systemd[1]: Reached target System Initialization.126a # [108558.128948] a systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container127a # [108558.128970] a systemd[1]: Started Daily Cleanup of Temporary Directories.128a # [108558.128984] a systemd[1]: Reached target Timer Units.129a # [108558.129087] a systemd[1]: Listening on D-Bus System Message Bus Socket.130a # [108558.129283] a systemd[1]: Listening on Nix Daemon Socket.131a # [108558.129384] a systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.132a # [108558.129398] a systemd[1]: Reached target Socket Units.133a # [108558.129425] a systemd[1]: Reached target Basic System.134a # [108558.130366] a systemd[1]: Starting Re-link flakelet services at boot...135a # [108558.131265] a systemd[1]: Starting Import lastlog data into lastlog2 database...136a # [108558.131999] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...137a # [108558.132708] a systemd[1]: Starting resolvconf update...138a # [108558.141787] a systemd[1]: Finished Re-link flakelet services at boot.139a # [108558.143676] a systemd[1]: Starting Reconcile flakelet services with the host configuration...140a # [108558.151704] a systemd[1]: Finished Import lastlog data into lastlog2 database.141a # [108558.154107] a systemd[1]: Finished Reconcile flakelet services with the host configuration.142a # [108558.201740] a systemd[1]: nscd.service: Deactivated successfully.143a # [108558.201944] a systemd[1]: Stopped Name Service Cache Daemon (nsncd).144a # [108558.306557] a systemd[1]: etc-machine\x2did.mount: Deactivated successfully.145a # [108558.307232] a systemd[1]: Finished Save Transient machine-id to Disk.146a # [108558.307365] a systemd[1]: Finished resolvconf update.147a # [108558.308615] a systemd[1]: Reached target Preparation for Network.148a # [108558.324496] a systemd[1]: Starting Address configuration of eth1...149a # [108558.325421] a systemd[1]: Starting Extra networking commands....150a # [108558.326365] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...151a # [108558.345480] a network-addresses-eth1-start[240]: adding address 192.168.1.1/24... done152a # [108558.348710] a network-addresses-eth1-start[240]: adding address 2001:db8:1::1/64... done153a # [108558.352933] a systemd[1]: Finished Address configuration of eth1.154a # [108558.392389] a systemd[1]: Finished Extra networking commands..155a # [108558.392473] a systemd[1]: Reached target Network.156a # [108558.393648] a systemd[1]: Starting PostgreSQL Server...157b # [108558.246625] b network-addresses-eth1-start[240]: adding address 192.168.1.2/24... done158b # [108558.249603] b network-addresses-eth1-start[240]: adding address 2001:db8:1::2/64... done159b # [108558.254508] b systemd[1]: Finished Address configuration of eth1.160b # [108558.287587] b systemd[1]: Finished Extra networking commands..161b # [108558.288178] b systemd[1]: Reached target Network.162b # [108558.289383] b systemd[1]: Starting PostgreSQL Server...163b # [108558.624804] b systemd[1]: Started Name Service Cache Daemon (nsncd).164b # [108558.625094] b nsncd[242]: Sep 03 15:36:59.944 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"165b # [108558.624862] b systemd[1]: Reached target Host and Network Name Lookups.166b # [108558.624961] b systemd[1]: Reached target User and Group Name Lookups.167b # [108558.627954] b systemd[1]: Starting User Login Management...168b # [108558.630415] b systemd[1]: Starting Permit User Sessions...169b # [108558.663666] b systemd[1]: Finished Permit User Sessions.170b # [108558.664626] b systemd[1]: Started Console Getty.171b # [108558.664650] b systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0172b # [108558.664661] b systemd[1]: Reached target Login Prompts.173a # [108558.654616] a nsncd[242]: Sep 03 15:36:59.974 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"174a # [108558.654667] a systemd[1]: Started Name Service Cache Daemon (nsncd).175a # [108558.654766] a systemd[1]: Reached target Host and Network Name Lookups.176a # [108558.654880] a systemd[1]: Reached target User and Group Name Lookups.177a # [108558.657339] a systemd[1]: Starting User Login Management...178a # [108558.658968] a systemd[1]: Starting Permit User Sessions...179a # [108558.670591] a systemd[1]: Finished Permit User Sessions.180a # [108558.672182] a systemd[1]: Started Console Getty.181a # [108558.672237] a systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0182a # [108558.672271] a systemd[1]: Reached target Login Prompts.183a # [108560.086189] a systemd-logind[314]: New seat seat0.184a # [108560.086535] a systemd[1]: Started User Login Management.185a # [108560.088727] a systemd[1]: Starting D-Bus System Message Bus...186a # [108560.090226] a systemd[1]: Starting linger-users.service...187a # [108560.101897] a postgresql-pre-start[325]: The files belonging to this database system will be owned by user "postgres".188a # [108560.101897] a postgresql-pre-start[325]: This user must also own the server process.189a # [108560.102470] a postgresql-pre-start[325]: The database cluster will be initialized with locale "en_US.UTF-8".190a # [108560.102470] a postgresql-pre-start[325]: The default database encoding has accordingly been set to "UTF8".191a # [108560.102470] a postgresql-pre-start[325]: The default text search configuration will be set to "english".192a # [108560.102470] a postgresql-pre-start[325]: Data page checksums are enabled.193a # [108560.102470] a postgresql-pre-start[325]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok194a # [108560.103230] a postgresql-pre-start[325]: creating subdirectories ... ok195a # [108560.103369] a postgresql-pre-start[325]: selecting dynamic shared memory implementation ... posix196a # [108560.121112] a systemd[1]: linger-users.service: Deactivated successfully.197a # [108560.121425] a systemd[1]: Finished linger-users.service.198a # [108560.124274] a postgresql-pre-start[325]: selecting default "max_connections" ... 100199a # [108560.149346] a postgresql-pre-start[325]: selecting default "shared_buffers" ... 128MB200b # [108560.083435] b postgresql-pre-start[325]: The files belonging to this database system will be owned by user "postgres".201b # [108560.083435] b postgresql-pre-start[325]: This user must also own the server process.202b # [108560.084198] b postgresql-pre-start[325]: The database cluster will be initialized with locale "en_US.UTF-8".203b # [108560.084198] b postgresql-pre-start[325]: The default database encoding has accordingly been set to "UTF8".204b # [108560.084198] b postgresql-pre-start[325]: The default text search configuration will be set to "english".205b # [108560.084198] b postgresql-pre-start[325]: Data page checksums are enabled.206b # [108560.084198] b postgresql-pre-start[325]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok207b # [108560.085023] b postgresql-pre-start[325]: creating subdirectories ... ok208b # [108560.085170] b postgresql-pre-start[325]: selecting dynamic shared memory implementation ... posix209b # [108560.106477] b postgresql-pre-start[325]: selecting default "max_connections" ... 100210b # [108560.130169] b postgresql-pre-start[325]: selecting default "shared_buffers" ... 128MB211b # [108560.167735] b systemd-logind[306]: New seat seat0.212b # [108560.168143] b systemd[1]: Started User Login Management.213b # [108560.176887] b systemd[1]: Starting D-Bus System Message Bus...214b # [108560.178371] b systemd[1]: Starting linger-users.service...215b # [108560.208927] b systemd[1]: linger-users.service: Deactivated successfully.216b # [108560.209238] b systemd[1]: Finished linger-users.service.217b # [108560.447987] b postgresql-pre-start[325]: selecting default time zone ... UTC218b # [108560.448982] b postgresql-pre-start[325]: creating configuration files ... ok219b # [108560.587862] b dbus-broker-launch[331]: Looking up NSS user entry for 'systemd-timesync'...220b # [108560.589315] b dbus-broker-launch[331]: NSS returned no entry for 'systemd-timesync'221b # [108560.589315] b dbus-broker-launch[331]: Invalid user-name in /nix/store/27h51va7k5wlf4rxs15qkwbr9qq78cc8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"222b # [108560.590217] b systemd[1]: Started D-Bus System Message Bus.223b # [108560.596940] b postgresql-pre-start[325]: running bootstrap script ... ok224b # [108560.596942] b dbus-broker-launch[331]: Ready225a # [108560.467159] a postgresql-pre-start[325]: selecting default time zone ... UTC226a # [108560.468247] a postgresql-pre-start[325]: creating configuration files ... ok227a # [108560.538450] a dbus-broker-launch[326]: Looking up NSS user entry for 'systemd-timesync'...228a # [108560.539471] a dbus-broker-launch[326]: NSS returned no entry for 'systemd-timesync'229a # [108560.539471] a dbus-broker-launch[326]: Invalid user-name in /nix/store/27h51va7k5wlf4rxs15qkwbr9qq78cc8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"230a # [108560.540383] a systemd[1]: Started D-Bus System Message Bus.231a # [108560.547365] a dbus-broker-launch[326]: Ready232a # [108560.614739] a postgresql-pre-start[325]: running bootstrap script ... ok233b # [108560.959272] b postgresql-pre-start[325]: performing post-bootstrap initialization ... ok234a # [108560.974901] a postgresql-pre-start[325]: performing post-bootstrap initialization ... ok235a # [108561.494852] a postgresql-pre-start[325]: syncing data to disk ... ok236a # [108561.494852] a postgresql-pre-start[325]: initdb: warning: enabling "trust" authentication for local connections237a # [108561.494852] a postgresql-pre-start[325]: 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.238a # [108561.494852] a postgresql-pre-start[325]: Success. You can now start the database server using:239a # [108561.494852] a postgresql-pre-start[325]: pg_ctl -D /var/lib/postgresql/18 -l logfile start240b # [108561.520028] b postgresql-pre-start[325]: syncing data to disk ... ok241b # [108561.520028] b postgresql-pre-start[325]: initdb: warning: enabling "trust" authentication for local connections242b # [108561.520028] b postgresql-pre-start[325]: 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.243b # [108561.520028] b postgresql-pre-start[325]: Success. You can now start the database server using:244b # [108561.520028] b postgresql-pre-start[325]: pg_ctl -D /var/lib/postgresql/18 -l logfile start245a # [108562.752148] a postgres[343]: [343] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit246a # [108562.753757] a postgres[343]: [343] LOG: listening on IPv6 address "::1", port 5432247a # [108562.753822] a postgres[343]: [343] LOG: listening on IPv4 address "127.0.0.1", port 5432248a # [108562.754327] a postgres[343]: [343] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"249a # [108562.760270] a postgres[352]: [352] LOG: database system was shut down at 2026-09-03 15:37:02 GMT250a # [108562.765721] a postgres[343]: [343] LOG: database system is ready to accept connections251a # [108562.766599] a systemd[1]: Started PostgreSQL Server.252a # [108562.768607] a systemd[1]: Starting PostgreSQL Setup Scripts...253a # [108562.822624] a systemd[1]: Finished PostgreSQL Setup Scripts.254a # [108562.823301] a systemd[1]: Reached target PostgreSQL.255a # [108562.823490] a systemd[1]: Reached target flakelet contract providers ready.256a # [108562.825299] a systemd[1]: Starting Update flakelet service web...257a # [108562.836325] a flakelet[361]: web: using prebuilt artifact /nix/store/80gh8cpkzmqdxj069w8knajip2kavfrk-flakelet-web258a # [108562.836898] a flakelet[361]: web: requires.postgres: provisioning via /nix/store/qp77pnc8s8l7i9xvwmzk7xd6ahsk13yz-flakelet-postgres-provision/bin/flakelet-postgres-provision259a # [108562.849945] a runuser[365]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)260a # [108562.919658] a runuser[365]: pam_unix(runuser:session): session closed for user postgres261a # [108562.921552] a flakelet[361]: web: activating generation 1262a # [108562.925051] a systemd[1]: Reload requested from client PID 368 ('systemctl') (unit flakelet-web.service)...263a # [108562.925100] a systemd[1]: Reloading...264b # [108562.775210] b postgres[343]: [343] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit265b # [108562.776625] b postgres[343]: [343] LOG: listening on IPv6 address "::1", port 5432266b # [108562.776695] b postgres[343]: [343] LOG: listening on IPv4 address "127.0.0.1", port 5432267b # [108562.777154] b postgres[343]: [343] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"268b # [108562.781805] b postgres[352]: [352] LOG: database system was shut down at 2026-09-03 15:37:02 GMT269b # [108562.785070] b postgres[343]: [343] LOG: database system is ready to accept connections270b # [108562.785737] b systemd[1]: Started PostgreSQL Server.271b # [108562.793895] b systemd[1]: Starting PostgreSQL Setup Scripts...272b # [108562.823499] b systemd[1]: Finished PostgreSQL Setup Scripts.273b # [108562.824913] b systemd[1]: Reached target PostgreSQL.274b # [108562.825136] b systemd[1]: Reached target flakelet contract providers ready.275b # [108562.826628] b systemd[1]: Starting Update flakelet service web...276b # [108562.837010] b flakelet[361]: web: using prebuilt artifact /nix/store/80gh8cpkzmqdxj069w8knajip2kavfrk-flakelet-web277b # [108562.837510] b flakelet[361]: web: requires.postgres: provisioning via /nix/store/qp77pnc8s8l7i9xvwmzk7xd6ahsk13yz-flakelet-postgres-provision/bin/flakelet-postgres-provision278b # [108562.849719] b runuser[365]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)279b # [108562.933738] b runuser[365]: pam_unix(runuser:session): session closed for user postgres280b # [108562.935240] b flakelet[361]: web: activating generation 1281b # [108562.940110] b systemd[1]: Reload requested from client PID 368 ('systemctl') (unit flakelet-web.service)...282b # [108562.940184] b systemd[1]: Reloading...283a # [108563.251592] a systemd[1]: Reloading finished in 326 ms.284a # [108563.330837] a systemd[1]: Reload requested from client PID 397 ('systemctl') (unit flakelet-web.service)...285a # [108563.330882] a systemd[1]: Reloading...286a # [108563.470223] a systemd[1]: multi-user.target: Wants dependency dropin /run/systemd/system/multi-user.target.wants/web.service target /nix/store/w17rpn65cmwysn3ww4sq8qf906cpz52i-web.service has different name287b # [108563.291411] b systemd[1]: Reloading finished in 350 ms.288b # [108563.363847] b systemd[1]: Reload requested from client PID 397 ('systemctl') (unit flakelet-web.service)...289b # [108563.363884] b systemd[1]: Reloading...290b # [108563.540336] b systemd[1]: multi-user.target: Wants dependency dropin /run/systemd/system/multi-user.target.wants/web.service target /nix/store/w17rpn65cmwysn3ww4sq8qf906cpz52i-web.service has different name291b # [108563.699439] b systemd[1]: Reloading finished in 335 ms.292b # [108563.794158] b systemd[1]: Starting web.service...293b # [108563.803458] b systemd[1]: Started web.service.294b # [108563.812444] b flakelet[361]: web: updated to generation 1295b # [108563.814094] b systemd[1]: Finished Update flakelet service web.296b # [108563.814328] b systemd[1]: Reached target flakelet managed services.297b # [108563.814407] b systemd[1]: Reached target Multi-User System.298b # [108563.814587] b systemd[1]: Startup finished in 7.266s.299a # [108563.639342] a systemd[1]: Reloading finished in 308 ms.300a # [108563.747859] a systemd[1]: Starting web.service...301a # [108563.767863] a systemd[1]: Started web.service.302a # [108563.774683] a flakelet[361]: web: updated to generation 1303a # [108563.776332] a systemd[1]: Finished Update flakelet service web.304a # [108563.776580] a systemd[1]: Reached target flakelet managed services.305a # [108563.776664] a systemd[1]: Reached target Multi-User System.306a # [108563.778097] a systemd[1]: Startup finished in 7.221s.307a: (finished: waiting for unit postgresql.target, in 8.16 seconds)308??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.309 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39310a: waiting for unit web.service311a: (finished: waiting for unit web.service, in 0.01 seconds)312a: 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 1313a: (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)314a: 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'\'')'315a: (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.02 seconds)316a: must succeed: flakelet export web --dry-run >&2317{318 "version": 1,319 "flakelet_version": "0.1.0",320 "name": "web",321 "source_host": "a",322 "created": 1788449825,323 "flake": "",324 "output": "flakelets.default",325 "flake_url": "prebuilt:web",326 "flake_rev": "",327 "settings_hash": "44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a",328 "state": {329 "folders": [330 {331 "path": "/var/lib/web",332 "user": "web",333 "group": null,334 "dynamic": false335 }336 ],337 "dump": null,338 "restore": null339 },340 "exports": {341 "requires": {342 "postgres": {343 "database": "web"344 }345 }346 },347 "consistency": "stopped"348}349a: (finished: must succeed: flakelet export web --dry-run >&2, in 0.01 seconds)350a: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst351web: stopping units352requires.postgres: running /nix/store/9m3k2nl1w5yffdzgwlbxz0qygcxa41i3-flakelet-postgres-dump/bin/flakelet-postgres-dump353web: archiving /var/lib/web354a # [108564.226920] a runuser[433]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)355a # [108564.236973] a runuser[433]: pam_unix(runuser:session): session closed for user postgres356a # [108564.246750] a runuser[437]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)357a # [108564.262219] a runuser[437]: pam_unix(runuser:session): session closed for user web358a # [108564.296895] a systemd[1]: Stopping web.service...359a # [108564.297341] a systemd[1]: web.service: Deactivated successfully.360a # [108564.297554] a systemd[1]: Stopped web.service.361a # [108564.315507] a runuser[450]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)362a # [108564.361523] a runuser[450]: pam_unix(runuser:session): session closed for user postgres363a # [108564.406244] a systemd[1]: Reload requested from client PID 465 ('systemctl')...364a # [108564.406313] a systemd[1]: Reloading...365a # [108564.715819] a systemd[1]: Reloading finished in 308 ms.366a # [108564.803050] a systemd[1]: Reload requested from client PID 493 ('systemctl')...367a # [108564.803092] a systemd[1]: Reloading...368web: disabled here, 'flakelet enable web' undoes that369a: (finished: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst, in 0.91 seconds)370a: must fail: systemctl is-active web.service371a: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)372a: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump373a: (finished: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump, in 0.01 seconds)374b: waiting for unit postgresql.target375b: (finished: waiting for unit postgresql.target, in 0.02 seconds)376b: waiting for unit web.service377b: (finished: waiting for unit web.service, in 0.01 seconds)378??? Warning (UserWarning): succeed(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.379 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39380b: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2381??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.382 File "/nix/store/fv4yr9c0f9kyrfc00100i4rlshiiidbd-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39383web: using prebuilt artifact /nix/store/80gh8cpkzmqdxj069w8knajip2kavfrk-flakelet-web384a # [108565.092326] a systemd[1]: Reloading finished in 288 ms.385b # [108565.265878] b systemd[1]: Stopping web.service...386b # [108565.266358] b systemd[1]: web.service: Deactivated successfully.387b # [108565.266617] b systemd[1]: Stopped web.service.388b # [108565.284582] b systemd[1]: Reload requested from client PID 445 ('systemctl')...389b # [108565.284649] b systemd[1]: Reloading...390b # [108565.603141] b systemd[1]: Reloading finished in 317 ms.391b # [108565.700118] b systemd[1]: Reload requested from client PID 473 ('systemctl')...392b # [108565.700156] b systemd[1]: Reloading...393web: restoring /var/lib/web394requires.postgres: running /nix/store/q78p8381gwpx86wjbpwf1dd2s464h4jz-flakelet-postgres-restore/bin/flakelet-postgres-restore395web: requires.postgres: provisioning via /nix/store/qp77pnc8s8l7i9xvwmzk7xd6ahsk13yz-flakelet-postgres-provision/bin/flakelet-postgres-provision396web: activating generation 2397b # [108566.010079] b systemd[1]: Reloading finished in 309 ms.398b # [108566.132737] b runuser[508]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)399b # [108566.144993] b runuser[508]: pam_unix(runuser:session): session closed for user postgres400b # [108566.149022] b runuser[511]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)401b # [108566.161688] b runuser[511]: pam_unix(runuser:session): session closed for user postgres402b # [108566.166151] b runuser[514]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)403b # [108566.178684] b runuser[514]: pam_unix(runuser:session): session closed for user postgres404b # [108566.193108] b runuser[520]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)405b # [108566.204395] b runuser[520]: pam_unix(runuser:session): session closed for user postgres406b # [108566.209658] b systemd[1]: Reload requested from client PID 523 ('systemctl')...407b # [108566.209700] b systemd[1]: Reloading...408b # [108566.517850] b systemd[1]: Reloading finished in 307 ms.409b # [108566.619253] b systemd[1]: Reload requested from client PID 551 ('systemctl')...410b # [108566.619293] b systemd[1]: Reloading...411b # [108566.764316] b systemd[1]: multi-user.target: Wants dependency dropin /run/systemd/system/multi-user.target.wants/web.service target /nix/store/w17rpn65cmwysn3ww4sq8qf906cpz52i-web.service has different name412b # [108566.923068] b systemd[1]: Reloading finished in 303 ms.413web: imported as generation 2414b: (finished: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2, in 1.82 seconds)415b: must succeed: systemctl is-active web.service416b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)417b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload418b: (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.02 seconds)419b: 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 web420b: (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)421b: 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 flakelet422b: (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)423b: must fail: flakelet import /tmp/shared/web.tar.zst >&2424web: using prebuilt artifact /nix/store/80gh8cpkzmqdxj069w8knajip2kavfrk-flakelet-web425b # [108567.008384] b systemd[1]: Starting web.service...426b # [108567.047224] b systemd[1]: Started web.service.427b # [108567.077976] b runuser[584]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)428b # [108567.087069] b runuser[584]: pam_unix(runuser:session): session closed for user web429b # [108567.096351] b runuser[589]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)430b # [108567.107034] b runuser[589]: pam_unix(runuser:session): session closed for user postgres431b # [108567.115749] b runuser[594]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)432b # [108567.124890] b runuser[594]: pam_unix(runuser:session): session closed for user postgres433b # [108567.149593] b systemd[1]: Stopping web.service...434b # [108567.150307] b systemd[1]: web.service: Deactivated successfully.435b # [108567.150433] b systemd[1]: Stopped web.service.436b # [108567.160211] b systemd[1]: Reload requested from client PID 610 ('systemctl')...437b # [108567.160248] b systemd[1]: Reloading...438b # [108567.469603] b systemd[1]: Reloading finished in 309 ms.439b # [108567.549599] b systemd[1]: Reload requested from client PID 638 ('systemctl')...440b # [108567.549638] b systemd[1]: Reloading...441b # [108567.863652] b systemd[1]: Reloading finished in 313 ms.442web: restoring /var/lib/web443requires.postgres: running /nix/store/q78p8381gwpx86wjbpwf1dd2s464h4jz-flakelet-postgres-restore/bin/flakelet-postgres-restore444error: /nix/store/q78p8381gwpx86wjbpwf1dd2s464h4jz-flakelet-postgres-restore/bin/flakelet-postgres-restore /var/cache/flakelet/.tmpuQkIJ4/requires/postgres/claim.json /var/cache/flakelet/.tmpuQkIJ4/requires/postgres failed:445flakelet-postgres-restore: database web is not empty, refusing446447b: (finished: must fail: flakelet import /tmp/shared/web.tar.zst >&2, in 0.89 seconds)448b: must fail: systemctl is-active web.service449b: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)450b: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2451web: using prebuilt artifact /nix/store/80gh8cpkzmqdxj069w8knajip2kavfrk-flakelet-web452b # [108567.979264] b runuser[673]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)453b # [108567.991267] b runuser[673]: pam_unix(runuser:session): session closed for user postgres454b # [108567.995597] b runuser[676]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)455b # [108568.007802] b runuser[676]: pam_unix(runuser:session): session closed for user postgres456b # [108568.068478] b systemd[1]: Reload requested from client PID 691 ('systemctl')...457b # [108568.068559] b systemd[1]: Reloading...458web: restoring /var/lib/web459requires.postgres: running /nix/store/q78p8381gwpx86wjbpwf1dd2s464h4jz-flakelet-postgres-restore/bin/flakelet-postgres-restore460web: requires.postgres: provisioning via /nix/store/qp77pnc8s8l7i9xvwmzk7xd6ahsk13yz-flakelet-postgres-provision/bin/flakelet-postgres-provision461b # [108568.387070] b systemd[1]: Reloading finished in 317 ms.462b # [108568.498203] b runuser[723]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)463b # [108568.508900] b postgres[350]: [350] LOG: checkpoint starting: immediate force wait464b # [108568.519989] 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.006 s, sync=0.004 s, total=0.012 s; sync files=14, longest=0.001 s, average=0.001 s; distance=4387 kB, estimate=4387 kB; lsn=0/1BAED90, redo lsn=0/1BAED38465b # [108568.533360] b runuser[723]: pam_unix(runuser:session): session closed for user postgres466b # [108568.547285] b runuser[729]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)467b # [108568.596121] b runuser[729]: pam_unix(runuser:session): session closed for user postgres468b # [108568.603041] b runuser[732]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)469b # [108568.617055] b runuser[732]: pam_unix(runuser:session): session closed for user postgres470b # [108568.621633] b runuser[735]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)471b # [108568.634169] b runuser[735]: pam_unix(runuser:session): session closed for user postgres472web: activating generation 3473b # [108568.649152] b runuser[741]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)474b # [108568.660574] b runuser[741]: pam_unix(runuser:session): session closed for user postgres475b # [108568.667052] b systemd[1]: Reload requested from client PID 744 ('systemctl')...476b # [108568.667101] b systemd[1]: Reloading...477b # [108568.971256] b systemd[1]: Reloading finished in 303 ms.478b # [108569.057311] b systemd[1]: Reload requested from client PID 772 ('systemctl')...479b # [108569.057352] b systemd[1]: Reloading...480b # [108569.207918] b systemd[1]: multi-user.target: Wants dependency dropin /run/systemd/system/multi-user.target.wants/web.service target /nix/store/w17rpn65cmwysn3ww4sq8qf906cpz52i-web.service has different name481b # [108569.368276] b systemd[1]: Reloading finished in 310 ms.482web: imported as generation 3483b: (finished: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2, in 1.47 seconds)484b: must succeed: systemctl is-active web.service485b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)486b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload487b: (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.02 seconds)488(finished: run the VM test script, in 13.50 seconds)489test script finished in 13.53s490cleanup491kill NspawnMachine (pid 51)492kill NspawnMachine (pid 52)493b # [108569.453535] b systemd[1]: Starting web.service...494b # [108569.487883] b systemd[1]: Started web.service.495b # [108569.522464] b runuser[805]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)496b # [108569.534434] b runuser[805]: pam_unix(runuser:session): session closed for user web497Container a terminated by signal KILL.498Container b terminated by signal KILL.499(finished: cleanup, in 0.38 seconds)500additionally exposed symbols:501 a, b,502 vlan1,503 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