vm-test-run-pg-upgrade-start-guard
checks.aarch64-linux.ext-pg-upgrade-start-guard
· build #422
· 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 # Disk image does not exist, creating the virtualisation disk image...19server # Formatting '/build/vm-state-server/tmp.hQfeGaysn9', fmt=raw size=429496729620server # Discarding device blocks: 0/1048576 done21server # Creating filesystem with 1048576 4k blocks and 262144 inodes22server: QEMU running (pid 9)23server # Filesystem UUID: 70de2958-0091-4a66-87da-83197d2548e924(finished: start all VMs, in 0.13 seconds)25server: waiting for unit postgresql.service26server: waiting for the VM to finish booting27server # Superblock backups stored on blocks:28server # 32768, 98304, 163840, 229376, 294912, 819200, 88473629server # 30server # Allocating group tables: 0/32 done31server # Writing inode tables: 0/32 done32server # Creating journal (16384 blocks): done33server # Writing superblocks and filesystem accounting information: 0/32 done34server # 35server # Virtualisation disk image created.36server # [ 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/w9smhp3bpdz8d9xzpxfq3ya1vpq3zfd8-nixos-system-server-test/init regInfo=/nix/store/0vnsz349g992ivz9anmpiscy0v7l03zv-closure-info/registration console=ttyAMA0,115200n8 console=tty069server # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/store/0vnsz349g992ivz9anmpiscy0v7l03zv-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 @446c0000 (indirect, esz 8, psz 64K, shr 1)101server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @446d0000 (flat, esz 8, psz 64K, shr 1)102server # [ 0.000000] GICv3: using LPI property table @0x00000000446e0000103server # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x00000000446f0000104server # [ 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.000039] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns108server # [ 0.002068] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)109server # [ 0.011961] Console: colour dummy device 80x25110server # [ 0.013310] printk: legacy console [tty0] enabled111server # [ 0.018062] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)112server # [ 0.018388] pid_max: default: 32768 minimum: 301113server # [ 0.019944] LSM: initializing lsm=capability,landlock,yama,bpf114server # [ 0.021360] landlock: Up and running.115server # [ 0.021406] Yama: becoming mindful.116server # [ 0.022906] LSM support for eBPF active117server # [ 0.025372] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)118server # [ 0.025877] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)119server # [ 0.052959] cacheinfo: Unable to detect cache hierarchy for CPU 0120server # [ 0.065492] rcu: Hierarchical SRCU implementation.121server # [ 0.065579] rcu: Max phase no-delay instances is 1000.122server # [ 0.072859] fsl-mc MSI: its@8080000 domain created123server # [ 0.075050] EFI services will not be available.124server # [ 0.076824] smp: Bringing up secondary CPUs ...125server # [ 0.077494] smp: Brought up 1 node, 1 CPU126server # [ 0.077538] SMP: Total of 1 processors activated.127server # [ 0.077583] CPU: All CPU(s) started at EL1128server # [ 0.077844] CPU features: detected: Branch Target Identification129server # [ 0.077901] CPU features: detected: 32-bit EL0 Support130server # [ 0.077935] CPU features: detected: 32-bit EL1 Support131server # [ 0.077962] CPU features: detected: ARMv8.4 Translation Table Level132server # [ 0.078003] CPU features: detected: Instruction cache invalidation not required for I/D coherence133server # [ 0.078051] CPU features: detected: Data cache clean to the PoU not required for I/D coherence134server # [ 0.078125] CPU features: detected: Common not Private translations135server # [ 0.078154] CPU features: detected: CRC32 instructions136server # [ 0.078180] CPU features: detected: Data cache clean to Point of Deep Persistence137server # [ 0.078215] CPU features: detected: Data cache clean to Point of Persistence138server # [ 0.078244] CPU features: detected: Data independent timing control (DIT)139server # [ 0.078274] CPU features: detected: E0PD140server # [ 0.078299] CPU features: detected: Enhanced Counter Virtualization141server # [ 0.078327] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)142server # [ 0.078357] CPU features: detected: Enhanced Privileged Access Never143server # [ 0.078385] CPU features: detected: Enhanced Virtualization Traps144server # [ 0.078414] CPU features: detected: Fine Grained Traps145server # [ 0.078487] CPU features: detected: Generic authentication (IMP DEF algorithm)146server # [ 0.078578] CPU features: detected: RCpc load-acquire (LDAPR)147server # [ 0.078630] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)148server # [ 0.078662] CPU features: detected: LSE atomic instructions149server # [ 0.078690] CPU features: detected: Memory Copy and Memory Set instructions150server # [ 0.078720] CPU features: detected: Privileged Access Never151server # [ 0.078746] CPU features: detected: RAS Extension Support152server # [ 0.078772] CPU features: detected: Random Number Generator153server # [ 0.078800] CPU features: detected: Speculation barrier (SB)154server # [ 0.078827] CPU features: detected: Stage-2 Force Write-Back155server # [ 0.078866] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality156server # [ 0.078900] CPU features: detected: TLB range maintenance instructions157server # [ 0.078922] CPU features: detected: WFx with timeout158server # [ 0.078956] CPU features: detected: Speculative Store Bypassing Safe (SSBS)159server # [ 0.078979] CPU features: detected: Scalable Vector Extension160server # [ 0.083750] alternatives: applying system-wide alternatives161server # [ 0.102240] CPU features: detected: Hardware dirty bit management on CPU0162server # [ 0.102954] SVE: maximum available vector length 256 bytes per vector163server # [ 0.103093] SVE: default vector length 64 bytes per vector164server # [ 0.114733] Memory: 1935332K/2097152K available (23296K kernel code, 6546K rwdata, 24596K rodata, 4416K init, 1047K bss, 118632K reserved, 32768K cma-reserved)165server # [ 0.136267] devtmpfs: initialized166server # [ 0.161263] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns167server # [ 0.161830] futex hash table entries: 256 (order: 2, 16384 bytes, linear)168server # [ 0.164477] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL169server # [ 0.164548] 0 pages in range for non-PLT usage170server # [ 0.164593] 509248 pages in range for PLT usage171server # [ 0.167339] pinctrl core: initialized pinctrl subsystem172server # [ 0.179286] DMI not present or invalid.173server # [ 0.196340] NET: Registered PF_NETLINK/PF_ROUTE protocol family174server # [ 0.207023] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations175server # [ 0.209215] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations176server # [ 0.211774] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations177server # [ 0.212040] audit: initializing netlink subsys (disabled)178server # [ 0.214410] audit: type=2000 audit(0.092:1): state=initialized audit_enabled=0 res=1179server # [ 0.221235] thermal_sys: Registered thermal governor 'fair_share'180server # [ 0.221288] thermal_sys: Registered thermal governor 'bang_bang'181server # [ 0.221338] thermal_sys: Registered thermal governor 'step_wise'182server # [ 0.221369] thermal_sys: Registered thermal governor 'user_space'183server # [ 0.221398] thermal_sys: Registered thermal governor 'power_allocator'184server # [ 0.221843] cpuidle: using governor ladder185server # [ 0.222003] cpuidle: using governor menu186server # [ 0.223740] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.187server # [ 0.224100] ASID allocator initialised with 65536 entries188server # [ 0.231043] Serial: AMBA PL011 UART driver189server # [ 0.279989] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1190server # [ 0.282025] printk: legacy console [ttyAMA0] enabled191server # [ 0.324902] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages192server # [ 0.325129] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page193server # [ 0.325290] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages194server # [ 0.325440] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page195server # [ 0.325579] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages196server # [ 0.325687] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page197server # [ 0.326124] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages198server # [ 0.326286] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page199server # [ 0.349490] fbcon: Taking over console200server # [ 0.355541] ACPI: Interpreter disabled.201server # [ 0.382808] iommu: Default domain type: Translated202server # [ 0.382996] iommu: DMA domain TLB invalidation policy: strict mode203server # [ 0.386042] SCSI subsystem initialized204server # [ 0.388301] usbcore: registered new interface driver usbfs205server # [ 0.389276] usbcore: registered new interface driver hub206server # [ 0.389798] usbcore: registered new device driver usb207server # [ 0.392266] pps_core: LinuxPPS API ver. 1 registered208server # [ 0.392414] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>209server # [ 0.393059] PTP clock support registered210server # [ 0.398239] EDAC MC: Ver: 3.0.0211server # [ 0.399837] scmi_core: SCMI protocol bus registered212server # [ 0.411616] FPGA manager framework213server # [ 0.413082] Advanced Linux Sound Architecture Driver Initialized.214server # [ 0.430044] vgaarb: loaded215server # [ 0.438390] clocksource: Switched to clocksource arch_sys_counter216server # [ 0.441238] VFS: Disk quotas dquot_6.6.0217server # [ 0.441446] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)218server # [ 0.448941] netfs: FS-Cache loaded219server # [ 0.450764] pnp: PnP ACPI: disabled220server # [ 0.508312] NET: Registered PF_INET protocol family221server # [ 0.509726] IP idents hash table entries: 32768 (order: 6, 262144 bytes, linear)222server # [ 0.636601] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)223server # [ 0.637499] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)224server # [ 0.639314] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)225server # [ 0.640111] TCP bind hash table entries: 16384 (order: 7, 524288 bytes, linear)226server # [ 0.640932] TCP: Hash tables configured (established 16384 bind 16384)227server # [ 0.643451] MPTCP token hash table entries: 2048 (order: 4, 49152 bytes, linear)228server # [ 0.643901] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)229server # [ 0.644820] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)230server # [ 0.646988] NET: Registered PF_UNIX/PF_LOCAL protocol family231server # [ 0.648010] NET: Registered PF_XDP protocol family232server # [ 0.648270] PCI: CLS 0 bytes, default 64233server # [ 0.651376] kvm [1]: HYP mode not available234server # [ 0.663632] Trying to unpack rootfs image as initramfs...235server # [ 0.870762] Initialise system trusted keyrings236server # [ 0.884282] workingset: timestamp_bits=42 max_order=19 bucket_order=0237server # [ 0.891245] squashfs: version 4.0 (2009/01/31) Phillip Lougher238server # [ 0.895653] 9p: Installing v9fs 9p2000 file system support239server # [ 1.026494] Key type asymmetric registered240server # [ 1.026949] Asymmetric key parser 'x509' registered241server # [ 1.027864] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244)242server # [ 1.030675] io scheduler mq-deadline registered243server # [ 1.030910] io scheduler kyber registered244server # [ 1.072223] pl061_gpio 9030000.pl061: PL061 GPIO chip registered245server # [ 1.079921] ledtrig-cpu: registered to indicate activity on CPUs246server # [ 1.087527] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:247server # [ 1.088277] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000248server # [ 1.088900] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000249server # [ 1.089524] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000250server # [ 1.094862] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits251server # [ 1.096222] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]252server # [ 1.098145] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00253server # [ 1.102848] pci_bus 0000:00: root bus resource [bus 00-ff]254server # [ 1.103090] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]255server # [ 1.103263] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]256server # [ 1.103383] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]257server # [ 1.104653] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint258server # [ 1.113481] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint259server # [ 1.114431] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]260server # [ 1.114657] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]261server # [ 1.114821] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]262server # [ 1.115001] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]263server # [ 1.121741] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint264server # [ 1.122070] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]265server # [ 1.122208] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]266server # [ 1.122685] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]267server # [ 1.123338] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint268server # [ 1.123530] pci 0000:00:03.0: BAR 0 [io 0x0000-0x003f]269server # [ 1.123702] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]270server # [ 1.123839] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]271server # [ 1.124412] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint272server # [ 1.124884] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]273server # [ 1.124994] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]274server # [ 1.125248] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]275server # [ 1.125743] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint276server # [ 1.126932] pci 0000:00:05.0: BAR 0 [io 0x0000-0x001f]277server # [ 1.127263] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]278server # [ 1.127400] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]279server # [ 1.138285] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint280server # [ 1.138765] pci 0000:00:06.0: BAR 0 [io 0x0000-0x007f]281server # [ 1.139218] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]282server # [ 1.139344] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]283server # [ 1.139927] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint284server # [ 1.140422] pci 0000:00:07.0: BAR 0 [io 0x0000-0x001f]285server # [ 1.140632] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]286server # [ 1.141144] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]287server # [ 1.141506] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]288server # [ 1.142861] pci 0000:00:08.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint289server # [ 1.143097] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]290server # [ 1.143316] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]291server # [ 1.143830] pci 0000:00:09.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint292server # [ 1.144495] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]293server # [ 1.144753] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]294server # [ 1.145676] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint295server # [ 1.146252] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]296server # [ 1.157801] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint297server # [ 1.158539] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]298server # [ 1.158768] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]299server # [ 1.158998] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]300server # [ 1.159819] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint301server # [ 1.160333] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]302server # [ 1.160512] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]303server # [ 1.160854] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]304server # [ 1.162959] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned305server # [ 1.163261] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned306server # [ 1.163461] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned307server # [ 1.163696] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned308server # [ 1.163867] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned309server # [ 1.164121] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned310server # [ 1.164528] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned311server # [ 1.164881] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned312server # [ 1.165134] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned313server # [ 1.165499] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned314server # [ 1.165655] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned315server # [ 1.165801] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned316server # [ 1.166789] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned317server # [ 1.167089] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned318server # [ 1.167220] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned319server # [ 1.167536] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned320server # [ 1.167798] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned321server # [ 1.167926] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned322server # [ 1.168044] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned323server # [ 1.168666] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned324server # [ 1.169427] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned325server # [ 1.169554] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned326server # [ 1.169676] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned327server # [ 1.170039] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned328server # [ 1.170171] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned329server # [ 1.170303] pci 0000:00:06.0: BAR 0 [io 0x1000-0x107f]: assigned330server # [ 1.170742] pci 0000:00:03.0: BAR 0 [io 0x1080-0x10bf]: assigned331server # [ 1.171257] pci 0000:00:0b.0: BAR 0 [io 0x10c0-0x10ff]: assigned332server # [ 1.171376] pci 0000:00:01.0: BAR 0 [io 0x1100-0x111f]: assigned333server # [ 1.171490] pci 0000:00:02.0: BAR 0 [io 0x1120-0x113f]: assigned334server # [ 1.171615] pci 0000:00:04.0: BAR 0 [io 0x1140-0x115f]: assigned335server # [ 1.171738] pci 0000:00:05.0: BAR 0 [io 0x1160-0x117f]: assigned336server # [ 1.171851] pci 0000:00:07.0: BAR 0 [io 0x1180-0x119f]: assigned337server # [ 1.172030] pci 0000:00:0c.0: BAR 0 [io 0x11a0-0x11bf]: assigned338server # [ 1.172350] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]339server # [ 1.172540] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]340server # [ 1.172658] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]341server # [ 1.184318] pci 0000:00:0a.0: enabling device (0000 -> 0002)342server # [ 1.307259] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)343server # [ 1.311153] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)344server # [ 1.313308] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)345server # [ 1.320097] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)346server # [ 1.321905] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)347server # [ 1.327467] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)348server # [ 1.328958] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)349server # [ 1.338222] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)350server # [ 1.339963] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)351server # [ 1.341661] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)352server # [ 1.348011] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)353server # [ 1.380741] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled354server # [ 1.401668] msm_serial: driver initialized355server # [ 1.403375] SuperH (H)SCI(F) driver initialized356server # [ 1.403846] STM32 USART driver initialized357server # [ 1.496011] loop: module loaded358server # [ 1.496576] virtio_blk virtio5: 1/0/0 default/read/poll queues359server # [ 1.499754] virtio_blk virtio5: [vda] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB)360server # [ 1.507332] Freeing initrd memory: 10684K361server # [ 1.519570] megasas: 07.727.03.00-rc1362server # [ 1.524012] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]363server # [ 1.526516] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000364server # [ 1.527369] Intel/Sharp Extended Query Table at 0x0031365server # [ 1.528474] Using buffer write method366server # [ 1.529192] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]367server # [ 1.530666] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000368server # [ 1.530980] Intel/Sharp Extended Query Table at 0x0031369server # [ 1.531892] Using buffer write method370server # [ 1.532205] Concatenating MTD devices:371server # [ 1.532353] (0): "0.flash"372server # [ 1.532523] (1): "0.flash"373server # [ 1.532587] into device "0.flash"374server # [ 1.551944] tun: Universal TUN/TAP device driver, 1.6375server # [ 1.563618] thunder_xcv, ver 1.0376server # [ 1.563846] thunder_bgx, ver 1.0377server # [ 1.564126] nicpf, ver 1.0378server # [ 1.566828] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version379server # [ 1.567062] hns3: Copyright (c) 2017 Huawei Corporation.380server # [ 1.567805] hclge is initializing381server # [ 1.568028] e1000: Intel(R) PRO/1000 Network Driver382server # [ 1.568119] e1000: Copyright (c) 1999-2006 Intel Corporation.383server # [ 1.568317] e1000e: Intel(R) PRO/1000 Network Driver384server # [ 1.568405] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.385server # [ 1.568612] igb: Intel(R) Gigabit Ethernet Network Driver386server # [ 1.568709] igb: Copyright (c) 2007-2014 Intel Corporation.387server # [ 1.568907] igbvf: Intel(R) Gigabit Virtual Function Network Driver388server # [ 1.569119] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.389server # [ 1.569938] sky2: driver version 1.30390server # [ 1.576737] ehci-pci 0000:00:0a.0: EHCI Host Controller391server # [ 1.577461] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1392server # [ 1.581774] usbcore: registered new interface driver usb-storage393server # [ 1.583786] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000394server # [ 1.584291] usbcore: registered new interface driver usbserial_generic395server # [ 1.584893] usbserial: USB Serial support registered for generic396server # [ 1.594062] rtc-pl031 9010000.pl031: registered as rtc0397server # [ 1.594894] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00398server # [ 1.597190] rtc-pl031 9010000.pl031: setting system clock to 2026-10-22T12:31:19 UTC (1792672279)399server # [ 1.600772] i2c_dev: i2c /dev entries driver400server # [ 1.605000] hub 1-0:1.0: USB hub found401server # [ 1.614082] hub 1-0:1.0: 6 ports detected402server # [ 1.620691] sdhci: Secure Digital Host Controller Interface driver403server # [ 1.620840] sdhci: Copyright(c) Pierre Ossman404server # [ 1.622812] Synopsys Designware Multimedia Card Interface Driver405server # [ 1.624609] sdhci-pltfm: SDHCI platform and OF driver helper406server # [ 1.631694] hid: raw HID events driver (C) Jiri Kosina407server # [ 1.634754] usbcore: registered new interface driver usbhid408server # [ 1.634926] usbhid: USB HID core driver409server # [ 1.643026] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available410server # [ 1.655049] drop_monitor: Initializing network drop monitor service411server # [ 1.656386] NET: Registered PF_INET6 protocol family412server # [ 1.666457] Segment Routing with IPv6413server # [ 1.666769] In-situ OAM (IOAM) with IPv6414server # [ 1.668133] NET: Registered PF_PACKET protocol family415server # [ 1.668999] 9pnet: Installing 9P2000 support416server # [ 1.673080] Key type dns_resolver registered417server # [ 1.708840] registered taskstats version 1418server # [ 1.710908] Loading compiled-in X.509 certificates419server # [ 1.768991] Demotion targets for Node 0: null420server # [ 1.770707] Key type .fscrypt registered421server # [ 1.770839] Key type fscrypt-provisioning registered422server # [ 1.778702] input: gpio-keys as /devices/platform/gpio-keys/input/input0423server # [ 1.823789] clk: Disabling unused clocks424server # [ 1.824097] PM: genpd: Disabling unused power domains425server # [ 1.824477] ALSA device list:426server # [ 1.824589] No soundcards found.427server # [ 1.886907] Freeing unused kernel memory: 4416K428server # [ 1.887373] usb 1-1: new high-speed USB device number 2 using ehci-pci429server # [ 1.890606] Run /init as init process430server # [ 2.059841] 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/input1431server # [ 2.163819] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0432server # [ 2.286240] usb 1-2: new high-speed USB device number 3 using ehci-pci433server # [ 2.374747] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev434server # [ 2.480938] 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/input2435server # [ 2.482836] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0436server # [ 2.497703] [drm] pci: virtio-gpu-pci detected at 0000:00:09.0437server # [ 2.498392] [drm] features: -virgl +edid -resource_blob -host_visible438server # [ 2.498417] [drm] features: -context_init439server # [ 2.501085] [drm] number of scanouts: 1440server # [ 2.501216] [drm] number of cap sets: 0441server # [ 2.510453] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:09.0 on minor 0442server # [ 2.542661] Console: switching to colour frame buffer device 160x50443server # [ 2.552952] virtio-pci 0000:00:09.0: [drm] fb0: virtio_gpudrmfb frame buffer device444server # [ 5.859360] EXT4-fs (vda): mounted filesystem 70de2958-0091-4a66-87da-83197d2548e9 r/w with ordered data mode. Quota mode: none.445server # [ 7.814276] EXT4-fs (vda): re-mounted 70de2958-0091-4a66-87da-83197d2548e9.446server # [ 7.830510] booting system configuration /nix/store/w9smhp3bpdz8d9xzpxfq3ya1vpq3zfd8-nixos-system-server-test447server # [ 18.010838] 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 # [ 18.020319] systemd[1]: Detected virtualization qemu.449server # [ 18.024939] systemd[1]: Detected architecture arm64.450server # [ 18.029846] systemd[1]: Detected first boot.451server # [ 18.055434] systemd[1]: Initializing machine ID from random generator.452server # [ 18.084916] systemd[1]: Hostname set to <server>.453server # [ 19.234647] systemd[1]: bpf-restrict-fs: LSM BPF program attached454server # [ 20.793407] systemd[1]: Applying preset policy.455server # [ 23.641464] systemd[1]: Populated /etc with preset unit settings.456server # [ 26.342873] systemd[1]: Queued start job for default target Multi-User System.457server # [ 26.517570] systemd[1]: Created slice Slice /system/getty.458server # [ 26.530957] systemd[1]: Created slice Slice /system/modprobe.459server # [ 26.542632] systemd[1]: Created slice User and Session Slice.460server # [ 26.549578] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.461server # [ 26.555084] systemd[1]: Started Forward Password Requests to Wall Directory Watch.462server # [ 26.559641] systemd[1]: Expecting device /dev/hvc0...463server # [ 26.564311] systemd[1]: Expecting device /dev/ttyAMA0...464server # [ 26.568495] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...465server # [ 26.573031] systemd[1]: Reached target Local Encrypted Volumes.466server # [ 26.577343] systemd[1]: Reached target Virtual Machines and Containers.467server # [ 26.582194] systemd[1]: Reached target Path Units.468server # [ 26.586279] systemd[1]: Reached target Remote File Systems.469server # [ 26.590955] systemd[1]: Reached target Slice Units.470server # [ 26.594763] systemd[1]: Reached target Swaps.471server # [ 26.626024] systemd[1]: Listening on Process Core Dump Socket.472server # [ 26.647551] systemd[1]: Listening on Credential Encryption/Decryption.473server # [ 26.657895] systemd[1]: Listening on Journal Audit Socket.474server # [ 26.664368] systemd[1]: Listening on Journal Socket (/dev/log).475server # [ 26.670405] systemd[1]: Listening on Journal Sockets.476server # [ 26.677908] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.477server # [ 26.683354] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).478server # [ 26.689164] systemd[1]: Listening on udev Control Socket.479server # [ 26.695490] systemd[1]: Listening on udev Kernel Socket.480server # [ 26.741523] systemd[1]: Mounting Huge Pages File System...481server # [ 26.784909] systemd[1]: Mounting POSIX Message Queue File System...482server # [ 26.859612] systemd[1]: Mounting Kernel Debug File System...483server # [ 26.935576] systemd[1]: Mounting Kernel Trace File System...484server # [ 27.076785] systemd[1]: Starting Create List of Static Device Nodes...485server # [ 27.241860] systemd[1]: Starting Load Kernel Module 9pnet_virtio...486server # [ 27.259656] systemd[1]: Load Kernel Module configfs was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!configfs).487server # [ 27.401221] systemd[1]: Mounting Kernel Configuration File System...488server # [ 27.425633] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).489server # [ 27.449822] systemd[1]: Load Kernel Module efi_pstore was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!efi_pstore).490server # [ 27.562258] systemd[1]: Starting Load Kernel Module fuse...491server # [ 27.580192] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).492server # [ 27.603717] 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 # [ 27.701783] systemd[1]: Starting Journal Service...494server # [ 27.784380] systemd[1]: Starting Load Kernel Modules...495server # [ 27.869877] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...496server # [ 27.937754] systemd[1]: Starting Remount Root and Kernel File Systems...497server # [ 27.942937] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).498server # [ 28.018908] systemd[1]: Starting Coldplug All udev Devices...499server # [ 28.096101] systemd[1]: Mounted Huge Pages File System.500server # [ 28.108849] systemd[1]: Mounted POSIX Message Queue File System.501server # [ 28.124032] systemd[1]: Mounted Kernel Debug File System.502server # [ 28.132513] systemd[1]: Mounted Kernel Trace File System.503server # [ 28.144305] systemd[1]: Mounted Kernel Configuration File System.504server # [ 28.211382] systemd[1]: Finished Create List of Static Device Nodes.505server # [ 28.269439] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...506server # [ 29.369375] EXT4-fs (vda): re-mounted 70de2958-0091-4a66-87da-83197d2548e9.507server # [ 29.503471] systemd[1]: Finished Load Kernel Modules.508server # [ 29.583776] systemd[1]: Starting Firewall...509server # [ 29.661920] systemd[1]: Starting Apply Kernel Variables...510server: Guest root shell did not produce any data yet...511server: To debug, enter the VM and run 'systemctl status backdoor.service'.512server # [ 29.684170] systemd[1]: Finished Remount Root and Kernel File Systems.513server # [ 29.695961] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).514server # [ 29.766210] systemd[1]: Starting Load/Save OS Random Seed...515server # [ 29.772240] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).516server # [ 29.790385] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.517server # [ 29.809137] systemd[1]: Finished Load Kernel Module 9pnet_virtio.518server # [ 30.292137] fuse: init (API version 7.41)519server # [ 30.382119] systemd[1]: modprobe@fuse.service: Deactivated successfully.520server # [ 30.388834] systemd-journald[374]: Collecting audit messages is enabled.521server # [ 30.402977] systemd[1]: Finished Load Kernel Module fuse.522server # [ 30.458601] systemd[1]: Mounting FUSE Control File System...523server # [ 30.715008] systemd[1]: Mounted FUSE Control File System.524server # [ 31.255569] systemd[1]: Finished Load/Save OS Random Seed.525server # [ 31.264173] systemd[1]: Reached target First Boot Complete.526server # [ 31.664546] systemd[1]: Finished Apply Kernel Variables.527server # [ 31.752489] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.528server # [ 31.841282] systemd[1]: Starting Create Static Device Nodes in /dev...529server # [ 32.515288] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.530server # [ 33.356183] systemd[1]: Finished Create Static Device Nodes in /dev.531server # [ 33.381802] systemd[1]: Reached target Preparation for Local File Systems.532server # [ 33.447496] systemd[1]: Mounting /run/wrappers...533server # [ 33.512974] systemd[1]: Starting Rule-based Manager for Device Events and Files...534server # [ 34.048939] systemd[1]: Mounted /run/wrappers.535server # [ 34.060431] systemd[1]: Reached target Local File Systems.536server # [ 34.099155] systemd[1]: Listening on Boot Entries Service Socket.537server # [ 34.153625] systemd[1]: Starting Create SUID/SGID Wrappers...538server # [ 34.164986] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.539server # [ 34.224052] systemd[1]: Starting Save Transient machine-id to Disk...540server # [ 34.364354] systemd[1]: Started Journal Service.541server # [ 34.219922] systemd-modules-load[375]: Module 'atkbd' is built in542server # [ 34.267051] systemd-modules-load[375]: Module 'loop' is built in543server # [ 34.340084] systemd-oomd[376]: No swap; memory pressure usage will be degraded544server # [ 34.387928] systemd[1]: Starting Flush Journal to Persistent Storage...545server # [ 35.323100] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.546server # [ 35.428259] systemd[1]: Finished Save Transient machine-id to Disk.547server # [ 35.655755] systemd-journald[374]: Received client request to flush runtime journal.548server # [ 36.085420] systemd-udevd[404]: Using default interface naming scheme 'v258'.549server # [ 36.139274] systemd[1]: Finished Flush Journal to Persistent Storage.550server # [ 36.194094] systemd[1]: Starting Create System Files and Directories...551server # [ 38.855045] systemd[1]: Finished Create System Files and Directories.552server # [ 38.946913] systemd[1]: Starting Rebuild Journal Catalog...553server # [ 38.999210] systemd[1]: Starting Record System Boot/Shutdown in UTMP...554server # [ 39.772566] systemd[1]: Started Rule-based Manager for Device Events and Files.555server # [ 40.048295] systemd[1]: Finished Record System Boot/Shutdown in UTMP.556server # [ 41.269870] systemd[1]: Finished Rebuild Journal Catalog.557server # [ 41.284697] systemd[1]: Starting Update is Completed...558server # [ 42.000224] systemd[1]: Finished Update is Completed.559server # [ 45.044367] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.560server # [ 45.064306] systemd[1]: Finished Create SUID/SGID Wrappers.561server # [ 45.074953] systemd[1]: suid-sgid-wrappers.service: Consumed 1.632s CPU time, 5.5M memory peak.562server # [ 47.188182] systemd[1]: Finished Firewall.563server # [ 50.323352] systemd[1]: Finished Coldplug All udev Devices.564server # [ 50.339496] systemd[1]: Reached target System Initialization.565server # [ 50.347798] systemd[1]: Started Discard unused filesystem blocks once a week.566server # [ 50.368205] systemd[1]: Started Daily Cleanup of Temporary Directories.567server # [ 50.370708] systemd[1]: Reached target Timer Units.568server # [ 50.372098] systemd[1]: Listening on D-Bus System Message Bus Socket.569server # [ 50.383104] systemd[1]: Listening on Nix Daemon Socket.570server # [ 50.390367] systemd[1]: Listening on Hostname Service Socket.571server # [ 50.405231] systemd[1]: Reached target Socket Units.572server # [ 50.432034] systemd[1]: Reached target Basic System.573server # [ 50.451122] systemd[1]: Starting Import lastlog data into lastlog2 database...574server # [ 50.482788] systemd[1]: Starting Name Service Cache Daemon (nsncd)...575server # [ 50.515810] systemd[1]: Starting postgresql.service...576server # [ 50.563347] systemd[1]: Started Reset console on configuration changes.577server # [ 50.618334] systemd[1]: Starting resolvconf update...578server # [ 50.699484] systemd[1]: Starting D-Bus System Message Bus...579server # [ 52.324881] systemd[1]: Finished Import lastlog data into lastlog2 database.580server # [ 52.615676] runuser[619]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)581server # [ 52.804246] systemd[1]: Started Name Service Cache Daemon (nsncd).582server # [ 52.837753] systemd[1]: Reached target Host and Network Name Lookups.583server # [ 52.838999] systemd[1]: Reached target User and Group Name Lookups.584server # [ 52.889492] nsncd[608]: Oct 22 12:32:10.860 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"585server # [ 52.926378] systemd[1]: Starting User Login Management...586server # [ 53.446400] dbus-daemon[612]: dbus[612]: Unknown username "systemd-timesync" in message bus configuration file587server # [ 54.262622] systemd[1]: Started D-Bus System Message Bus.588server # [ 55.137603] systemd[1]: Stopped target Host and Network Name Lookups.589server # [ 55.148559] systemd[1]: Stopping Host and Network Name Lookups...590server # [ 55.182129] systemd[1]: Stopped target User and Group Name Lookups.591server # [ 55.204276] systemd[1]: Stopping User and Group Name Lookups...592server # [ 55.227103] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...593server # [ 55.255458] systemd[1]: nscd.service: Deactivated successfully.594server # [ 55.302015] systemd[1]: Stopped Name Service Cache Daemon (nsncd).595server # [ 55.387432] systemd[1]: Starting Name Service Cache Daemon (nsncd)...596server # [ 55.920899] systemd-logind[626]: New seat seat0.597server # [ 56.008155] systemd[1]: Started User Login Management.598server # [ 56.053037] systemd[1]: Starting linger-users.service...599server # [ 56.416308] init-old[623]: The files belonging to this database system will be owned by user "postgres".600server # [ 56.457577] init-old[623]: This user must also own the server process.601server # [ 56.524205] systemd[1]: Started Name Service Cache Daemon (nsncd).602server # [ 56.536002] nsncd[672]: Oct 22 12:32:14.561 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"603server # [ 56.585023] systemd[1]: Reached target Host and Network Name Lookups.604server # [ 56.616480] systemd[1]: Reached target User and Group Name Lookups.605server # [ 56.665518] init-old[623]: The database cluster will be initialized with locale "C".606server # [ 56.673565] init-old[623]: The default text search configuration will be set to "english".607server # [ 56.678346] init-old[623]: Data page checksums are disabled.608server # [ 56.687944] init-old[623]: fixing permissions on existing directory /var/lib/postgresql/data ... ok609server # [ 56.693330] init-old[623]: creating subdirectories ... ok610server # [ 56.715846] init-old[623]: selecting dynamic shared memory implementation ... posix611server # [ 56.911599] systemd[1]: linger-users.service: Deactivated successfully.612server # [ 56.930407] systemd[1]: Finished linger-users.service.613server # [ 57.345092] systemd[1]: Finished resolvconf update.614server # [ 57.353854] systemd[1]: Reached target Preparation for Network.615server # [ 57.417856] systemd[1]: Starting DHCP Client...616server # [ 58.328449] init-old[623]: selecting default max_connections ... 100617server # [ 59.247631] init-old[623]: selecting default shared_buffers ... 128MB618server: Guest root shell did not produce any data yet...619server: To debug, enter the VM and run 'systemctl status backdoor.service'.620server # [ 60.176160] dhcpcd[711]: dhcpcd-10.2.4 starting621server # [ 60.376914] dhcpcd[727]: dev: loaded udev622server # [ 60.928880] 8021q: 802.1Q VLAN Support v1.8623server # [ 61.488570] cfg80211: Loading compiled-in X.509 certificates for regulatory database624server # [ 61.730463] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'625server # [ 61.741075] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'626server # [ 61.777398] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2627server # [ 61.788213] cfg80211: failed to load regulatory.db628server # [ 62.843454] 8021q: adding VLAN 0 to HW filter on device eth0629server # [ 62.659803] dhcpcd[727]: eth0: waiting for carrier630server # [ 62.678703] dhcpcd[727]: eth0: carrier acquired631server # [ 62.841045] dhcpcd[727]: DUID 00:01:00:01:32:6c:be:d4:52:54:00:12:34:56632server # [ 62.849500] dhcpcd[727]: eth0: IAID 00:12:34:56633server # [ 62.850533] dhcpcd[727]: eth0: adding address fe80::5054:ff:fe12:3456634server # [ 63.302563] dhcpcd[727]: eth0: soliciting a DHCP lease635server # [ 63.350212] dhcpcd[727]: eth0: offered 10.0.2.15 from 10.0.2.2636server # [ 63.368031] dhcpcd[727]: eth0: probing address 10.0.2.15/24637server # [ 65.083479] dhcpcd[727]: eth0: soliciting an IPv6 router638server # [ 65.109630] dhcpcd[727]: eth0: Router Advertisement from fe80::2639server # [ 65.124005] dhcpcd[727]: eth0: adding address fec0::5054:ff:fe12:3456/64640server # [ 65.139704] dhcpcd[727]: eth0: adding route to fec0::/64641server # [ 65.157362] dhcpcd[727]: eth0: adding default route via fe80::2642server # [ 68.039749] dhcpcd[727]: eth0: leased 10.0.2.15 for 86400 seconds643server # [ 68.052460] dhcpcd[727]: eth0: adding route to 10.0.2.0/24644server # [ 68.066257] dhcpcd[727]: eth0: adding default route via 10.0.2.2645server # [ 69.339798] init-old[623]: selecting default time zone ... UTC646server # [ 69.405069] init-old[623]: creating configuration files ... ok647server # [ 71.066726] systemd[1]: Started DHCP Client.648server # [ 74.803126] systemd[1]: Found device /dev/hvc0.649server # [ 74.874907] init-old[623]: running bootstrap script ... ok650server # [ 77.962398] systemd[1]: Found device /dev/ttyAMA0.651server # [ 77.990702] systemd[1]: Started backdoor.service.652server # connecting to host...653server: Guest shell says: b'Spawning backdoor root shell...\n'654server: connected to guest root shell655server: (connecting took 79.53 seconds)656server: (finished: waiting for the VM to finish booting, in 79.53 seconds)657server # [ 79.312385] (udev-worker)[875]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.658server # [ 79.351671] (udev-worker)[879]: Network interface NamePolicy= disabled on kernel command line.659server # [ 79.366197] (udev-worker)[875]: Network interface NamePolicy= disabled on kernel command line.660server # [ 80.859897] systemd[1]: Found device Virtio network device.661server # [ 80.924766] systemd[1]: Starting Address configuration of eth1...662server # [ 80.990948] dhcpcd[727]: eth0: IAID 00:12:34:56663server # [ 81.151571] dhcpcd[727]: eth0: soliciting an IPv6 router664server # [ 82.827493] 8021q: adding VLAN 0 to HW filter on device eth1665server # [ 82.670235] dhcpcd[727]: eth0: rebinding lease of 10.0.2.15666server # [ 82.685628] dhcpcd[727]: eth0: leased 10.0.2.15 for 86400 seconds667server # [ 83.078081] network-addresses-eth1-start[902]: adding address 192.168.1.1/24... done668server # [ 83.405308] network-addresses-eth1-start[902]: adding address 2001:db8:1::1/64... done669server # [ 83.717050] systemd[1]: Finished Address configuration of eth1.670server # [ 83.790450] systemd[1]: Starting Networking Setup...671server # [ 87.170838] systemd[1]: Finished Networking Setup.672server # [ 87.171912] systemd[1]: Reached target Network.673server # [ 87.222735] systemd[1]: Starting Permit User Sessions...674server # [ 87.890667] systemd[1]: Finished Permit User Sessions.675server # [ 87.977569] systemd[1]: Started Getty on tty1.676server # [ 87.978829] systemd[1]: Reached target Login Prompts.677server # [ 96.958163] systemd-logind[626]: Watching system buttons on /dev/input/event0 (gpio-keys)678server # [ 97.002821] init-old[623]: performing post-bootstrap initialization ... ok679server # [ 100.947609] init-old[623]: syncing data to disk ... ok680server # [ 100.969738] init-old[623]: initdb: warning: enabling "trust" authentication for local connections681server # [ 100.970577] init-old[623]: 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.682server # [ 100.971710] init-old[623]: Success. You can now start the database server using:683server # [ 100.990555] init-old[623]: /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl -D /var/lib/postgresql/data -l logfile start684server # [ 101.025321] runuser[619]: pam_unix(runuser:session): session closed for user postgres685server # [ 102.167021] postgres[1085]: 2026-10-22 12:33:00.256 UTC [1085] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit686server # [ 102.266834] postgres[1085]: 2026-10-22 12:33:00.364 UTC [1085] LOG: listening on IPv6 address "::1", port 5432687server # [ 102.267944] postgres[1085]: 2026-10-22 12:33:00.367 UTC [1085] LOG: listening on IPv4 address "127.0.0.1", port 5432688server # [ 102.288940] postgres[1085]: 2026-10-22 12:33:00.388 UTC [1085] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"689server # [ 102.440236] postgres[1096]: 2026-10-22 12:33:00.535 UTC [1096] LOG: database system was shut down at 2026-10-22 12:32:54 UTC690server # [ 102.603050] postgres[1085]: 2026-10-22 12:33:00.691 UTC [1085] LOG: database system is ready to accept connections691server # [ 102.643625] systemd[1]: Started postgresql.service.692server # [ 102.672038] systemd[1]: Reached target Multi-User System.693server # [ 102.673820] systemd[1]: Startup finished in 17.321s (kernel) + 1min 25.329s (userspace) = 1min 42.650s.694server: (finished: waiting for unit postgresql.service, in 103.61 seconds)695subtest: Seed the source cluster696server: must succeed: /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-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"697server # [ 106.603091] mousedev: PS/2 mouse device common for all mice698server # [ 109.178466] systemd-logind[626]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)699server: (finished: must succeed: /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-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 12.51 seconds)700server: must succeed: /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-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"701server: (finished: must succeed: /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-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.90 seconds)702(finished: subtest: Seed the source cluster, in 14.40 seconds)703subtest: Control: with no guard the start loop brings the source up704server: must succeed: systemctl stop postgresql705server # [ 117.855243] postgres[1085]: 2026-10-22 12:33:15.951 UTC [1085] LOG: received fast shutdown request706server # [ 117.911649] systemd[1]: Stopping postgresql.service...707server # [ 117.925238] postgres[1085]: 2026-10-22 12:33:15.978 UTC [1085] LOG: aborting any active transactions708server # [ 118.089051] postgres[1085]: 2026-10-22 12:33:16.188 UTC [1085] LOG: background worker "logical replication launcher" (PID 1102) exited with exit code 1709server # [ 118.112075] postgres[1094]: 2026-10-22 12:33:16.196 UTC [1094] LOG: shutting down710server # [ 118.125264] postgres[1094]: 2026-10-22 12:33:16.223 UTC [1094] LOG: checkpoint starting: shutdown immediate711server # [ 118.915274] postgres[1094]: 2026-10-22 12:33:17.015 UTC [1094] LOG: checkpoint complete: wrote 2176 buffers (13.3%); 0 WAL file(s) added, 0 removed, 4 recycled; write=0.423 s, sync=0.260 s, total=0.819 s; sync files=28, longest=0.204 s, average=0.010 s; distance=69073 kB, estimate=69073 kB712server # [ 119.047727] postgres[1085]: 2026-10-22 12:33:17.135 UTC [1085] LOG: database system is shut down713server # [ 119.106214] systemd[1]: postgresql.service: Deactivated successfully.714server # [ 119.123249] systemd[1]: Stopped postgresql.service.715server # [ 119.141799] systemd[1]: postgresql.service: Consumed 19.490s CPU time, 232.9M memory peak, 241.9M written to disk, 1.2K incoming IP traffic, 1.7K outgoing IP traffic.716server: (finished: must succeed: systemctl stop postgresql, in 1.76 seconds)717server: must succeed: systemd-run --unit=salt-sim --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim718server # [ 119.853383] systemd[1]: Started [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim.719server # Running as unit: salt-sim.service; invocation ID: a064162cc3574576ac35798669a25774720server: (finished: must succeed: systemd-run --unit=salt-sim --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim, in 0.79 seconds)721server: waiting for success: systemctl is-active --quiet postgresql722server # [ 120.720007] systemd[1]: Starting postgresql.service...723server # [ 121.971708] postgres[1223]: 2026-10-22 12:33:20.057 UTC [1223] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit724server # [ 121.985301] postgres[1223]: 2026-10-22 12:33:20.085 UTC [1223] LOG: listening on IPv6 address "::1", port 5432725server # [ 121.995662] postgres[1223]: 2026-10-22 12:33:20.088 UTC [1223] LOG: listening on IPv4 address "127.0.0.1", port 5432726server # [ 122.009777] postgres[1223]: 2026-10-22 12:33:20.104 UTC [1223] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"727server # [ 122.144013] postgres[1234]: 2026-10-22 12:33:20.228 UTC [1234] LOG: database system was shut down at 2026-10-22 12:33:16 UTC728server # [ 122.332732] postgres[1223]: 2026-10-22 12:33:20.431 UTC [1223] LOG: database system is ready to accept connections729server # [ 122.374585] systemd[1]: Started postgresql.service.730server: (finished: waiting for success: systemctl is-active --quiet postgresql, in 2.92 seconds)731server: must succeed: systemctl stop salt-sim732server # [ 123.756196] systemd[1]: Stopping [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim...733server # [ 123.818022] systemd[1]: salt-sim.service: Deactivated successfully.734server # [ 123.834934] systemd[1]: Stopped [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim.735server: (finished: must succeed: systemctl stop salt-sim, in 1.02 seconds)736(finished: subtest: Control: with no guard the start loop brings the source up, in 6.50 seconds)737subtest: A systemd start is refused while the block is held738server: must succeed: systemd-run --unit=hold-block --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_block739server # [ 124.434507] systemd[1]: Started [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_block.740server # Running as unit: hold-block.service; invocation ID: 06193e285f1244a7ba832302427ef031741server: (finished: must succeed: systemd-run --unit=hold-block --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_block, in 0.58 seconds)742server: waiting for success: systemctl show -p ExecCondition postgresql | grep -q start-guard743server # [ 125.151743] systemd[1]: Stopping postgresql.service...744server # [ 125.222330] postgres[1223]: 2026-10-22 12:33:23.245 UTC [1223] LOG: received fast shutdown request745server # [ 125.223596] postgres[1223]: 2026-10-22 12:33:23.274 UTC [1223] LOG: aborting any active transactions746server # [ 125.340965] postgres[1223]: 2026-10-22 12:33:23.441 UTC [1223] LOG: background worker "logical replication launcher" (PID 1239) exited with exit code 1747server # [ 125.361705] postgres[1232]: 2026-10-22 12:33:23.455 UTC [1232] LOG: shutting down748server # [ 125.377558] postgres[1232]: 2026-10-22 12:33:23.475 UTC [1232] LOG: checkpoint starting: shutdown immediate749server # [ 125.491427] postgres[1232]: 2026-10-22 12:33:23.588 UTC [1232] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.023 s, sync=0.025 s, total=0.132 s; sync files=2, longest=0.018 s, average=0.012 s; distance=0 kB, estimate=0 kB750server # [ 125.615865] postgres[1223]: 2026-10-22 12:33:23.712 UTC [1223] LOG: database system is shut down751server # [ 125.700909] systemd[1]: postgresql.service: Deactivated successfully.752server # [ 125.720639] systemd[1]: Stopped postgresql.service.753server # [ 126.188063] systemd[1]: Reload requested from client PID 1282 ('systemctl') (unit hold-block.service)...754server # [ 126.196146] systemd[1]: Reloading...755server # [ 131.744126] systemd[1]: Reloading finished in 5536 ms.756server: (finished: waiting for success: systemctl show -p ExecCondition postgresql | grep -q start-guard, in 7.90 seconds)757server: must fail: systemctl start postgresql758server # [ 133.069455] systemd[1]: Starting postgresql.service...759server # [ 133.641134] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION760server # [ 133.647803] systemd[1]: postgresql.service: Failed with result 'exit-code'.761server # [ 133.669740] systemd[1]: Failed to start postgresql.service.762server # Job for postgresql.service failed because the control process exited with error code.763server # See "systemctl status postgresql.service" and "journalctl -xeu postgresql.service" for details.764server: (finished: must fail: systemctl start postgresql, in 1.36 seconds)765server: must succeed: sleep 5766server: (finished: must succeed: sleep 5, in 5.48 seconds)767server: must fail: systemctl is-active --quiet postgresql768server: (finished: must fail: systemctl is-active --quiet postgresql, in 0.53 seconds)769server: must succeed: systemctl show -p Restart postgresql770server: (finished: must succeed: systemctl show -p Restart postgresql, in 0.52 seconds)771(finished: subtest: A systemd start is refused while the block is held, in 16.37 seconds)772subtest: The block expires on its own when the holder is SIGKILLed773server: must succeed: systemctl kill -s KILL hold-block774server # [ 140.742892] systemd[1]: hold-block.service: Sent signal SIGKILL to main process 1263 (sleep) on client request.775server # [ 140.766509] systemd[1]: hold-block.service: Killed unit cgroup '/system.slice/hold-block.service' with SIGKILL on client request.776server # [ 140.786210] systemd[1]: hold-block.service: Main process exited, code=killed, status=9/KILL777server # [ 140.806232] systemd[1]: hold-block.service: Failed with result 'signal'.778server: (finished: must succeed: systemctl kill -s KILL hold-block, in 0.51 seconds)779server: waiting for failure: systemctl is-active --quiet hold-block780server: (finished: waiting for failure: systemctl is-active --quiet hold-block, in 0.50 seconds)781server: must succeed: systemctl start postgresql782server # [ 141.783142] systemd[1]: Starting postgresql.service...783server # [ 143.743919] postgres[1398]: 2026-10-22 12:33:41.835 UTC [1398] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit784server # [ 143.766944] postgres[1398]: 2026-10-22 12:33:41.866 UTC [1398] LOG: listening on IPv6 address "::1", port 5432785server # [ 143.767889] postgres[1398]: 2026-10-22 12:33:41.866 UTC [1398] LOG: listening on IPv4 address "127.0.0.1", port 5432786server # [ 143.784151] postgres[1398]: 2026-10-22 12:33:41.881 UTC [1398] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"787server # [ 143.878591] postgres[1415]: 2026-10-22 12:33:41.968 UTC [1415] LOG: database system was shut down at 2026-10-22 12:33:23 UTC788server # [ 143.985809] postgres[1398]: 2026-10-22 12:33:42.079 UTC [1398] LOG: database system is ready to accept connections789server # [ 144.710697] systemd[1]: Reload requested from client PID 1422 ('systemctl') (unit postgresql.service)...790server # [ 144.718976] systemd[1]: Reloading...791server # [ 150.453837] systemd[1]: Reloading finished in 5719 ms.792server # [ 150.765912] systemd[1]: Started postgresql.service.793server: (finished: must succeed: systemctl start postgresql, in 9.56 seconds)794server: waiting for unit postgresql.service795server: (finished: waiting for unit postgresql.service, in 0.85 seconds)796server: must fail: test -e /run/systemd/system/postgresql.service.d/pg-upgrade-lock.conf797server: (finished: must fail: test -e /run/systemd/system/postgresql.service.d/pg-upgrade-lock.conf, in 0.29 seconds)798server: must succeed: systemctl show -p Restart postgresql799server: (finished: must succeed: systemctl show -p Restart postgresql, in 0.61 seconds)800server: must succeed: systemctl show -p NeedDaemonReload postgresql801server: (finished: must succeed: systemctl show -p NeedDaemonReload postgresql, in 0.51 seconds)802(finished: subtest: The block expires on its own when the holder is SIGKILLed, in 12.82 seconds)803subtest: The pid lock stops a direct start once the new cluster is up804server: must succeed: systemctl stop postgresql805server # [ 153.547522] postgres[1398]: 2026-10-22 12:33:51.638 UTC [1398] LOG: received fast shutdown request806server # [ 153.576678] systemd[1]: Stopping postgresql.service...807server # [ 153.606928] postgres[1398]: 2026-10-22 12:33:51.657 UTC [1398] LOG: aborting any active transactions808server # [ 153.735452] postgres[1398]: 2026-10-22 12:33:51.835 UTC [1398] LOG: background worker "logical replication launcher" (PID 1419) exited with exit code 1809server # [ 153.763085] postgres[1412]: 2026-10-22 12:33:51.842 UTC [1412] LOG: shutting down810server # [ 153.772856] postgres[1412]: 2026-10-22 12:33:51.856 UTC [1412] LOG: checkpoint starting: shutdown immediate811server # [ 153.843762] postgres[1412]: 2026-10-22 12:33:51.944 UTC [1412] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.021 s, sync=0.010 s, total=0.102 s; sync files=2, longest=0.007 s, average=0.005 s; distance=0 kB, estimate=0 kB812server # [ 153.911730] postgres[1398]: 2026-10-22 12:33:52.012 UTC [1398] LOG: database system is shut down813server # [ 153.971487] systemd[1]: postgresql.service: Deactivated successfully.814server # [ 153.983170] systemd[1]: Stopped postgresql.service.815server: (finished: must succeed: systemctl stop postgresql, in 0.93 seconds)816server: must succeed: systemd-run --unit=hold-lock --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_lock817server # [ 154.572290] systemd[1]: Started [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_lock.818server # Running as unit: hold-lock.service; invocation ID: 4d12c4a4238945348a9a639491021b6c819server: (finished: must succeed: systemd-run --unit=hold-lock --collect /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive hold_lock, in 0.64 seconds)820server: waiting for success: test -s /var/lib/postgresql/data/postmaster.pid821server # [ 155.654853] runuser[1495]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)822server # [ 157.074938] drive[1496]: [12:33:55] Locked /var/lib/postgresql/data with pg_upgrade pid 1499823server: (finished: waiting for success: test -s /var/lib/postgresql/data/postmaster.pid, in 3.55 seconds)824server: must fail: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log -t 5825server # [ 158.785314] runuser[1533]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)826server # pg_ctl: another server might be running; trying to start server anyway827server # [ 160.023926] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:08.0/virtio7/input/input3828server # pg_ctl: could not start server829server # Examine the log output.830server # [ 159.939070] runuser[1533]: pam_unix(runuser:session): session closed for user postgres831server: (finished: must fail: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-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.71 seconds)832server: must succeed: systemctl kill -s KILL hold-lock833server # [ 160.375003] systemd[1]: hold-lock.service: Sent signal SIGKILL to main process 1489 (drive) on client request.834server # [ 160.392298] systemd[1]: hold-lock.service: Killed unit cgroup '/system.slice/hold-lock.service' with SIGKILL on client request.835server # [ 160.447849] systemd[1]: hold-lock.service: Main process exited, code=killed, status=9/KILL836server: (finished: must succeed: systemctl kill -s KILL hold-lock, in 0.51 seconds)837server: waiting for failure: systemctl is-active --quiet hold-lock838server # [ 160.491066] systemd[1]: hold-lock.service: Failed with result 'signal'.839server: (finished: waiting for failure: systemctl is-active --quiet hold-lock, in 0.55 seconds)840server: must succeed: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log 841server # [ 161.439529] runuser[1563]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)842server # pg_ctl: another server might be running; trying to start server anyway843server # [ 163.050984] runuser[1563]: pam_unix(runuser:session): session closed for user postgres844server: (finished: must succeed: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl start -D /var/lib/postgresql/data -w -s -l /tmp/pg_ctl.log , in 2.05 seconds)845server: must succeed: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl stop -D /var/lib/postgresql/data -w -s 846server # [ 163.434839] runuser[1581]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)847server # [ 163.808374] runuser[1581]: pam_unix(runuser:session): session closed for user postgres848server: (finished: must succeed: runuser -u postgres -- /nix/store/jk4km6vsq6dg3cx4c21nfva5s1dr9w1r-postgresql-and-plugins-15.19/bin/pg_ctl stop -D /var/lib/postgresql/data -w -s , in 0.76 seconds)849server: must succeed: rm -f /run/pg-upgrade-source.pid850server: (finished: must succeed: rm -f /run/pg-upgrade-source.pid, in 0.33 seconds)851server: must succeed: systemctl start postgresql852server # [ 164.647583] systemd[1]: Starting postgresql.service...853server # [ 165.959720] postgres[1604]: 2026-10-22 12:34:04.051 UTC [1604] LOG: starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit854server # [ 165.977941] postgres[1604]: 2026-10-22 12:34:04.078 UTC [1604] LOG: listening on IPv6 address "::1", port 5432855server # [ 165.981458] postgres[1604]: 2026-10-22 12:34:04.080 UTC [1604] LOG: listening on IPv4 address "127.0.0.1", port 5432856server # [ 165.995998] postgres[1604]: 2026-10-22 12:34:04.094 UTC [1604] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"857server # [ 166.068905] postgres[1613]: 2026-10-22 12:34:04.167 UTC [1613] LOG: database system was shut down at 2026-10-22 12:34:01 UTC858server # [ 166.162775] postgres[1604]: 2026-10-22 12:34:04.263 UTC [1604] LOG: database system is ready to accept connections859server # [ 166.211344] systemd[1]: Started postgresql.service.860server: (finished: must succeed: systemctl start postgresql, in 2.10 seconds)861server: waiting for unit postgresql.service862server: (finished: waiting for unit postgresql.service, in 0.57 seconds)863(finished: subtest: The pid lock stops a direct start once the new cluster is up, in 13.69 seconds)864subtest: A real pg_upgrade copy under a start storm865server: must succeed: systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive upgrade866server # [ 167.338392] systemd[1]: Started [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive upgrade.867server # Running as unit: fake-initiate.service; invocation ID: ea4313e297c445d7acad8bfc562b9fd2868server # [ 167.945231] systemd[1]: Stopping postgresql.service...869server # [ 167.974322] postgres[1604]: 2026-10-22 12:34:06.040 UTC [1604] LOG: received fast shutdown request870server # [ 167.975383] postgres[1604]: 2026-10-22 12:34:06.063 UTC [1604] LOG: aborting any active transactions871server # [ 168.085795] postgres[1604]: 2026-10-22 12:34:06.181 UTC [1604] LOG: background worker "logical replication launcher" (PID 1619) exited with exit code 1872server # [ 168.105552] postgres[1610]: 2026-10-22 12:34:06.195 UTC [1610] LOG: shutting down873server # [ 168.116873] postgres[1610]: 2026-10-22 12:34:06.215 UTC [1610] LOG: checkpoint starting: shutdown immediate874server # [ 168.205209] postgres[1610]: 2026-10-22 12:34:06.303 UTC [1610] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.021 s, sync=0.008 s, total=0.108 s; sync files=2, longest=0.005 s, average=0.004 s; distance=0 kB, estimate=0 kB875server # [ 168.277867] postgres[1604]: 2026-10-22 12:34:06.376 UTC [1604] LOG: database system is shut down876server # [ 168.346871] systemd[1]: postgresql.service: Deactivated successfully.877server # [ 168.355440] systemd[1]: Stopped postgresql.service.878server # [ 168.784018] systemd[1]: Reload requested from client PID 1642 ('systemctl') (unit fake-initiate.service)...879server # [ 168.795096] systemd[1]: Reloading...880server # [ 174.648219] systemd[1]: Reloading finished in 5846 ms.881server # [ 175.211458] runuser[1687]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)882server # [ 190.074710] systemd[1]: Starting Virtual Console Setup...883server # [ 190.389394] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.884server # [ 190.390441] systemd[1]: Stopped Virtual Console Setup.885server # [ 190.453723] systemd[1]: Starting Virtual Console Setup...886server # [ 195.705548] systemd[1]: Finished Virtual Console Setup.887server # [ 196.436551] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.888server # [ 199.283524] systemd-logind[626]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)889server # initdb: warning: enabling "trust" authentication for local connections890server # 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.891server # [ 205.295934] runuser[1687]: pam_unix(runuser:session): session closed for user postgres892server # [ 205.520563] systemd[1]: Started [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim.893server # Running as unit: salt-sim.service; invocation ID: 0b735d5a40ad49078c20ad436c112030894server # [ 205.863581] runuser[1801]: pam_unix(runuser:session): session opened for user postgres(uid=997) by (uid=0)895server # [ 206.134038] systemd[1]: Starting postgresql.service...896server # [ 206.672337] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION897server # [ 206.713196] systemd[1]: postgresql.service: Failed with result 'exit-code'.898server # [ 206.714519] systemd[1]: Failed to start postgresql.service.899server # [ 207.433290] systemd[1]: Starting postgresql.service...900server # [ 207.969455] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION901server # [ 207.970588] systemd[1]: postgresql.service: Failed with result 'exit-code'.902server # [ 207.971111] systemd[1]: Failed to start postgresql.service.903server # [ 208.698904] systemd[1]: Starting postgresql.service...904server # [ 209.219114] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION905server # [ 209.251495] systemd[1]: postgresql.service: Failed with result 'exit-code'.906server # [ 209.258168] systemd[1]: Failed to start postgresql.service.907server # [ 210.005121] systemd[1]: Starting postgresql.service...908server # [ 210.511739] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION909server # [ 210.534433] systemd[1]: postgresql.service: Failed with result 'exit-code'.910server # [ 210.536003] systemd[1]: Failed to start postgresql.service.911server # [ 211.266897] systemd[1]: Starting postgresql.service...912server # [ 211.811419] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION913server # [ 211.839161] systemd[1]: postgresql.service: Failed with result 'exit-code'.914server # [ 211.840261] systemd[1]: Failed to start postgresql.service.915server # [ 212.513716] systemd[1]: postgresql.service: Start request repeated too quickly.916server # [ 212.515733] systemd[1]: postgresql.service: Failed with result 'exit-code'.917server # [ 212.541760] systemd[1]: Failed to start postgresql.service.918server # [ 213.234983] systemd[1]: postgresql.service: Start request repeated too quickly.919server # [ 213.257972] systemd[1]: postgresql.service: Failed with result 'exit-code'.920server # [ 213.258734] systemd[1]: Failed to start postgresql.service.921server # [ 213.941904] systemd[1]: postgresql.service: Start request repeated too quickly.922server # [ 213.947981] systemd[1]: postgresql.service: Failed with result 'exit-code'.923server # [ 213.971732] systemd[1]: Failed to start postgresql.service.924server # [ 214.605136] systemd[1]: postgresql.service: Start request repeated too quickly.925server # [ 214.619774] systemd[1]: postgresql.service: Failed with result 'exit-code'.926server # [ 214.620629] systemd[1]: Failed to start postgresql.service.927server # [ 215.259259] systemd[1]: postgresql.service: Start request repeated too quickly.928server # [ 215.262940] systemd[1]: postgresql.service: Failed with result 'exit-code'.929server # [ 215.263760] systemd[1]: Failed to start postgresql.service.930server # [ 215.885584] systemd[1]: postgresql.service: Start request repeated too quickly.931server # [ 215.906629] systemd[1]: postgresql.service: Failed with result 'exit-code'.932server # [ 215.907463] systemd[1]: Failed to start postgresql.service.933server # [ 216.557275] systemd[1]: Starting postgresql.service...934server # [ 216.991331] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION935server # [ 217.014036] systemd[1]: postgresql.service: Failed with result 'exit-code'.936server # [ 217.014992] systemd[1]: Failed to start postgresql.service.937server # [ 217.634700] systemd[1]: Starting postgresql.service...938server # [ 218.071288] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION939server # [ 218.109404] systemd[1]: postgresql.service: Failed with result 'exit-code'.940server # [ 218.110380] systemd[1]: Failed to start postgresql.service.941server # [ 218.705102] systemd[1]: Starting postgresql.service...942server # [ 219.179196] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION943server # [ 219.210882] systemd[1]: postgresql.service: Failed with result 'exit-code'.944server # [ 219.212227] systemd[1]: Failed to start postgresql.service.945server # [ 219.849327] systemd[1]: Starting postgresql.service...946server # [ 220.296455] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION947server # [ 220.315920] systemd[1]: postgresql.service: Failed with result 'exit-code'.948server # [ 220.329345] systemd[1]: Failed to start postgresql.service.949server # [ 221.013970] systemd[1]: Starting postgresql.service...950server # [ 221.495767] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION951server # [ 221.521997] systemd[1]: postgresql.service: Failed with result 'exit-code'.952server # [ 221.522926] systemd[1]: Failed to start postgresql.service.953server # [ 222.073070] systemd[1]: postgresql.service: Start request repeated too quickly.954server # [ 222.074453] systemd[1]: postgresql.service: Failed with result 'exit-code'.955server # [ 222.075020] systemd[1]: Failed to start postgresql.service.956server # [ 222.706142] systemd[1]: postgresql.service: Start request repeated too quickly.957server # [ 222.717718] systemd[1]: postgresql.service: Failed with result 'exit-code'.958server # [ 222.718434] systemd[1]: Failed to start postgresql.service.959server # [ 223.302901] systemd[1]: postgresql.service: Start request repeated too quickly.960server # [ 223.304209] systemd[1]: postgresql.service: Failed with result 'exit-code'.961server # [ 223.320938] systemd[1]: Failed to start postgresql.service.962server # [ 223.891984] systemd[1]: postgresql.service: Start request repeated too quickly.963server # [ 223.914200] systemd[1]: postgresql.service: Failed with result 'exit-code'.964server # [ 223.914976] systemd[1]: Failed to start postgresql.service.965server # [ 224.527056] systemd[1]: postgresql.service: Start request repeated too quickly.966server # [ 224.528263] systemd[1]: postgresql.service: Failed with result 'exit-code'.967server # [ 224.558842] systemd[1]: Failed to start postgresql.service.968server # [ 225.167199] systemd[1]: postgresql.service: Start request repeated too quickly.969server # [ 225.189387] systemd[1]: postgresql.service: Failed with result 'exit-code'.970server # [ 225.190161] systemd[1]: Failed to start postgresql.service.971server # [ 225.755719] systemd[1]: postgresql.service: Start request repeated too quickly.972server # [ 225.774614] systemd[1]: postgresql.service: Failed with result 'exit-code'.973server # [ 225.775664] systemd[1]: Failed to start postgresql.service.974server # [ 226.416412] systemd[1]: postgresql.service: Start request repeated too quickly.975server # [ 226.455250] systemd[1]: postgresql.service: Failed with result 'exit-code'.976server # [ 226.457163] systemd[1]: Failed to start postgresql.service.977server # [ 227.092933] systemd[1]: Starting postgresql.service...978server # [ 227.575276] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION979server # [ 227.604087] systemd[1]: postgresql.service: Failed with result 'exit-code'.980server # [ 227.618311] systemd[1]: Failed to start postgresql.service.981server # [ 228.273641] systemd[1]: Starting postgresql.service...982server # [ 228.769611] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION983server # [ 228.797153] systemd[1]: postgresql.service: Failed with result 'exit-code'.984server # [ 228.798027] systemd[1]: Failed to start postgresql.service.985server # [ 229.474493] systemd[1]: Starting postgresql.service...986server # [ 229.927519] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION987server # [ 229.950207] systemd[1]: postgresql.service: Failed with result 'exit-code'.988server # [ 229.951129] systemd[1]: Failed to start postgresql.service.989server # [ 230.603348] systemd[1]: Starting postgresql.service...990server # [ 231.049283] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION991server # [ 231.066395] systemd[1]: postgresql.service: Failed with result 'exit-code'.992server # [ 231.067631] systemd[1]: Failed to start postgresql.service.993server # [ 231.733781] systemd[1]: Starting postgresql.service...994server # [ 232.191837] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION995server # [ 232.211292] systemd[1]: postgresql.service: Failed with result 'exit-code'.996server # [ 232.214059] systemd[1]: Failed to start postgresql.service.997server # [ 232.793203] systemd[1]: postgresql.service: Start request repeated too quickly.998server # [ 232.805497] systemd[1]: postgresql.service: Failed with result 'exit-code'.999server # [ 232.818125] systemd[1]: Failed to start postgresql.service.1000server # [ 233.415619] systemd[1]: postgresql.service: Start request repeated too quickly.1001server # [ 233.435423] systemd[1]: postgresql.service: Failed with result 'exit-code'.1002server # [ 233.453698] systemd[1]: Failed to start postgresql.service.1003server # [ 234.031965] systemd[1]: postgresql.service: Start request repeated too quickly.1004server # [ 234.033825] systemd[1]: postgresql.service: Failed with result 'exit-code'.1005server # [ 234.034480] systemd[1]: Failed to start postgresql.service.1006server # [ 234.641054] systemd[1]: postgresql.service: Start request repeated too quickly.1007server # [ 234.669660] systemd[1]: postgresql.service: Failed with result 'exit-code'.1008server # [ 234.671172] systemd[1]: Failed to start postgresql.service.1009server # [ 235.247796] systemd[1]: postgresql.service: Start request repeated too quickly.1010server # [ 235.249361] systemd[1]: postgresql.service: Failed with result 'exit-code'.1011server # [ 235.250286] systemd[1]: Failed to start postgresql.service.1012server # [ 235.855736] systemd[1]: postgresql.service: Start request repeated too quickly.1013server # [ 235.873930] systemd[1]: postgresql.service: Failed with result 'exit-code'.1014server # [ 235.874769] systemd[1]: Failed to start postgresql.service.1015server # [ 236.469225] systemd[1]: postgresql.service: Start request repeated too quickly.1016server # [ 236.470350] systemd[1]: postgresql.service: Failed with result 'exit-code'.1017server # [ 236.471615] systemd[1]: Failed to start postgresql.service.1018server # [ 237.119431] systemd[1]: Starting postgresql.service...1019server # [ 237.607593] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1020server # [ 237.613463] systemd[1]: postgresql.service: Failed with result 'exit-code'.1021server # [ 237.631824] systemd[1]: Failed to start postgresql.service.1022server # [ 238.306023] systemd[1]: Starting postgresql.service...1023server # [ 238.710356] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1024server # [ 238.720752] systemd[1]: postgresql.service: Failed with result 'exit-code'.1025server # [ 238.733959] systemd[1]: Failed to start postgresql.service.1026server # [ 239.391612] systemd[1]: Starting postgresql.service...1027server # [ 239.861170] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1028server # [ 239.866633] systemd[1]: postgresql.service: Failed with result 'exit-code'.1029server # [ 239.884831] systemd[1]: Failed to start postgresql.service.1030server # [ 240.603338] systemd[1]: Starting postgresql.service...1031server # [ 241.035254] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1032server # [ 241.054621] systemd[1]: postgresql.service: Failed with result 'exit-code'.1033server # [ 241.055883] systemd[1]: Failed to start postgresql.service.1034server # [ 241.746703] systemd[1]: Starting postgresql.service...1035server # [ 242.208567] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1036server # [ 242.215697] systemd[1]: postgresql.service: Failed with result 'exit-code'.1037server # [ 242.231570] systemd[1]: Failed to start postgresql.service.1038server # [ 242.889315] systemd[1]: postgresql.service: Start request repeated too quickly.1039server # [ 242.910844] systemd[1]: postgresql.service: Failed with result 'exit-code'.1040server # [ 242.911788] systemd[1]: Failed to start postgresql.service.1041server # [ 243.523090] systemd[1]: postgresql.service: Start request repeated too quickly.1042server # [ 243.524350] systemd[1]: postgresql.service: Failed with result 'exit-code'.1043server # [ 243.554271] systemd[1]: Failed to start postgresql.service.1044server # [ 244.162315] systemd[1]: postgresql.service: Start request repeated too quickly.1045server # [ 244.182542] systemd[1]: postgresql.service: Failed with result 'exit-code'.1046server # [ 244.183411] systemd[1]: Failed to start postgresql.service.1047server # [ 244.842471] systemd[1]: postgresql.service: Start request repeated too quickly.1048server # [ 244.844022] systemd[1]: postgresql.service: Failed with result 'exit-code'.1049server # [ 244.860155] systemd[1]: Failed to start postgresql.service.1050server # [ 245.512662] systemd[1]: postgresql.service: Start request repeated too quickly.1051server # [ 245.529560] systemd[1]: postgresql.service: Failed with result 'exit-code'.1052server # [ 245.530230] systemd[1]: Failed to start postgresql.service.1053server # [ 246.108822] systemd[1]: postgresql.service: Start request repeated too quickly.1054server # [ 246.111036] systemd[1]: postgresql.service: Failed with result 'exit-code'.1055server # [ 246.139955] systemd[1]: Failed to start postgresql.service.1056server # [ 246.781445] systemd[1]: postgresql.service: Start request repeated too quickly.1057server # [ 246.793870] systemd[1]: postgresql.service: Failed with result 'exit-code'.1058server # [ 246.794625] systemd[1]: Failed to start postgresql.service.1059server # [ 247.434734] systemd[1]: Starting postgresql.service...1060server # [ 247.893820] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1061server # [ 247.895251] systemd[1]: postgresql.service: Failed with result 'exit-code'.1062server # [ 247.896188] systemd[1]: Failed to start postgresql.service.1063server # [ 248.513053] systemd[1]: Starting postgresql.service...1064server # [ 249.006974] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1065server # [ 249.033227] systemd[1]: postgresql.service: Failed with result 'exit-code'.1066server # [ 249.034446] systemd[1]: Failed to start postgresql.service.1067server # [ 249.655149] systemd[1]: Starting postgresql.service...1068server # [ 250.173526] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1069server # [ 250.175211] systemd[1]: postgresql.service: Failed with result 'exit-code'.1070server # [ 250.191472] systemd[1]: Failed to start postgresql.service.1071server # [ 250.813281] systemd[1]: Starting postgresql.service...1072server # [ 251.275603] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1073server # [ 251.311535] systemd[1]: postgresql.service: Failed with result 'exit-code'.1074server # [ 251.315289] systemd[1]: Failed to start postgresql.service.1075server # [ 251.932715] systemd[1]: Starting postgresql.service...1076server # [ 252.347182] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1077server # [ 252.348189] systemd[1]: postgresql.service: Failed with result 'exit-code'.1078server # [ 252.382741] systemd[1]: Failed to start postgresql.service.1079server # [ 252.960941] systemd[1]: postgresql.service: Start request repeated too quickly.1080server # [ 252.962191] systemd[1]: postgresql.service: Failed with result 'exit-code'.1081server # [ 252.962997] systemd[1]: Failed to start postgresql.service.1082server # [ 253.534852] systemd[1]: postgresql.service: Start request repeated too quickly.1083server # [ 253.561434] systemd[1]: postgresql.service: Failed with result 'exit-code'.1084server # [ 253.568865] systemd[1]: Failed to start postgresql.service.1085server # [ 254.160420] systemd[1]: postgresql.service: Start request repeated too quickly.1086server # [ 254.161432] systemd[1]: postgresql.service: Failed with result 'exit-code'.1087server # [ 254.162896] systemd[1]: Failed to start postgresql.service.1088server # [ 254.835414] systemd[1]: postgresql.service: Start request repeated too quickly.1089server # [ 254.853757] systemd[1]: postgresql.service: Failed with result 'exit-code'.1090server # [ 254.854581] systemd[1]: Failed to start postgresql.service.1091server # [ 255.586583] systemd[1]: postgresql.service: Start request repeated too quickly.1092server # [ 255.601632] systemd[1]: postgresql.service: Failed with result 'exit-code'.1093server # [ 255.602500] systemd[1]: Failed to start postgresql.service.1094server # [ 256.303070] systemd[1]: postgresql.service: Start request repeated too quickly.1095server # [ 256.326949] systemd[1]: postgresql.service: Failed with result 'exit-code'.1096server # [ 256.327755] systemd[1]: Failed to start postgresql.service.1097server # [ 257.178186] systemd[1]: postgresql.service: Start request repeated too quickly.1098server # [ 257.182651] systemd[1]: postgresql.service: Failed with result 'exit-code'.1099server # [ 257.183601] systemd[1]: Failed to start postgresql.service.1100server # [ 257.938647] systemd[1]: Starting postgresql.service...1101server # [ 258.464890] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1102server # [ 258.466082] systemd[1]: postgresql.service: Failed with result 'exit-code'.1103server # [ 258.485292] systemd[1]: Failed to start postgresql.service.1104server # [ 259.105051] systemd[1]: Starting postgresql.service...1105server # [ 259.825532] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1106server # [ 259.838489] systemd[1]: postgresql.service: Failed with result 'exit-code'.1107server # [ 259.850748] systemd[1]: Failed to start postgresql.service.1108server # [ 260.879039] systemd[1]: Starting postgresql.service...1109server # [ 261.383350] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1110server # [ 261.395525] systemd[1]: postgresql.service: Failed with result 'exit-code'.1111server # [ 261.409165] systemd[1]: Failed to start postgresql.service.1112server # [ 261.988921] runuser[1801]: pam_unix(runuser:session): session closed for user postgres1113server # [ 262.167559] systemd[1]: Starting postgresql.service...1114server # [ 262.258671] systemd[1]: Stopping [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim...1115server # [ 262.348224] systemd[1]: salt-sim.service: Deactivated successfully.1116server # [ 262.361101] systemd[1]: Stopped [systemd-run] /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive salt_sim.1117server # [ 262.362210] systemd[1]: salt-sim.service: Consumed 9.273s CPU time, 1.9M memory peak.1118server # [ 262.777031] systemd[1]: fake-initiate.service: Main process exited, code=exited, status=1/FAILURE1119server # [ 262.778328] systemd[1]: fake-initiate.service: Failed with result 'exit-code'.1120server # [ 262.789394] systemd[1]: fake-initiate.service: Consumed 35.091s CPU time, 148.3M memory peak, 238.4M written to disk.1121server # [ 262.829698] systemd[1]: postgresql.service: Condition check process exited, code=exited, status=255/EXCEPTION1122server # [ 262.830878] systemd[1]: postgresql.service: Failed with result 'exit-code'.1123server # [ 262.838717] systemd[1]: Failed to start postgresql.service.1124server # Finished with result: exit-code1125server # Main processes terminated with: code=exited, status=1/FAILURE1126server # Service runtime: 1min 35.448s1127server # CPU time consumed: 35.091s1128server # Memory peak: 148.3M (swap: 0B)1129server # IO Bytes: written 238.4M1130server: output: The files belonging to this database system will be owned by user "postgres".1131This user must also own the server process.11321133The database cluster will be initialized with locale "C".1134The default text search configuration will be set to "english".11351136Data page checksums are disabled.11371138creating directory /var/lib/postgresql/data-17 ... ok1139creating subdirectories ... ok1140selecting dynamic shared memory implementation ... posix1141selecting default "max_connections" ... 1001142selecting default "shared_buffers" ... 128MB1143selecting default time zone ... UTC1144creating configuration files ... ok1145running bootstrap script ... ok1146performing post-bootstrap initialization ... ok1147syncing data to disk ... ok114811491150Success. You can now start the database server using:11511152 /nix/store/rzqj1a80dyp0c09ddabi2jnql4kms0jc-postgresql-and-plugins-17.11/bin/pg_ctl -D /var/lib/postgresql/data-17 -l logfile start11531154Performing Consistency Checks1155-----------------------------1156Checking cluster versions ok1157Checking database user is the install user ok1158Checking database connection settings ok1159Checking for prepared transactions ok1160Checking for contrib/isn with bigint-passing mismatch ok1161Checking data type usage ok1162Checking for not-null constraint inconsistencies ok1163Creating dump of global objects ok1164Creating dump of database schemas ok1165[12:35:09] Locked /var/lib/postgresql/data with pg_upgrade pid 18041166Checking for presence of required libraries ok1167Checking database user is the install user ok1168Checking for prepared transactions ok1169Checking for new cluster tablespace directories ok11701171If pg_upgrade fails after this point, you must re-initdb the1172new cluster before continuing.11731174Performing Upgrade1175------------------1176Setting locale and encoding for new cluster ok1177Analyzing all rows in the new cluster ok1178Freezing all rows in the new cluster ok1179Deleting files from new pg_xact ok1180Copying old pg_xact to new server ok1181Setting oldest XID for new cluster ok1182Setting next transaction ID and epoch for new cluster ok1183Deleting files from new pg_multixact/offsets ok1184Copying old pg_multixact/offsets to new server ok1185Deleting files from new pg_multixact/members ok1186Copying old pg_multixact/members to new server ok1187Setting next multixact ID and offset for new cluster ok1188Resetting WAL archives ok1189Setting frozenxid and minmxid counters in new cluster ok1190Restoring global objects in the new cluster ok1191Restoring database schemas in the new cluster ok1192Copying user relation files ok1193Setting next OID for new cluster ok1194Sync data directory to disk ok1195Creating script to delete old cluster ok1196Checking for extension updates ok11971198Upgrade Complete1199----------------1200Optimizer statistics are not transferred by pg_upgrade.1201Once you start the new server, consider running:1202 /nix/store/rzqj1a80dyp0c09ddabi2jnql4kms0jc-postgresql-and-plugins-17.11/bin/vacuumdb -U postgres --all --analyze-in-stages1203Running this script will delete the old cluster's data files:1204 ./delete_old_cluster.sh1205[12:35:40] ERROR: postgresql.service is activating after pg_upgrade; the copied data files may be inconsistent12061207!!! Test "A real pg_upgrade copy under a start storm" failed with error: "command `systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive upgrade` failed (exit code 1)"1208!!! Traceback (most recent call last):1209!!! File "<string>", line 69, in <module>1210!!! server.succeed(f"systemd-run --unit=fake-initiate --collect --pipe --wait {DRIVE} upgrade")1211!!! 1212!!! RequestedAssertionFailed: command `systemd-run --unit=fake-initiate --collect --pipe --wait /nix/store/n7iyg9ckgj0sd4qqxq9z6spd6zq1x14j-drive/bin/drive upgrade` failed (exit code 1)1213cleanup1214kill machine (pid 9)1215qemu-system-aarch64: terminating on signal 15 from pid 6 (/nix/store/y88crn50yx35fiiwcjx6xqwi6ahk7mlq-python3-3.13.11/bin/python3.13)1216vde_switch: EOF data port: Interrupted system call1217kill vlan (pid 7)1218(finished: cleanup, in 0.00 seconds)1219vde_switch: Caught signal 15, cleaning up and exiting