container-test-run-flakelet-postgres-transfer
checks.x86_64-linux.transfer
· build #21
· 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)10a: Waiting for journal at /build/vm-state-a/var/log/journal...11b: systemd-nspawn running (pid 52)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 # [279681.312371] b systemd-journald[58]: Journal started24b # [279681.312498] b systemd-journald[58]: Runtime Journal (/run/log/journal/a2f349a92ae6486c9ceea50ac19053a4) is 8M, max 4G, 3.9G free.25b # [279681.320842] b systemd[1]: Finished Apply Kernel Variables.26b # [279681.332579] b systemd[1]: Finished Create Static Device Nodes in /dev gracefully.27b # [279681.346267] b systemd[1]: Starting Flush Journal to Persistent Storage...28b # [279681.379600] b systemd[1]: Starting Create Static Device Nodes in /dev...29b # [279681.387154] b systemd-journald[58]: Time spent on flushing to /var/log/journal/a2f349a92ae6486c9ceea50ac19053a4 is 1.594ms for 6 entries.30b # [279681.387154] b systemd-journald[58]: System Journal (/var/log/journal/a2f349a92ae6486c9ceea50ac19053a4) is 512B, max 4G, 3.9G free.31b # [279681.396438] b systemd[1]: Finished Create Static Device Nodes in /dev.32b # [279681.397202] b systemd[1]: Reached target Preparation for Local File Systems.33b # [279681.397319] b systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys34b # [279681.411953] b systemd[1]: Finished Flush Journal to Persistent Storage.35a # [279681.312370] a systemd-journald[58]: Journal started36a # [279681.312495] a systemd-journald[58]: Runtime Journal (/run/log/journal/b0b4a57ddfa04851becb12b5faab3584) is 8M, max 4G, 3.9G free.37a # [279681.319554] a systemd[1]: Finished Apply Kernel Variables.38a # [279681.330524] a systemd[1]: Finished Create Static Device Nodes in /dev gracefully.39a # [279681.342960] a systemd[1]: Starting Flush Journal to Persistent Storage...40a # [279681.343691] a systemd[1]: Starting Create Static Device Nodes in /dev...41a # [279681.386467] a systemd-journald[58]: Time spent on flushing to /var/log/journal/b0b4a57ddfa04851becb12b5faab3584 is 1.599ms for 6 entries.42a # [279681.386467] a systemd-journald[58]: System Journal (/var/log/journal/b0b4a57ddfa04851becb12b5faab3584) is 512B, max 4G, 3.9G free.43a # [279681.393339] a systemd[1]: Finished Create Static Device Nodes in /dev.44a # [279681.394214] a systemd[1]: Reached target Preparation for Local File Systems.45a # [279681.394327] a systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys46a # [279681.410965] a systemd[1]: Finished Flush Journal to Persistent Storage.47a # [279681.476247] a systemd[1]: Finished Firewall.48b # [279681.469779] b systemd[1]: Finished Firewall.49a # [279682.308380] a systemd[1]: Mounting /run/wrappers...50a # [279682.347819] a systemd[1]: Mounted /run/wrappers.51a # [279682.348682] a systemd[1]: Reached target Local File Systems.52a # [279682.349419] a systemd[1]: Listening on Boot Loader Control Service Socket.53a # [279682.350284] a systemd[1]: Starting Create SUID/SGID Wrappers...54a # [279682.350315] a systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container55a # [279682.351232] a systemd[1]: Starting Save Transient machine-id to Disk...56a # [279682.352169] a systemd[1]: Starting Create System Files and Directories...57a # [279682.371683] a systemd-tmpfiles[162]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted58a # [279682.372141] a systemd-tmpfiles[162]: fchmod() of /var/log/journal failed: Operation not permitted59a # [279682.372436] a systemd-tmpfiles[162]: fchmod() of /var/log/journal/b0b4a57ddfa04851becb12b5faab3584 failed: Operation not permitted60a # [279682.372772] a systemd-tmpfiles[162]: fchmod() of /run/log/journal failed: Operation not permitted61b # [279682.332761] b systemd[1]: Mounting /run/wrappers...62b # [279682.362330] b systemd[1]: Mounted /run/wrappers.63b # [279682.363498] b systemd[1]: Reached target Local File Systems.64b # [279682.364648] b systemd[1]: Listening on Boot Loader Control Service Socket.65b # [279682.365873] b systemd[1]: Starting Create SUID/SGID Wrappers...66b # [279682.365920] b systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container67b # [279682.366862] b systemd[1]: Starting Save Transient machine-id to Disk...68b # [279682.368026] b systemd[1]: Starting Create System Files and Directories...69b # [279682.391270] b suid-sgid-wrappers-start[169]: chmod: changing permissions of '/run/wrappers/wrappers.nYccLhJY0d/chsh': Operation not permitted70b # [279682.421017] b systemd-tmpfiles[162]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted71b # [279682.421422] b systemd-tmpfiles[162]: fchmod() of /var/log/journal failed: Operation not permitted72b # [279682.421719] b systemd-tmpfiles[162]: fchmod() of /var/log/journal/a2f349a92ae6486c9ceea50ac19053a4 failed: Operation not permitted73b # [279682.422057] b systemd-tmpfiles[162]: fchmod() of /run/log/journal failed: Operation not permitted74a # [279682.378021] a suid-sgid-wrappers-start[170]: chmod: changing permissions of '/run/wrappers/wrappers.16DCYz7E70/chsh': Operation not permitted75a # [279682.385949] a systemd[1]: Finished Create System Files and Directories.76a # [279682.418374] a systemd[1]: etc-machine\x2did.mount: Deactivated successfully.77a # [279682.428747] a systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE78a # [279682.428818] a systemd[1]: suid-sgid-wrappers.service: Failed to read pids.max for control group /system.slice/suid-sgid-wrappers.service, ignoring: No data available79a # [279682.428861] a systemd[1]: suid-sgid-wrappers.service: Failed to read pids.max for control group /system.slice/suid-sgid-wrappers.service, ignoring: No data available80a # [279682.428892] a systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.81a # [279682.429061] a systemd[1]: Failed to start Create SUID/SGID Wrappers.82a # [279682.429299] a systemd[1]: Finished Save Transient machine-id to Disk.83a # [279682.431989] a systemd[1]: Starting Rebuild Journal Catalog...84a # [279682.432852] a systemd[1]: Starting Record System Boot/Shutdown in UTMP...85a # [279682.479145] a systemd[1]: Finished Record System Boot/Shutdown in UTMP.86a # [279682.485768] a systemd[1]: Finished Rebuild Journal Catalog.87a # [279682.487148] a systemd[1]: Starting Update is Completed...88a # [279682.498517] a systemd[1]: Finished Update is Completed.89a # [279682.498620] a systemd[1]: Reached target System Initialization.90a # [279682.498713] a systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container91a # [279682.498763] a systemd[1]: Started Daily Cleanup of Temporary Directories.92a # [279682.498780] a systemd[1]: Reached target Timer Units.93a # [279682.498890] a systemd[1]: Listening on D-Bus System Message Bus Socket.94a # [279682.499115] a systemd[1]: Listening on Nix Daemon Socket.95a # [279682.499216] a systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.96a # [279682.499232] a systemd[1]: Reached target Socket Units.97a # [279682.499260] a systemd[1]: Reached target Basic System.98a # [279682.500460] a systemd[1]: Starting Re-link flakelet services at boot...99a # [279682.501166] a systemd[1]: Starting Import lastlog data into lastlog2 database...100a # [279682.502135] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...101a # [279682.502815] a systemd[1]: Starting resolvconf update...102a # [279682.512622] a systemd[1]: Finished Re-link flakelet services at boot.103a # [279682.515120] a systemd[1]: Starting Reconcile flakelet services with the host configuration...104a # [279682.522862] a systemd[1]: Finished Import lastlog data into lastlog2 database.105a # [279682.527821] a systemd[1]: Finished Reconcile flakelet services with the host configuration.106b # [279682.427718] b systemd[1]: etc-machine\x2did.mount: Deactivated successfully.107b # [279682.439105] b systemd[1]: suid-sgid-wrappers.service: Main process exited, code=exited, status=1/FAILURE108b # [279682.439138] b systemd[1]: suid-sgid-wrappers.service: Failed to read pids.max for control group /system.slice/suid-sgid-wrappers.service, ignoring: No data available109b # [279682.439157] b systemd[1]: suid-sgid-wrappers.service: Failed to read pids.max for control group /system.slice/suid-sgid-wrappers.service, ignoring: No data available110b # [279682.439169] b systemd[1]: suid-sgid-wrappers.service: Failed with result 'exit-code'.111b # [279682.439233] b systemd[1]: Failed to start Create SUID/SGID Wrappers.112b # [279682.439388] b systemd[1]: Finished Save Transient machine-id to Disk.113b # [279682.467556] b systemd[1]: Finished Create System Files and Directories.114b # [279682.481515] b systemd[1]: Starting Rebuild Journal Catalog...115b # [279682.482689] b systemd[1]: Starting Record System Boot/Shutdown in UTMP...116b # [279682.499354] b systemd[1]: Finished Record System Boot/Shutdown in UTMP.117b # [279682.503532] b systemd[1]: Finished Rebuild Journal Catalog.118b # [279682.505359] b systemd[1]: Starting Update is Completed...119b # [279682.517552] b systemd[1]: Finished Update is Completed.120b # [279682.517781] b systemd[1]: Reached target System Initialization.121b # [279682.517887] b systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container122b # [279682.517927] b systemd[1]: Started Daily Cleanup of Temporary Directories.123b # [279682.517950] b systemd[1]: Reached target Timer Units.124b # [279682.518127] b systemd[1]: Listening on D-Bus System Message Bus Socket.125b # [279682.518387] b systemd[1]: Listening on Nix Daemon Socket.126b # [279682.518563] b systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.127b # [279682.518585] b systemd[1]: Reached target Socket Units.128b # [279682.518633] b systemd[1]: Reached target Basic System.129b # [279682.520308] b systemd[1]: Starting Re-link flakelet services at boot...130b # [279682.521319] b systemd[1]: Starting Import lastlog data into lastlog2 database...131b # [279682.522777] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...132b # [279682.523860] b systemd[1]: Starting resolvconf update...133b # [279682.534571] b systemd[1]: Finished Re-link flakelet services at boot.134b # [279682.536062] b systemd[1]: Starting Reconcile flakelet services with the host configuration...135b # [279682.542673] b systemd[1]: Finished Import lastlog data into lastlog2 database.136b # [279682.546985] b systemd[1]: Finished Reconcile flakelet services with the host configuration.137b # [279682.606943] b systemd[1]: nscd.service: Failed to read pids.max for control group /system.slice/nscd.service, ignoring: No data available138b # [279682.607023] b systemd[1]: nscd.service: Deactivated successfully.139b # [279682.624253] b systemd[1]: Stopped Name Service Cache Daemon (nsncd).140b # [279682.627099] b systemd[1]: Finished resolvconf update.141b # [279682.628554] b systemd[1]: Reached target Preparation for Network.142b # [279682.630091] b systemd[1]: Starting Address configuration of eth1...143b # [279682.631637] b systemd[1]: Starting Extra networking commands....144b # [279682.633183] b systemd[1]: Starting Name Service Cache Daemon (nsncd)...145b # [279682.650589] b network-addresses-eth1-start[241]: adding address 192.168.1.2/24... done146b # [279682.653714] b network-addresses-eth1-start[241]: adding address 2001:db8:1::2/64... done147b # [279682.658310] b systemd[1]: Finished Address configuration of eth1.148b # [279682.703380] b systemd[1]: Finished Extra networking commands..149b # [279682.703501] b systemd[1]: Reached target Network.150b # [279682.704712] b systemd[1]: Starting PostgreSQL Server...151a # [279682.584523] a systemd[1]: nscd.service: Failed to read pids.max for control group /system.slice/nscd.service, ignoring: No data available152a # [279682.584557] a systemd[1]: nscd.service: Deactivated successfully.153a # [279682.584677] a systemd[1]: Stopped Name Service Cache Daemon (nsncd).154a # [279682.587353] a systemd[1]: Starting Name Service Cache Daemon (nsncd)...155a # [279682.624243] a systemd[1]: Finished resolvconf update.156a # [279682.624533] a systemd[1]: Reached target Preparation for Network.157a # [279682.625846] a systemd[1]: Starting Address configuration of eth1...158a # [279682.626951] a systemd[1]: Starting Extra networking commands....159a # [279682.647151] a network-addresses-eth1-start[243]: adding address 192.168.1.1/24... done160a # [279682.651441] a network-addresses-eth1-start[243]: adding address 2001:db8:1::1/64... done161a # [279682.657148] a systemd[1]: Finished Address configuration of eth1.162a # [279682.698497] a systemd[1]: Finished Extra networking commands..163a # [279682.699197] a systemd[1]: Reached target Network.164a # [279682.700764] a systemd[1]: Starting PostgreSQL Server...165a # [279682.884989] a nsncd[239]: Oct 29 15:36:38.929 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"166a # [279682.884920] a systemd[1]: Started Name Service Cache Daemon (nsncd).167a # [279682.884992] a systemd[1]: Reached target Host and Network Name Lookups.168a # [279682.885123] a systemd[1]: Reached target User and Group Name Lookups.169a # [279682.886634] a systemd[1]: Starting User Login Management...170a # [279682.887450] a systemd[1]: Starting Permit User Sessions...171a # [279682.927736] a systemd[1]: Finished Permit User Sessions.172a # [279682.928950] a systemd[1]: Started Console Getty.173a # [279682.928976] a systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0174a # [279682.928991] a systemd[1]: Reached target Login Prompts.175b # [279682.882730] b nsncd[243]: Oct 29 15:36:38.927 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"176b # [279682.882792] b systemd[1]: Started Name Service Cache Daemon (nsncd).177b # [279682.882894] b systemd[1]: Reached target Host and Network Name Lookups.178b # [279682.883018] b systemd[1]: Reached target User and Group Name Lookups.179b # [279682.885646] b systemd[1]: Starting User Login Management...180b # [279682.887074] b systemd[1]: Starting Permit User Sessions...181b # [279682.923530] b systemd[1]: Finished Permit User Sessions.182b # [279682.926531] b systemd[1]: Started Console Getty.183b # [279682.926587] b systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0184b # [279682.926622] b systemd[1]: Reached target Login Prompts.185a # [279683.975284] a systemd-logind[315]: New seat seat0.186a # [279683.976068] a systemd[1]: Started User Login Management.187a # [279684.000138] a systemd[1]: Starting D-Bus System Message Bus...188a # [279684.001344] a systemd[1]: Starting linger-users.service...189a # [279684.024873] a systemd[1]: linger-users.service: Failed to read pids.max for control group /system.slice/linger-users.service, ignoring: No data available190a # [279684.024924] a systemd[1]: linger-users.service: Failed to read pids.max for control group /system.slice/linger-users.service, ignoring: No data available191a # [279684.024969] a systemd[1]: linger-users.service: Deactivated successfully.192a # [279684.025130] a systemd[1]: Finished linger-users.service.193a # [279684.111159] a postgresql-pre-start[330]: The files belonging to this database system will be owned by user "postgres".194a # [279684.111159] a postgresql-pre-start[330]: This user must also own the server process.195a # [279684.111930] a postgresql-pre-start[330]: The database cluster will be initialized with locale "en_US.UTF-8".196a # [279684.111930] a postgresql-pre-start[330]: The default database encoding has accordingly been set to "UTF8".197a # [279684.111930] a postgresql-pre-start[330]: The default text search configuration will be set to "english".198a # [279684.111930] a postgresql-pre-start[330]: Data page checksums are enabled.199a # [279684.111930] a postgresql-pre-start[330]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok200a # [279684.112646] a postgresql-pre-start[330]: creating subdirectories ... ok201a # [279684.112798] a postgresql-pre-start[330]: selecting dynamic shared memory implementation ... posix202a # [279684.135700] a postgresql-pre-start[330]: selecting default "max_connections" ... 100203a # [279684.163605] a postgresql-pre-start[330]: selecting default "shared_buffers" ... 128MB204b # [279683.969111] b systemd-logind[315]: New seat seat0.205b # [279683.970109] b systemd[1]: Starting D-Bus System Message Bus...206b # [279683.970312] b systemd[1]: Started User Login Management.207b # [279683.971432] b systemd[1]: Starting linger-users.service...208b # [279683.994609] b postgresql-pre-start[326]: The files belonging to this database system will be owned by user "postgres".209b # [279683.994609] b postgresql-pre-start[326]: This user must also own the server process.210b # [279683.995313] b postgresql-pre-start[326]: The database cluster will be initialized with locale "en_US.UTF-8".211b # [279683.995313] b postgresql-pre-start[326]: The default database encoding has accordingly been set to "UTF8".212b # [279683.995313] b postgresql-pre-start[326]: The default text search configuration will be set to "english".213b # [279683.995313] b postgresql-pre-start[326]: Data page checksums are enabled.214b # [279683.995313] b postgresql-pre-start[326]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok215b # [279683.996168] b postgresql-pre-start[326]: creating subdirectories ... ok216b # [279683.996316] b postgresql-pre-start[326]: selecting dynamic shared memory implementation ... posix217b # [279684.009409] b systemd[1]: linger-users.service: Failed to read pids.max for control group /system.slice/linger-users.service, ignoring: No data available218b # [279684.009457] b systemd[1]: linger-users.service: Failed to read pids.max for control group /system.slice/linger-users.service, ignoring: No data available219b # [279684.009488] b systemd[1]: linger-users.service: Deactivated successfully.220b # [279684.009672] b systemd[1]: Finished linger-users.service.221b # [279684.022590] b postgresql-pre-start[326]: selecting default "max_connections" ... 100222b # [279684.051434] b postgresql-pre-start[326]: selecting default "shared_buffers" ... 128MB223b # [279684.364319] b dbus-broker-launch[327]: Looking up NSS user entry for 'systemd-timesync'...224a # [279684.360337] a dbus-broker-launch[325]: Looking up NSS user entry for 'systemd-timesync'...225a # [279684.364042] a dbus-broker-launch[325]: NSS returned no entry for 'systemd-timesync'226a # [279684.364042] a dbus-broker-launch[325]: Invalid user-name in /nix/store/mvl79r6dv02smjnd8gvrxxy96a1ip98k-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"227a # [279684.365414] a systemd[1]: Started D-Bus System Message Bus.228a # [279684.373843] a dbus-broker-launch[325]: Ready229a # [279684.486255] a postgresql-pre-start[330]: selecting default time zone ... UTC230a # [279684.487282] a postgresql-pre-start[330]: creating configuration files ... ok231a # [279684.618218] a postgresql-pre-start[330]: running bootstrap script ... ok232b # [279684.365732] b dbus-broker-launch[327]: NSS returned no entry for 'systemd-timesync'233b # [279684.365732] b dbus-broker-launch[327]: Invalid user-name in /nix/store/mvl79r6dv02smjnd8gvrxxy96a1ip98k-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"234b # [279684.366798] b systemd[1]: Started D-Bus System Message Bus.235b # [279684.373920] b dbus-broker-launch[327]: Ready236b # [279684.400195] b postgresql-pre-start[326]: selecting default time zone ... UTC237b # [279684.401186] b postgresql-pre-start[326]: creating configuration files ... ok238b # [279684.527896] b postgresql-pre-start[326]: running bootstrap script ... ok239b # [279684.867227] b postgresql-pre-start[326]: performing post-bootstrap initialization ... ok240a # [279684.966245] a postgresql-pre-start[330]: performing post-bootstrap initialization ... ok241b # [279685.224340] b postgresql-pre-start[326]: syncing data to disk ... ok242b # [279685.224340] b postgresql-pre-start[326]: initdb: warning: enabling "trust" authentication for local connections243b # [279685.224340] b postgresql-pre-start[326]: 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.244b # [279685.224340] b postgresql-pre-start[326]: Success. You can now start the database server using:245b # [279685.224340] b postgresql-pre-start[326]: pg_ctl -D /var/lib/postgresql/18 -l logfile start246a # [279685.322734] a postgresql-pre-start[330]: syncing data to disk ... ok247a # [279685.322734] a postgresql-pre-start[330]: initdb: warning: enabling "trust" authentication for local connections248a # [279685.322734] a postgresql-pre-start[330]: 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.249a # [279685.322734] a postgresql-pre-start[330]: Success. You can now start the database server using:250a # [279685.322734] a postgresql-pre-start[330]: pg_ctl -D /var/lib/postgresql/18 -l logfile start251b # [279686.294522] b postgres[344]: [344] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit252b # [279686.296824] b postgres[344]: [344] LOG: listening on IPv6 address "::1", port 5432253b # [279686.296955] b postgres[344]: [344] LOG: listening on IPv4 address "127.0.0.1", port 5432254b # [279686.297427] b postgres[344]: [344] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"255b # [279686.303099] b postgres[353]: [353] LOG: database system was shut down at 2026-10-29 15:36:40 GMT256b # [279686.307268] b postgres[344]: [344] LOG: database system is ready to accept connections257b # [279686.307971] b systemd[1]: Started PostgreSQL Server.258b # [279686.310329] b systemd[1]: Starting PostgreSQL Setup Scripts...259b # [279686.385938] b systemd[1]: Finished PostgreSQL Setup Scripts.260b # [279686.386605] b systemd[1]: Reached target PostgreSQL.261b # [279686.386803] b systemd[1]: Reached target flakelet contract providers ready.262b # [279686.388708] b systemd[1]: Starting Update flakelet service web...263b # [279686.435635] b flakelet[362]: web: using prebuilt artifact /nix/store/hpzr1hm2j0h7mvfcs76fq9fz2z4nbvf4-flakelet-web264b # [279686.436266] b flakelet[362]: web: requires.postgres: provisioning via /nix/store/znfschrqf30ml2wzf1zyxv8zpdrmrlxx-flakelet-postgres-provision/bin/flakelet-postgres-provision265b # [279686.453211] b runuser[366]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)266b # [279686.538294] b runuser[366]: pam_unix(runuser:session): session closed for user postgres267b # [279686.540916] b flakelet[362]: web: activating generation 1268b # [279686.546919] b systemd[1]: Reload requested from client PID 369 ('systemctl') (unit flakelet-web.service)...269b # [279686.547020] b systemd[1]: Reloading...270a # [279686.396102] a postgres[344]: [344] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit271a # [279686.397277] a postgres[344]: [344] LOG: listening on IPv6 address "::1", port 5432272a # [279686.397277] a postgres[344]: [344] LOG: listening on IPv4 address "127.0.0.1", port 5432273a # [279686.397791] a postgres[344]: [344] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"274a # [279686.402691] a postgres[353]: [353] LOG: database system was shut down at 2026-10-29 15:36:40 GMT275a # [279686.406146] a postgres[344]: [344] LOG: database system is ready to accept connections276a # [279686.406858] a systemd[1]: Started PostgreSQL Server.277a # [279686.426092] a systemd[1]: Starting PostgreSQL Setup Scripts...278a # [279686.459424] a systemd[1]: Finished PostgreSQL Setup Scripts.279a # [279686.459725] a systemd[1]: Reached target PostgreSQL.280a # [279686.459818] a systemd[1]: Reached target flakelet contract providers ready.281a # [279686.460855] a systemd[1]: Starting Update flakelet service web...282a # [279686.474222] a flakelet[362]: web: using prebuilt artifact /nix/store/hpzr1hm2j0h7mvfcs76fq9fz2z4nbvf4-flakelet-web283a # [279686.474664] a flakelet[362]: web: requires.postgres: provisioning via /nix/store/znfschrqf30ml2wzf1zyxv8zpdrmrlxx-flakelet-postgres-provision/bin/flakelet-postgres-provision284a # [279686.487943] a runuser[366]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)285a # [279686.571509] a runuser[366]: pam_unix(runuser:session): session closed for user postgres286a # [279686.573734] a flakelet[362]: web: activating generation 1287a # [279686.578710] a systemd[1]: Reload requested from client PID 369 ('systemctl') (unit flakelet-web.service)...288a # [279686.578791] a systemd[1]: Reloading...289b # [279686.850012] b systemd[1]: Reloading finished in 302 ms.290b # [279687.021832] b systemd[1]: Reload requested from client PID 399 ('systemctl') (unit flakelet-web.service)...291b # [279687.021902] b systemd[1]: Reloading...292a # [279686.849285] a systemd[1]: Reloading finished in 269 ms.293a # [279687.015828] a systemd[1]: Reload requested from client PID 399 ('systemctl') (unit flakelet-web.service)...294a # [279687.015889] a systemd[1]: Reloading...295a: (finished: waiting for unit postgresql.target, in 7.16 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/nnab7wdwimd0gr2jj9xc8bi3rbkzkzjh-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 1301b # [279687.290396] b systemd[1]: Reloading finished in 267 ms.302b # [279687.424951] b systemd[1]: Starting web.service...303b # [279687.458036] b systemd[1]: Started web.service.304b # [279687.465316] b flakelet[362]: web: updated to generation 1305b # [279687.467248] b systemd[1]: Finished Update flakelet service web.306b # [279687.467875] b systemd[1]: Reached target flakelet managed services.307b # [279687.468108] b systemd[1]: Reached target Multi-User System.308b # [279687.468405] b systemd[1]: Startup finished in 6.526s.309a # [279687.286419] a systemd[1]: Reloading finished in 269 ms.310a # [279687.422274] a systemd[1]: Starting web.service...311a # [279687.457818] a systemd[1]: Started web.service.312a # [279687.465819] a flakelet[362]: web: updated to generation 1313a # [279687.467756] a systemd[1]: Finished Update flakelet service web.314a # [279687.468642] a systemd[1]: Reached target flakelet managed services.315a # [279687.468908] a systemd[1]: Reached target Multi-User System.316a # [279687.469199] a systemd[1]: Startup finished in 6.527s.317a: (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.03 seconds)318a: 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'\'')'319a: (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)320a: must succeed: flakelet export web --dry-run >&2321{322 "version": 1,323 "flakelet_version": "0.1.0",324 "name": "web",325 "source_host": "a",326 "created": 1793288203,327 "flake": "",328 "output": "flakelets.default",329 "flake_url": "prebuilt:web",330 "flake_rev": "",331 "settings_hash": "44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a",332 "state": {333 "folders": [334 {335 "path": "/var/lib/web",336 "user": "web",337 "group": null,338 "dynamic": false339 }340 ],341 "dump": null,342 "restore": null343 },344 "exports": {345 "requires": {346 "postgres": {347 "database": "web"348 }349 }350 },351 "consistency": "stopped"352}353a: (finished: must succeed: flakelet export web --dry-run >&2, in 0.01 seconds)354a: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst355web: stopping units356requires.postgres: running /nix/store/yi51jng5aj5cn8g8jmgjrbqdarjgr1s0-flakelet-postgres-dump/bin/flakelet-postgres-dump357web: archiving /var/lib/web358a # [279687.639145] a runuser[436]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)359a # [279687.652187] a runuser[436]: pam_unix(runuser:session): session closed for user postgres360a # [279687.663086] a runuser[440]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)361a # [279687.677730] a runuser[440]: pam_unix(runuser:session): session closed for user web362a # [279687.710891] a systemd[1]: Stopping web.service...363a # [279687.711298] a systemd[1]: web.service: Failed to read pids.max for control group /system.slice/web.service, ignoring: No data available364a # [279687.711359] a systemd[1]: web.service: Deactivated successfully.365a # [279687.711563] a systemd[1]: Stopped web.service.366a # [279687.730149] a runuser[453]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)367a # [279687.781218] a runuser[453]: pam_unix(runuser:session): session closed for user postgres368a # [279687.827174] a systemd[1]: Reload requested from client PID 468 ('systemctl')...369a # [279687.827246] a systemd[1]: Reloading...370a # [279688.089715] a systemd[1]: Reloading finished in 261 ms.371a # [279688.174940] a systemd[1]: Reload requested from client PID 497 ('systemctl')...372a # [279688.174982] a systemd[1]: Reloading...373web: disabled here, 'flakelet enable web' undoes that374a: (finished: must succeed: flakelet export web --to b > /tmp/shared/web.tar.zst, in 0.83 seconds)375a: must fail: systemctl is-active web.service376a: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)377a: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump378a: (finished: must succeed: tar --zstd -tf /tmp/shared/web.tar.zst | grep -q requires/postgres/db.pgdump, in 0.01 seconds)379b: waiting for unit postgresql.target380b: (finished: waiting for unit postgresql.target, in 0.02 seconds)381b: waiting for unit web.service382b: (finished: waiting for unit web.service, in 0.02 seconds)383??? Warning (UserWarning): succeed(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.384 File "/nix/store/nnab7wdwimd0gr2jj9xc8bi3rbkzkzjh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39385b: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2386??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.387 File "/nix/store/nnab7wdwimd0gr2jj9xc8bi3rbkzkzjh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39388web: using prebuilt artifact /nix/store/hpzr1hm2j0h7mvfcs76fq9fz2z4nbvf4-flakelet-web389a # [279688.422196] a systemd[1]: Reloading finished in 246 ms.390b # [279688.612798] b systemd[1]: Stopping web.service...391b # [279688.614433] b systemd[1]: web.service: Failed to read pids.max for control group /system.slice/web.service, ignoring: No data available392b # [279688.614491] b systemd[1]: web.service: Deactivated successfully.393b # [279688.614752] b systemd[1]: Stopped web.service.394b # [279688.631089] b systemd[1]: Reload requested from client PID 448 ('systemctl')...395b # [279688.631157] b systemd[1]: Reloading...396b # [279688.892977] b systemd[1]: Reloading finished in 261 ms.397b # [279688.991400] b systemd[1]: Reload requested from client PID 477 ('systemctl')...398b # [279688.991441] b systemd[1]: Reloading...399b # [279689.241289] b systemd[1]: Reloading finished in 249 ms.400web: restoring /var/lib/web401requires.postgres: running /nix/store/c9rf88nplna0k28pn24kwa7imva8halg-flakelet-postgres-restore/bin/flakelet-postgres-restore402web: requires.postgres: provisioning via /nix/store/znfschrqf30ml2wzf1zyxv8zpdrmrlxx-flakelet-postgres-provision/bin/flakelet-postgres-provision403web: activating generation 2404b # [279689.358646] b runuser[513]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)405b # [279689.372784] b runuser[513]: pam_unix(runuser:session): session closed for user postgres406b # [279689.377817] b runuser[516]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)407b # [279689.391897] b runuser[516]: pam_unix(runuser:session): session closed for user postgres408b # [279689.396441] b runuser[519]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)409b # [279689.413991] b runuser[519]: pam_unix(runuser:session): session closed for user postgres410b # [279689.432147] b runuser[525]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)411b # [279689.444857] b runuser[525]: pam_unix(runuser:session): session closed for user postgres412b # [279689.452268] b systemd[1]: Reload requested from client PID 528 ('systemctl')...413b # [279689.452349] b systemd[1]: Reloading...414b # [279689.730604] b systemd[1]: Reloading finished in 277 ms.415b # [279689.823237] b systemd[1]: Reload requested from client PID 557 ('systemctl')...416b # [279689.823277] b systemd[1]: Reloading...417b # [279690.067185] b systemd[1]: Reloading finished in 243 ms.418web: imported as generation 2419b: (finished: must succeed: flakelet import - < /tmp/shared/web.tar.zst >&2, in 1.61 seconds)420b: must succeed: systemctl is-active web.service421b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)422b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload423b: (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)424b: 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 web425b: (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)426b: 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 flakelet427b: (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)428b: must fail: flakelet import /tmp/shared/web.tar.zst >&2429web: using prebuilt artifact /nix/store/hpzr1hm2j0h7mvfcs76fq9fz2z4nbvf4-flakelet-web430b # [279690.154123] b systemd[1]: Starting web.service...431b # [279690.177950] b systemd[1]: Started web.service.432b # [279690.211646] b runuser[591]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)433b # [279690.223956] b runuser[591]: pam_unix(runuser:session): session closed for user web434b # [279690.235766] b runuser[596]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)435b # [279690.248250] b runuser[596]: pam_unix(runuser:session): session closed for user postgres436b # [279690.258703] b runuser[601]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)437b # [279690.270042] b runuser[601]: pam_unix(runuser:session): session closed for user postgres438b # [279690.308510] b systemd[1]: Stopping web.service...439b # [279690.310255] b systemd[1]: web.service: Failed to read pids.max for control group /system.slice/web.service, ignoring: No data available440b # [279690.310343] b systemd[1]: web.service: Deactivated successfully.441b # [279690.310688] b systemd[1]: Stopped web.service.442b # [279690.327137] b systemd[1]: Reload requested from client PID 617 ('systemctl')...443b # [279690.327207] b systemd[1]: Reloading...444b # [279690.594481] b systemd[1]: Reloading finished in 266 ms.445b # [279690.681297] b systemd[1]: Reload requested from client PID 646 ('systemctl')...446b # [279690.681337] b systemd[1]: Reloading...447web: restoring /var/lib/web448requires.postgres: running /nix/store/c9rf88nplna0k28pn24kwa7imva8halg-flakelet-postgres-restore/bin/flakelet-postgres-restore449error: /nix/store/c9rf88nplna0k28pn24kwa7imva8halg-flakelet-postgres-restore/bin/flakelet-postgres-restore /var/cache/flakelet/.tmpk5Kex9/requires/postgres/claim.json /var/cache/flakelet/.tmpk5Kex9/requires/postgres failed:450flakelet-postgres-restore: database web is not empty, refusing451452b: (finished: must fail: flakelet import /tmp/shared/web.tar.zst >&2, in 0.82 seconds)453b: must fail: systemctl is-active web.service454b: (finished: must fail: systemctl is-active web.service, in 0.01 seconds)455b: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2456web: using prebuilt artifact /nix/store/hpzr1hm2j0h7mvfcs76fq9fz2z4nbvf4-flakelet-web457b # [279690.935346] b systemd[1]: Reloading finished in 253 ms.458b # [279691.053974] b runuser[682]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)459b # [279691.067705] b runuser[682]: pam_unix(runuser:session): session closed for user postgres460b # [279691.072585] b runuser[685]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)461b # [279691.084796] b runuser[685]: pam_unix(runuser:session): session closed for user postgres462b # [279691.139991] b systemd[1]: Reload requested from client PID 700 ('systemctl')...463b # [279691.140039] b systemd[1]: Reloading...464web: restoring /var/lib/web465requires.postgres: running /nix/store/c9rf88nplna0k28pn24kwa7imva8halg-flakelet-postgres-restore/bin/flakelet-postgres-restore466b # [279691.392008] b systemd[1]: Reloading finished in 251 ms.467b # [279691.491623] b runuser[733]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)468b # [279691.503279] b postgres[351]: [351] LOG: checkpoint starting: immediate force wait469b # [279691.513556] b postgres[351]: [351] 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/1BAED38470b # [279691.532553] b runuser[733]: pam_unix(runuser:session): session closed for user postgres471b # [279691.551525] b runuser[739]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)472b # [279691.601571] b runuser[739]: pam_unix(runuser:session): session closed for user postgres473b # [279691.608163] b runuser[742]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)474b # [279691.624381] b runuser[742]: pam_unix(runuser:session): session closed for user postgres475b # [279691.629447] b runuser[745]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)476b # [279691.643117] b runuser[745]: pam_unix(runuser:session): session closed for user postgres477web: requires.postgres: provisioning via /nix/store/znfschrqf30ml2wzf1zyxv8zpdrmrlxx-flakelet-postgres-provision/bin/flakelet-postgres-provision478web: activating generation 3479b # [279691.660635] b runuser[751]: pam_unix(runuser:session): session opened for user postgres(uid=71) by (uid=0)480b # [279691.673253] b runuser[751]: pam_unix(runuser:session): session closed for user postgres481b # [279691.681377] b systemd[1]: Reload requested from client PID 754 ('systemctl')...482b # [279691.681458] b systemd[1]: Reloading...483b # [279691.979366] b systemd[1]: Reloading finished in 297 ms.484b # [279692.069452] b systemd[1]: Reload requested from client PID 783 ('systemctl')...485b # [279692.069491] b systemd[1]: Reloading...486b # [279692.320273] b systemd[1]: Reloading finished in 250 ms.487web: imported as generation 3488b: (finished: must succeed: flakelet import --replace /tmp/shared/web.tar.zst >&2, in 1.33 seconds)489b: must succeed: systemctl is-active web.service490b: (finished: must succeed: systemctl is-active web.service, in 0.01 seconds)491b: must succeed: runuser -u web -- psql -qtAX -v ON_ERROR_STOP=1 -d web -c 'SELECT v FROM t' | grep -qx payload492b: (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)493(finished: run the VM test script, in 12.03 seconds)494test script finished in 12.06s495cleanup496kill NspawnMachine (pid 51)497kill NspawnMachine (pid 52)498b # [279692.397349] b systemd[1]: Starting web.service...499b # [279692.429528] b systemd[1]: Started web.service.500b # [279692.463139] b runuser[817]: pam_unix(runuser:session): session opened for user web(uid=996) by (uid=0)501b # [279692.474134] b runuser[817]: pam_unix(runuser:session): session closed for user web502Container a terminated by signal KILL.503Container b terminated by signal KILL.504(finished: cleanup, in 0.28 seconds)505additionally exposed symbols:506 a, b,507 vlan1,508 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