vm-test-run-pg-upgrade-start-guard
checks.aarch64-linux.ext-pg-upgrade-start-guard
· build #459
· raw
1Machine state will be reset. To keep it, pass --keep-vm-state2start all VLans3start vlan4running vlan (pid 7; ctl /build/vde1.ctl)5(finished: start all VLans, in 0.00 seconds)6Test will time out and terminate in 3600 seconds7run the VM test script8additionally exposed symbols:9 server,10 vlan1,11 start_all, test_script, machines, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, Machine, t, debug12start all VMs13server: starting vm14mke2fs 1.47.3 (8-Jul-2025)15qemu-system-aarch64: Could not access KVM kernel module: No such file or directory16qemu-system-aarch64: failed to initialize kvm: No such file or directory17qemu-system-aarch64: falling back to tcg18server: QEMU running (pid 9)19server # Disk image does not exist, creating the virtualisation disk image...20server # Formatting '/build/vm-state-server/tmp.p0eFR0aDEO', fmt=raw size=429496729621server # Discarding device blocks: 0/1048576 done22server # Creating filesystem with 1048576 4k blocks and 262144 inodes23server # Filesystem UUID: c8864e5a-98a6-4f1a-ad39-932338216f5724server # Superblock backups stored on blocks:25server # 32768, 98304, 163840, 229376, 294912, 819200, 88473626server # 27server # Allocating group tables: 0/32 done28server # Writing inode tables: 0/32 done29server # Creating journal (16384 blocks): done30server # Writing superblocks and filesystem accounting information: 0/32 done31server # 32server # Virtualisation disk image created.33(finished: start all VMs, in 0.16 seconds)34server: waiting for unit postgresql.service35server: waiting for the VM to finish booting36server # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]37server # [ 0.000000] Linux version 6.12.63 (nixbld@localhost) (gcc (GCC) 15.2.0, GNU ld (GNU Binutils) 2.44) #1-NixOS SMP Thu Dec 18 12:55:23 UTC 202538server # [ 0.000000] KASLR enabled39server # [ 0.000000] random: crng init done40server # [ 0.000000] Machine model: linux,dummy-virt41server # [ 0.000000] efi: UEFI not found.42server # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT43server # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000bfffffff]44server # [ 0.000000] NODE_DATA(0) allocated [mem 0xbfa04780-0xbfa07ebf]45server # [ 0.000000] Zone ranges:46server # [ 0.000000] DMA [mem 0x0000000040000000-0x00000000bfffffff]47server # [ 0.000000] DMA32 empty48server # [ 0.000000] Normal empty49server # [ 0.000000] Device empty50server # [ 0.000000] Movable zone start for each node51server # [ 0.000000] Early memory node ranges52server # [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000bfffffff]53server # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000bfffffff]54server # [ 0.000000] cma: Reserved 32 MiB at 0x00000000bb800000 on node -155server # [ 0.000000] psci: probing for conduit method from DT.56server # [ 0.000000] psci: PSCIv1.1 detected in firmware.57server # [ 0.000000] psci: Using standard PSCI v0.2 function IDs58server # [ 0.000000] psci: Trusted OS migration not required59server # [ 0.000000] psci: SMC Calling Convention v1.060server # [ 0.000000] percpu: Embedded 88 pages/cpu s180056 r65536 d114856 u36044861server # [ 0.000000] Detected PIPT I-cache on CPU062server # [ 0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)63server # [ 0.000000] CPU features: detected: GIC system register CPU interface64server # [ 0.000000] CPU features: detected: HCRX_EL2 register65server # [ 0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)66server # [ 0.000000] CPU features: detected: Spectre-v467server # [ 0.000000] alternatives: applying boot alternatives68server # [ 0.000000] Kernel command line: console=ttyAMA0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/3960cr78lr0kri4dkq5m414vzc2pa2b0-nixos-system-server-test/init regInfo=/nix/store/9y27pqvmbzqsqylrm2zlcl2x3pl285zx-closure-info/registration console=ttyAMA0,115200n8 console=tty069server # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/store/9y27pqvmbzqsqylrm2zlcl2x3pl285zx-closure-info/registration", will be passed to user space.70server # [ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)71server # [ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)72server # [ 0.000000] Fallback order for Node 0: 073server # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 52428874server # [ 0.000000] Policy zone: DMA75server # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off76server # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 2MB77server # [ 0.000000] software IO TLB: area num 1.78server # [ 0.000000] software IO TLB: mapped [mem 0x00000000bb25a000-0x00000000bb45a000] (2MB)79server # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=180server # [ 0.000000] allocated 4194304 bytes of page_ext81server # [ 0.000000] ftrace: allocating 72257 entries in 283 pages82server # [ 0.000000] ftrace: allocated 283 pages with 5 groups83server # [ 0.000000] rcu: Hierarchical RCU implementation.84server # [ 0.000000] rcu: RCU event tracing is enabled.85server # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.86server # [ 0.000000] Rude variant of Tasks RCU enabled.87server # [ 0.000000] Tracing variant of Tasks RCU enabled.88server # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.89server # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=190server # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.91server # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.92server # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 093server # [ 0.000000] GICv3: 256 SPIs implemented94server # [ 0.000000] GICv3: 0 Extended SPIs implemented95server # [ 0.000000] Root IRQ handler: gic_handle_irq96server # [ 0.000000] GICv3: GICv3 features: 16 PPIs97server # [ 0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=098server # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a000099server # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]100server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @446d0000 (indirect, esz 8, psz 64K, shr 1)101server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @446e0000 (flat, esz 8, psz 64K, shr 1)102server # [ 0.000000] GICv3: using LPI property table @0x00000000446f0000103server # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044700000104server # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.105server # [ 0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (virt).106server # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns107server # [ 0.000031] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns108server # [ 0.001544] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)109server # [ 0.007575] Console: colour dummy device 80x25110server # [ 0.008661] printk: legacy console [tty0] enabled111server # [ 0.012698] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)112server # [ 0.012999] pid_max: default: 32768 minimum: 301113server # [ 0.014378] LSM: initializing lsm=capability,landlock,yama,bpf114server # [ 0.015114] landlock: Up and running.115server # [ 0.015142] Yama: becoming mindful.116server # [ 0.016076] LSM support for eBPF active117server # [ 0.017827] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)118server # [ 0.017888] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)119server # [ 0.039965] cacheinfo: Unable to detect cache hierarchy for CPU 0120server # [ 0.047377] rcu: Hierarchical SRCU implementation.121server # [ 0.047426] rcu: Max phase no-delay instances is 1000.122server # [ 0.052702] fsl-mc MSI: its@8080000 domain created123server # [ 0.054026] EFI services will not be available.124server # [ 0.055232] smp: Bringing up secondary CPUs ...125server # [ 0.055644] smp: Brought up 1 node, 1 CPU126server # [ 0.055675] SMP: Total of 1 processors activated.127server # [ 0.055705] CPU: All CPU(s) started at EL1128server # [ 0.055878] CPU features: detected: Branch Target Identification129server # [ 0.055915] CPU features: detected: 32-bit EL0 Support130server # [ 0.055937] CPU features: detected: 32-bit EL1 Support131server # [ 0.055956] CPU features: detected: ARMv8.4 Translation Table Level132server # [ 0.055981] CPU features: detected: Instruction cache invalidation not required for I/D coherence133server # [ 0.056010] CPU features: detected: Data cache clean to the PoU not required for I/D coherence134server # [ 0.056058] CPU features: detected: Common not Private translations135server # [ 0.056078] CPU features: detected: CRC32 instructions136server # [ 0.056095] CPU features: detected: Data cache clean to Point of Deep Persistence137server # [ 0.056117] CPU features: detected: Data cache clean to Point of Persistence138server # [ 0.056137] CPU features: detected: Data independent timing control (DIT)139server # [ 0.056156] CPU features: detected: E0PD140server # [ 0.056172] CPU features: detected: Enhanced Counter Virtualization141server # [ 0.056190] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)142server # [ 0.056210] CPU features: detected: Enhanced Privileged Access Never143server # [ 0.056229] CPU features: detected: Enhanced Virtualization Traps144server # [ 0.056248] CPU features: detected: Fine Grained Traps145server # [ 0.056299] CPU features: detected: Generic authentication (IMP DEF algorithm)146server # [ 0.056361] CPU features: detected: RCpc load-acquire (LDAPR)147server # [ 0.056396] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)148server # [ 0.056417] CPU features: detected: LSE atomic instructions149server # [ 0.056435] CPU features: detected: Memory Copy and Memory Set instructions150server # [ 0.056454] CPU features: detected: Privileged Access Never151server # [ 0.056472] CPU features: detected: RAS Extension Support152server # [ 0.056490] CPU features: detected: Random Number Generator153server # [ 0.056507] CPU features: detected: Speculation barrier (SB)154server # [ 0.056525] CPU features: detected: Stage-2 Force Write-Back155server # [ 0.056543] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality156server # [ 0.056565] CPU features: detected: TLB range maintenance instructions157server # [ 0.056584] CPU features: detected: WFx with timeout158server # [ 0.056615] CPU features: detected: Speculative Store Bypassing Safe (SSBS)159server # [ 0.056645] CPU features: detected: Scalable Vector Extension160server # [ 0.059895] alternatives: applying system-wide alternatives161server # [ 0.071870] CPU features: detected: Hardware dirty bit management on CPU0162server # [ 0.072326] SVE: maximum available vector length 256 bytes per vector163server # [ 0.072394] SVE: default vector length 64 bytes per vector164server # [ 0.079640] Memory: 1935300K/2097152K available (23296K kernel code, 6546K rwdata, 24596K rodata, 4416K init, 1047K bss, 118632K reserved, 32768K cma-reserved)165server # [ 0.094030] devtmpfs: initialized166server # [ 0.109790] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns167server # [ 0.110124] futex hash table entries: 256 (order: 2, 16384 bytes, linear)168server # [ 0.111860] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL169server # [ 0.111901] 0 pages in range for non-PLT usage170server # [ 0.111930] 509248 pages in range for PLT usage171server # [ 0.113811] pinctrl core: initialized pinctrl subsystem172server # [ 0.120510] DMI not present or invalid.173server # [ 0.131159] NET: Registered PF_NETLINK/PF_ROUTE protocol family174server # [ 0.138359] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations175server # [ 0.139710] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations176server # [ 0.141484] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations177server # [ 0.141640] audit: initializing netlink subsys (disabled)178server # [ 0.142979] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1179server # [ 0.147204] thermal_sys: Registered thermal governor 'fair_share'180server # [ 0.147230] thermal_sys: Registered thermal governor 'bang_bang'181server # [ 0.147260] thermal_sys: Registered thermal governor 'step_wise'182server # [ 0.147281] thermal_sys: Registered thermal governor 'user_space'183server # [ 0.147301] thermal_sys: Registered thermal governor 'power_allocator'184server # [ 0.147583] cpuidle: using governor ladder185server # [ 0.147685] cpuidle: using governor menu186server # [ 0.149210] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.187server # [ 0.149512] ASID allocator initialised with 65536 entries188server # [ 0.154582] Serial: AMBA PL011 UART driver189server # [ 0.188104] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1190server # [ 0.188871] printk: legacy console [ttyAMA0] enabled191server # [ 0.238966] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages192server # [ 0.239125] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page193server # [ 0.239347] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages194server # [ 0.239437] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page195server # [ 0.239673] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages196server # [ 0.239988] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page197server # [ 0.240297] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages198server # [ 0.240389] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page199server # [ 0.281457] fbcon: Taking over console200server # [ 0.282052] ACPI: Interpreter disabled.201server # [ 0.286686] iommu: Default domain type: Translated202server # [ 0.287114] iommu: DMA domain TLB invalidation policy: strict mode203server # [ 0.307021] SCSI subsystem initialized204server # [ 0.308672] usbcore: registered new interface driver usbfs205server # [ 0.309082] usbcore: registered new interface driver hub206server # [ 0.309394] usbcore: registered new device driver usb207server # [ 0.311436] pps_core: LinuxPPS API ver. 1 registered208server # [ 0.311559] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>209server # [ 0.311906] PTP clock support registered210server # [ 0.312510] EDAC MC: Ver: 3.0.0211server # [ 0.313745] scmi_core: SCMI protocol bus registered212server # [ 0.315893] FPGA manager framework213server # [ 0.316851] Advanced Linux Sound Architecture Driver Initialized.214server # [ 0.322961] vgaarb: loaded215server # [ 0.325483] clocksource: Switched to clocksource arch_sys_counter216server # [ 0.334551] VFS: Disk quotas dquot_6.6.0217server # [ 0.334746] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)218server # [ 0.336886] netfs: FS-Cache loaded219server # [ 0.337939] pnp: PnP ACPI: disabled220server # [ 0.354372] NET: Registered PF_INET protocol family221server # [ 0.355424] IP idents hash table entries: 32768 (order: 6, 262144 bytes, linear)222server # [ 0.434362] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)223server # [ 0.434678] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)224server # [ 0.436000] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)225server # [ 0.436658] TCP bind hash table entries: 16384 (order: 7, 524288 bytes, linear)226server # [ 0.437221] TCP: Hash tables configured (established 16384 bind 16384)227server # [ 0.438437] MPTCP token hash table entries: 2048 (order: 4, 49152 bytes, linear)228server # [ 0.438928] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)229server # [ 0.439380] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)230server # [ 0.440687] NET: Registered PF_UNIX/PF_LOCAL protocol family231server # [ 0.441277] NET: Registered PF_XDP protocol family232server # [ 0.441591] PCI: CLS 0 bytes, default 64233server # [ 0.444255] Trying to unpack rootfs image as initramfs...234server # [ 0.454684] kvm [1]: HYP mode not available235server # [ 0.597901] Initialise system trusted keyrings236server # [ 0.599336] workingset: timestamp_bits=42 max_order=19 bucket_order=0237server # [ 0.602089] squashfs: version 4.0 (2009/01/31) Phillip Lougher238server # [ 0.602928] 9p: Installing v9fs 9p2000 file system support239server # [ 0.691245] Key type asymmetric registered240server # [ 0.691422] Asymmetric key parser 'x509' registered241server # [ 0.692047] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244)242server # [ 0.692815] io scheduler mq-deadline registered243server # [ 0.692951] io scheduler kyber registered244server # [ 0.730935] pl061_gpio 9030000.pl061: PL061 GPIO chip registered245server # [ 0.733598] ledtrig-cpu: registered to indicate activity on CPUs246server # [ 0.736020] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:247server # [ 0.736670] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000248server # [ 0.737346] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000249server # [ 0.737606] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000250server # [ 0.738493] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits251server # [ 0.739082] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]252server # [ 0.740231] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00253server # [ 0.740764] pci_bus 0000:00: root bus resource [bus 00-ff]254server # [ 0.740916] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]255server # [ 0.741136] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]256server # [ 0.741239] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]257server # [ 0.770792] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint258server # [ 0.773449] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint259server # [ 0.773857] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]260server # [ 0.774293] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]261server # [ 0.774512] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]262server # [ 0.774857] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]263server # [ 0.775640] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint264server # [ 0.775823] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]265server # [ 0.776036] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]266server # [ 0.776363] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]267server # [ 0.777085] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint268server # [ 0.777254] pci 0000:00:03.0: BAR 0 [io 0x0000-0x003f]269server # [ 0.777718] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]270server # [ 0.778045] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]271server # [ 0.778847] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint272server # [ 0.779028] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]273server # [ 0.779264] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]274server # [ 0.779491] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]275server # [ 0.780238] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint276server # [ 0.780415] pci 0000:00:05.0: BAR 0 [io 0x0000-0x001f]277server # [ 0.780779] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]278server # [ 0.781027] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]279server # [ 0.781819] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint280server # [ 0.782017] pci 0000:00:06.0: BAR 0 [io 0x0000-0x007f]281server # [ 0.782218] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]282server # [ 0.782316] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]283server # [ 0.783060] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint284server # [ 0.783238] pci 0000:00:07.0: BAR 0 [io 0x0000-0x001f]285server # [ 0.783475] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]286server # [ 0.783610] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]287server # [ 0.784137] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]288server # [ 0.784886] pci 0000:00:08.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint289server # [ 0.785065] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]290server # [ 0.785186] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]291server # [ 0.786219] pci 0000:00:09.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint292server # [ 0.786403] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]293server # [ 0.786720] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]294server # [ 0.787439] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint295server # [ 0.787638] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]296server # [ 0.788331] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint297server # [ 0.788546] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]298server # [ 0.788802] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]299server # [ 0.788902] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]300server # [ 0.789711] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint301server # [ 0.789886] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]302server # [ 0.790109] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]303server # [ 0.790383] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]304server # [ 0.792143] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned305server # [ 0.792491] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned306server # [ 0.792744] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned307server # [ 0.793149] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned308server # [ 0.793646] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned309server # [ 0.793961] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned310server # [ 0.794297] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned311server # [ 0.794688] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned312server # [ 0.795018] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned313server # [ 0.795253] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned314server # [ 0.795385] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned315server # [ 0.795923] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned316server # [ 0.796334] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned317server # [ 0.796727] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned318server # [ 0.796997] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned319server # [ 0.797113] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned320server # [ 0.797230] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned321server # [ 0.797912] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned322server # [ 0.798214] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned323server # [ 0.798540] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned324server # [ 0.798875] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned325server # [ 0.799194] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned326server # [ 0.799495] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned327server # [ 0.799819] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned328server # [ 0.800098] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned329server # [ 0.800241] pci 0000:00:06.0: BAR 0 [io 0x1000-0x107f]: assigned330server # [ 0.800573] pci 0000:00:03.0: BAR 0 [io 0x1080-0x10bf]: assigned331server # [ 0.801006] pci 0000:00:0b.0: BAR 0 [io 0x10c0-0x10ff]: assigned332server # [ 0.801126] pci 0000:00:01.0: BAR 0 [io 0x1100-0x111f]: assigned333server # [ 0.801572] pci 0000:00:02.0: BAR 0 [io 0x1120-0x113f]: assigned334server # [ 0.802030] pci 0000:00:04.0: BAR 0 [io 0x1140-0x115f]: assigned335server # [ 0.802348] pci 0000:00:05.0: BAR 0 [io 0x1160-0x117f]: assigned336server # [ 0.802646] pci 0000:00:07.0: BAR 0 [io 0x1180-0x119f]: assigned337server # [ 0.802973] pci 0000:00:0c.0: BAR 0 [io 0x11a0-0x11bf]: assigned338server # [ 0.803528] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]339server # [ 0.803660] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]340server # [ 0.803972] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]341server # [ 0.850537] pci 0000:00:0a.0: enabling device (0000 -> 0002)342server # [ 0.913880] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)343server # [ 0.916958] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)344server # [ 0.918589] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)345server # [ 0.919827] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)346server # [ 0.921102] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)347server # [ 0.930312] Freeing initrd memory: 10684K348server # [ 0.931167] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)349server # [ 0.932208] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)350server # [ 0.933475] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)351server # [ 0.934719] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)352server # [ 0.936031] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)353server # [ 0.938022] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)354server # [ 0.948700] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled355server # [ 0.954086] msm_serial: driver initialized356server # [ 0.954987] SuperH (H)SCI(F) driver initialized357server # [ 0.955404] STM32 USART driver initialized358server # [ 0.985221] loop: module loaded359server # [ 0.985797] virtio_blk virtio5: 1/0/0 default/read/poll queues360server # [ 0.987789] virtio_blk virtio5: [vda] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB)361server # [ 0.996902] megasas: 07.727.03.00-rc1362server # [ 1.000491] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]363server # [ 1.002081] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000364server # [ 1.002883] Intel/Sharp Extended Query Table at 0x0031365server # [ 1.003790] Using buffer write method366server # [ 1.004303] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]367server # [ 1.005243] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000368server # [ 1.005435] Intel/Sharp Extended Query Table at 0x0031369server # [ 1.006618] Using buffer write method370server # [ 1.006789] Concatenating MTD devices:371server # [ 1.007045] (0): "0.flash"372server # [ 1.007136] (1): "0.flash"373server # [ 1.007415] into device "0.flash"374server # [ 1.021101] tun: Universal TUN/TAP device driver, 1.6375server # [ 1.028613] thunder_xcv, ver 1.0376server # [ 1.028808] thunder_bgx, ver 1.0377server # [ 1.029082] nicpf, ver 1.0378server # [ 1.031301] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version379server # [ 1.031450] hns3: Copyright (c) 2017 Huawei Corporation.380server # [ 1.031940] hclge is initializing381server # [ 1.032263] e1000: Intel(R) PRO/1000 Network Driver382server # [ 1.032428] e1000: Copyright (c) 1999-2006 Intel Corporation.383server # [ 1.032866] e1000e: Intel(R) PRO/1000 Network Driver384server # [ 1.033157] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.385server # [ 1.033442] igb: Intel(R) Gigabit Ethernet Network Driver386server # [ 1.033812] igb: Copyright (c) 2007-2014 Intel Corporation.387server # [ 1.034148] igbvf: Intel(R) Gigabit Virtual Function Network Driver388server # [ 1.034466] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.389server # [ 1.035301] sky2: driver version 1.30390server # [ 1.039955] ehci-pci 0000:00:0a.0: EHCI Host Controller391server # [ 1.042476] usbcore: registered new interface driver usb-storage392server # [ 1.043020] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1393server # [ 1.044629] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000394server # [ 1.045131] usbcore: registered new interface driver usbserial_generic395server # [ 1.045639] usbserial: USB Serial support registered for generic396server # [ 1.051137] rtc-pl031 9010000.pl031: registered as rtc0397server # [ 1.051916] rtc-pl031 9010000.pl031: setting system clock to 2026-10-26T11:36:33 UTC (1793014593)398server # [ 1.053291] i2c_dev: i2c /dev entries driver399server # [ 1.053870] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00400server # [ 1.063667] sdhci: Secure Digital Host Controller Interface driver401server # [ 1.063791] sdhci: Copyright(c) Pierre Ossman402server # [ 1.067615] hub 1-0:1.0: USB hub found403server # [ 1.068599] hub 1-0:1.0: 6 ports detected404server # [ 1.071813] Synopsys Designware Multimedia Card Interface Driver405server # [ 1.073361] sdhci-pltfm: SDHCI platform and OF driver helper406server # [ 1.077734] hid: raw HID events driver (C) Jiri Kosina407server # [ 1.079429] usbcore: registered new interface driver usbhid408server # [ 1.079560] usbhid: USB HID core driver409server # [ 1.084438] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available410server # [ 1.092109] drop_monitor: Initializing network drop monitor service411server # [ 1.094001] NET: Registered PF_INET6 protocol family412server # [ 1.100742] Segment Routing with IPv6413server # [ 1.101323] In-situ OAM (IOAM) with IPv6414server # [ 1.102142] NET: Registered PF_PACKET protocol family415server # [ 1.102834] 9pnet: Installing 9P2000 support416server # [ 1.105404] Key type dns_resolver registered417server # [ 1.128367] registered taskstats version 1418server # [ 1.130602] Loading compiled-in X.509 certificates419server # [ 1.168536] Demotion targets for Node 0: null420server # [ 1.169753] Key type .fscrypt registered421server # [ 1.169852] Key type fscrypt-provisioning registered422server # [ 1.175384] input: gpio-keys as /devices/platform/gpio-keys/input/input0423server # [ 1.205332] clk: Disabling unused clocks424server # [ 1.205567] PM: genpd: Disabling unused power domains425server # [ 1.206254] ALSA device list:426server # [ 1.206366] No soundcards found.427server # [ 1.247664] Freeing unused kernel memory: 4416K428server # [ 1.248582] Run /init as init process429server # [ 1.321937] usb 1-1: new high-speed USB device number 2 using ehci-pci430server # [ 1.517355] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev431server # [ 1.576321] input: QEMU QEMU USB Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:0a.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input1432server # [ 1.588817] [drm] pci: virtio-gpu-pci detected at 0000:00:09.0433server # [ 1.589590] [drm] features: -virgl +edid -resource_blob -host_visible434server # [ 1.589607] [drm] features: -context_init435server # [ 1.591351] [drm] number of scanouts: 1436server # [ 1.591462] [drm] number of cap sets: 0437server # [ 1.597889] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:09.0 on minor 0438server # [ 1.619981] Console: switching to colour frame buffer device 160x50439server # [ 1.627425] virtio-pci 0000:00:09.0: [drm] fb0: virtio_gpudrmfb frame buffer device440server # [ 1.774609] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0441server # [ 1.906368] usb 1-2: new high-speed USB device number 3 using ehci-pci442server # [ 2.190755] input: QEMU QEMU USB Tablet as /devices/platform/4010000000.pcie/pci0000:00/0000:00:0a.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input2443server # [ 2.192436] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0444server # [ 3.602714] EXT4-fs (vda): mounted filesystem c8864e5a-98a6-4f1a-ad39-932338216f57 r/w with ordered data mode. Quota mode: none.445server # [ 4.725355] EXT4-fs (vda): re-mounted c8864e5a-98a6-4f1a-ad39-932338216f57.446server # [ 4.737601] booting system configuration /nix/store/3960cr78lr0kri4dkq5m414vzc2pa2b0-nixos-system-server-test447server # [ 10.287046] systemd[1]: systemd 258.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)448server # [ 10.294368] systemd[1]: Detected virtualization qemu.449server # [ 10.297360] systemd[1]: Detected architecture arm64.450server # [ 10.300556] systemd[1]: Detected first boot.451server # [ 10.314747] systemd[1]: Initializing machine ID from random generator.452server # [ 10.330844] systemd[1]: Hostname set to <server>.453server # [ 11.189576] systemd[1]: bpf-restrict-fs: LSM BPF program attached454server # [ 12.004145] systemd[1]: Applying preset policy.455server # [ 13.473967] systemd[1]: Populated /etc with preset unit settings.456server # [ 14.872231] systemd[1]: Queued start job for default target Multi-User System.457server # [ 15.022625] systemd[1]: Created slice Slice /system/getty.458server # [ 15.031578] systemd[1]: Created slice Slice /system/modprobe.459server # [ 15.038733] systemd[1]: Created slice User and Session Slice.460server # [ 15.043980] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.461server # [ 15.047630] systemd[1]: Started Forward Password Requests to Wall Directory Watch.462server # [ 15.051159] systemd[1]: Expecting device /dev/hvc0...463server # [ 15.054247] systemd[1]: Expecting device /dev/ttyAMA0...464server # [ 15.057053] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...465server # [ 15.060158] systemd[1]: Reached target Local Encrypted Volumes.466server # [ 15.063168] systemd[1]: Reached target Virtual Machines and Containers.467server # [ 15.066166] systemd[1]: Reached target Path Units.468server # [ 15.069006] systemd[1]: Reached target Remote File Systems.469server # [ 15.071862] systemd[1]: Reached target Slice Units.470server # [ 15.074694] systemd[1]: Reached target Swaps.471server # [ 15.093136] systemd[1]: Listening on Process Core Dump Socket.472server # [ 15.105246] systemd[1]: Listening on Credential Encryption/Decryption.473server # [ 15.111442] systemd[1]: Listening on Journal Audit Socket.474server # [ 15.115329] systemd[1]: Listening on Journal Socket (/dev/log).475server # [ 15.118860] systemd[1]: Listening on Journal Sockets.476server # [ 15.123267] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.477server # [ 15.126450] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).478server # [ 15.129980] systemd[1]: Listening on udev Control Socket.479server # [ 15.133251] systemd[1]: Listening on udev Kernel Socket.480server # [ 15.158346] systemd[1]: Mounting Huge Pages File System...481server # [ 15.181735] systemd[1]: Mounting POSIX Message Queue File System...482server # [ 15.224689] systemd[1]: Mounting Kernel Debug File System...483server # [ 15.271833] systemd[1]: Mounting Kernel Trace File System...484server # [ 15.351751] systemd[1]: Starting Create List of Static Device Nodes...485server # [ 15.424847] systemd[1]: Starting Load Kernel Module 9pnet_virtio...486server # [ 15.431467] systemd[1]: Load Kernel Module configfs was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!configfs).487server # [ 15.508568] systemd[1]: Mounting Kernel Configuration File System...488server # [ 15.513085] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).489server # [ 15.535013] systemd[1]: Load Kernel Module efi_pstore was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!efi_pstore).490server # [ 15.605448] systemd[1]: Starting Load Kernel Module fuse...491server # [ 15.612132] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).492server # [ 15.615341] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).493server # [ 15.701332] systemd[1]: Starting Journal Service...494server # [ 15.727932] systemd[1]: Starting Load Kernel Modules...495server # [ 15.765714] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...496server # [ 15.795179] systemd[1]: Starting Remount Root and Kernel File Systems...497server # [ 15.800142] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).498server # [ 15.833082] systemd[1]: Starting Coldplug All udev Devices...499server # [ 15.851715] systemd[1]: Mounted Huge Pages File System.500server # [ 15.889723] systemd[1]: Mounted POSIX Message Queue File System.501server # [ 15.893700] systemd[1]: Mounted Kernel Debug File System.502server # [ 15.897365] systemd[1]: Mounted Kernel Trace File System.503server # [ 15.917671] systemd[1]: Finished Create List of Static Device Nodes.504server # [ 15.925366] systemd[1]: Mounted Kernel Configuration File System.505server # [ 15.968899] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...506server # [ 16.551089] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.507server # [ 16.559187] systemd[1]: Finished Load Kernel Module 9pnet_virtio.508server # [ 16.612237] EXT4-fs (vda): re-mounted c8864e5a-98a6-4f1a-ad39-932338216f57.509server # [ 16.625166] systemd[1]: Finished Load Kernel Modules.510server # [ 16.679038] systemd[1]: Starting Firewall...511server # [ 16.740183] fuse: init (API version 7.41)512server # [ 16.749534] systemd[1]: Starting Apply Kernel Variables...513server # [ 16.789600] systemd[1]: Finished Remount Root and Kernel File Systems.514server # [ 16.793018] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).515server # [ 16.818864] systemd[1]: Starting Load/Save OS Random Seed...516server # [ 16.822032] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).517server # [ 16.899905] systemd[1]: modprobe@fuse.service: Deactivated successfully.518server # [ 16.904979] systemd[1]: Finished Load Kernel Module fuse.519server # [ 16.930590] systemd[1]: Mounting FUSE Control File System...520server # [ 17.053842] systemd[1]: Mounted FUSE Control File System.521server # [ 17.167081] systemd-journald[387]: Collecting audit messages is enabled.522server # [ 17.555270] systemd[1]: Finished Load/Save OS Random Seed.523server # [ 17.560009] systemd[1]: Reached target First Boot Complete.524server # [ 17.687606] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.525server # [ 17.751845] systemd[1]: Starting Create Static Device Nodes in /dev...526server # [ 17.760336] systemd[1]: Finished Apply Kernel Variables.527server # [ 18.098095] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.528server # [ 18.422522] systemd[1]: Started Journal Service.529server # [ 18.204772] systemd-modules-load[388]: Module 'atkbd' is built in530server # [ 18.218636] systemd-modules-load[388]: Module 'loop' is built in531server # [ 18.263613] systemd-oomd[389]: No swap; memory pressure usage will be degraded532server # [ 18.284040] systemd[1]: Starting Flush Journal to Persistent Storage...533server # [ 18.529147] systemd[1]: Finished Create Static Device Nodes in /dev.534server # [ 18.530330] systemd[1]: Reached target Preparation for Local File Systems.535server # [ 18.564190] systemd[1]: Mounting /run/wrappers...536server # [ 18.603681] systemd[1]: Starting Rule-based Manager for Device Events and Files...537server # [ 18.904304] systemd-journald[387]: Received client request to flush runtime journal.538server # [ 19.000868] systemd[1]: Mounted /run/wrappers.539server # [ 19.002394] systemd[1]: Reached target Local File Systems.540server # [ 19.003209] systemd[1]: Listening on Boot Entries Service Socket.541server # [ 19.037140] systemd[1]: Starting Create SUID/SGID Wrappers...542server # [ 19.039671] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.543server # [ 19.056678] systemd[1]: Starting Save Transient machine-id to Disk...544server # [ 19.069433] systemd[1]: Finished Flush Journal to Persistent Storage.545server # [ 19.107771] systemd[1]: Starting Create System Files and Directories...546server # [ 19.541446] systemd-udevd[430]: Using default interface naming scheme 'v258'.547server # [ 19.650559] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.548server # [ 19.678416] systemd[1]: Finished Save Transient machine-id to Disk.549server # [ 20.304220] systemd[1]: Finished Create System Files and Directories.550server # [ 20.359774] systemd[1]: Starting Rebuild Journal Catalog...551server # [ 20.377827] systemd[1]: Starting Record System Boot/Shutdown in UTMP...552server # [ 20.935989] systemd[1]: Finished Record System Boot/Shutdown in UTMP.553server # [ 21.453261] systemd[1]: Started Rule-based Manager for Device Events and Files.554server # [ 21.769696] systemd[1]: Finished Rebuild Journal Catalog.555server # [ 21.819860] systemd[1]: Starting Update is Completed...556server # [ 22.188986] systemd[1]: Finished Update is Completed.557server # [ 24.652300] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.558server # [ 24.657992] systemd[1]: Finished Create SUID/SGID Wrappers.559server # [ 26.405534] systemd[1]: Finished Coldplug All udev Devices.560server # [ 26.463413] systemd[1]: Reached target System Initialization.561server # [ 26.465051] systemd[1]: Started Discard unused filesystem blocks once a week.562server # [ 26.466057] systemd[1]: Started Daily Cleanup of Temporary Directories.563server # [ 26.467035] systemd[1]: Reached target Timer Units.564server # [ 26.467986] systemd[1]: Listening on D-Bus System Message Bus Socket.565server # [ 26.469348] systemd[1]: Listening on Nix Daemon Socket.566server # [ 26.470222] systemd[1]: Listening on Hostname Service Socket.567server # [ 26.471164] systemd[1]: Reached target Socket Units.568server # [ 26.472141] systemd[1]: Reached target Basic System.569server # [ 26.484670] systemd[1]: Starting Import lastlog data into lastlog2 database...570server # [ 26.501667] systemd[1]: Starting Name Service Cache Daemon (nsncd)...571server # [ 26.543697] systemd[1]: Starting postgresql.service...572server # [ 26.560953] systemd[1]: Started Reset console on configuration changes.573server # [ 26.638357] systemd[1]: Starting resolvconf update...574server # [ 26.679962] systemd[1]: Starting D-Bus System Message Bus...575server # [ 27.481382] systemd[1]: Finished Import lastlog data into lastlog2 database.576server # [ 27.629283] runuser[633]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)577server # [ 27.755022] systemd[1]: Started Name Service Cache Daemon (nsncd).578server # [ 27.756172] systemd[1]: Reached target Host and Network Name Lookups.579server # [ 27.770143] systemd[1]: Reached target User and Group Name Lookups.580server # [ 27.786070] nsncd[617]: Oct 26 11:37:00.388 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"581server # [ 27.816323] systemd[1]: Starting User Login Management...582server # [ 27.833978] systemd[1]: Finished Firewall.583server # [ 28.175666] dbus-daemon[622]: dbus[622]: Unknown username "systemd-timesync" in message bus configuration file584server # [ 28.620986] systemd[1]: Started D-Bus System Message Bus.585server # [ 28.885442] systemd[1]: Stopped target Host and Network Name Lookups.586server # [ 28.893675] systemd[1]: Stopping Host and Network Name Lookups...587server # [ 28.905580] systemd[1]: Stopped target User and Group Name Lookups.588server # [ 28.919966] systemd[1]: Stopping User and Group Name Lookups...589server # [ 28.926591] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...590server # [ 28.943277] systemd[1]: nscd.service: Deactivated successfully.591server # [ 28.962393] systemd[1]: Stopped Name Service Cache Daemon (nsncd).592server # [ 29.031115] systemd[1]: Starting Name Service Cache Daemon (nsncd)...593server # [ 29.403517] systemd-logind[641]: New seat seat0.594server # [ 29.475268] systemd[1]: Started User Login Management.595server # [ 29.508270] systemd[1]: Starting linger-users.service...596server: Guest root shell did not produce any data yet...597server: To debug, enter the VM and run 'systemctl status backdoor.service'.598server # [ 29.762500] init-old[637]: The files belonging to this database system will be owned by user "postgres".599server # [ 29.770994] init-old[637]: This user must also own the server process.600server # [ 29.787408] systemd[1]: Started Name Service Cache Daemon (nsncd).601server # [ 29.813102] systemd[1]: Reached target Host and Network Name Lookups.602server # [ 29.826435] nsncd[690]: Oct 26 11:37:02.471 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"603server # [ 29.847229] systemd[1]: Reached target User and Group Name Lookups.604server # [ 29.889450] init-old[637]: The database cluster will be initialized with locale "C".605server # [ 29.905487] init-old[637]: The default text search configuration will be set to "english".606server # [ 29.910604] init-old[637]: Data page checksums are disabled.607server # [ 29.913917] init-old[637]: fixing permissions on existing directory /var/lib/postgresql/data ... ok608server # [ 29.918845] init-old[637]: creating subdirectories ... ok609server # [ 29.941832] init-old[637]: selecting dynamic shared memory implementation ... posix610server # [ 30.113031] systemd[1]: linger-users.service: Deactivated successfully.611server # [ 30.123229] systemd[1]: Finished linger-users.service.612server # [ 30.324123] systemd[1]: Finished resolvconf update.613server # [ 30.335100] systemd[1]: Reached target Preparation for Network.614server # [ 30.385340] systemd[1]: Starting DHCP Client...615server # [ 30.915139] init-old[637]: selecting default max_connections ... 100616server # [ 31.567359] init-old[637]: selecting default shared_buffers ... 128MB617server # [ 32.375561] dhcpcd[740]: dhcpcd-10.2.4 starting618server # [ 32.558467] dhcpcd[745]: dev: loaded udev619server # [ 33.035005] 8021q: 802.1Q VLAN Support v1.8620server # [ 33.470607] cfg80211: Loading compiled-in X.509 certificates for regulatory database621server # [ 33.642670] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'622server # [ 33.647652] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'623server # [ 33.673729] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2624server # [ 33.680870] cfg80211: failed to load regulatory.db625server # [ 34.559563] 8021q: adding VLAN 0 to HW filter on device eth0626server # [ 34.355501] dhcpcd[745]: eth0: waiting for carrier627server # [ 34.374179] dhcpcd[745]: eth0: carrier acquired628server # [ 34.486955] dhcpcd[745]: DUID 00:01:00:01:32:71:f7:e3:52:54:00:12:34:56629server # [ 34.491277] dhcpcd[745]: eth0: IAID 00:12:34:56630server # [ 34.492342] dhcpcd[745]: eth0: adding address fe80::5054:ff:fe12:3456631server # [ 34.767887] dhcpcd[745]: eth0: soliciting a DHCP lease632server # [ 34.811799] dhcpcd[745]: eth0: offered 10.0.2.15 from 10.0.2.2633server # [ 34.826938] dhcpcd[745]: eth0: probing address 10.0.2.15/24634server # [ 36.323574] dhcpcd[745]: eth0: soliciting an IPv6 router635server # [ 36.345618] dhcpcd[745]: eth0: Router Advertisement from fe80::2636server # [ 36.354706] dhcpcd[745]: eth0: adding address fec0::5054:ff:fe12:3456/64637server # [ 36.373866] dhcpcd[745]: eth0: adding route to fec0::/64638server # [ 36.379225] dhcpcd[745]: eth0: adding default route via fe80::2639server # [ 39.377079] init-old[637]: selecting default time zone ... UTC640server # [ 39.423746] init-old[637]: creating configuration files ... ok641server # [ 40.454566] systemd[1]: Found device /dev/hvc0.642server # [ 40.760285] dhcpcd[745]: eth0: leased 10.0.2.15 for 86400 seconds643server # [ 40.778800] dhcpcd[745]: eth0: adding route to 10.0.2.0/24644server # [ 40.787899] dhcpcd[745]: eth0: adding default route via 10.0.2.2645server # [ 43.024044] systemd[1]: Started DHCP Client.646server # [ 43.629295] systemd[1]: Found device /dev/ttyAMA0.647server # [ 43.659012] systemd[1]: Started backdoor.service.648server # connecting to host...649server # [ 44.509020] (udev-worker)[849]: Network interface NamePolicy= disabled on kernel command line.650server: Guest shell says: b'Spawning backdoor root shell...\n'651server: connected to guest root shell652server: (connecting took 45.04 seconds)653server: (finished: waiting for the VM to finish booting, in 45.04 seconds)654server # [ 44.558620] (udev-worker)[866]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.655server # [ 44.585036] (udev-worker)[866]: Network interface NamePolicy= disabled on kernel command line.656server # [ 45.584756] init-old[637]: running bootstrap script ... ok657server # [ 46.026985] systemd[1]: Found device Virtio network device.658server # [ 46.076835] dhcpcd[745]: eth0: IAID 00:12:34:56659server # [ 46.099657] systemd[1]: Starting Address configuration of eth1...660server # [ 46.251447] dhcpcd[745]: eth0: rebinding lease of 10.0.2.15661server # [ 46.282651] dhcpcd[745]: eth0: leased 10.0.2.15 for 86400 seconds662server # [ 47.368113] 8021q: adding VLAN 0 to HW filter on device eth1663server # [ 47.450131] network-addresses-eth1-start[889]: adding address 192.168.1.1/24... done664server # [ 47.820759] network-addresses-eth1-start[889]: adding address 2001:db8:1::1/64... done665server # [ 47.851931] dhcpcd[745]: eth0: soliciting an IPv6 router666server # [ 48.107934] systemd[1]: Finished Address configuration of eth1.667server # [ 48.162058] systemd[1]: Starting Networking Setup...668server # [ 50.827706] systemd[1]: Finished Networking Setup.669server # [ 50.851448] systemd[1]: Reached target Network.670server # [ 50.873464] systemd[1]: Starting Permit User Sessions...671server # [ 51.452991] systemd[1]: Finished Permit User Sessions.672server # [ 51.524747] systemd[1]: Started Getty on tty1.673server # [ 51.525880] systemd[1]: Reached target Login Prompts.674server # [ 60.226924] systemd-logind[641]: Watching system buttons on /dev/input/event0 (gpio-keys)675server # [ 65.743180] init-old[637]: performing post-bootstrap initialization ... ok676server # [ 66.868903] mousedev: PS/2 mouse device common for all mice677server # [ 69.512747] init-old[637]: syncing data to disk ... ok678server # [ 69.525586] init-old[637]: initdb: warning: enabling "trust" authentication for local connections679server # [ 69.526428] init-old[637]: 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.680server # [ 69.526897] init-old[637]: Success. You can now start the database server using:681server # [ 69.527203] init-old[637]: /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl -D /var/lib/postgresql/data -l logfile start682server # [ 69.563124] runuser[633]: pam_unix(runuser:session): session closed for user postgres683server # [ 70.507269] postgres[1114]: 2026-10-26 11:37:43.171 UTC [1114] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit684server # [ 70.709601] postgres[1114]: 2026-10-26 11:37:43.385 UTC [1114] LOG: listening on IPv6 address "::1", port 5432685server # [ 70.729785] postgres[1114]: 2026-10-26 11:37:43.401 UTC [1114] LOG: listening on IPv4 address "127.0.0.1", port 5432686server # [ 70.749700] postgres[1114]: 2026-10-26 11:37:43.429 UTC [1114] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"687server # [ 70.963688] postgres[1121]: 2026-10-26 11:37:43.625 UTC [1121] LOG: database system was shut down at 2026-10-26 11:37:38 UTC688server # [ 71.086954] postgres[1114]: 2026-10-26 11:37:43.761 UTC [1114] LOG: database system is ready to accept connections689server # [ 71.205405] systemd[1]: Started postgresql.service.690server # [ 71.218282] systemd[1]: Reached target Multi-User System.691server # [ 71.219181] systemd[1]: Startup finished in 9.555s (kernel) + 1min 1.641s (userspace) = 1min 11.196s.692server # [ 72.787108] systemd-logind[641]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)693server: (finished: waiting for unit postgresql.service, in 73.34 seconds)694subtest: Seed the source cluster695server: must succeed: /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/psql -h 127.0.0.1 -p 5432 -U postgres -d postgres -Atc "create table seed as select g as id, repeat(md5(g::text), 20) as pad from generate_series(1, 100000) g"696server: (finished: must succeed: /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/psql -h 127.0.0.1 -p 5432 -U postgres -d postgres -Atc "create table seed as select g as id, repeat(md5(g::text), 20) as pad from generate_series(1, 100000) g", in 13.76 seconds)697server: must succeed: /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/psql -h 127.0.0.1 -p 5432 -U postgres -d postgres -Atc "select count(*) || ',' || sum(id) from seed"698server: (finished: must succeed: /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/psql -h 127.0.0.1 -p 5432 -U postgres -d postgres -Atc "select count(*) || ',' || sum(id) from seed", in 1.78 seconds)699(finished: subtest: Seed the source cluster, in 15.53 seconds)700subtest: Control: with no guard the start loop brings the source up701server: must succeed: systemctl stop postgresql702server # [ 88.904674] systemd[1]: Stopping postgresql.service...703server # [ 88.950911] postgres[1114]: 2026-10-26 11:38:01.579 UTC [1114] LOG: received fast shutdown request704server # [ 88.952048] postgres[1114]: 2026-10-26 11:38:01.598 UTC [1114] LOG: aborting any active transactions705server # [ 89.110352] postgres[1114]: 2026-10-26 11:38:01.791 UTC [1114] LOG: background worker "logical replication launcher" (PID 1124) exited with exit code 1706server # [ 89.154801] postgres[1119]: 2026-10-26 11:38:01.831 UTC [1119] LOG: shutting down707server # [ 89.196518] postgres[1119]: 2026-10-26 11:38:01.858 UTC [1119] LOG: checkpoint starting: shutdown immediate708server # [ 90.017269] postgres[1119]: 2026-10-26 11:38:02.693 UTC [1119] LOG: checkpoint complete: wrote 2176 buffers (13.3%); 0 WAL file(s) added, 0 removed, 4 recycled; write=0.445 s, sync=0.258 s, total=0.855 s; sync files=28, longest=0.199 s, average=0.010 s; distance=69073 kB, estimate=69073 kB709server # [ 90.121748] postgres[1114]: 2026-10-26 11:38:02.796 UTC [1114] LOG: database system is shut down710server # [ 90.179298] systemd[1]: postgresql.service: Deactivated successfully.711server # [ 90.207087] systemd[1]: Stopped postgresql.service.712server # [ 90.208079] systemd[1]: postgresql.service: Consumed 18.580s CPU time, 233.3M memory peak, 241.7M written to disk, 1.2K incoming IP traffic, 1.8K outgoing IP traffic.713server: (finished: must succeed: systemctl stop postgresql, in 1.91 seconds)714server: must succeed: systemd-run --unit=salt-sim --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim715server # [ 90.840780] systemd[1]: Started [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim.716server # Running as unit: salt-sim.service; invocation ID: c337def05d224fdb8eee0329e840da25717server: (finished: must succeed: systemd-run --unit=salt-sim --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim, in 0.69 seconds)718server: waiting for success: systemctl is-active --quiet postgresql719server # [ 91.755276] systemd[1]: Starting postgresql.service...720server # [ 93.229327] postgres[1261]: 2026-10-26 11:38:05.884 UTC [1261] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit721server # [ 93.247795] postgres[1261]: 2026-10-26 11:38:05.926 UTC [1261] LOG: listening on IPv6 address "::1", port 5432722server # [ 93.252356] postgres[1261]: 2026-10-26 11:38:05.931 UTC [1261] LOG: listening on IPv4 address "127.0.0.1", port 5432723server # [ 93.271491] postgres[1261]: 2026-10-26 11:38:05.951 UTC [1261] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"724server # [ 93.395808] postgres[1276]: 2026-10-26 11:38:06.072 UTC [1276] LOG: database system was shut down at 2026-10-26 11:38:02 UTC725server # [ 93.592972] postgres[1261]: 2026-10-26 11:38:06.270 UTC [1261] LOG: database system is ready to accept connections726server # [ 93.631971] systemd[1]: Started postgresql.service.727server: (finished: waiting for success: systemctl is-active --quiet postgresql, in 2.82 seconds)728server: must succeed: systemctl stop salt-sim729server # [ 94.459885] systemd[1]: Stopping [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim...730server # [ 94.538725] systemd[1]: salt-sim.service: Deactivated successfully.731server # [ 94.558771] systemd[1]: Stopped [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim.732server: (finished: must succeed: systemctl stop salt-sim, in 0.85 seconds)733(finished: subtest: Control: with no guard the start loop brings the source up, in 6.27 seconds)734subtest: A systemd start is refused while the block is held735server: must succeed: systemd-run --unit=hold-block --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_block736server # [ 95.140412] systemd[1]: Started [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_block.737server # Running as unit: hold-block.service; invocation ID: 6d9c55e0307f474883d0ce0f941b449f738server: (finished: must succeed: systemd-run --unit=hold-block --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_block, in 0.62 seconds)739server: waiting for success: systemctl show -p ExecCondition postgresql | grep -q start-guard740server # [ 95.915789] postgres[1261]: 2026-10-26 11:38:08.588 UTC [1261] LOG: received fast shutdown request741server # [ 95.944261] systemd[1]: Stopping postgresql.service...742server # [ 95.961593] postgres[1261]: 2026-10-26 11:38:08.613 UTC [1261] LOG: aborting any active transactions743server # [ 96.137798] postgres[1261]: 2026-10-26 11:38:08.815 UTC [1261] LOG: background worker "logical replication launcher" (PID 1281) exited with exit code 1744server # [ 96.162477] postgres[1272]: 2026-10-26 11:38:08.822 UTC [1272] LOG: shutting down745server # [ 96.176210] postgres[1272]: 2026-10-26 11:38:08.837 UTC [1272] LOG: checkpoint starting: shutdown immediate746server # [ 96.279088] postgres[1272]: 2026-10-26 11:38:08.956 UTC [1272] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.035 s, sync=0.014 s, total=0.133 s; sync files=2, longest=0.008 s, average=0.007 s; distance=0 kB, estimate=0 kB747server # [ 96.445224] postgres[1261]: 2026-10-26 11:38:09.106 UTC [1261] LOG: database system is shut down748server # [ 96.549340] systemd[1]: postgresql.service: Deactivated successfully.749server # [ 96.574676] systemd[1]: Stopped postgresql.service.750server # [ 96.994122] systemd[1]: Reload requested from client PID 1318 ('systemctl') (unit hold-block.service)...751server # [ 96.996201] systemd[1]: Reloading...752server # [ 102.959178] systemd[1]: Reloading finished in 5950 ms.753server: (finished: waiting for success: systemctl show -p ExecCondition postgresql | grep -q start-guard, in 8.45 seconds)754server: must fail: systemctl start postgresql755server # [ 104.262944] systemd[1]: Starting postgresql.service...756server # [ 104.893204] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION757server # [ 104.895571] systemd[1]: postgresql.service: Failed with result 'exit-code'.758server # [ 104.919828] systemd[1]: Failed to start postgresql.service.759server # Job for postgresql.service failed because the control process exited with error code.760server # See "systemctl status postgresql.service" and "journalctl -xeu postgresql.service" for details.761server: (finished: must fail: systemctl start postgresql, in 1.29 seconds)762server: must succeed: sleep 5763server: (finished: must succeed: sleep 5, in 5.43 seconds)764server: must fail: systemctl is-active --quiet postgresql765server: (finished: must fail: systemctl is-active --quiet postgresql, in 0.43 seconds)766server: must succeed: systemctl show -p Restart postgresql767server: (finished: must succeed: systemctl show -p Restart postgresql, in 0.55 seconds)768(finished: subtest: A systemd start is refused while the block is held, in 16.78 seconds)769subtest: The block expires on its own when the holder is SIGKILLed770server: must succeed: systemctl kill -s KILL hold-block771server # [ 111.934689] systemd[1]: hold-block.service: Sent signal SIGKILL to main process 1299 (sleep) on client request.772server # [ 111.936057] systemd[1]: hold-block.service: Killed unit cgroup '/system.slice/hold-block.service' with SIGKILL on client request.773server # [ 111.943602] systemd[1]: hold-block.service: Main process exited, code=killed, status=9/KILL774server # [ 111.954467] systemd[1]: hold-block.service: Failed with result 'signal'.775server: (finished: must succeed: systemctl kill -s KILL hold-block, in 0.58 seconds)776server: waiting for failure: systemctl is-active --quiet hold-block777server: (finished: waiting for failure: systemctl is-active --quiet hold-block, in 0.66 seconds)778server: must succeed: systemctl start postgresql779server # [ 113.150445] systemd[1]: Starting postgresql.service...780server # [ 115.010730] postgres[1444]: 2026-10-26 11:38:27.683 UTC [1444] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit781server # [ 115.033142] postgres[1444]: 2026-10-26 11:38:27.712 UTC [1444] LOG: listening on IPv6 address "::1", port 5432782server # [ 115.036549] postgres[1444]: 2026-10-26 11:38:27.716 UTC [1444] LOG: listening on IPv4 address "127.0.0.1", port 5432783server # [ 115.053018] postgres[1444]: 2026-10-26 11:38:27.731 UTC [1444] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"784server # [ 115.170585] postgres[1447]: 2026-10-26 11:38:27.827 UTC [1447] LOG: database system was shut down at 2026-10-26 11:38:08 UTC785server # [ 115.284088] postgres[1444]: 2026-10-26 11:38:27.963 UTC [1444] LOG: database system is ready to accept connections786server # [ 116.151326] systemd[1]: Reload requested from client PID 1457 ('systemctl') (unit postgresql.service)...787server # [ 116.170499] systemd[1]: Reloading...788server # [ 122.230885] systemd[1]: Reloading finished in 6080 ms.789server # [ 122.573402] systemd[1]: Started postgresql.service.790server: (finished: must succeed: systemctl start postgresql, in 10.06 seconds)791server: waiting for unit postgresql.service792server: (finished: waiting for unit postgresql.service, in 0.88 seconds)793server: must fail: test -e /run/systemd/system/postgresql.service.d/pg-upgrade-lock.conf794server: (finished: must fail: test -e /run/systemd/system/postgresql.service.d/pg-upgrade-lock.conf, in 0.40 seconds)795server: must succeed: systemctl show -p Restart postgresql796server: (finished: must succeed: systemctl show -p Restart postgresql, in 0.59 seconds)797server: must succeed: systemctl show -p NeedDaemonReload postgresql798server: (finished: must succeed: systemctl show -p NeedDaemonReload postgresql, in 0.56 seconds)799(finished: subtest: The block expires on its own when the holder is SIGKILLed, in 13.73 seconds)800subtest: The pid lock stops a direct start once the new cluster is up801server: must succeed: systemctl stop postgresql802server # [ 125.659015] systemd[1]: Stopping postgresql.service...803server # [ 125.718183] postgres[1444]: 2026-10-26 11:38:38.332 UTC [1444] LOG: received fast shutdown request804server # [ 125.719307] postgres[1444]: 2026-10-26 11:38:38.385 UTC [1444] LOG: aborting any active transactions805server # [ 125.825945] postgres[1444]: 2026-10-26 11:38:38.503 UTC [1444] LOG: background worker "logical replication launcher" (PID 1450) exited with exit code 1806server # [ 125.882448] postgres[1445]: 2026-10-26 11:38:38.544 UTC [1445] LOG: shutting down807server # [ 125.883832] postgres[1445]: 2026-10-26 11:38:38.560 UTC [1445] LOG: checkpoint starting: shutdown immediate808server # [ 125.961635] postgres[1445]: 2026-10-26 11:38:38.641 UTC [1445] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.027 s, sync=0.007 s, total=0.097 s; sync files=2, longest=0.004 s, average=0.004 s; distance=0 kB, estimate=0 kB809server # [ 126.027208] postgres[1444]: 2026-10-26 11:38:38.705 UTC [1444] LOG: database system is shut down810server # [ 126.084719] systemd[1]: postgresql.service: Deactivated successfully.811server # [ 126.095768] systemd[1]: Stopped postgresql.service.812server # [ 126.360608] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:08.0/virtio7/input/input3813server: (finished: must succeed: systemctl stop postgresql, in 1.04 seconds)814server: must succeed: systemd-run --unit=hold-lock --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_lock815server # [ 126.720921] systemd[1]: Started [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_lock.816server # Running as unit: hold-lock.service; invocation ID: 7452d097834745668cc157b48ea39e83817server: (finished: must succeed: systemd-run --unit=hold-lock --collect /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive hold_lock, in 0.65 seconds)818server: waiting for success: test -s /var/lib/postgresql/data/postmaster.pid819server # [ 127.747899] runuser[1542]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)820server # [ 129.257240] drive[1543]: [11:38:41] Locked /var/lib/postgresql/data with pg_upgrade pid 1546821server: (finished: waiting for success: test -s /var/lib/postgresql/data/postmaster.pid, in 3.54 seconds)822server: must fail: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log -t 5823server # [ 130.748845] runuser[1581]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)824server # pg_ctl: another server might be running; trying to start server anyway825server # pg_ctl: could not start server826server # Examine the log output.827server # [ 131.930958] runuser[1581]: pam_unix(runuser:session): session closed for user postgres828server: (finished: must fail: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log -t 5, in 1.59 seconds)829server: must succeed: systemctl kill -s KILL hold-lock830server # [ 132.419012] systemd[1]: hold-lock.service: Sent signal SIGKILL to main process 1536 (drive) on client request.831server # [ 132.420333] systemd[1]: hold-lock.service: Killed unit cgroup '/system.slice/hold-lock.service' with SIGKILL on client request.832server # [ 132.492441] systemd[1]: hold-lock.service: Main process exited, code=killed, status=9/KILL833server # [ 132.523881] systemd[1]: hold-lock.service: Failed with result 'signal'.834server: (finished: must succeed: systemctl kill -s KILL hold-lock, in 0.56 seconds)835server: waiting for failure: systemctl is-active --quiet hold-lock836server: (finished: waiting for failure: systemctl is-active --quiet hold-lock, in 0.64 seconds)837server: must succeed: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log 838server # [ 133.544023] runuser[1601]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)839server # pg_ctl: another server might be running; trying to start server anyway840server # [ 135.014180] runuser[1601]: pam_unix(runuser:session): session closed for user postgres841server: (finished: must succeed: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log , in 1.89 seconds)842server: must succeed: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl stop -D /var/lib/postgresql/data -w -s 843server # [ 135.507590] runuser[1622]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)844server # [ 135.924104] runuser[1622]: pam_unix(runuser:session): session closed for user postgres845server: (finished: must succeed: runuser -u postgres -- /nix/store/pq36ia5m70l8q0iwq5vbv4y7i3aibf73-postgresql-and-plugins-15.19/bin/pg_ctl stop -D /var/lib/postgresql/data -w -s , in 0.95 seconds)846server: must succeed: rm -f /run/pg-upgrade-source.pid847server: (finished: must succeed: rm -f /run/pg-upgrade-source.pid, in 0.36 seconds)848server: must succeed: systemctl start postgresql849server # [ 136.808411] systemd[1]: Starting postgresql.service...850server # [ 138.079532] postgres[1650]: 2026-10-26 11:38:50.755 UTC [1650] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit851server # [ 138.107927] postgres[1650]: 2026-10-26 11:38:50.787 UTC [1650] LOG: listening on IPv6 address "::1", port 5432852server # [ 138.111483] postgres[1650]: 2026-10-26 11:38:50.791 UTC [1650] LOG: listening on IPv4 address "127.0.0.1", port 5432853server # [ 138.126779] postgres[1650]: 2026-10-26 11:38:50.808 UTC [1650] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"854server # [ 138.229626] postgres[1653]: 2026-10-26 11:38:50.904 UTC [1653] LOG: database system was shut down at 2026-10-26 11:38:48 UTC855server # [ 138.362147] postgres[1650]: 2026-10-26 11:38:51.043 UTC [1650] LOG: database system is ready to accept connections856server # [ 138.389745] systemd[1]: Started postgresql.service.857server: (finished: must succeed: systemctl start postgresql, in 2.12 seconds)858server: waiting for unit postgresql.service859server: (finished: waiting for unit postgresql.service, in 0.70 seconds)860(finished: subtest: The pid lock stops a direct start once the new cluster is up, in 14.04 seconds)861subtest: A real pg_upgrade copy under a start storm862server: must succeed: systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive upgrade863server # [ 139.809199] systemd[1]: Started [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive upgrade.864server # Running as unit: fake-initiate.service; invocation ID: 72338baa5a5f42a2b78cda0b24c15d31865server # [ 140.461220] systemd[1]: Stopping postgresql.service...866server # [ 140.509486] postgres[1650]: 2026-10-26 11:38:53.138 UTC [1650] LOG: received fast shutdown request867server # [ 140.510620] postgres[1650]: 2026-10-26 11:38:53.161 UTC [1650] LOG: aborting any active transactions868server # [ 140.598545] postgres[1650]: 2026-10-26 11:38:53.272 UTC [1650] LOG: background worker "logical replication launcher" (PID 1656) exited with exit code 1869server # [ 140.626149] postgres[1651]: 2026-10-26 11:38:53.272 UTC [1651] LOG: shutting down870server # [ 140.629785] postgres[1651]: 2026-10-26 11:38:53.287 UTC [1651] LOG: checkpoint starting: shutdown immediate871server # [ 140.701789] postgres[1651]: 2026-10-26 11:38:53.378 UTC [1651] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.022 s, sync=0.010 s, total=0.106 s; sync files=2, longest=0.006 s, average=0.005 s; distance=0 kB, estimate=0 kB872server # [ 140.762490] postgres[1650]: 2026-10-26 11:38:53.444 UTC [1650] LOG: database system is shut down873server # [ 140.856910] systemd[1]: postgresql.service: Deactivated successfully.874server # [ 140.871880] systemd[1]: Stopped postgresql.service.875server # [ 141.246598] systemd[1]: Reload requested from client PID 1688 ('systemctl') (unit fake-initiate.service)...876server # [ 141.254833] systemd[1]: Reloading...877server # [ 146.708763] systemd[1]: Reloading finished in 5435 ms.878server # [ 147.282009] runuser[1718]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)879server # [ 151.955743] systemd[1]: Starting Virtual Console Setup...880server # [ 152.329343] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.881server # [ 152.343581] systemd[1]: Stopped Virtual Console Setup.882server # [ 152.398045] systemd[1]: Starting Virtual Console Setup...883server # [ 157.916345] systemd[1]: Finished Virtual Console Setup.884server # [ 160.827116] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.885server # [ 163.635450] systemd-logind[641]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)886server # initdb: warning: enabling "trust" authentication for local connections887server # 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.888server # [ 172.135974] runuser[1718]: pam_unix(runuser:session): session closed for user postgres889server # [ 172.383880] systemd[1]: Started [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim.890server # Running as unit: salt-sim.service; invocation ID: daaa0b6095224a8d9683b6abce0f13cc891server # [ 172.699628] runuser[1798]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)892server # [ 173.019209] systemd[1]: Starting postgresql.service...893server # [ 173.555556] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION894server # [ 173.573517] systemd[1]: postgresql.service: Failed with result 'exit-code'.895server # [ 173.574603] systemd[1]: Failed to start postgresql.service.896server # [ 174.344200] systemd[1]: Starting postgresql.service...897server # [ 174.886918] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION898server # [ 174.888234] systemd[1]: postgresql.service: Failed with result 'exit-code'.899server # [ 174.915638] systemd[1]: Failed to start postgresql.service.900server # [ 175.690853] systemd[1]: Starting postgresql.service...901server # [ 176.219432] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION902server # [ 176.244017] systemd[1]: postgresql.service: Failed with result 'exit-code'.903server # [ 176.252078] systemd[1]: Failed to start postgresql.service.904server # [ 176.966422] systemd[1]: Starting postgresql.service...905server # [ 177.491596] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION906server # [ 177.528154] systemd[1]: postgresql.service: Failed with result 'exit-code'.907server # [ 177.536748] systemd[1]: Failed to start postgresql.service.908server # [ 178.264998] systemd[1]: Starting postgresql.service...909server # [ 178.791946] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION910server # [ 178.810653] systemd[1]: postgresql.service: Failed with result 'exit-code'.911server # [ 178.811838] systemd[1]: Failed to start postgresql.service.912server # [ 179.513338] systemd[1]: postgresql.service: Start request repeated too quickly.913server # [ 179.514501] systemd[1]: postgresql.service: Failed with result 'exit-code'.914server # [ 179.514980] systemd[1]: Failed to start postgresql.service.915server # [ 180.242231] systemd[1]: postgresql.service: Start request repeated too quickly.916server # [ 180.250459] systemd[1]: postgresql.service: Failed with result 'exit-code'.917server # [ 180.251444] systemd[1]: Failed to start postgresql.service.918server # [ 180.905931] systemd[1]: postgresql.service: Start request repeated too quickly.919server # [ 180.907673] systemd[1]: postgresql.service: Failed with result 'exit-code'.920server # [ 180.941979] systemd[1]: Failed to start postgresql.service.921server # [ 181.592593] systemd[1]: postgresql.service: Start request repeated too quickly.922server # [ 181.615763] systemd[1]: postgresql.service: Failed with result 'exit-code'.923server # [ 181.637807] systemd[1]: Failed to start postgresql.service.924server # [ 182.218493] systemd[1]: postgresql.service: Start request repeated too quickly.925server # [ 182.241161] systemd[1]: postgresql.service: Failed with result 'exit-code'.926server # [ 182.242341] systemd[1]: Failed to start postgresql.service.927server # [ 182.839104] systemd[1]: postgresql.service: Start request repeated too quickly.928server # [ 182.840376] systemd[1]: postgresql.service: Failed with result 'exit-code'.929server # [ 182.869545] systemd[1]: Failed to start postgresql.service.930server # [ 183.518612] systemd[1]: Starting postgresql.service...931server # [ 183.971319] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION932server # [ 184.002206] systemd[1]: postgresql.service: Failed with result 'exit-code'.933server # [ 184.003554] systemd[1]: Failed to start postgresql.service.934server # [ 184.628823] systemd[1]: Starting postgresql.service...935server # [ 185.070735] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION936server # [ 185.098240] systemd[1]: postgresql.service: Failed with result 'exit-code'.937server # [ 185.099820] systemd[1]: Failed to start postgresql.service.938server # [ 185.711844] systemd[1]: Starting postgresql.service...939server # [ 186.171924] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION940server # [ 186.199973] systemd[1]: postgresql.service: Failed with result 'exit-code'.941server # [ 186.205830] systemd[1]: Failed to start postgresql.service.942server # [ 186.796857] systemd[1]: Starting postgresql.service...943server # [ 187.216751] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION944server # [ 187.236216] systemd[1]: postgresql.service: Failed with result 'exit-code'.945server # [ 187.253846] systemd[1]: Failed to start postgresql.service.946server # [ 187.930437] systemd[1]: Starting postgresql.service...947server # [ 188.398147] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION948server # [ 188.426175] systemd[1]: postgresql.service: Failed with result 'exit-code'.949server # [ 188.426988] systemd[1]: Failed to start postgresql.service.950server # [ 189.077623] systemd[1]: postgresql.service: Start request repeated too quickly.951server # [ 189.079687] systemd[1]: postgresql.service: Failed with result 'exit-code'.952server # [ 189.099718] systemd[1]: Failed to start postgresql.service.953server # [ 189.706623] systemd[1]: postgresql.service: Start request repeated too quickly.954server # [ 189.723525] systemd[1]: postgresql.service: Failed with result 'exit-code'.955server # [ 189.724307] systemd[1]: Failed to start postgresql.service.956server # [ 190.259887] systemd[1]: postgresql.service: Start request repeated too quickly.957server # [ 190.262890] systemd[1]: postgresql.service: Failed with result 'exit-code'.958server # [ 190.263780] systemd[1]: Failed to start postgresql.service.959server # [ 190.874925] systemd[1]: postgresql.service: Start request repeated too quickly.960server # [ 190.897313] systemd[1]: postgresql.service: Failed with result 'exit-code'.961server # [ 190.898711] systemd[1]: Failed to start postgresql.service.962server # [ 191.535366] systemd[1]: postgresql.service: Start request repeated too quickly.963server # [ 191.537734] systemd[1]: postgresql.service: Failed with result 'exit-code'.964server # [ 191.538623] systemd[1]: Failed to start postgresql.service.965server # [ 192.191780] systemd[1]: postgresql.service: Start request repeated too quickly.966server # [ 192.211905] systemd[1]: postgresql.service: Failed with result 'exit-code'.967server # [ 192.225775] systemd[1]: Failed to start postgresql.service.968server # [ 192.806541] systemd[1]: postgresql.service: Start request repeated too quickly.969server # [ 192.807841] systemd[1]: postgresql.service: Failed with result 'exit-code'.970server # [ 192.827182] systemd[1]: Failed to start postgresql.service.971server # [ 193.586748] systemd[1]: Starting postgresql.service...972server # [ 193.995866] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION973server # [ 194.009943] systemd[1]: postgresql.service: Failed with result 'exit-code'.974server # [ 194.017869] systemd[1]: Failed to start postgresql.service.975server # [ 194.722820] systemd[1]: Starting postgresql.service...976server # [ 195.198312] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION977server # [ 195.210174] systemd[1]: postgresql.service: Failed with result 'exit-code'.978server # [ 195.222822] systemd[1]: Failed to start postgresql.service.979server # [ 195.970385] systemd[1]: Starting postgresql.service...980server # [ 196.493050] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION981server # [ 196.509983] systemd[1]: postgresql.service: Failed with result 'exit-code'.982server # [ 196.511231] systemd[1]: Failed to start postgresql.service.983server # [ 197.263683] systemd[1]: Starting postgresql.service...984server # [ 197.698513] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION985server # [ 197.699925] systemd[1]: postgresql.service: Failed with result 'exit-code'.986server # [ 197.722614] systemd[1]: Failed to start postgresql.service.987server # [ 198.387824] systemd[1]: Starting postgresql.service...988server # [ 198.837322] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION989server # [ 198.849198] systemd[1]: postgresql.service: Failed with result 'exit-code'.990server # [ 198.861750] systemd[1]: Failed to start postgresql.service.991server # [ 199.464153] systemd[1]: postgresql.service: Start request repeated too quickly.992server # [ 199.489717] systemd[1]: postgresql.service: Failed with result 'exit-code'.993server # [ 199.490559] systemd[1]: Failed to start postgresql.service.994server # [ 200.053379] systemd[1]: postgresql.service: Start request repeated too quickly.995server # [ 200.054376] systemd[1]: postgresql.service: Failed with result 'exit-code'.996server # [ 200.071272] systemd[1]: Failed to start postgresql.service.997server # [ 200.657744] systemd[1]: postgresql.service: Start request repeated too quickly.998server # [ 200.685153] systemd[1]: postgresql.service: Failed with result 'exit-code'.999server # [ 200.685926] systemd[1]: Failed to start postgresql.service.1000server # [ 201.130845] systemd[1]: postgresql.service: Start request repeated too quickly.1001server # [ 201.134350] systemd[1]: postgresql.service: Failed with result 'exit-code'.1002server # [ 201.134932] systemd[1]: Failed to start postgresql.service.1003server # [ 201.663566] systemd[1]: postgresql.service: Start request repeated too quickly.1004server # [ 201.689893] systemd[1]: postgresql.service: Failed with result 'exit-code'.1005server # [ 201.690672] systemd[1]: Failed to start postgresql.service.1006server # [ 202.143132] systemd[1]: postgresql.service: Start request repeated too quickly.1007server # [ 202.153648] systemd[1]: postgresql.service: Failed with result 'exit-code'.1008server # [ 202.154539] systemd[1]: Failed to start postgresql.service.1009server # [ 202.633010] systemd[1]: postgresql.service: Start request repeated too quickly.1010server # [ 202.634733] systemd[1]: postgresql.service: Failed with result 'exit-code'.1011server # [ 202.635317] systemd[1]: Failed to start postgresql.service.1012server # [ 203.133460] systemd[1]: postgresql.service: Start request repeated too quickly.1013server # [ 203.153895] systemd[1]: postgresql.service: Failed with result 'exit-code'.1014server # [ 203.167708] systemd[1]: Failed to start postgresql.service.1015server # [ 203.697939] systemd[1]: Starting postgresql.service...1016server # [ 204.042494] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1017server # [ 204.054339] systemd[1]: postgresql.service: Failed with result 'exit-code'.1018server # [ 204.055706] systemd[1]: Failed to start postgresql.service.1019server # [ 204.560739] systemd[1]: Starting postgresql.service...1020server # [ 204.894561] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1021server # [ 204.901432] systemd[1]: postgresql.service: Failed with result 'exit-code'.1022server # [ 204.916040] systemd[1]: Failed to start postgresql.service.1023server # [ 205.596317] systemd[1]: Starting postgresql.service...1024server # [ 206.150273] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1025server # [ 206.152389] systemd[1]: postgresql.service: Failed with result 'exit-code'.1026server # [ 206.179540] systemd[1]: Failed to start postgresql.service.1027server # [ 206.875568] systemd[1]: Starting postgresql.service...1028server # [ 207.373736] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1029server # [ 207.376970] systemd[1]: postgresql.service: Failed with result 'exit-code'.1030server # [ 207.389128] systemd[1]: Failed to start postgresql.service.1031server # [ 208.099962] systemd[1]: Starting postgresql.service...1032server # [ 208.555369] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1033server # [ 208.566964] systemd[1]: postgresql.service: Failed with result 'exit-code'.1034server # [ 208.582605] systemd[1]: Failed to start postgresql.service.1035server # [ 209.299990] systemd[1]: postgresql.service: Start request repeated too quickly.1036server # [ 209.329215] systemd[1]: postgresql.service: Failed with result 'exit-code'.1037server # [ 209.330347] systemd[1]: Failed to start postgresql.service.1038server # [ 209.946802] systemd[1]: postgresql.service: Start request repeated too quickly.1039server # [ 209.954202] systemd[1]: postgresql.service: Failed with result 'exit-code'.1040server # [ 209.955742] systemd[1]: Failed to start postgresql.service.1041server # [ 210.636069] systemd[1]: postgresql.service: Start request repeated too quickly.1042server # [ 210.646529] systemd[1]: postgresql.service: Failed with result 'exit-code'.1043server # [ 210.647635] systemd[1]: Failed to start postgresql.service.1044server # [ 211.264381] systemd[1]: postgresql.service: Start request repeated too quickly.1045server # [ 211.271065] systemd[1]: postgresql.service: Failed with result 'exit-code'.1046server # [ 211.271940] systemd[1]: Failed to start postgresql.service.1047server # [ 211.883210] systemd[1]: postgresql.service: Start request repeated too quickly.1048server # [ 211.917776] systemd[1]: postgresql.service: Failed with result 'exit-code'.1049server # [ 211.919234] systemd[1]: Failed to start postgresql.service.1050server # [ 212.564727] systemd[1]: postgresql.service: Start request repeated too quickly.1051server # [ 212.566565] systemd[1]: postgresql.service: Failed with result 'exit-code'.1052server # [ 212.567730] systemd[1]: Failed to start postgresql.service.1053server # [ 213.159967] systemd[1]: postgresql.service: Start request repeated too quickly.1054server # [ 213.182368] systemd[1]: postgresql.service: Failed with result 'exit-code'.1055server # [ 213.183323] systemd[1]: Failed to start postgresql.service.1056server # [ 213.784795] systemd[1]: Starting postgresql.service...1057server # [ 214.238407] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1058server # [ 214.239698] systemd[1]: postgresql.service: Failed with result 'exit-code'.1059server # [ 214.257052] systemd[1]: Failed to start postgresql.service.1060server # [ 214.852786] systemd[1]: Starting postgresql.service...1061server # [ 215.262737] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1062server # [ 215.263990] systemd[1]: postgresql.service: Failed with result 'exit-code'.1063server # [ 215.303188] systemd[1]: Failed to start postgresql.service.1064server # [ 215.910999] systemd[1]: Starting postgresql.service...1065server # [ 216.320560] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1066server # [ 216.338972] systemd[1]: postgresql.service: Failed with result 'exit-code'.1067server # [ 216.340108] systemd[1]: Failed to start postgresql.service.1068server # [ 216.931040] systemd[1]: Starting postgresql.service...1069server # [ 217.342794] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1070server # [ 217.343927] systemd[1]: postgresql.service: Failed with result 'exit-code'.1071server # [ 217.378217] systemd[1]: Failed to start postgresql.service.1072server # [ 217.977062] systemd[1]: Starting postgresql.service...1073server # [ 218.420011] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1074server # [ 218.441284] systemd[1]: postgresql.service: Failed with result 'exit-code'.1075server # [ 218.442349] systemd[1]: Failed to start postgresql.service.1076server # [ 218.980794] systemd[1]: postgresql.service: Start request repeated too quickly.1077server # [ 218.982009] systemd[1]: postgresql.service: Failed with result 'exit-code'.1078server # [ 218.982740] systemd[1]: Failed to start postgresql.service.1079server # [ 219.552041] systemd[1]: postgresql.service: Start request repeated too quickly.1080server # [ 219.571036] systemd[1]: postgresql.service: Failed with result 'exit-code'.1081server # [ 219.571984] systemd[1]: Failed to start postgresql.service.1082server # [ 220.169321] systemd[1]: postgresql.service: Start request repeated too quickly.1083server # [ 220.170502] systemd[1]: postgresql.service: Failed with result 'exit-code'.1084server # [ 220.171056] systemd[1]: Failed to start postgresql.service.1085server # [ 220.872747] systemd[1]: postgresql.service: Start request repeated too quickly.1086server # [ 220.874241] systemd[1]: postgresql.service: Failed with result 'exit-code'.1087server # [ 220.874827] systemd[1]: Failed to start postgresql.service.1088server # [ 221.749214] systemd[1]: postgresql.service: Start request repeated too quickly.1089server # [ 221.766789] systemd[1]: postgresql.service: Failed with result 'exit-code'.1090server # [ 221.785053] systemd[1]: Failed to start postgresql.service.1091server # [ 222.676648] systemd[1]: postgresql.service: Start request repeated too quickly.1092server # [ 222.696237] systemd[1]: postgresql.service: Failed with result 'exit-code'.1093server # [ 222.703480] systemd[1]: Failed to start postgresql.service.1094server # [ 223.457501] systemd[1]: postgresql.service: Start request repeated too quickly.1095server # [ 223.458819] systemd[1]: postgresql.service: Failed with result 'exit-code'.1096server # [ 223.459845] systemd[1]: Failed to start postgresql.service.1097server # [ 224.147237] systemd[1]: Starting postgresql.service...1098server # [ 224.847642] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1099server # [ 224.861310] systemd[1]: postgresql.service: Failed with result 'exit-code'.1100server # [ 224.870043] systemd[1]: Failed to start postgresql.service.1101server # [ 226.011416] systemd[1]: Starting postgresql.service...1102server # [ 226.607660] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1103server # [ 226.622700] systemd[1]: postgresql.service: Failed with result 'exit-code'.1104server # [ 226.637846] systemd[1]: Failed to start postgresql.service.1105server # [ 227.193369] runuser[1798]: pam_unix(runuser:session): session closed for user postgres1106server # [ 227.336822] systemd[1]: Starting postgresql.service...1107server # [ 227.473688] systemd[1]: Stopping [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim...1108server # [ 227.543270] systemd[1]: salt-sim.service: Deactivated successfully.1109server # [ 227.558372] systemd[1]: Stopped [systemd-run] /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive salt_sim.1110server # [ 227.566818] systemd[1]: salt-sim.service: Consumed 9.115s CPU time, 1.9M memory peak.1111server # [ 227.967527] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1112server # [ 227.987765] systemd[1]: postgresql.service: Failed with result 'exit-code'.1113server # [ 227.995227] systemd[1]: Failed to start postgresql.service.1114server # [ 228.011499] systemd[1]: fake-initiate.service: Main process exited, code=exited, status=1/FAILURE1115server # [ 228.023430] systemd[1]: fake-initiate.service: Failed with result 'exit-code'.1116server # [ 228.030435] systemd[1]: fake-initiate.service: Consumed 33.579s CPU time, 148.2M memory peak, 231.5M written to disk.1117server # Finished with result: exit-code1118server # Main processes terminated with: code=exited, status=1/FAILURE1119server # Service runtime: 1min 28.209s1120server # CPU time consumed: 33.579s1121server # Memory peak: 148.2M (swap: 0B)1122server # IO Bytes: written 231.5M1123server: output: The files belonging to this database system will be owned by user "postgres".1124This user must also own the server process.11251126The database cluster will be initialized with locale "C".1127The default text search configuration will be set to "english".11281129Data page checksums are disabled.11301131creating directory /var/lib/postgresql/data-17 ... ok1132creating subdirectories ... ok1133selecting dynamic shared memory implementation ... posix1134selecting default "max_connections" ... 1001135selecting default "shared_buffers" ... 128MB1136selecting default time zone ... UTC1137creating configuration files ... ok1138running bootstrap script ... ok1139performing post-bootstrap initialization ... ok1140syncing data to disk ... ok114111421143Success. You can now start the database server using:11441145 /nix/store/7dffajjaar5v34qqq1r5rbmiy33z18ic-postgresql-and-plugins-17.11/bin/pg_ctl -D /var/lib/postgresql/data-17 -l logfile start11461147Performing Consistency Checks1148-----------------------------1149Checking cluster versions ok1150Checking database user is the install user ok1151Checking database connection settings ok1152Checking for prepared transactions ok1153Checking for contrib/isn with bigint-passing mismatch ok1154Checking data type usage ok1155Checking for not-null constraint inconsistencies ok1156Creating dump of global objects ok1157Creating dump of database schemas ok1158[11:39:51] Locked /var/lib/postgresql/data with pg_upgrade pid 18001159Checking for presence of required libraries ok1160Checking database user is the install user ok1161Checking for prepared transactions ok1162Checking for new cluster tablespace directories ok11631164If pg_upgrade fails after this point, you must re-initdb the1165new cluster before continuing.11661167Performing Upgrade1168------------------1169Setting locale and encoding for new cluster ok1170Analyzing all rows in the new cluster ok1171Freezing all rows in the new cluster ok1172Deleting files from new pg_xact ok1173Copying old pg_xact to new server ok1174Setting oldest XID for new cluster ok1175Setting next transaction ID and epoch for new cluster ok1176Deleting files from new pg_multixact/offsets ok1177Copying old pg_multixact/offsets to new server ok1178Deleting files from new pg_multixact/members ok1179Copying old pg_multixact/members to new server ok1180Setting next multixact ID and offset for new cluster ok1181Resetting WAL archives ok1182Setting frozenxid and minmxid counters in new cluster ok1183Restoring global objects in the new cluster ok1184Restoring database schemas in the new cluster ok1185Copying user relation files ok1186Setting next OID for new cluster ok1187Sync data directory to disk ok1188Creating script to delete old cluster ok1189Checking for extension updates ok11901191Upgrade Complete1192----------------1193Optimizer statistics are not transferred by pg_upgrade.1194Once you start the new server, consider running:1195 /nix/store/7dffajjaar5v34qqq1r5rbmiy33z18ic-postgresql-and-plugins-17.11/bin/vacuumdb -U postgres --all --analyze-in-stages1196Running this script will delete the old cluster's data files:1197 ./delete_old_cluster.sh1198[11:40:20] ERROR: postgresql.service is activating after pg_upgrade; the copied data files may be inconsistent11991200!!! Test "A real pg_upgrade copy under a start storm" failed with error: "command `systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive upgrade` failed (exit code 1)"1201!!! Traceback (most recent call last):1202!!! File "<string>", line 69, in <module>1203!!! server.succeed(f"systemd-run --unit=fake-initiate --collect --pipe --wait {DRIVE} upgrade")1204!!! 1205!!! RequestedAssertionFailed: command `systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/k4v95s7v71vjgciwms3mkdcr71i5inx4-drive/bin/drive upgrade` failed (exit code 1)1206cleanup1207kill machine (pid 9)1208qemu-system-aarch64: terminating on signal 15 from pid 6 (/nix/store/y88crn50yx35fiiwcjx6xqwi6ahk7mlq-python3-3.13.11/bin/python3.13)1209vde_switch: EOF data port: Interrupted system call1210kill vlan (pid 7)1211vde_switch: (finished: cleanup, in 0.00 seconds)1212Caught signal 15, cleaning up and exiting