nixbot

1these 2 derivations will be built:2  /nix/store/hls0qdgcd963b78q878dh6k3733j6gl4-nixos-test-driver-wal2json.drv3  /nix/store/7vf0yc0q4laszgbf8p0h67mb73l06fgw-vm-test-run-wal2json.drv4building '/nix/store/hls0qdgcd963b78q878dh6k3733j6gl4-nixos-test-driver-wal2json.drv' on 'ssh-ng://nixbot-remote-build@78.232.36.247'5building '/nix/store/hls0qdgcd963b78q878dh6k3733j6gl4-nixos-test-driver-wal2json.drv'6nixos-test-driver-wal2json> Running type check (enable/disable: config.skipTypeCheck)7nixos-test-driver-wal2json> See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck8nixos-test-driver-wal2json> Success: no issues found in 1 source file9nixos-test-driver-wal2json> additionally exposed symbols:10nixos-test-driver-wal2json>     ,11nixos-test-driver-wal2json>     ,12nixos-test-driver-wal2json>     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, debug13nixos-test-driver-wal2json> Linting test script (enable/disable: config.skipLint)14nixos-test-driver-wal2json> See https://nixos.org/manual/nixos/stable/#test-opt-skipLint15building '/nix/store/7vf0yc0q4laszgbf8p0h67mb73l06fgw-vm-test-run-wal2json.drv' on 'ssh-ng://builder@mac-linux-builder'16building '/nix/store/7vf0yc0q4laszgbf8p0h67mb73l06fgw-vm-test-run-wal2json.drv'17vm-test-run-wal2json> Machine state will be reset. To keep it, pass --keep-vm-state18vm-test-run-wal2json> start all VLans19vm-test-run-wal2json> start vlan20vm-test-run-wal2json> running vlan (pid 7; ctl /build/vde1.ctl)21vm-test-run-wal2json> (finished: start all VLans, in 0.00 seconds)22vm-test-run-wal2json> Test will time out and terminate in 3600 seconds23vm-test-run-wal2json> run the VM test script24vm-test-run-wal2json> additionally exposed symbols:25vm-test-run-wal2json>     server,26vm-test-run-wal2json>     vlan1,27vm-test-run-wal2json>     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, debug28vm-test-run-wal2json> Running tests for extension: wal2json29vm-test-run-wal2json> start all VMs30vm-test-run-wal2json> server: starting vm31vm-test-run-wal2json> mke2fs 1.47.3 (8-Jul-2025)32vm-test-run-wal2json> qemu-system-aarch64: Could not access KVM kernel module: No such file or directory33vm-test-run-wal2json> qemu-system-aarch64: failed to initialize kvm: No such file or directory34vm-test-run-wal2json> qemu-system-aarch64: falling back to tcg35vm-test-run-wal2json> server # Disk image does not exist, creating the virtualisation disk image...36vm-test-run-wal2json> server # Formatting '/build/vm-state-server/tmp.toMw3kZoB8', fmt=raw size=107374182437vm-test-run-wal2json> server # Discarding device blocks:      0/262144             done38vm-test-run-wal2json> server # Creating filesystem with 262144 4k blocks and 65536 inodes39vm-test-run-wal2json> server # Filesystem UUID: 24155e35-2eda-4194-b47d-451bbb0df07540vm-test-run-wal2json> server # Superblock backups stored on blocks:41vm-test-run-wal2json> server # 	32768, 98304, 163840, 22937642vm-test-run-wal2json> server # 43vm-test-run-wal2json> server # Allocating group tables: 0/8   done44vm-test-run-wal2json> server # Writing inode tables: 0/8   done45vm-test-run-wal2json> server # Creating journal (8192 blocks): done46vm-test-run-wal2json> server # Writing superblocks and filesystem accounting information: 0/8   done47vm-test-run-wal2json> server: QEMU running (pid 9)48vm-test-run-wal2json> server # 49vm-test-run-wal2json> server # Virtualisation disk image created.50vm-test-run-wal2json> (finished: start all VMs, in 0.22 seconds)51vm-test-run-wal2json> server: waiting for unit multi-user.target52vm-test-run-wal2json> server: waiting for the VM to finish booting53vm-test-run-wal2json> server # [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]54vm-test-run-wal2json> server # [    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 202555vm-test-run-wal2json> server # [    0.000000] KASLR enabled56vm-test-run-wal2json> server # [    0.000000] random: crng init done57vm-test-run-wal2json> server # [    0.000000] Machine model: linux,dummy-virt58vm-test-run-wal2json> server # [    0.000000] efi: UEFI not found.59vm-test-run-wal2json> server # [    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT60vm-test-run-wal2json> server # [    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]61vm-test-run-wal2json> server # [    0.000000] NODE_DATA(0) allocated [mem 0x13f602200-0x13f60593f]62vm-test-run-wal2json> server # [    0.000000] Zone ranges:63vm-test-run-wal2json> server # [    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]64vm-test-run-wal2json> server # [    0.000000]   DMA32    empty65vm-test-run-wal2json> server # [    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]66vm-test-run-wal2json> server # [    0.000000]   Device   empty67vm-test-run-wal2json> server # [    0.000000] Movable zone start for each node68vm-test-run-wal2json> server # [    0.000000] Early memory node ranges69vm-test-run-wal2json> server # [    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]70vm-test-run-wal2json> server # [    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]71vm-test-run-wal2json> server # [    0.000000] cma: Reserved 32 MiB at 0x00000000fe000000 on node -172vm-test-run-wal2json> server # [    0.000000] psci: probing for conduit method from DT.73vm-test-run-wal2json> server # [    0.000000] psci: PSCIv1.1 detected in firmware.74vm-test-run-wal2json> server # [    0.000000] psci: Using standard PSCI v0.2 function IDs75vm-test-run-wal2json> server # [    0.000000] psci: Trusted OS migration not required76vm-test-run-wal2json> server # [    0.000000] psci: SMC Calling Convention v1.077vm-test-run-wal2json> server # [    0.000000] percpu: Embedded 88 pages/cpu s180056 r65536 d114856 u36044878vm-test-run-wal2json> server # [    0.000000] Detected PIPT I-cache on CPU079vm-test-run-wal2json> server # [    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)80vm-test-run-wal2json> server # [    0.000000] CPU features: detected: GIC system register CPU interface81vm-test-run-wal2json> server # [    0.000000] CPU features: detected: HCRX_EL2 register82vm-test-run-wal2json> server # [    0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)83vm-test-run-wal2json> server # [    0.000000] CPU features: detected: Spectre-v484vm-test-run-wal2json> server # [    0.000000] alternatives: applying boot alternatives85vm-test-run-wal2json> server # [    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/md474dkd4ixy20nkn54m8m3fqy1z83lq-nixos-system-server-test/init regInfo=/nix/store/8kqrgm24650crxzjy058d10hj3f56vpi-closure-info/registration console=ttyAMA0,115200n8 console=tty086vm-test-run-wal2json> server # [    0.000000] Unknown kernel command line parameters "regInfo=/nix/store/8kqrgm24650crxzjy058d10hj3f56vpi-closure-info/registration", will be passed to user space.87vm-test-run-wal2json> server # [    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)88vm-test-run-wal2json> server # [    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)89vm-test-run-wal2json> server # [    0.000000] Fallback order for Node 0: 090vm-test-run-wal2json> server # [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 104857691vm-test-run-wal2json> server # [    0.000000] Policy zone: Normal92vm-test-run-wal2json> server # [    0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off93vm-test-run-wal2json> server # [    0.000000] software IO TLB: area num 2.94vm-test-run-wal2json> server # [    0.000000] software IO TLB: mapped [mem 0x00000000fa000000-0x00000000fe000000] (64MB)95vm-test-run-wal2json> server # [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=196vm-test-run-wal2json> server # [    0.000000] allocated 8388608 bytes of page_ext97vm-test-run-wal2json> server # [    0.000000] ftrace: allocating 72257 entries in 283 pages98vm-test-run-wal2json> server # [    0.000000] ftrace: allocated 283 pages with 5 groups99vm-test-run-wal2json> server # [    0.000000] rcu: Hierarchical RCU implementation.100vm-test-run-wal2json> server # [    0.000000] rcu: 	RCU event tracing is enabled.101vm-test-run-wal2json> server # [    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=2.102vm-test-run-wal2json> server # [    0.000000] 	Rude variant of Tasks RCU enabled.103vm-test-run-wal2json> server # [    0.000000] 	Tracing variant of Tasks RCU enabled.104vm-test-run-wal2json> server # [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.105vm-test-run-wal2json> server # [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2106vm-test-run-wal2json> server # [    0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.107vm-test-run-wal2json> server # [    0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.108vm-test-run-wal2json> server # [    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0109vm-test-run-wal2json> server # [    0.000000] GICv3: 256 SPIs implemented110vm-test-run-wal2json> server # [    0.000000] GICv3: 0 Extended SPIs implemented111vm-test-run-wal2json> server # [    0.000000] Root IRQ handler: gic_handle_irq112vm-test-run-wal2json> server # [    0.000000] GICv3: GICv3 features: 16 PPIs113vm-test-run-wal2json> server # [    0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=0114vm-test-run-wal2json> server # [    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000115vm-test-run-wal2json> server # [    0.000000] ITS [mem 0x08080000-0x0809ffff]116vm-test-run-wal2json> server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @100ae0000 (indirect, esz 8, psz 64K, shr 1)117vm-test-run-wal2json> server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @100af0000 (flat, esz 8, psz 64K, shr 1)118vm-test-run-wal2json> server # [    0.000000] GICv3: using LPI property table @0x0000000100b00000119vm-test-run-wal2json> server # [    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000100b10000120vm-test-run-wal2json> server # [    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.121vm-test-run-wal2json> server # [    0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (virt).122vm-test-run-wal2json> server # [    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns123vm-test-run-wal2json> server # [    0.000035] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns124vm-test-run-wal2json> server # [    0.003579] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)125vm-test-run-wal2json> server # [    0.013193] Console: colour dummy device 80x25126vm-test-run-wal2json> server # [    0.014560] printk: legacy console [tty0] enabled127vm-test-run-wal2json> server # [    0.019789] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)128vm-test-run-wal2json> server # [    0.020458] pid_max: default: 32768 minimum: 301129vm-test-run-wal2json> server # [    0.022309] LSM: initializing lsm=capability,landlock,yama,bpf130vm-test-run-wal2json> server # [    0.023643] landlock: Up and running.131vm-test-run-wal2json> server # [    0.023693] Yama: becoming mindful.132vm-test-run-wal2json> server # [    0.026839] LSM support for eBPF active133vm-test-run-wal2json> server # [    0.029610] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)134vm-test-run-wal2json> server # [    0.029723] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)135vm-test-run-wal2json> server # [    0.057362] cacheinfo: Unable to detect cache hierarchy for CPU 0136vm-test-run-wal2json> server # [    0.067541] rcu: Hierarchical SRCU implementation.137vm-test-run-wal2json> server # [    0.067628] rcu: 	Max phase no-delay instances is 1000.138vm-test-run-wal2json> server # [    0.069185] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level139vm-test-run-wal2json> server # [    0.074983] fsl-mc MSI: its@8080000 domain created140vm-test-run-wal2json> server # [    0.077353] EFI services will not be available.141vm-test-run-wal2json> server # [    0.079514] smp: Bringing up secondary CPUs ...142vm-test-run-wal2json> server # [    0.084536] Detected PIPT I-cache on CPU1143vm-test-run-wal2json> server # [    0.085745] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000144vm-test-run-wal2json> server # [    0.086474] GICv3: CPU1: using allocated LPI pending table @0x0000000100b20000145vm-test-run-wal2json> server # [    0.088186] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]146vm-test-run-wal2json> server # [    0.091518] smp: Brought up 1 node, 2 CPUs147vm-test-run-wal2json> server # [    0.091664] SMP: Total of 2 processors activated.148vm-test-run-wal2json> server # [    0.091708] CPU: All CPU(s) started at EL1149vm-test-run-wal2json> server # [    0.091874] CPU features: detected: Branch Target Identification150vm-test-run-wal2json> server # [    0.091928] CPU features: detected: 32-bit EL0 Support151vm-test-run-wal2json> server # [    0.091960] CPU features: detected: 32-bit EL1 Support152vm-test-run-wal2json> server # [    0.091986] CPU features: detected: ARMv8.4 Translation Table Level153vm-test-run-wal2json> server # [    0.092021] CPU features: detected: Instruction cache invalidation not required for I/D coherence154vm-test-run-wal2json> server # [    0.092062] CPU features: detected: Data cache clean to the PoU not required for I/D coherence155vm-test-run-wal2json> server # [    0.092129] CPU features: detected: Common not Private translations156vm-test-run-wal2json> server # [    0.092157] CPU features: detected: CRC32 instructions157vm-test-run-wal2json> server # [    0.092181] CPU features: detected: Data cache clean to Point of Deep Persistence158vm-test-run-wal2json> server # [    0.092211] CPU features: detected: Data cache clean to Point of Persistence159vm-test-run-wal2json> server # [    0.092239] CPU features: detected: Data independent timing control (DIT)160vm-test-run-wal2json> server # [    0.092266] CPU features: detected: E0PD161vm-test-run-wal2json> server # [    0.092287] CPU features: detected: Enhanced Counter Virtualization162vm-test-run-wal2json> server # [    0.092313] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)163vm-test-run-wal2json> server # [    0.092340] CPU features: detected: Enhanced Privileged Access Never164vm-test-run-wal2json> server # [    0.092366] CPU features: detected: Enhanced Virtualization Traps165vm-test-run-wal2json> server # [    0.092392] CPU features: detected: Fine Grained Traps166vm-test-run-wal2json> server # [    0.092452] CPU features: detected: Generic authentication (IMP DEF algorithm)167vm-test-run-wal2json> server # [    0.092536] CPU features: detected: RCpc load-acquire (LDAPR)168vm-test-run-wal2json> server # [    0.092581] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)169vm-test-run-wal2json> server # [    0.092604] CPU features: detected: LSE atomic instructions170vm-test-run-wal2json> server # [    0.092624] CPU features: detected: Memory Copy and Memory Set instructions171vm-test-run-wal2json> server # [    0.092650] CPU features: detected: Privileged Access Never172vm-test-run-wal2json> server # [    0.092675] CPU features: detected: RAS Extension Support173vm-test-run-wal2json> server # [    0.092694] CPU features: detected: Random Number Generator174vm-test-run-wal2json> server # [    0.092714] CPU features: detected: Speculation barrier (SB)175vm-test-run-wal2json> server # [    0.092734] CPU features: detected: Stage-2 Force Write-Back176vm-test-run-wal2json> server # [    0.092754] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality177vm-test-run-wal2json> server # [    0.092782] CPU features: detected: TLB range maintenance instructions178vm-test-run-wal2json> server # [    0.092807] CPU features: detected: WFx with timeout179vm-test-run-wal2json> server # [    0.092847] CPU features: detected: Speculative Store Bypassing Safe (SSBS)180vm-test-run-wal2json> server # [    0.092875] CPU features: detected: Scalable Vector Extension181vm-test-run-wal2json> server # [    0.101343] alternatives: applying system-wide alternatives182vm-test-run-wal2json> server # [    0.115774] CPU features: detected: Hardware dirty bit management on CPU0-1183vm-test-run-wal2json> server # [    0.116405] SVE: maximum available vector length 256 bytes per vector184vm-test-run-wal2json> server # [    0.116486] SVE: default vector length 64 bytes per vector185vm-test-run-wal2json> server # [    0.127988] Memory: 3922868K/4194304K available (23296K kernel code, 6546K rwdata, 24596K rodata, 4416K init, 1047K bss, 223164K reserved, 32768K cma-reserved)186vm-test-run-wal2json> server # [    0.149561] devtmpfs: initialized187vm-test-run-wal2json> server # [    0.174604] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns188vm-test-run-wal2json> server # [    0.175054] futex hash table entries: 512 (order: 3, 32768 bytes, linear)189vm-test-run-wal2json> server # [    0.177020] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL190vm-test-run-wal2json> server # [    0.177073] 0 pages in range for non-PLT usage191vm-test-run-wal2json> server # [    0.177108] 509248 pages in range for PLT usage192vm-test-run-wal2json> server # [    0.179320] pinctrl core: initialized pinctrl subsystem193vm-test-run-wal2json> server # [    0.189387] DMI not present or invalid.194vm-test-run-wal2json> server # [    0.206434] NET: Registered PF_NETLINK/PF_ROUTE protocol family195vm-test-run-wal2json> server # [    0.217139] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations196vm-test-run-wal2json> server # [    0.218143] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations197vm-test-run-wal2json> server # [    0.219349] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations198vm-test-run-wal2json> server # [    0.219615] audit: initializing netlink subsys (disabled)199vm-test-run-wal2json> server # [    0.221860] audit: type=2000 audit(0.140:1): state=initialized audit_enabled=0 res=1200vm-test-run-wal2json> server # [    0.227202] thermal_sys: Registered thermal governor 'fair_share'201vm-test-run-wal2json> server # [    0.227258] thermal_sys: Registered thermal governor 'bang_bang'202vm-test-run-wal2json> server # [    0.227311] thermal_sys: Registered thermal governor 'step_wise'203vm-test-run-wal2json> server # [    0.227337] thermal_sys: Registered thermal governor 'user_space'204vm-test-run-wal2json> server # [    0.227359] thermal_sys: Registered thermal governor 'power_allocator'205vm-test-run-wal2json> server # [    0.228021] cpuidle: using governor ladder206vm-test-run-wal2json> server # [    0.228293] cpuidle: using governor menu207vm-test-run-wal2json> server # [    0.230322] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.208vm-test-run-wal2json> server # [    0.230951] ASID allocator initialised with 65536 entries209vm-test-run-wal2json> server # [    0.238916] Serial: AMBA PL011 UART driver210vm-test-run-wal2json> server # [    0.285455] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1211vm-test-run-wal2json> server # [    0.286942] printk: legacy console [ttyAMA0] enabled212vm-test-run-wal2json> server # [    0.319235] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages213vm-test-run-wal2json> server # [    0.319450] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page214vm-test-run-wal2json> server # [    0.319572] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages215vm-test-run-wal2json> server # [    0.319676] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page216vm-test-run-wal2json> server # [    0.319981] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages217vm-test-run-wal2json> server # [    0.320076] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page218vm-test-run-wal2json> server # [    0.320167] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages219vm-test-run-wal2json> server # [    0.320259] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page220vm-test-run-wal2json> server # [    0.330547] fbcon: Taking over console221vm-test-run-wal2json> server # [    0.331487] ACPI: Interpreter disabled.222vm-test-run-wal2json> server # [    0.339099] iommu: Default domain type: Translated223vm-test-run-wal2json> server # [    0.339250] iommu: DMA domain TLB invalidation policy: strict mode224vm-test-run-wal2json> server # [    0.341762] SCSI subsystem initialized225vm-test-run-wal2json> server # [    0.345553] usbcore: registered new interface driver usbfs226vm-test-run-wal2json> server # [    0.345998] usbcore: registered new interface driver hub227vm-test-run-wal2json> server # [    0.346232] usbcore: registered new device driver usb228vm-test-run-wal2json> server # [    0.348863] pps_core: LinuxPPS API ver. 1 registered229vm-test-run-wal2json> server # [    0.349007] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>230vm-test-run-wal2json> server # [    0.349395] PTP clock support registered231vm-test-run-wal2json> server # [    0.350526] EDAC MC: Ver: 3.0.0232vm-test-run-wal2json> server # [    0.352224] scmi_core: SCMI protocol bus registered233vm-test-run-wal2json> server # [    0.355629] FPGA manager framework234vm-test-run-wal2json> server # [    0.357006] Advanced Linux Sound Architecture Driver Initialized.235vm-test-run-wal2json> server # [    0.365322] vgaarb: loaded236vm-test-run-wal2json> server # [    0.369062] clocksource: Switched to clocksource arch_sys_counter237vm-test-run-wal2json> server # [    0.372138] VFS: Disk quotas dquot_6.6.0238vm-test-run-wal2json> server # [    0.373204] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)239vm-test-run-wal2json> server # [    0.375368] netfs: FS-Cache loaded240vm-test-run-wal2json> server # [    0.376621] pnp: PnP ACPI: disabled241vm-test-run-wal2json> server # [    0.402175] NET: Registered PF_INET protocol family242vm-test-run-wal2json> server # [    0.403842] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)243vm-test-run-wal2json> server # [    0.514232] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)244vm-test-run-wal2json> server # [    0.514599] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)245vm-test-run-wal2json> server # [    0.514942] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)246vm-test-run-wal2json> server # [    0.516228] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)247vm-test-run-wal2json> server # [    0.517404] TCP: Hash tables configured (established 32768 bind 32768)248vm-test-run-wal2json> server # [    0.519037] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)249vm-test-run-wal2json> server # [    0.519495] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)250vm-test-run-wal2json> server # [    0.520183] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)251vm-test-run-wal2json> server # [    0.522287] NET: Registered PF_UNIX/PF_LOCAL protocol family252vm-test-run-wal2json> server # [    0.522915] NET: Registered PF_XDP protocol family253vm-test-run-wal2json> server # [    0.523279] PCI: CLS 0 bytes, default 64254vm-test-run-wal2json> server # [    0.525211] kvm [1]: HYP mode not available255vm-test-run-wal2json> server # [    0.527651] Trying to unpack rootfs image as initramfs...256vm-test-run-wal2json> server # [    0.638645] Initialise system trusted keyrings257vm-test-run-wal2json> server # [    0.640178] workingset: timestamp_bits=42 max_order=20 bucket_order=0258vm-test-run-wal2json> server # [    0.644892] squashfs: version 4.0 (2009/01/31) Phillip Lougher259vm-test-run-wal2json> server # [    0.646253] 9p: Installing v9fs 9p2000 file system support260vm-test-run-wal2json> server # [    0.705553] Key type asymmetric registered261vm-test-run-wal2json> server # [    0.705787] Asymmetric key parser 'x509' registered262vm-test-run-wal2json> server # [    0.706492] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244)263vm-test-run-wal2json> server # [    0.707988] io scheduler mq-deadline registered264vm-test-run-wal2json> server # [    0.708349] io scheduler kyber registered265vm-test-run-wal2json> server # [    0.736773] pl061_gpio 9030000.pl061: PL061 GPIO chip registered266vm-test-run-wal2json> server # [    0.747896] ledtrig-cpu: registered to indicate activity on CPUs267vm-test-run-wal2json> server # [    0.754135] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:268vm-test-run-wal2json> server # [    0.756092] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000269vm-test-run-wal2json> server # [    0.757660] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000270vm-test-run-wal2json> server # [    0.758163] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000271vm-test-run-wal2json> server # [    0.759502] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits272vm-test-run-wal2json> server # [    0.760672] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]273vm-test-run-wal2json> server # [    0.763682] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00274vm-test-run-wal2json> server # [    0.764475] pci_bus 0000:00: root bus resource [bus 00-ff]275vm-test-run-wal2json> server # [    0.765525] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]276vm-test-run-wal2json> server # [    0.766091] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]277vm-test-run-wal2json> server # [    0.766351] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]278vm-test-run-wal2json> server # [    0.768743] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint279vm-test-run-wal2json> server # [    0.776723] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint280vm-test-run-wal2json> server # [    0.777775] pci 0000:00:01.0: BAR 0 [io  0x0000-0x001f]281vm-test-run-wal2json> server # [    0.778168] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]282vm-test-run-wal2json> server # [    0.778963] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]283vm-test-run-wal2json> server # [    0.780153] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]284vm-test-run-wal2json> server # [    0.783876] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint285vm-test-run-wal2json> server # [    0.784538] pci 0000:00:02.0: BAR 0 [io  0x0000-0x001f]286vm-test-run-wal2json> server # [    0.784689] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]287vm-test-run-wal2json> server # [    0.784810] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]288vm-test-run-wal2json> server # [    0.786347] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint289vm-test-run-wal2json> server # [    0.786554] pci 0000:00:03.0: BAR 0 [io  0x0000-0x003f]290vm-test-run-wal2json> server # [    0.786883] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]291vm-test-run-wal2json> server # [    0.787098] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]292vm-test-run-wal2json> server # [    0.790733] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint293vm-test-run-wal2json> server # [    0.791096] pci 0000:00:04.0: BAR 0 [io  0x0000-0x001f]294vm-test-run-wal2json> server # [    0.791222] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]295vm-test-run-wal2json> server # [    0.791347] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]296vm-test-run-wal2json> server # [    0.792056] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint297vm-test-run-wal2json> server # [    0.792485] pci 0000:00:05.0: BAR 0 [io  0x0000-0x001f]298vm-test-run-wal2json> server # [    0.792856] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]299vm-test-run-wal2json> server # [    0.794989] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]300vm-test-run-wal2json> server # [    0.796091] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint301vm-test-run-wal2json> server # [    0.796341] pci 0000:00:06.0: BAR 0 [io  0x0000-0x007f]302vm-test-run-wal2json> server # [    0.796616] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]303vm-test-run-wal2json> server # [    0.797585] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]304vm-test-run-wal2json> server # [    0.798669] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint305vm-test-run-wal2json> server # [    0.799252] pci 0000:00:07.0: BAR 0 [io  0x0000-0x001f]306vm-test-run-wal2json> server # [    0.799529] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]307vm-test-run-wal2json> server # [    0.799725] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]308vm-test-run-wal2json> server # [    0.799837] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]309vm-test-run-wal2json> server # [    0.800368] pci 0000:00:08.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint310vm-test-run-wal2json> server # [    0.800898] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]311vm-test-run-wal2json> server # [    0.801013] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]312vm-test-run-wal2json> server # [    0.802007] pci 0000:00:09.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint313vm-test-run-wal2json> server # [    0.802596] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]314vm-test-run-wal2json> server # [    0.803112] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]315vm-test-run-wal2json> server # [    0.803846] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint316vm-test-run-wal2json> server # [    0.804321] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]317vm-test-run-wal2json> server # [    0.805055] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint318vm-test-run-wal2json> server # [    0.805638] pci 0000:00:0b.0: BAR 0 [io  0x0000-0x003f]319vm-test-run-wal2json> server # [    0.805751] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]320vm-test-run-wal2json> server # [    0.805914] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]321vm-test-run-wal2json> server # [    0.806861] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint322vm-test-run-wal2json> server # [    0.807027] pci 0000:00:0c.0: BAR 0 [io  0x0000-0x001f]323vm-test-run-wal2json> server # [    0.807129] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]324vm-test-run-wal2json> server # [    0.807242] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]325vm-test-run-wal2json> server # [    0.809379] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned326vm-test-run-wal2json> server # [    0.809877] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned327vm-test-run-wal2json> server # [    0.810103] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned328vm-test-run-wal2json> server # [    0.810333] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned329vm-test-run-wal2json> server # [    0.810490] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned330vm-test-run-wal2json> server # [    0.810622] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned331vm-test-run-wal2json> server # [    0.810990] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned332vm-test-run-wal2json> server # [    0.811138] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned333vm-test-run-wal2json> server # [    0.811277] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned334vm-test-run-wal2json> server # [    0.811407] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned335vm-test-run-wal2json> server # [    0.811545] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned336vm-test-run-wal2json> server # [    0.811704] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned337vm-test-run-wal2json> server # [    0.812169] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned338vm-test-run-wal2json> server # [    0.812441] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned339vm-test-run-wal2json> server # [    0.812573] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned340vm-test-run-wal2json> server # [    0.812683] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned341vm-test-run-wal2json> server # [    0.812882] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned342vm-test-run-wal2json> server # [    0.813177] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned343vm-test-run-wal2json> server # [    0.813328] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned344vm-test-run-wal2json> server # [    0.814355] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned345vm-test-run-wal2json> server # [    0.814565] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned346vm-test-run-wal2json> server # [    0.814981] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned347vm-test-run-wal2json> server # [    0.815122] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned348vm-test-run-wal2json> server # [    0.815238] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned349vm-test-run-wal2json> server # [    0.815535] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned350vm-test-run-wal2json> server # [    0.815663] pci 0000:00:06.0: BAR 0 [io  0x1000-0x107f]: assigned351vm-test-run-wal2json> server # [    0.815786] pci 0000:00:03.0: BAR 0 [io  0x1080-0x10bf]: assigned352vm-test-run-wal2json> server # [    0.815887] pci 0000:00:0b.0: BAR 0 [io  0x10c0-0x10ff]: assigned353vm-test-run-wal2json> server # [    0.815998] pci 0000:00:01.0: BAR 0 [io  0x1100-0x111f]: assigned354vm-test-run-wal2json> server # [    0.816101] pci 0000:00:02.0: BAR 0 [io  0x1120-0x113f]: assigned355vm-test-run-wal2json> server # [    0.816217] pci 0000:00:04.0: BAR 0 [io  0x1140-0x115f]: assigned356vm-test-run-wal2json> server # [    0.816317] pci 0000:00:05.0: BAR 0 [io  0x1160-0x117f]: assigned357vm-test-run-wal2json> server # [    0.816414] pci 0000:00:07.0: BAR 0 [io  0x1180-0x119f]: assigned358vm-test-run-wal2json> server # [    0.816587] pci 0000:00:0c.0: BAR 0 [io  0x11a0-0x11bf]: assigned359vm-test-run-wal2json> server # [    0.816869] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]360vm-test-run-wal2json> server # [    0.816984] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]361vm-test-run-wal2json> server # [    0.817083] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]362vm-test-run-wal2json> server # [    0.818712] pci 0000:00:0a.0: enabling device (0000 -> 0002)363vm-test-run-wal2json> server # [    0.880132] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)364vm-test-run-wal2json> server # [    0.884527] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)365vm-test-run-wal2json> server # [    0.887869] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)366vm-test-run-wal2json> server # [    0.890629] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)367vm-test-run-wal2json> server # [    0.893281] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)368vm-test-run-wal2json> server # [    0.895264] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)369vm-test-run-wal2json> server # [    0.897696] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)370vm-test-run-wal2json> server # [    0.899943] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)371vm-test-run-wal2json> server # [    0.901314] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)372vm-test-run-wal2json> server # [    0.904908] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)373vm-test-run-wal2json> server # [    0.907540] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)374vm-test-run-wal2json> server # [    0.925110] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled375vm-test-run-wal2json> server # [    0.935026] msm_serial: driver initialized376vm-test-run-wal2json> server # [    0.936602] SuperH (H)SCI(F) driver initialized377vm-test-run-wal2json> server # [    0.937719] STM32 USART driver initialized378vm-test-run-wal2json> server # [    0.990635] loop: module loaded379vm-test-run-wal2json> server # [    0.991315] virtio_blk virtio5: 2/0/0 default/read/poll queues380vm-test-run-wal2json> server # [    0.995846] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)381vm-test-run-wal2json> server # [    1.000187] Freeing initrd memory: 10684K382vm-test-run-wal2json> server # [    1.010273] megasas: 07.727.03.00-rc1383vm-test-run-wal2json> server # [    1.016477] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]384vm-test-run-wal2json> server # [    1.019477] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000385vm-test-run-wal2json> server # [    1.020215] Intel/Sharp Extended Query Table at 0x0031386vm-test-run-wal2json> server # [    1.023343] Using buffer write method387vm-test-run-wal2json> server # [    1.024260] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]388vm-test-run-wal2json> server # [    1.026103] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000389vm-test-run-wal2json> server # [    1.026920] Intel/Sharp Extended Query Table at 0x0031390vm-test-run-wal2json> server # [    1.028647] Using buffer write method391vm-test-run-wal2json> server # [    1.028945] Concatenating MTD devices:392vm-test-run-wal2json> server # [    1.029717] (0): "0.flash"393vm-test-run-wal2json> server # [    1.030112] (1): "0.flash"394vm-test-run-wal2json> server # [    1.030176] into device "0.flash"395vm-test-run-wal2json> server # [    1.056918] tun: Universal TUN/TAP device driver, 1.6396vm-test-run-wal2json> server # [    1.071142] thunder_xcv, ver 1.0397vm-test-run-wal2json> server # [    1.071502] thunder_bgx, ver 1.0398vm-test-run-wal2json> server # [    1.071682] nicpf, ver 1.0399vm-test-run-wal2json> server # [    1.075001] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version400vm-test-run-wal2json> server # [    1.075186] hns3: Copyright (c) 2017 Huawei Corporation.401vm-test-run-wal2json> server # [    1.075597] hclge is initializing402vm-test-run-wal2json> server # [    1.075900] e1000: Intel(R) PRO/1000 Network Driver403vm-test-run-wal2json> server # [    1.076282] e1000: Copyright (c) 1999-2006 Intel Corporation.404vm-test-run-wal2json> server # [    1.076518] e1000e: Intel(R) PRO/1000 Network Driver405vm-test-run-wal2json> server # [    1.076798] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.406vm-test-run-wal2json> server # [    1.077031] igb: Intel(R) Gigabit Ethernet Network Driver407vm-test-run-wal2json> server # [    1.077227] igb: Copyright (c) 2007-2014 Intel Corporation.408vm-test-run-wal2json> server # [    1.077795] igbvf: Intel(R) Gigabit Virtual Function Network Driver409vm-test-run-wal2json> server # [    1.078116] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.410vm-test-run-wal2json> server # [    1.079104] sky2: driver version 1.30411vm-test-run-wal2json> server # [    1.087537] ehci-pci 0000:00:0a.0: EHCI Host Controller412vm-test-run-wal2json> server # [    1.088274] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1413vm-test-run-wal2json> server # [    1.089810] usbcore: registered new interface driver usb-storage414vm-test-run-wal2json> server # [    1.090613] usbcore: registered new interface driver usbserial_generic415vm-test-run-wal2json> server # [    1.091754] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000416vm-test-run-wal2json> server # [    1.092005] usbserial: USB Serial support registered for generic417vm-test-run-wal2json> server # [    1.103191] rtc-pl031 9010000.pl031: registered as rtc0418vm-test-run-wal2json> server # [    1.104246] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00419vm-test-run-wal2json> server # [    1.104462] rtc-pl031 9010000.pl031: setting system clock to 2026-10-07T22:00:58 UTC (1791410458)420vm-test-run-wal2json> server # [    1.106962] i2c_dev: i2c /dev entries driver421vm-test-run-wal2json> server # [    1.112718] hub 1-0:1.0: USB hub found422vm-test-run-wal2json> server # [    1.113534] hub 1-0:1.0: 6 ports detected423vm-test-run-wal2json> server # [    1.121659] sdhci: Secure Digital Host Controller Interface driver424vm-test-run-wal2json> server # [    1.121850] sdhci: Copyright(c) Pierre Ossman425vm-test-run-wal2json> server # [    1.123386] Synopsys Designware Multimedia Card Interface Driver426vm-test-run-wal2json> server # [    1.125173] sdhci-pltfm: SDHCI platform and OF driver helper427vm-test-run-wal2json> server # [    1.132039] hid: raw HID events driver (C) Jiri Kosina428vm-test-run-wal2json> server # [    1.134454] usbcore: registered new interface driver usbhid429vm-test-run-wal2json> server # [    1.134635] usbhid: USB HID core driver430vm-test-run-wal2json> server # [    1.142678] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available431vm-test-run-wal2json> server # [    1.156531] drop_monitor: Initializing network drop monitor service432vm-test-run-wal2json> server # [    1.158472] NET: Registered PF_INET6 protocol family433vm-test-run-wal2json> server # [    1.174058] Segment Routing with IPv6434vm-test-run-wal2json> server # [    1.175154] In-situ OAM (IOAM) with IPv6435vm-test-run-wal2json> server # [    1.176698] NET: Registered PF_PACKET protocol family436vm-test-run-wal2json> server # [    1.178555] 9pnet: Installing 9P2000 support437vm-test-run-wal2json> server # [    1.182982] Key type dns_resolver registered438vm-test-run-wal2json> server # [    1.219289] registered taskstats version 1439vm-test-run-wal2json> server # [    1.221567] Loading compiled-in X.509 certificates440vm-test-run-wal2json> server # [    1.279965] Demotion targets for Node 0: null441vm-test-run-wal2json> server # [    1.282796] Key type .fscrypt registered442vm-test-run-wal2json> server # [    1.282941] Key type fscrypt-provisioning registered443vm-test-run-wal2json> server # [    1.291941] input: gpio-keys as /devices/platform/gpio-keys/input/input0444vm-test-run-wal2json> server # [    1.337271] clk: Disabling unused clocks445vm-test-run-wal2json> server # [    1.337565] PM: genpd: Disabling unused power domains446vm-test-run-wal2json> server # [    1.338350] ALSA device list:447vm-test-run-wal2json> server # [    1.338482]   No soundcards found.448vm-test-run-wal2json> server # [    1.421419] Freeing unused kernel memory: 4416K449vm-test-run-wal2json> server # [    1.422223] usb 1-1: new high-speed USB device number 2 using ehci-pci450vm-test-run-wal2json> server # [    1.424233] Run /init as init process451vm-test-run-wal2json> server # [    1.628406] 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/input1452vm-test-run-wal2json> server # [    1.765883] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0453vm-test-run-wal2json> server # [    1.894568] usb 1-2: new high-speed USB device number 3 using ehci-pci454vm-test-run-wal2json> server # [    2.033188] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev455vm-test-run-wal2json> server # [    2.079193] 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/input2456vm-test-run-wal2json> server # [    2.084563] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0457vm-test-run-wal2json> server # [    2.171220] [drm] pci: virtio-gpu-pci detected at 0000:00:09.0458vm-test-run-wal2json> server # [    2.171927] [drm] features: -virgl +edid -resource_blob -host_visible459vm-test-run-wal2json> server # [    2.171952] [drm] features: -context_init460vm-test-run-wal2json> server # [    2.174451] [drm] number of scanouts: 1461vm-test-run-wal2json> server # [    2.174583] [drm] number of cap sets: 0462vm-test-run-wal2json> server # [    2.184560] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:09.0 on minor 0463vm-test-run-wal2json> server # [    2.219020] Console: switching to colour frame buffer device 160x50464vm-test-run-wal2json> server # [    2.229806] virtio-pci 0000:00:09.0: [drm] fb0: virtio_gpudrmfb frame buffer device465vm-test-run-wal2json> server # [    5.021818] EXT4-fs (vda): mounted filesystem 24155e35-2eda-4194-b47d-451bbb0df075 r/w with ordered data mode. Quota mode: none.466vm-test-run-wal2json> server # [    7.255453] EXT4-fs (vda): re-mounted 24155e35-2eda-4194-b47d-451bbb0df075.467vm-test-run-wal2json> server # [    7.274164] booting system configuration /nix/store/md474dkd4ixy20nkn54m8m3fqy1z83lq-nixos-system-server-test468vm-test-run-wal2json> server # [   18.913941] 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)469vm-test-run-wal2json> server # [   18.923895] systemd[1]: Detected virtualization qemu.470vm-test-run-wal2json> server # [   18.927966] systemd[1]: Detected architecture arm64.471vm-test-run-wal2json> server # [   18.932358] systemd[1]: Detected first boot.472vm-test-run-wal2json> server # [   18.953689] systemd[1]: Initializing machine ID from random generator.473vm-test-run-wal2json> server # [   18.977899] systemd[1]: Hostname set to <server>.474vm-test-run-wal2json> server # [   20.142582] systemd[1]: bpf-restrict-fs: LSM BPF program attached475vm-test-run-wal2json> server # [   21.434217] NET: Registered PF_VSOCK protocol family476vm-test-run-wal2json> server # [   21.494454] Guest personality initialized and is inactive477vm-test-run-wal2json> server # [   21.501314] VMCI host device registered (name=vmci, major=10, minor=261)478vm-test-run-wal2json> server # [   21.504728] Initialized host personality479vm-test-run-wal2json> server # [   21.739200] systemd[1]: Applying preset policy.480vm-test-run-wal2json> server # [   25.209492] systemd[1]: Populated /etc with preset unit settings.481vm-test-run-wal2json> server # [   28.277458] systemd[1]: Queued start job for default target Multi-User System.482vm-test-run-wal2json> server # [   28.455398] systemd[1]: Created slice Slice /system/getty.483vm-test-run-wal2json> server # [   28.469186] systemd[1]: Created slice Slice /system/modprobe.484vm-test-run-wal2json> server # [   28.482371] systemd[1]: Created slice User and Session Slice.485vm-test-run-wal2json> server # [   28.490348] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.486vm-test-run-wal2json> server # [   28.495230] systemd[1]: Started Forward Password Requests to Wall Directory Watch.487vm-test-run-wal2json> server # [   28.500650] systemd[1]: Expecting device /dev/hvc0...488vm-test-run-wal2json> server # [   28.506593] systemd[1]: Expecting device /dev/ttyAMA0...489vm-test-run-wal2json> server # [   28.511281] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...490vm-test-run-wal2json> server # [   28.515290] systemd[1]: Reached target Local Encrypted Volumes.491vm-test-run-wal2json> server # [   28.519930] systemd[1]: Reached target Virtual Machines and Containers.492vm-test-run-wal2json> server # [   28.524329] systemd[1]: Reached target Path Units.493vm-test-run-wal2json> server # [   28.528867] systemd[1]: Reached target Remote File Systems.494vm-test-run-wal2json> server # [   28.533651] systemd[1]: Reached target Slice Units.495vm-test-run-wal2json> server # [   28.539058] systemd[1]: Reached target Swaps.496vm-test-run-wal2json> server # [   28.573940] systemd[1]: Listening on Process Core Dump Socket.497vm-test-run-wal2json> server # [   28.594974] systemd[1]: Listening on Credential Encryption/Decryption.498vm-test-run-wal2json> server # [   28.605496] systemd[1]: Listening on Journal Audit Socket.499vm-test-run-wal2json> server # [   28.611785] systemd[1]: Listening on Journal Socket (/dev/log).500vm-test-run-wal2json> server # [   28.617277] systemd[1]: Listening on Journal Sockets.501vm-test-run-wal2json> server # [   28.624446] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.502vm-test-run-wal2json> server # [   28.628175] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).503vm-test-run-wal2json> server # [   28.634681] systemd[1]: Listening on udev Control Socket.504vm-test-run-wal2json> server # [   28.639704] systemd[1]: Listening on udev Kernel Socket.505vm-test-run-wal2json> server # [   28.682394] systemd[1]: Mounting Huge Pages File System...506vm-test-run-wal2json> server # [   28.713644] systemd[1]: Mounting POSIX Message Queue File System...507vm-test-run-wal2json> server # [   28.755662] systemd[1]: Mounting Kernel Debug File System...508vm-test-run-wal2json> server # [   28.824246] systemd[1]: Mounting Kernel Trace File System...509vm-test-run-wal2json> server # [   28.976967] systemd[1]: Starting Create List of Static Device Nodes...510vm-test-run-wal2json> server # [   29.097494] systemd[1]: Starting Load Kernel Module 9pnet_virtio...511vm-test-run-wal2json> server # [   29.111967] systemd[1]: Load Kernel Module configfs was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!configfs).512vm-test-run-wal2json> server: Guest root shell did not produce any data yet...513vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.514vm-test-run-wal2json> server # [   29.323702] systemd[1]: Mounting Kernel Configuration File System...515vm-test-run-wal2json> server # [   29.338844] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).516vm-test-run-wal2json> server # [   29.353531] systemd[1]: Load Kernel Module efi_pstore was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!efi_pstore).517vm-test-run-wal2json> server # [   29.455615] systemd[1]: Starting Load Kernel Module fuse...518vm-test-run-wal2json> server # [   29.466229] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).519vm-test-run-wal2json> server # [   29.474669] 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).520vm-test-run-wal2json> server # [   29.560496] systemd[1]: Starting Journal Service...521vm-test-run-wal2json> server # [   29.632250] systemd[1]: Starting Load Kernel Modules...522vm-test-run-wal2json> server # [   29.734451] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...523vm-test-run-wal2json> server # [   29.793923] systemd[1]: Starting Remount Root and Kernel File Systems...524vm-test-run-wal2json> server # [   29.798553] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).525vm-test-run-wal2json> server # [   29.888830] systemd[1]: Starting Coldplug All udev Devices...526vm-test-run-wal2json> server # [   29.964685] systemd[1]: Mounted Huge Pages File System.527vm-test-run-wal2json> server # [   29.980007] systemd[1]: Mounted POSIX Message Queue File System.528vm-test-run-wal2json> server # [   29.990102] systemd[1]: Mounted Kernel Debug File System.529vm-test-run-wal2json> server # [   30.003538] systemd[1]: Mounted Kernel Trace File System.530vm-test-run-wal2json> server # [   30.030984] systemd[1]: Finished Create List of Static Device Nodes.531vm-test-run-wal2json> server # [   30.044900] systemd[1]: Mounted Kernel Configuration File System.532vm-test-run-wal2json> server # [   30.108829] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...533vm-test-run-wal2json> server # [   30.467771] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.534vm-test-run-wal2json> server # [   30.492065] systemd[1]: Finished Load Kernel Module 9pnet_virtio.535vm-test-run-wal2json> server # [   30.866848] systemd[1]: Finished Load Kernel Modules.536vm-test-run-wal2json> server # [   30.922992] systemd[1]: Starting Firewall...537vm-test-run-wal2json> server # [   30.929925] EXT4-fs (vda): re-mounted 24155e35-2eda-4194-b47d-451bbb0df075.538vm-test-run-wal2json> server # [   30.988456] fuse: init (API version 7.41)539vm-test-run-wal2json> server # [   31.013691] systemd[1]: Starting Apply Kernel Variables...540vm-test-run-wal2json> server # [   31.077197] systemd[1]: Finished Remount Root and Kernel File Systems.541vm-test-run-wal2json> server # [   31.088770] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).542vm-test-run-wal2json> server # [   31.154380] systemd[1]: Starting Load/Save OS Random Seed...543vm-test-run-wal2json> server # [   31.161988] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).544vm-test-run-wal2json> server # [   31.178114] systemd[1]: modprobe@fuse.service: Deactivated successfully.545vm-test-run-wal2json> server # [   31.202108] systemd[1]: Finished Load Kernel Module fuse.546vm-test-run-wal2json> server # [   31.242313] systemd[1]: Mounting FUSE Control File System...547vm-test-run-wal2json> server # [   31.446884] systemd-journald[397]: Collecting audit messages is enabled.548vm-test-run-wal2json> server # [   31.486126] systemd[1]: Mounted FUSE Control File System.549vm-test-run-wal2json> server # [   32.261064] systemd[1]: Finished Load/Save OS Random Seed.550vm-test-run-wal2json> server # [   32.278300] systemd[1]: Reached target First Boot Complete.551vm-test-run-wal2json> server # [   32.495969] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.552vm-test-run-wal2json> server # [   32.526998] systemd[1]: Finished Apply Kernel Variables.553vm-test-run-wal2json> server # [   32.630632] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.554vm-test-run-wal2json> server # [   32.712674] systemd[1]: Starting Create Static Device Nodes in /dev...555vm-test-run-wal2json> server # [   33.681409] systemd[1]: Finished Create Static Device Nodes in /dev.556vm-test-run-wal2json> server # [   33.705618] systemd[1]: Reached target Preparation for Local File Systems.557vm-test-run-wal2json> server # [   33.751418] systemd[1]: Mounting /run/wrappers...558vm-test-run-wal2json> server # [   33.817889] systemd[1]: Starting Rule-based Manager for Device Events and Files...559vm-test-run-wal2json> server # [   34.033347] systemd[1]: Started Journal Service.560vm-test-run-wal2json> server # [   33.955654] systemd-modules-load[398]: Module 'atkbd' is built in561vm-test-run-wal2json> server # [   33.970355] systemd-modules-load[398]: Module 'loop' is built in562vm-test-run-wal2json> server # [   34.006498] systemd-oomd[399]: No swap; memory pressure usage will be degraded563vm-test-run-wal2json> server # [   34.047221] systemd[1]: Starting Flush Journal to Persistent Storage...564vm-test-run-wal2json> server # [   34.235204] systemd[1]: Mounted /run/wrappers.565vm-test-run-wal2json> server # [   34.369310] systemd[1]: Reached target Local File Systems.566vm-test-run-wal2json> server # [   34.391154] systemd[1]: Listening on Boot Entries Service Socket.567vm-test-run-wal2json> server # [   34.429757] systemd[1]: Starting Create SUID/SGID Wrappers...568vm-test-run-wal2json> server # [   34.436442] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.569vm-test-run-wal2json> server # [   34.479576] systemd[1]: Starting Save Transient machine-id to Disk...570vm-test-run-wal2json> server # [   35.064204] systemd-journald[397]: Received client request to flush runtime journal.571vm-test-run-wal2json> server # [   35.794117] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.572vm-test-run-wal2json> server # [   35.803227] systemd[1]: Finished Save Transient machine-id to Disk.573vm-test-run-wal2json> server # [   35.845410] systemd-udevd[430]: Using default interface naming scheme 'v258'.574vm-test-run-wal2json> server # [   35.885183] systemd[1]: Finished Flush Journal to Persistent Storage.575vm-test-run-wal2json> server # [   35.912876] systemd[1]: Starting Create System Files and Directories...576vm-test-run-wal2json> server # [   37.995030] systemd[1]: Finished Create System Files and Directories.577vm-test-run-wal2json> server # [   38.089365] systemd[1]: Starting Rebuild Journal Catalog...578vm-test-run-wal2json> server # [   38.180172] systemd[1]: Starting Record System Boot/Shutdown in UTMP...579vm-test-run-wal2json> server # [   38.217448] systemd[1]: Started Rule-based Manager for Device Events and Files.580vm-test-run-wal2json> server # [   39.222285] systemd[1]: Finished Record System Boot/Shutdown in UTMP.581vm-test-run-wal2json> server # [   40.280521] systemd[1]: Finished Rebuild Journal Catalog.582vm-test-run-wal2json> server # [   40.344648] systemd[1]: Starting Update is Completed...583vm-test-run-wal2json> server # [   41.044478] systemd[1]: Finished Update is Completed.584vm-test-run-wal2json> server # [   44.185339] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.585vm-test-run-wal2json> server # [   44.195473] systemd[1]: Finished Create SUID/SGID Wrappers.586vm-test-run-wal2json> server # [   44.201404] systemd[1]: suid-sgid-wrappers.service: Consumed 2.622s CPU time, 5.6M memory peak.587vm-test-run-wal2json> server # [   46.343026] systemd[1]: Finished Firewall.588vm-test-run-wal2json> server # [   47.863188] systemd[1]: Finished Coldplug All udev Devices.589vm-test-run-wal2json> server # [   47.878109] systemd[1]: Reached target System Initialization.590vm-test-run-wal2json> server # [   47.889870] systemd[1]: Started Discard unused filesystem blocks once a week.591vm-test-run-wal2json> server # [   47.894342] systemd[1]: Started Daily Cleanup of Temporary Directories.592vm-test-run-wal2json> server # [   47.918579] systemd[1]: Reached target Timer Units.593vm-test-run-wal2json> server # [   47.929748] systemd[1]: Listening on D-Bus System Message Bus Socket.594vm-test-run-wal2json> server # [   47.933542] systemd[1]: Listening on Nix Daemon Socket.595vm-test-run-wal2json> server # [   47.955309] systemd[1]: Listening on OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local).596vm-test-run-wal2json> server # [   47.997811] systemd[1]: Starting OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK)...597vm-test-run-wal2json> server # [   48.002005] systemd[1]: Listening on Hostname Service Socket.598vm-test-run-wal2json> server # [   48.150150] (sh-issue)[631]: sshd-vsock.socket: Unable to locate executable '/usr/lib/systemd/systemd-ssh-issue': No such file or directory599vm-test-run-wal2json> server # [   48.185157] systemd[1]: Listening on OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK).600vm-test-run-wal2json> server # [   48.193136] systemd[1]: Reached target Socket Units.601vm-test-run-wal2json> server # [   48.199034] systemd[1]: Reached target Basic System.602vm-test-run-wal2json> server # [   48.233541] systemd[1]: Starting D-Bus System Message Bus...603vm-test-run-wal2json> server # [   48.269003] systemd[1]: Starting Import lastlog data into lastlog2 database...604vm-test-run-wal2json> server # [   48.321666] systemd[1]: Starting Name Service Cache Daemon (nsncd)...605vm-test-run-wal2json> server # [   48.352035] systemd[1]: Started Reset console on configuration changes.606vm-test-run-wal2json> server # [   48.400267] systemd[1]: Starting resolvconf update...607vm-test-run-wal2json> server # [   48.481783] systemd[1]: Starting SSH Host Keys Generation...608vm-test-run-wal2json> server # [   49.575647] systemd[1]: Finished Import lastlog data into lastlog2 database.609vm-test-run-wal2json> server # [   49.785644] dbus-daemon[633]: dbus[633]: Unknown username "systemd-timesync" in message bus configuration file610vm-test-run-wal2json> server # [   49.879617] systemd[1]: Started Name Service Cache Daemon (nsncd).611vm-test-run-wal2json> server # [   49.902593] systemd[1]: Reached target Host and Network Name Lookups.612vm-test-run-wal2json> server # [   49.940754] systemd[1]: Reached target User and Group Name Lookups.613vm-test-run-wal2json> server # [   49.968060] nsncd[635]: Oct 07 22:01:47.365 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"614vm-test-run-wal2json> server # [   49.997113] systemd[1]: Starting User Login Management...615vm-test-run-wal2json> server # [   50.484798] systemd[1]: Started D-Bus System Message Bus.616vm-test-run-wal2json> server # [   51.623613] systemd-logind[657]: New seat seat0.617vm-test-run-wal2json> server # [   51.679450] systemd[1]: Started User Login Management.618vm-test-run-wal2json> server # [   51.739993] systemd[1]: Starting linger-users.service...619vm-test-run-wal2json> server # [   51.979266] systemd[1]: Stopped target Host and Network Name Lookups.620vm-test-run-wal2json> server # [   51.986241] systemd[1]: Stopping Host and Network Name Lookups...621vm-test-run-wal2json> server # [   52.003358] systemd[1]: Stopped target User and Group Name Lookups.622vm-test-run-wal2json> server # [   52.008701] systemd[1]: Stopping User and Group Name Lookups...623vm-test-run-wal2json> server # [   52.018298] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...624vm-test-run-wal2json> server # [   52.087566] systemd[1]: nscd.service: Deactivated successfully.625vm-test-run-wal2json> server # [   52.118620] systemd[1]: Stopped Name Service Cache Daemon (nsncd).626vm-test-run-wal2json> server # [   52.245594] systemd[1]: Starting Name Service Cache Daemon (nsncd)...627vm-test-run-wal2json> server # [   52.412851] systemd[1]: linger-users.service: Deactivated successfully.628vm-test-run-wal2json> server # [   52.435662] systemd[1]: Finished linger-users.service.629vm-test-run-wal2json> server # [   52.919719] nsncd[714]: Oct 07 22:01:50.436 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"630vm-test-run-wal2json> server # [   52.939945] systemd[1]: Started Name Service Cache Daemon (nsncd).631vm-test-run-wal2json> server # [   52.950620] systemd[1]: Reached target Host and Network Name Lookups.632vm-test-run-wal2json> server # [   52.953421] systemd[1]: Reached target User and Group Name Lookups.633vm-test-run-wal2json> server # [   53.503353] systemd[1]: Finished resolvconf update.634vm-test-run-wal2json> server # [   53.516279] systemd[1]: Reached target Preparation for Network.635vm-test-run-wal2json> server # [   53.567372] systemd[1]: Starting DHCP Client...636vm-test-run-wal2json> server # [   55.217419] dhcpcd[750]: dhcpcd-10.2.4 starting637vm-test-run-wal2json> server # [   55.383981] dhcpcd[774]: dev: loaded udev638vm-test-run-wal2json> server # [   55.780589] 8021q: 802.1Q VLAN Support v1.8639vm-test-run-wal2json> server # [   56.183975] cfg80211: Loading compiled-in X.509 certificates for regulatory database640vm-test-run-wal2json> server # [   56.434896] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'641vm-test-run-wal2json> server # [   56.445182] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'642vm-test-run-wal2json> server # [   56.476314] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2643vm-test-run-wal2json> server # [   56.480810] cfg80211: failed to load regulatory.db644vm-test-run-wal2json> server # [   57.586456] 8021q: adding VLAN 0 to HW filter on device eth0645vm-test-run-wal2json> server # [   57.483818] dhcpcd[774]: eth0: waiting for carrier646vm-test-run-wal2json> server # [   57.513080] dhcpcd[774]: libudev: received NULL device647vm-test-run-wal2json> server # [   57.522793] dhcpcd[774]: libudev: received NULL device648vm-test-run-wal2json> server # [   57.529555] dhcpcd[774]: eth0: carrier acquired649vm-test-run-wal2json> server # [   57.669265] dhcpcd[774]: DUID 00:01:00:01:32:59:7d:d3:52:54:00:12:34:56650vm-test-run-wal2json> server # [   57.671438] dhcpcd[774]: eth0: IAID 00:12:34:56651vm-test-run-wal2json> server # [   57.673635] dhcpcd[774]: eth0: adding address fe80::5054:ff:fe12:3456652vm-test-run-wal2json> server # [   57.981178] sshd-keygen-start[660]: Generating public/private rsa key pair.653vm-test-run-wal2json> server # [   57.984903] sshd-keygen-start[660]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key654vm-test-run-wal2json> server # [   57.989201] sshd-keygen-start[660]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub655vm-test-run-wal2json> server # [   57.997319] sshd-keygen-start[660]: The key fingerprint is:656vm-test-run-wal2json> server # [   57.999960] sshd-keygen-start[660]: SHA256:YM4H92d8CpDCw5zuflPeA00BpxzA1hcp4p8PsJDc6BM root@server657vm-test-run-wal2json> server # [   58.001942] sshd-keygen-start[660]: The key's randomart image is:658vm-test-run-wal2json> server # [   58.002860] sshd-keygen-start[660]: +---[RSA 4096]----+659vm-test-run-wal2json> server # [   58.004089] sshd-keygen-start[660]: |       ..oo.oo   |660vm-test-run-wal2json> server # [   58.005766] sshd-keygen-start[660]: |     + .+oo++    |661vm-test-run-wal2json> server # [   58.007226] sshd-keygen-start[660]: |     .@*+.oo .   |662vm-test-run-wal2json> server # [   58.008631] sshd-keygen-start[660]: |     =E*+o ..    |663vm-test-run-wal2json> server # [   58.009709] sshd-keygen-start[660]: |     .+oS+o++ .  |664vm-test-run-wal2json> server # [   58.013763] sshd-keygen-start[660]: |     .o.. *+.o   |665vm-test-run-wal2json> server # [   58.015231] sshd-keygen-start[660]: |      .. o =.    |666vm-test-run-wal2json> server # [   58.022202] sshd-keygen-start[660]: |     .  o . +    |667vm-test-run-wal2json> server # [   58.029754] sshd-keygen-start[660]: |      .. .   .   |668vm-test-run-wal2json> server # [   58.031283] sshd-keygen-start[660]: +----[SHA256]-----+669vm-test-run-wal2json> server # [   58.495608] sshd-keygen-start[813]: Generating public/private ed25519 key pair.670vm-test-run-wal2json> server # [   58.500079] sshd-keygen-start[813]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key671vm-test-run-wal2json> server # [   58.503451] sshd-keygen-start[813]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub672vm-test-run-wal2json> server # [   58.505589] sshd-keygen-start[813]: The key fingerprint is:673vm-test-run-wal2json> server # [   58.510764] sshd-keygen-start[813]: SHA256:UXtDowz+IuR3hIcdnJWqD4F5/5VWkeikR9bpHURiFzw root@server674vm-test-run-wal2json> server # [   58.513745] sshd-keygen-start[813]: The key's randomart image is:675vm-test-run-wal2json> server # [   58.521302] sshd-keygen-start[813]: +--[ED25519 256]--+676vm-test-run-wal2json> server # [   58.523837] sshd-keygen-start[813]: |        ..oo++*=+|677vm-test-run-wal2json> server # [   58.537090] sshd-keygen-start[813]: |       . Bo=o*oE |678vm-test-run-wal2json> server # [   58.545103] sshd-keygen-start[813]: |      .o= B.O . =|679vm-test-run-wal2json> server # [   58.553010] sshd-keygen-start[813]: |     oo o=.o + .o|680vm-test-run-wal2json> server # [   58.558737] sshd-keygen-start[813]: |      o.S+o .  o |681vm-test-run-wal2json> server # [   58.562220] sshd-keygen-start[813]: |       ooo.   +  |682vm-test-run-wal2json> server # [   58.563035] sshd-keygen-start[813]: |         o . o   |683vm-test-run-wal2json> server # [   58.573438] sshd-keygen-start[813]: |          . .    |684vm-test-run-wal2json> server # [   58.574954] sshd-keygen-start[813]: |                 |685vm-test-run-wal2json> server # [   58.575974] sshd-keygen-start[813]: +----[SHA256]-----+686vm-test-run-wal2json> server # [   58.580992] systemd[1]: sshd-keygen.service: Deactivated successfully.687vm-test-run-wal2json> server # [   58.582344] systemd[1]: Finished SSH Host Keys Generation.688vm-test-run-wal2json> server # [   58.583802] systemd[1]: sshd-keygen.service: Consumed 4.941s CPU time, 2.9M memory peak.689vm-test-run-wal2json> server # [   58.662888] dhcpcd[774]: eth0: soliciting a DHCP lease690vm-test-run-wal2json> server # [   58.695160] dhcpcd[774]: eth0: offered 10.0.2.15 from 10.0.2.2691vm-test-run-wal2json> server # [   58.719749] dhcpcd[774]: eth0: probing address 10.0.2.15/24692vm-test-run-wal2json> server # [   58.847083] systemd[1]: Found device /dev/hvc0.693vm-test-run-wal2json> server: Guest root shell did not produce any data yet...694vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.695vm-test-run-wal2json> server # [   60.123218] systemd[1]: Found device /dev/ttyAMA0.696vm-test-run-wal2json> server # [   60.189580] dhcpcd[774]: eth0: soliciting an IPv6 router697vm-test-run-wal2json> server # [   60.194187] dhcpcd[774]: eth0: Router Advertisement from fe80::2698vm-test-run-wal2json> server # [   60.202114] systemd[1]: Started backdoor.service.699vm-test-run-wal2json> server # [   60.210958] dhcpcd[774]: eth0: adding address fec0::5054:ff:fe12:3456/64700vm-test-run-wal2json> server # [   60.214100] dhcpcd[774]: eth0: adding route to fec0::/64701vm-test-run-wal2json> server # [   60.219421] dhcpcd[774]: eth0: adding default route via fe80::2702vm-test-run-wal2json> server # connecting to host...703vm-test-run-wal2json> server: Guest shell says: b'Spawning backdoor root shell...\n'704vm-test-run-wal2json> server: connected to guest root shell705vm-test-run-wal2json> server: (connecting took 61.98 seconds)706vm-test-run-wal2json> server: (finished: waiting for the VM to finish booting, in 61.98 seconds)707vm-test-run-wal2json> server # [   61.118381] (udev-worker)[834]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.708vm-test-run-wal2json> server # [   61.180994] (udev-worker)[834]: Network interface NamePolicy= disabled on kernel command line.709vm-test-run-wal2json> server # [   62.195264] (udev-worker)[818]: Network interface NamePolicy= disabled on kernel command line.710vm-test-run-wal2json> server # [   63.131952] systemd[1]: Found device Virtio network device.711vm-test-run-wal2json> server # [   63.178538] systemd[1]: Starting Address configuration of eth1...712vm-test-run-wal2json> server # [   63.355263] dhcpcd[774]: eth0: IAID 00:12:34:56713vm-test-run-wal2json> server # [   63.902239] 8021q: adding VLAN 0 to HW filter on device eth1714vm-test-run-wal2json> server # [   63.968962] network-addresses-eth1-start[859]: adding address 192.168.1.1/24... done715vm-test-run-wal2json> server # [   63.973214] dhcpcd[774]: eth0: soliciting a DHCP lease716vm-test-run-wal2json> server # [   63.975479] dhcpcd[774]: eth0: offered 10.0.2.15 from 10.0.2.2717vm-test-run-wal2json> server # [   63.978452] dhcpcd[774]: eth0: probing address 10.0.2.15/24718vm-test-run-wal2json> server # [   64.083195] network-addresses-eth1-start[859]: adding address 2001:db8:1::1/64... done719vm-test-run-wal2json> server # [   64.201422] dhcpcd[774]: eth0: soliciting an IPv6 router720vm-test-run-wal2json> server # [   64.432468] systemd[1]: Finished Address configuration of eth1.721vm-test-run-wal2json> server # [   64.497195] systemd[1]: Starting Networking Setup...722vm-test-run-wal2json> server # [   65.381610] dhcpcd[774]: eth0: leased 10.0.2.15 for 86400 seconds723vm-test-run-wal2json> server # [   65.393268] dhcpcd[774]: eth0: adding route to 10.0.2.0/24724vm-test-run-wal2json> server # [   65.395310] dhcpcd[774]: eth0: adding default route via 10.0.2.2725vm-test-run-wal2json> server # [   66.231662] dhcpcd[906]: /nix/store/hsj50yr7hr62ql9xaynbihkhfhbgprcn-openresolv-3.17.0/sbin/.resolvconf-wrapped: line 1221: kill: (885) - Operation not permitted726vm-test-run-wal2json> server # [   66.246449] dhcpcd[906]: clearing stale lock pid 885727vm-test-run-wal2json> server # [   67.790955] systemd[1]: Finished Networking Setup.728vm-test-run-wal2json> server # [   67.815609] systemd[1]: Reached target Network.729vm-test-run-wal2json> server # [   67.892882] systemd[1]: Starting PostgreSQL Server...730vm-test-run-wal2json> server # [   67.931514] systemd[1]: Starting SSH Daemon...731vm-test-run-wal2json> server # [   68.014989] systemd[1]: Starting Permit User Sessions...732vm-test-run-wal2json> server # [   69.103892] systemd[1]: Finished Permit User Sessions.733vm-test-run-wal2json> server # [   69.146213] systemd[1]: Started Getty on tty1.734vm-test-run-wal2json> server # [   69.171034] systemd[1]: Reached target Login Prompts.735vm-test-run-wal2json> server # [   69.517529] sshd[984]: Server listening on 0.0.0.0 port 22.736vm-test-run-wal2json> server # [   69.537031] sshd[984]: Server listening on :: port 22.737vm-test-run-wal2json> server # [   69.539468] systemd[1]: Started SSH Daemon.738vm-test-run-wal2json> server # [   70.265474] systemd[1]: Started DHCP Client.739vm-test-run-wal2json> server # [   71.964414] postgresql-pre-start[1010]: The files belonging to this database system will be owned by user "postgres".740vm-test-run-wal2json> server # [   71.972384] postgresql-pre-start[1010]: This user must also own the server process.741vm-test-run-wal2json> server # [   72.036177] postgresql-pre-start[1010]: The database cluster will be initialized with locale "en_US.UTF-8".742vm-test-run-wal2json> server # [   72.041884] postgresql-pre-start[1010]: The default database encoding has accordingly been set to "UTF8".743vm-test-run-wal2json> server # [   72.043189] postgresql-pre-start[1010]: The default text search configuration will be set to "english".744vm-test-run-wal2json> server # [   72.043635] postgresql-pre-start[1010]: Data page checksums are disabled.745vm-test-run-wal2json> server # [   72.044040] postgresql-pre-start[1010]: fixing permissions on existing directory /var/lib/postgresql/15 ... ok746vm-test-run-wal2json> server # [   72.059677] postgresql-pre-start[1010]: creating subdirectories ... ok747vm-test-run-wal2json> server # [   72.069344] postgresql-pre-start[1010]: selecting dynamic shared memory implementation ... posix748vm-test-run-wal2json> server # [   73.269849] postgresql-pre-start[1010]: selecting default max_connections ... 100749vm-test-run-wal2json> server # [   74.139993] postgresql-pre-start[1010]: selecting default shared_buffers ... 128MB750vm-test-run-wal2json> server # [   76.998225] systemd-logind[657]: Watching system buttons on /dev/input/event0 (gpio-keys)751vm-test-run-wal2json> server # [   87.038295] mousedev: PS/2 mouse device common for all mice752vm-test-run-wal2json> server # [   87.540936] postgresql-pre-start[1010]: selecting default time zone ... UTC753vm-test-run-wal2json> server # [   87.590859] postgresql-pre-start[1010]: creating configuration files ... ok754vm-test-run-wal2json> server # [   91.304534] systemd-logind[657]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)755vm-test-run-wal2json> server # [   92.682331] postgresql-pre-start[1010]: running bootstrap script ... ok756vm-test-run-wal2json> server # [  106.607779] postgresql-pre-start[1010]: performing post-bootstrap initialization ... ok757vm-test-run-wal2json> server # [  109.645391] postgresql-pre-start[1010]: syncing data to disk ... ok758vm-test-run-wal2json> server # [  109.649805] postgresql-pre-start[1010]: initdb: warning: enabling "trust" authentication for local connections759vm-test-run-wal2json> server # [  109.651222] postgresql-pre-start[1010]: 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.760vm-test-run-wal2json> server # [  109.652034] postgresql-pre-start[1010]: Success. You can now start the database server using:761vm-test-run-wal2json> server # [  109.653083] postgresql-pre-start[1010]:     /nix/store/781kj061s41a7j3vkcys4m78m94c6rv4-postgresql-15-wal2json/bin/pg_ctl -D /var/lib/postgresql/15 -l logfile start762vm-test-run-wal2json> server # [  111.699517] postgres[1395]: [1395] LOG:  starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit763vm-test-run-wal2json> server # [  111.706964] postgres[1395]: [1395] LOG:  listening on IPv4 address "0.0.0.0", port 5432764vm-test-run-wal2json> server # [  111.711994] postgres[1395]: [1395] LOG:  listening on IPv6 address "::", port 5432765vm-test-run-wal2json> server # [  111.724980] postgres[1395]: [1395] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"766vm-test-run-wal2json> server # [  111.884053] postgres[1407]: [1407] LOG:  database system was shut down at 2026-10-07 22:02:44 GMT767vm-test-run-wal2json> server # [  112.080970] postgres[1395]: [1395] LOG:  database system is ready to accept connections768vm-test-run-wal2json> server # [  112.123531] systemd[1]: Started PostgreSQL Server.769vm-test-run-wal2json> server # [  112.211092] systemd[1]: Starting PostgreSQL Setup Scripts...770vm-test-run-wal2json> server # [  114.401882] postgresql-setup-start[1447]: CREATE ROLE771vm-test-run-wal2json> server # [  114.623946] postgresql-setup-start[1449]: ALTER ROLE772vm-test-run-wal2json> server # [  114.690920] systemd[1]: Finished PostgreSQL Setup Scripts.773vm-test-run-wal2json> server # [  114.706007] systemd[1]: Reached target PostgreSQL.774vm-test-run-wal2json> server # [  114.711583] systemd[1]: Reached target Multi-User System.775vm-test-run-wal2json> server # [  114.720956] systemd[1]: Startup finished in 18.186s (kernel) + 1min 36.519s (userspace) = 1min 54.705s.776vm-test-run-wal2json> server: (finished: waiting for unit multi-user.target, in 116.97 seconds)777vm-test-run-wal2json> server: waiting for unit postgresql.service778vm-test-run-wal2json> server: (finished: waiting for unit postgresql.service, in 1.11 seconds)779vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE SCHEMA IF NOT EXISTS public;" 780vm-test-run-wal2json> server # NOTICE:  schema "public" already exists, skipping781vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE SCHEMA IF NOT EXISTS public;" , in 0.47 seconds)782vm-test-run-wal2json> subtest: Check upgrade path with postgresql 15783vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 784vm-test-run-wal2json> server # NOTICE:  extension "wal2json" does not exist, skipping785vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.51 seconds)786vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 787vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" , in 0.94 seconds)788vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 789vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" , in 0.69 seconds)790vm-test-run-wal2json> (finished: subtest: Check upgrade path with postgresql 15, in 2.14 seconds)791vm-test-run-wal2json> subtest: Check pg_regress with postgresql 15 after extension upgrade792vm-test-run-wal2json> server: must succeed: sudo -u postgres /nix/store/781kj061s41a7j3vkcys4m78m94c6rv4-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 "wal2json" 793vm-test-run-wal2json> server # [  120.593478] sudo[1516]:     root : TTY=hvc0 ; PWD=/tmp ; USER=postgres ; COMMAND=/nix/store/781kj061s41a7j3vkcys4m78m94c6rv4-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 wal2json794vm-test-run-wal2json> server # [  120.813872] sudo[1516]: pam_unix(sudo:session): session opened for user postgres(uid=71) by (uid=0)795vm-test-run-wal2json> server # pg_regress: could not set core size: disallowed by hard limit796vm-test-run-wal2json> server # [  121.755243] postgres[1530]: [1530] LOG:  logical decoding found consistent point at 0/152AC48797vm-test-run-wal2json> server # [  121.759444] postgres[1530]: [1530] DETAIL:  There are no running transactions.798vm-test-run-wal2json> server # [  121.763386] postgres[1530]: [1530] STATEMENT:  select799vm-test-run-wal2json> server # [  121.769355] postgres[1530]: 	  1800vm-test-run-wal2json> server # [  121.770612] postgres[1530]: 	from801vm-test-run-wal2json> server # [  121.770959] postgres[1530]: 	  pg_create_logical_replication_slot('reg_test', 'wal2json', false);802vm-test-run-wal2json> server # [  121.885839] postgres[1530]: [1530] LOG:  starting logical decoding for slot "reg_test"803vm-test-run-wal2json> server # [  121.893730] postgres[1530]: [1530] DETAIL:  Streaming transactions committing after 0/152AC80, reading WAL from 0/152AC48.804vm-test-run-wal2json> server # [  121.896148] postgres[1530]: [1530] STATEMENT:  select805vm-test-run-wal2json> server # [  121.900887] postgres[1530]: 	  data806vm-test-run-wal2json> server # [  121.917642] postgres[1530]: 	from807vm-test-run-wal2json> server # [  121.925121] postgres[1530]: 	  pg_logical_slot_get_changes(808vm-test-run-wal2json> server # [  121.927780] postgres[1530]: 		'reg_test',809vm-test-run-wal2json> server # [  121.934590] postgres[1530]: 	    null,810vm-test-run-wal2json> server # [  121.942531] postgres[1530]: 	    null,811vm-test-run-wal2json> server # [  121.950602] postgres[1530]: 		'include-pk', 'true',812vm-test-run-wal2json> server # [  121.953033] postgres[1530]: 		'include-transaction', 'false',813vm-test-run-wal2json> server # [  121.953727] postgres[1530]: 		'include-timestamp', 'false',814vm-test-run-wal2json> server # [  121.954520] postgres[1530]: 		'include-type-oids', 'true',815vm-test-run-wal2json> server # [  121.955419] postgres[1530]: 		'format-version', '2',816vm-test-run-wal2json> server # [  121.970680] postgres[1530]: 		'actions', 'insert,update,delete',817vm-test-run-wal2json> server # [  121.971428] postgres[1530]: 		'add-tables', 'v.foo'818vm-test-run-wal2json> server # [  121.972207] postgres[1530]: 	  ) x;819vm-test-run-wal2json> server # [  121.975685] postgres[1530]: [1530] LOG:  logical decoding found consistent point at 0/152AC48820vm-test-run-wal2json> server # [  121.985817] postgres[1530]: [1530] DETAIL:  There are no running transactions.821vm-test-run-wal2json> server # [  121.987408] postgres[1530]: [1530] STATEMENT:  select822vm-test-run-wal2json> server # [  121.988938] postgres[1530]: 	  data823vm-test-run-wal2json> server # [  121.989524] postgres[1530]: 	from824vm-test-run-wal2json> server # [  121.993493] postgres[1530]: 	  pg_logical_slot_get_changes(825vm-test-run-wal2json> server # [  121.995009] postgres[1530]: 		'reg_test',826vm-test-run-wal2json> server # [  121.995373] postgres[1530]: 	    null,827vm-test-run-wal2json> server # [  121.995615] postgres[1530]: 	    null,828vm-test-run-wal2json> server # [  121.995951] postgres[1530]: 		'include-pk', 'true',829vm-test-run-wal2json> server # [  121.996186] postgres[1530]: 		'include-transaction', 'false',830vm-test-run-wal2json> server # [  121.997032] postgres[1530]: 		'include-timestamp', 'false',831vm-test-run-wal2json> server # [  121.997668] postgres[1530]: 		'include-type-oids', 'true',832vm-test-run-wal2json> server # [  121.998828] postgres[1530]: 		'format-version', '2',833vm-test-run-wal2json> server # [  121.999920] postgres[1530]: 		'actions', 'insert,update,delete',834vm-test-run-wal2json> server # [  122.000397] postgres[1530]: 		'add-tables', 'v.foo'835vm-test-run-wal2json> server # [  122.003781] postgres[1530]: 	  ) x;836vm-test-run-wal2json> server # [  122.443778] sudo[1516]: pam_unix(sudo:session): session closed for user postgres837vm-test-run-wal2json> server: (finished: must succeed: sudo -u postgres /nix/store/781kj061s41a7j3vkcys4m78m94c6rv4-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 "wal2json" , in 2.80 seconds)838vm-test-run-wal2json> (using postmaster on Unix socket, default port)839vm-test-run-wal2json> ============== running regression test queries        ==============840vm-test-run-wal2json> test wal2json                     ... ok         1234 ms841vm-test-run-wal2json> 842vm-test-run-wal2json> =====================843vm-test-run-wal2json>  All 1 tests passed. 844vm-test-run-wal2json> =====================845vm-test-run-wal2json> 846vm-test-run-wal2json> 847vm-test-run-wal2json> (finished: subtest: Check pg_regress with postgresql 15 after extension upgrade, in 2.80 seconds)848vm-test-run-wal2json> subtest: Check the install of the last version of the extension849vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 850vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.58 seconds)851vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 852vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" , in 0.53 seconds)853vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 854vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" , in 0.57 seconds)855vm-test-run-wal2json> (finished: subtest: Check the install of the last version of the extension, in 1.67 seconds)856vm-test-run-wal2json> subtest: switch to postgresql 17857vm-test-run-wal2json> server # Checking switch inhibitors... done858vm-test-run-wal2json> server # stopping the following units: postgresql-setup.service, postgresql.service859vm-test-run-wal2json> server # [  134.836158] nixos[1570]: switching to system configuration /nix/store/pm6kclvckraz7gg68mm9kvdwg0239sbj-nixos-system-server-test860vm-test-run-wal2json> server # [  134.895582] systemd[1]: Stopped target Remote File Systems.861vm-test-run-wal2json> server # [  134.928857] systemd[1]: Stopped target Local File Systems.862vm-test-run-wal2json> server # [  134.995066] systemd[1]: Stopped target PostgreSQL.863vm-test-run-wal2json> server # [  135.002874] systemd[1]: postgresql-setup.service: Deactivated successfully.864vm-test-run-wal2json> server # [  135.019695] systemd[1]: Stopped PostgreSQL Setup Scripts.865vm-test-run-wal2json> server # [  135.048242] postgres[1395]: [1395] LOG:  received fast shutdown request866vm-test-run-wal2json> server # [  135.059200] postgres[1395]: [1395] LOG:  aborting any active transactions867vm-test-run-wal2json> server # [  135.067220] systemd[1]: Stopping PostgreSQL Server...868vm-test-run-wal2json> server # [  135.169731] postgres[1395]: [1395] LOG:  background worker "logical replication launcher" (PID 1416) exited with exit code 1869vm-test-run-wal2json> server # [  135.197617] postgres[1405]: [1405] LOG:  shutting down870vm-test-run-wal2json> server # [  135.203977] postgres[1405]: [1405] LOG:  checkpoint starting: shutdown immediate871vm-test-run-wal2json> server # [  135.407840] postgres[1405]: [1405] LOG:  checkpoint complete: wrote 54 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.056 s, sync=0.084 s, total=0.223 s; sync files=48, longest=0.018 s, average=0.002 s; distance=149 kB, estimate=149 kB872vm-test-run-wal2json> server # [  135.484401] postgres[1395]: [1395] LOG:  database system is shut down873vm-test-run-wal2json> server # [  135.569740] systemd[1]: postgresql.service: Deactivated successfully.874vm-test-run-wal2json> server # [  135.578147] systemd[1]: Stopped PostgreSQL Server.875vm-test-run-wal2json> server # [  135.586068] systemd[1]: postgresql.service: Consumed 22.683s CPU time, 91M memory peak, 46.1M written to disk.876vm-test-run-wal2json> server # activating the configuration...877vm-test-run-wal2json> server # setting up /etc...878vm-test-run-wal2json> server # [  144.507797] systemd[1]: Reload requested from client PID 1570 ('.switch-to-conf') (unit backdoor.service)...879vm-test-run-wal2json> server # [  144.514059] systemd[1]: Reloading...880vm-test-run-wal2json> server # [  151.094448] systemd[1]: Reloading finished in 6563 ms.881vm-test-run-wal2json> server # restarting sysinit-reactivation.target882vm-test-run-wal2json> server # [  151.555389] systemd[1]: Starting Re-setup tmpfiles on a system that is already running....883vm-test-run-wal2json> server # [  153.183493] systemd[1]: Finished Re-setup tmpfiles on a system that is already running..884vm-test-run-wal2json> server # [  153.219903] systemd[1]: Reached target Reactivate sysinit units.885vm-test-run-wal2json> server # reloading the following units: dbus.service886vm-test-run-wal2json> server # [  153.295530] systemd[1]: Reloading D-Bus System Message Bus...887vm-test-run-wal2json> server # [  153.843845] dbus-daemon[633]: Unknown username "systemd-timesync" in message bus configuration file888vm-test-run-wal2json> server # [  154.211995] dbus-daemon[633]: [system] Reloaded configuration889vm-test-run-wal2json> server # [  154.224207] dbus-send[1781]: method return time=1791410611.730517 sender=org.freedesktop.DBus -> destination=:1.5 serial=3 reply_serial=2890vm-test-run-wal2json> server # [  154.290100] systemd[1]: Reloaded D-Bus System Message Bus.891vm-test-run-wal2json> server # [  154.412242] dbus-daemon[633]: Unknown username "systemd-timesync" in message bus configuration file892vm-test-run-wal2json> server # [  154.762066] dbus-daemon[633]: [system] Reloaded configuration893vm-test-run-wal2json> server # starting the following units: postgresql-setup.service, postgresql.service894vm-test-run-wal2json> server # [  154.918119] systemd[1]: Starting postgresql-migrate.service...895vm-test-run-wal2json> server # [  155.049179] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).896vm-test-run-wal2json> server # [  155.061704] systemd[1]: Reached target Local File Systems.897vm-test-run-wal2json> server # [  155.117013] systemd[1]: Reached target Remote File Systems.898vm-test-run-wal2json> server # [  155.164862] systemd[1]: Starting linger-users.service...899vm-test-run-wal2json> server # [  155.166287] systemd[1]: SSH Host Keys Generation was skipped because no trigger condition checks were met.900vm-test-run-wal2json> server # [  155.213480] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).901vm-test-run-wal2json> server # [  155.533292] systemd[1]: Load Kernel Module efi_pstore was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!efi_pstore).902vm-test-run-wal2json> server # [  155.576170] systemd[1]: Starting Create SUID/SGID Wrappers...903vm-test-run-wal2json> server # [  155.583639] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.904vm-test-run-wal2json> server # [  155.598655] 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).905vm-test-run-wal2json> server # [  155.615047] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).906vm-test-run-wal2json> server # [  155.616782] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).907vm-test-run-wal2json> server # [  155.644735] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).908vm-test-run-wal2json> server # [  155.838740] systemd[1]: linger-users.service: Deactivated successfully.909vm-test-run-wal2json> server # [  155.851298] systemd[1]: Finished linger-users.service.910vm-test-run-wal2json> server # [  157.563187] postgresql-migrate-start[1810]: The files belonging to this database system will be owned by user "postgres".911vm-test-run-wal2json> server # [  157.569806] postgresql-migrate-start[1810]: This user must also own the server process.912vm-test-run-wal2json> server # [  157.684363] postgresql-migrate-start[1810]: The database cluster will be initialized with locale "en_US.UTF-8".913vm-test-run-wal2json> server # [  157.686895] postgresql-migrate-start[1810]: The default database encoding has accordingly been set to "UTF8".914vm-test-run-wal2json> server # [  157.696212] postgresql-migrate-start[1810]: The default text search configuration will be set to "english".915vm-test-run-wal2json> server # [  157.706325] postgresql-migrate-start[1810]: Data page checksums are disabled.916vm-test-run-wal2json> server # [  157.710639] postgresql-migrate-start[1810]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok917vm-test-run-wal2json> server # [  157.711446] postgresql-migrate-start[1810]: creating subdirectories ... ok918vm-test-run-wal2json> server # [  157.713655] postgresql-migrate-start[1810]: selecting dynamic shared memory implementation ... posix919vm-test-run-wal2json> server # [  159.500128] postgresql-migrate-start[1810]: selecting default "max_connections" ... 100920vm-test-run-wal2json> server # [  160.555094] postgresql-migrate-start[1810]: selecting default "shared_buffers" ... 128MB921vm-test-run-wal2json> server # [  164.636947] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.922vm-test-run-wal2json> server # [  164.647554] systemd[1]: Finished Create SUID/SGID Wrappers.923vm-test-run-wal2json> server # [  164.659765] systemd[1]: suid-sgid-wrappers.service: Consumed 3.603s CPU time, 3.3M memory peak.924vm-test-run-wal2json> server # [  172.039253] postgresql-migrate-start[1810]: selecting default time zone ... UTC925vm-test-run-wal2json> server # [  172.086598] postgresql-migrate-start[1810]: creating configuration files ... ok926vm-test-run-wal2json> server # [  176.238956] postgresql-migrate-start[1810]: running bootstrap script ... ok927vm-test-run-wal2json> server # [  183.508257] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:08.0/virtio7/input/input3928vm-test-run-wal2json> server # [  185.811136] postgresql-migrate-start[1810]: performing post-bootstrap initialization ... ok929vm-test-run-wal2json> server # [  188.100096] postgresql-migrate-start[1810]: syncing data to disk ... ok930vm-test-run-wal2json> server # [  188.101812] postgresql-migrate-start[1810]: initdb: warning: enabling "trust" authentication for local connections931vm-test-run-wal2json> server # [  188.102399] postgresql-migrate-start[1810]: 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.932vm-test-run-wal2json> server # [  188.103904] postgresql-migrate-start[1810]: Success. You can now start the database server using:933vm-test-run-wal2json> server # [  188.105353] postgresql-migrate-start[1810]:     /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/bin/pg_ctl -D /var/lib/postgresql/17 -l logfile start934vm-test-run-wal2json> server # [  194.024747] postgresql-migrate-start[2070]: Performing Consistency Checks935vm-test-run-wal2json> server # [  194.031781] postgresql-migrate-start[2070]: -----------------------------936vm-test-run-wal2json> server # [  194.035346] postgresql-migrate-start[2070]: Checking cluster versions                                     ok937vm-test-run-wal2json> server # [  196.164172] systemd[1]: Starting Virtual Console Setup...938vm-test-run-wal2json> server # [  196.520097] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.939vm-test-run-wal2json> server # [  196.537514] systemd[1]: Stopped Virtual Console Setup.940vm-test-run-wal2json> server # [  196.609842] systemd[1]: Starting Virtual Console Setup...941vm-test-run-wal2json> server # [  198.862811] postgresql-migrate-start[2070]: Checking database user is the install user                    ok942vm-test-run-wal2json> server # [  199.188949] postgresql-migrate-start[2070]: Checking database connection settings                         ok943vm-test-run-wal2json> server # [  199.465402] postgresql-migrate-start[2070]: Checking for prepared transactions                            ok944vm-test-run-wal2json> server # [  199.489670] postgresql-migrate-start[2070]: Checking for contrib/isn with bigint-passing mismatch         ok945vm-test-run-wal2json> server # [  201.119995] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.946vm-test-run-wal2json> server # [  201.671897] postgresql-migrate-start[2070]: Checking data type usage                                      ok947vm-test-run-wal2json> server # [  202.229426] postgresql-migrate-start[2070]: Checking for not-null constraint inconsistencies              ok948vm-test-run-wal2json> server # [  202.295776] systemd[1]: Finished Virtual Console Setup.949vm-test-run-wal2json> server # [  203.145467] postgresql-migrate-start[2070]: Creating dump of global objects                               ok950vm-test-run-wal2json> server # [  206.011448] systemd-logind[657]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)951vm-test-run-wal2json> server # [  206.512779] postgresql-migrate-start[2070]: Creating dump of database schemas                             ok952vm-test-run-wal2json> server # [  208.726095] postgresql-migrate-start[2070]: Checking for presence of required libraries                   ok953vm-test-run-wal2json> server # [  208.795424] postgresql-migrate-start[2070]: Checking database user is the install user                    ok954vm-test-run-wal2json> server # [  208.868719] postgresql-migrate-start[2070]: Checking for prepared transactions                            ok955vm-test-run-wal2json> server # [  208.875935] postgresql-migrate-start[2070]: Checking for new cluster tablespace directories               ok956vm-test-run-wal2json> server # [  208.878433] postgresql-migrate-start[2070]: If pg_upgrade fails after this point, you must re-initdb the957vm-test-run-wal2json> server # [  208.881801] postgresql-migrate-start[2070]: new cluster before continuing.958vm-test-run-wal2json> server # [  208.882985] postgresql-migrate-start[2070]: Performing Upgrade959vm-test-run-wal2json> server # [  208.890464] postgresql-migrate-start[2070]: ------------------960vm-test-run-wal2json> server # [  208.935894] postgresql-migrate-start[2070]: Setting locale and encoding for new cluster                   ok961vm-test-run-wal2json> server # [  211.146392] postgresql-migrate-start[2070]: Analyzing all rows in the new cluster                         ok962vm-test-run-wal2json> server # [  212.170404] postgresql-migrate-start[2070]: Freezing all rows in the new cluster                          ok963vm-test-run-wal2json> server # [  212.466307] postgresql-migrate-start[2070]: Deleting files from new pg_xact                               ok964vm-test-run-wal2json> server # [  212.626060] postgresql-migrate-start[2070]: Copying old pg_xact to new server                             ok965vm-test-run-wal2json> server # [  212.966685] postgresql-migrate-start[2070]: Setting oldest XID for new cluster                            ok966vm-test-run-wal2json> server # [  213.884702] postgresql-migrate-start[2070]: Setting next transaction ID and epoch for new cluster         ok967vm-test-run-wal2json> server # [  213.887427] postgresql-migrate-start[2070]: Deleting files from new pg_multixact/offsets                  ok968vm-test-run-wal2json> server # [  214.037007] postgresql-migrate-start[2070]: Copying old pg_multixact/offsets to new server                ok969vm-test-run-wal2json> server # [  214.040719] postgresql-migrate-start[2070]: Deleting files from new pg_multixact/members                  ok970vm-test-run-wal2json> server # [  214.188562] postgresql-migrate-start[2070]: Copying old pg_multixact/members to new server                ok971vm-test-run-wal2json> server # [  214.490396] postgresql-migrate-start[2070]: Setting next multixact ID and offset for new cluster          ok972vm-test-run-wal2json> server # [  214.809117] postgresql-migrate-start[2070]: Resetting WAL archives                                        ok973vm-test-run-wal2json> server # [  216.372919] postgresql-migrate-start[2070]: Setting frozenxid and minmxid counters in new cluster         ok974vm-test-run-wal2json> server # [  216.733390] postgresql-migrate-start[2070]: Restoring global objects in the new cluster                   ok975vm-test-run-wal2json> server # [  218.738606] postgresql-migrate-start[2070]: Restoring database schemas in the new cluster                 ok976vm-test-run-wal2json> server # [  219.431080] postgresql-migrate-start[2070]: Copying user relation files                                   ok977vm-test-run-wal2json> server # [  219.769370] postgresql-migrate-start[2070]: Setting next OID for new cluster                              ok978vm-test-run-wal2json> server # [  221.537296] postgresql-migrate-start[2070]: Sync data directory to disk                                   ok979vm-test-run-wal2json> server # [  221.541591] postgresql-migrate-start[2070]: Creating script to delete old cluster                         ok980vm-test-run-wal2json> server # [  223.799264] postgresql-migrate-start[2070]: Checking for extension updates                                ok981vm-test-run-wal2json> server # [  224.087950] postgresql-migrate-start[2070]: Upgrade Complete982vm-test-run-wal2json> server # [  224.090649] postgresql-migrate-start[2070]: ----------------983vm-test-run-wal2json> server # [  224.091910] postgresql-migrate-start[2070]: Optimizer statistics are not transferred by pg_upgrade.984vm-test-run-wal2json> server # [  224.100090] postgresql-migrate-start[2070]: Once you start the new server, consider running:985vm-test-run-wal2json> server # [  224.102319] postgresql-migrate-start[2070]:     /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/bin/vacuumdb --all --analyze-in-stages986vm-test-run-wal2json> server # [  224.102744] postgresql-migrate-start[2070]: Running this script will delete the old cluster's data files:987vm-test-run-wal2json> server # [  224.104055] postgresql-migrate-start[2070]:     ./delete_old_cluster.sh988vm-test-run-wal2json> server # [  224.147981] systemd[1]: Finished postgresql-migrate.service.989vm-test-run-wal2json> server # [  224.199245] systemd[1]: Starting PostgreSQL Server...990vm-test-run-wal2json> server # [  225.621860] postgres[2341]: [2341] LOG:  starting PostgreSQL 17.11 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.2.0, 64-bit991vm-test-run-wal2json> server # [  225.626244] postgres[2341]: [2341] LOG:  listening on IPv4 address "0.0.0.0", port 5432992vm-test-run-wal2json> server # [  225.630150] postgres[2341]: [2341] LOG:  listening on IPv6 address "::", port 5432993vm-test-run-wal2json> server # [  225.642004] postgres[2341]: [2341] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"994vm-test-run-wal2json> server # [  225.724074] postgres[2347]: [2347] LOG:  database system was shut down at 2026-10-07 22:04:41 GMT995vm-test-run-wal2json> server # [  225.815915] postgres[2341]: [2341] LOG:  database system is ready to accept connections996vm-test-run-wal2json> server # [  225.853759] systemd[1]: Started PostgreSQL Server.997vm-test-run-wal2json> server # [  225.893710] systemd[1]: Starting PostgreSQL Setup Scripts...998vm-test-run-wal2json> server # [  226.797512] postgresql-setup-start[2357]: ALTER ROLE999vm-test-run-wal2json> server # [  226.863205] systemd[1]: Finished PostgreSQL Setup Scripts.1000vm-test-run-wal2json> server # [  226.875236] systemd[1]: Reached target PostgreSQL.1001vm-test-run-wal2json> server # the following new units were started: postgresql-migrate.service, sys-devices-platform-4010000000.pcie-pci0000:00-0000:00:0b.0-virtio9-virtio\x2dports-vport9p0.device, sys-devices-virtual-input-mice.device, sys-devices-virtual-misc-rfkill.device, sys-devices-virtual-misc-tun.device, sys-devices-virtual-mtd-mtd0ro.device, sysinit-reactivation.target, systemd-rfkill.socket, systemd-tmpfiles-resetup.service, systemd-vconsole-setup.service1002vm-test-run-wal2json> server # [  227.175169] nixos[1570]: finished switching to system configuration /nix/store/pm6kclvckraz7gg68mm9kvdwg0239sbj-nixos-system-server-test1003vm-test-run-wal2json> server: waiting for unit postgresql.service1004vm-test-run-wal2json> server: (finished: waiting for unit postgresql.service, in 0.88 seconds)1005vm-test-run-wal2json> server: must succeed: test -f /var/lib/postgresql/update_extensions.sql && echo 'yes' || echo 'no'1006vm-test-run-wal2json> server: (finished: must succeed: test -f /var/lib/postgresql/update_extensions.sql && echo 'yes' || echo 'no', in 0.15 seconds)1007vm-test-run-wal2json> (finished: subtest: switch to postgresql 17, in 104.08 seconds)1008vm-test-run-wal2json> subtest: Check last version of the extension after postgresql upgrade1009vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 1010vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" , in 0.38 seconds)1011vm-test-run-wal2json> (finished: subtest: Check last version of the extension after postgresql upgrade, in 0.38 seconds)1012vm-test-run-wal2json> subtest: Check upgrade path with postgresql 171013vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 1014vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.34 seconds)1015vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 1016vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" , in 0.38 seconds)1017vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 1018vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" , in 0.33 seconds)1019vm-test-run-wal2json> (finished: subtest: Check upgrade path with postgresql 17, in 1.05 seconds)1020vm-test-run-wal2json> subtest: Check pg_regress with postgresql 17 after extension upgrade1021vm-test-run-wal2json> server: must succeed: sudo -u postgres /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 "wal2json" 1022vm-test-run-wal2json> server # [  230.038428] sudo[2383]:     root : TTY=hvc0 ; PWD=/tmp ; USER=postgres ; COMMAND=/nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 wal2json1023vm-test-run-wal2json> server # [  230.157389] sudo[2383]: pam_unix(sudo:session): session opened for user postgres(uid=71) by (uid=0)1024vm-test-run-wal2json> server # # could not set core size: disallowed by hard limit1025vm-test-run-wal2json> server # [  230.619003] postgres[2390]: [2390] LOG:  logical decoding found consistent point at 0/8034E981026vm-test-run-wal2json> server # [  230.620012] postgres[2390]: [2390] DETAIL:  There are no running transactions.1027vm-test-run-wal2json> server # [  230.621664] postgres[2390]: [2390] STATEMENT:  select1028vm-test-run-wal2json> server # [  230.623251] postgres[2390]: 	  11029vm-test-run-wal2json> server # [  230.625334] postgres[2390]: 	from1030vm-test-run-wal2json> server # [  230.626179] postgres[2390]: 	  pg_create_logical_replication_slot('reg_test', 'wal2json', false);1031vm-test-run-wal2json> server # [  230.661588] postgres[2390]: [2390] LOG:  starting logical decoding for slot "reg_test"1032vm-test-run-wal2json> server # [  230.662949] postgres[2390]: [2390] DETAIL:  Streaming transactions committing after 0/8034ED0, reading WAL from 0/8034E98.1033vm-test-run-wal2json> server # [  230.663608] postgres[2390]: [2390] STATEMENT:  select1034vm-test-run-wal2json> server # [  230.665462] postgres[2390]: 	  data1035vm-test-run-wal2json> server # [  230.665830] postgres[2390]: 	from1036vm-test-run-wal2json> server # [  230.666243] postgres[2390]: 	  pg_logical_slot_get_changes(1037vm-test-run-wal2json> server # [  230.666556] postgres[2390]: 		'reg_test',1038vm-test-run-wal2json> server # [  230.666841] postgres[2390]: 	    null,1039vm-test-run-wal2json> server # [  230.667070] postgres[2390]: 	    null,1040vm-test-run-wal2json> server # [  230.667633] postgres[2390]: 		'include-pk', 'true',1041vm-test-run-wal2json> server # [  230.668149] postgres[2390]: 		'include-transaction', 'false',1042vm-test-run-wal2json> server # [  230.670239] postgres[2390]: 		'include-timestamp', 'false',1043vm-test-run-wal2json> server # [  230.671986] postgres[2390]: 		'include-type-oids', 'true',1044vm-test-run-wal2json> server # [  230.673084] postgres[2390]: 		'format-version', '2',1045vm-test-run-wal2json> server # [  230.673602] postgres[2390]: 		'actions', 'insert,update,delete',1046vm-test-run-wal2json> server # [  230.674319] postgres[2390]: 		'add-tables', 'v.foo'1047vm-test-run-wal2json> server # [  230.674619] postgres[2390]: 	  ) x;1048vm-test-run-wal2json> server # [  230.675250] postgres[2390]: [2390] LOG:  logical decoding found consistent point at 0/8034E981049vm-test-run-wal2json> server # [  230.675878] postgres[2390]: [2390] DETAIL:  There are no running transactions.1050vm-test-run-wal2json> server # [  230.676777] postgres[2390]: [2390] STATEMENT:  select1051vm-test-run-wal2json> server # [  230.677283] postgres[2390]: 	  data1052vm-test-run-wal2json> server # [  230.677592] postgres[2390]: 	from1053vm-test-run-wal2json> server # [  230.677848] postgres[2390]: 	  pg_logical_slot_get_changes(1054vm-test-run-wal2json> server # [  230.678544] postgres[2390]: 		'reg_test',1055vm-test-run-wal2json> server # [  230.678791] postgres[2390]: 	    null,1056vm-test-run-wal2json> server # [  230.679029] postgres[2390]: 	    null,1057vm-test-run-wal2json> server # [  230.679278] postgres[2390]: 		'include-pk', 'true',1058vm-test-run-wal2json> server # [  230.679637] postgres[2390]: 		'include-transaction', 'false',1059vm-test-run-wal2json> server # [  230.680073] postgres[2390]: 		'include-timestamp', 'false',1060vm-test-run-wal2json> server # [  230.680347] postgres[2390]: 		'include-type-oids', 'true',1061vm-test-run-wal2json> server # [  230.680587] postgres[2390]: 		'format-version', '2',1062vm-test-run-wal2json> server # [  230.682178] postgres[2390]: 		'actions', 'insert,update,delete',1063vm-test-run-wal2json> server # [  230.682690] postgres[2390]: 		'add-tables', 'v.foo'1064vm-test-run-wal2json> server # [  230.682973] postgres[2390]: 	  ) x;1065vm-test-run-wal2json> server # [  230.913147] sudo[2383]: pam_unix(sudo:session): session closed for user postgres1066vm-test-run-wal2json> server: (finished: must succeed: sudo -u postgres /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 "wal2json" , in 1.26 seconds)1067vm-test-run-wal2json> # using postmaster on Unix socket, default port1068vm-test-run-wal2json> ok 1         - wal2json                                  490 ms1069vm-test-run-wal2json> 1..11070vm-test-run-wal2json> # All 1 tests passed.1071vm-test-run-wal2json> 1072vm-test-run-wal2json> (finished: subtest: Check pg_regress with postgresql 17 after extension upgrade, in 1.26 seconds)1073vm-test-run-wal2json> subtest: Check the install of the last version of the extension1074vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 1075vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.35 seconds)1076vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 1077vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" , in 0.37 seconds)1078vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 1079vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" , in 0.33 seconds)1080vm-test-run-wal2json> (finished: subtest: Check the install of the last version of the extension, in 1.04 seconds)1081vm-test-run-wal2json> subtest: Check pg_regress with postgresql 17 after installing the last version1082vm-test-run-wal2json> server: must succeed: sudo -u postgres /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 "wal2json" 1083vm-test-run-wal2json> server # [  232.323004] sudo[2405]:     root : TTY=hvc0 ; PWD=/tmp ; USER=postgres ; COMMAND=/nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 wal2json1084vm-test-run-wal2json> server # [  232.475904] sudo[2405]: pam_unix(sudo:session): session opened for user postgres(uid=71) by (uid=0)1085vm-test-run-wal2json> server # # could not set core size: disallowed by hard limit1086vm-test-run-wal2json> server # [  232.960438] postgres[2412]: [2412] LOG:  logical decoding found consistent point at 0/803B8E81087vm-test-run-wal2json> server # [  232.963379] postgres[2412]: [2412] DETAIL:  There are no running transactions.1088vm-test-run-wal2json> server # [  232.964357] postgres[2412]: [2412] STATEMENT:  select1089vm-test-run-wal2json> server # [  232.966033] postgres[2412]: 	  11090vm-test-run-wal2json> server # [  232.966838] postgres[2412]: 	from1091vm-test-run-wal2json> server # [  232.967261] postgres[2412]: 	  pg_create_logical_replication_slot('reg_test', 'wal2json', false);1092vm-test-run-wal2json> server # [  233.001329] postgres[2412]: [2412] LOG:  starting logical decoding for slot "reg_test"1093vm-test-run-wal2json> server # [  233.002999] postgres[2412]: [2412] DETAIL:  Streaming transactions committing after 0/803B920, reading WAL from 0/803B8E8.1094vm-test-run-wal2json> server # [  233.004849] postgres[2412]: [2412] STATEMENT:  select1095vm-test-run-wal2json> server # [  233.005252] postgres[2412]: 	  data1096vm-test-run-wal2json> server # [  233.005501] postgres[2412]: 	from1097vm-test-run-wal2json> server # [  233.005724] postgres[2412]: 	  pg_logical_slot_get_changes(1098vm-test-run-wal2json> server # [  233.005999] postgres[2412]: 		'reg_test',1099vm-test-run-wal2json> server # [  233.006227] postgres[2412]: 	    null,1100vm-test-run-wal2json> server # [  233.006446] postgres[2412]: 	    null,1101vm-test-run-wal2json> server # [  233.006646] postgres[2412]: 		'include-pk', 'true',1102vm-test-run-wal2json> server # [  233.006870] postgres[2412]: 		'include-transaction', 'false',1103vm-test-run-wal2json> server # [  233.007262] postgres[2412]: 		'include-timestamp', 'false',1104vm-test-run-wal2json> server # [  233.007501] postgres[2412]: 		'include-type-oids', 'true',1105vm-test-run-wal2json> server # [  233.007728] postgres[2412]: 		'format-version', '2',1106vm-test-run-wal2json> server # [  233.008678] postgres[2412]: 		'actions', 'insert,update,delete',1107vm-test-run-wal2json> server # [  233.010593] postgres[2412]: 		'add-tables', 'v.foo'1108vm-test-run-wal2json> server # [  233.011366] postgres[2412]: 	  ) x;1109vm-test-run-wal2json> server # [  233.011949] postgres[2412]: [2412] LOG:  logical decoding found consistent point at 0/803B8E81110vm-test-run-wal2json> server # [  233.013590] postgres[2412]: [2412] DETAIL:  There are no running transactions.1111vm-test-run-wal2json> server # [  233.014502] postgres[2412]: [2412] STATEMENT:  select1112vm-test-run-wal2json> server # [  233.014844] postgres[2412]: 	  data1113vm-test-run-wal2json> server # [  233.015648] postgres[2412]: 	from1114vm-test-run-wal2json> server # [  233.016081] postgres[2412]: 	  pg_logical_slot_get_changes(1115vm-test-run-wal2json> server # [  233.017828] postgres[2412]: 		'reg_test',1116vm-test-run-wal2json> server # [  233.018578] postgres[2412]: 	    null,1117vm-test-run-wal2json> server # [  233.018828] postgres[2412]: 	    null,1118vm-test-run-wal2json> server # [  233.019048] postgres[2412]: 		'include-pk', 'true',1119vm-test-run-wal2json> server # [  233.019293] postgres[2412]: 		'include-transaction', 'false',1120vm-test-run-wal2json> server # [  233.019520] postgres[2412]: 		'include-timestamp', 'false',1121vm-test-run-wal2json> server # [  233.019753] postgres[2412]: 		'include-type-oids', 'true',1122vm-test-run-wal2json> server # [  233.019983] postgres[2412]: 		'format-version', '2',1123vm-test-run-wal2json> server # [  233.021396] postgres[2412]: 		'actions', 'insert,update,delete',1124vm-test-run-wal2json> server # [  233.022709] postgres[2412]: 		'add-tables', 'v.foo'1125vm-test-run-wal2json> server # [  233.026740] postgres[2412]: 	  ) x;1126vm-test-run-wal2json> server # [  233.279230] sudo[2405]: pam_unix(sudo:session): session closed for user postgres1127vm-test-run-wal2json> server: (finished: must succeed: sudo -u postgres /nix/store/21wp83042vyjzxgh1068wq8k6yh007bh-postgresql-17-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/lf35v8rm0q74qf8h1ijs9m6isvkgfcj3-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_17 "wal2json" , in 1.34 seconds)1128vm-test-run-wal2json> # using postmaster on Unix socket, default port1129vm-test-run-wal2json> ok 1         - wal2json                                  499 ms1130vm-test-run-wal2json> 1..11131vm-test-run-wal2json> # All 1 tests passed.1132vm-test-run-wal2json> 1133vm-test-run-wal2json> (finished: subtest: Check pg_regress with postgresql 17 after installing the last version, in 1.34 seconds)1134vm-test-run-wal2json> subtest: switch to orioledb 171135vm-test-run-wal2json> server # Checking switch inhibitors... done1136vm-test-run-wal2json> server # stopping the following units: postgresql-migrate.service, postgresql-setup.service, postgresql.service1137vm-test-run-wal2json> server # [  240.268748] nixos[2419]: switching to system configuration /nix/store/fqflp15g45z0a44svny2agnd4qznqb8f-nixos-system-server-test1138vm-test-run-wal2json> server # [  240.283187] systemd[1]: Stopped target PostgreSQL.1139vm-test-run-wal2json> server # [  240.298473] systemd[1]: postgresql-setup.service: Deactivated successfully.1140vm-test-run-wal2json> server # [  240.314596] postgres[2341]: [2341] LOG:  received fast shutdown request1141vm-test-run-wal2json> server # [  240.319226] systemd[1]: Stopped PostgreSQL Setup Scripts.1142vm-test-run-wal2json> server # [  240.320202] systemd[1]: Stopping PostgreSQL Server...1143vm-test-run-wal2json> server # [  240.323138] systemd[1]: Stopped target Local File Systems.1144vm-test-run-wal2json> server # [  240.326515] postgres[2341]: [2341] LOG:  aborting any active transactions1145vm-test-run-wal2json> server # [  240.393014] systemd[1]: Stopped target Remote File Systems.1146vm-test-run-wal2json> server # [  240.402962] postgres[2341]: [2341] LOG:  background worker "logical replication launcher" (PID 2350) exited with exit code 11147vm-test-run-wal2json> server # [  240.435591] postgres[2345]: [2345] LOG:  shutting down1148vm-test-run-wal2json> server # [  240.445416] postgres[2345]: [2345] LOG:  checkpoint starting: shutdown immediate1149vm-test-run-wal2json> server # [  240.605730] postgres[2345]: [2345] LOG:  checkpoint complete: wrote 57 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.045 s, sync=0.060 s, total=0.179 s; sync files=45, longest=0.016 s, average=0.002 s; distance=242 kB, estimate=242 kB; lsn=0/803C9C0, redo lsn=0/803C9C01150vm-test-run-wal2json> server # [  240.653592] postgres[2341]: [2341] LOG:  database system is shut down1151vm-test-run-wal2json> server # [  240.712821] systemd[1]: postgresql.service: Deactivated successfully.1152vm-test-run-wal2json> server # [  240.721383] systemd[1]: Stopped PostgreSQL Server.1153vm-test-run-wal2json> server # [  240.733454] systemd[1]: postgresql.service: Consumed 2.287s CPU time, 22.3M memory peak, 264K written to disk.1154vm-test-run-wal2json> server # [  240.774287] systemd[1]: postgresql-migrate.service: Deactivated successfully.1155vm-test-run-wal2json> server # [  240.779949] systemd[1]: Stopped postgresql-migrate.service.1156vm-test-run-wal2json> server # [  240.782995] systemd[1]: postgresql-migrate.service: Consumed 38.792s CPU time, 97M memory peak, 173.8M written to disk.1157vm-test-run-wal2json> server # activating the configuration...1158vm-test-run-wal2json> server # setting up /etc...1159vm-test-run-wal2json> server # [  245.576272] systemd[1]: Reload requested from client PID 2419 ('.switch-to-conf') (unit backdoor.service)...1160vm-test-run-wal2json> server # [  245.580009] systemd[1]: Reloading...1161vm-test-run-wal2json> server # [  252.199899] systemd[1]: Reloading finished in 6605 ms.1162vm-test-run-wal2json> server # restarting sysinit-reactivation.target1163vm-test-run-wal2json> server # [  252.536877] systemd[1]: Stopped target Reactivate sysinit units.1164vm-test-run-wal2json> server # [  252.538896] systemd[1]: Stopping Reactivate sysinit units...1165vm-test-run-wal2json> server # [  252.539847] systemd[1]: Reached target Reactivate sysinit units.1166vm-test-run-wal2json> server # reloading the following units: dbus.service1167vm-test-run-wal2json> server # [  252.581269] systemd[1]: Reloading D-Bus System Message Bus...1168vm-test-run-wal2json> server # [  252.874956] dbus-daemon[633]: Unknown username "systemd-timesync" in message bus configuration file1169vm-test-run-wal2json> server # [  253.064624] dbus-daemon[633]: [system] Reloaded configuration1170vm-test-run-wal2json> server # [  253.080039] dbus-send[2495]: method return time=1791410710.588839 sender=org.freedesktop.DBus -> destination=:1.7 serial=3 reply_serial=21171vm-test-run-wal2json> server # [  253.156193] dbus-daemon[633]: Unknown username "systemd-timesync" in message bus configuration file1172vm-test-run-wal2json> server # [  253.323591] dbus-daemon[633]: [system] Reloaded configuration1173vm-test-run-wal2json> server # [  253.340789] systemd[1]: Reloaded D-Bus System Message Bus.1174vm-test-run-wal2json> server # starting the following units: postgresql-migrate.service, postgresql-setup.service, postgresql.service1175vm-test-run-wal2json> server # [  253.398314] systemd[1]: Reached target Remote File Systems.1176vm-test-run-wal2json> server # [  253.430146] systemd[1]: Starting linger-users.service...1177vm-test-run-wal2json> server # [  253.467724] systemd[1]: Starting postgresql-migrate.service...1178vm-test-run-wal2json> server # [  253.474706] systemd[1]: SSH Host Keys Generation was skipped because no trigger condition checks were met.1179vm-test-run-wal2json> server # [  253.577023] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).1180vm-test-run-wal2json> server # [  253.592860] systemd[1]: Reached target Local File Systems.1181vm-test-run-wal2json> server # [  253.782407] systemd[1]: Load Kernel Module efi_pstore was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!efi_pstore).1182vm-test-run-wal2json> server # [  253.831807] systemd[1]: Starting Create SUID/SGID Wrappers...1183vm-test-run-wal2json> server # [  253.834167] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.1184vm-test-run-wal2json> server # [  253.839290] 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).1185vm-test-run-wal2json> server # [  253.843534] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).1186vm-test-run-wal2json> server # [  253.851082] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).1187vm-test-run-wal2json> server # [  253.851885] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).1188vm-test-run-wal2json> server # [  253.945034] systemd[1]: linger-users.service: Deactivated successfully.1189vm-test-run-wal2json> server # [  253.954559] systemd[1]: Finished linger-users.service.1190vm-test-run-wal2json> server # [  254.199441] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).1191vm-test-run-wal2json> server # [  254.646012] systemd[1]: Finished postgresql-migrate.service.1192vm-test-run-wal2json> server # [  258.088141] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1193vm-test-run-wal2json> server # [  258.094715] systemd[1]: Finished Create SUID/SGID Wrappers.1194vm-test-run-wal2json> server # [  258.096129] systemd[1]: suid-sgid-wrappers.service: Consumed 1.961s CPU time, 3.3M memory peak.1195vm-test-run-wal2json> server # [  258.143270] systemd[1]: Starting PostgreSQL Server...1196vm-test-run-wal2json> server # [  259.606768] postgresql-pre-start[2578]: The files belonging to this database system will be owned by user "postgres".1197vm-test-run-wal2json> server # [  259.610324] postgresql-pre-start[2578]: This user must also own the server process.1198vm-test-run-wal2json> server # [  259.686951] postgresql-pre-start[2578]: Using language tag "en-US" for ICU locale "en_US.UTF-8".1199vm-test-run-wal2json> server # [  259.689090] postgresql-pre-start[2578]: The database cluster will be initialized with this locale configuration:1200vm-test-run-wal2json> server # [  259.689756] postgresql-pre-start[2578]:   locale provider:   icu1201vm-test-run-wal2json> server # [  259.690649] postgresql-pre-start[2578]:   default collation: en-US1202vm-test-run-wal2json> server # [  259.691298] postgresql-pre-start[2578]:   LC_COLLATE:  en_US.UTF-81203vm-test-run-wal2json> server # [  259.691614] postgresql-pre-start[2578]:   LC_CTYPE:    en_US.UTF-81204vm-test-run-wal2json> server # [  259.692223] postgresql-pre-start[2578]:   LC_MESSAGES: en_US.UTF-81205vm-test-run-wal2json> server # [  259.694334] postgresql-pre-start[2578]:   LC_MONETARY: en_US.UTF-81206vm-test-run-wal2json> server # [  259.695592] postgresql-pre-start[2578]:   LC_NUMERIC:  en_US.UTF-81207vm-test-run-wal2json> server # [  259.696022] postgresql-pre-start[2578]:   LC_TIME:     en_US.UTF-81208vm-test-run-wal2json> server # [  259.697460] postgresql-pre-start[2578]: The default text search configuration will be set to "english".1209vm-test-run-wal2json> server # [  259.698549] postgresql-pre-start[2578]: Data page checksums are disabled.1210vm-test-run-wal2json> server # [  259.698967] postgresql-pre-start[2578]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok1211vm-test-run-wal2json> server # [  259.701522] postgresql-pre-start[2578]: creating subdirectories ... ok1212vm-test-run-wal2json> server # [  259.704214] postgresql-pre-start[2578]: selecting dynamic shared memory implementation ... posix1213vm-test-run-wal2json> server # [  260.419127] postgresql-pre-start[2578]: selecting default "max_connections" ... 1001214vm-test-run-wal2json> server # [  260.934165] postgresql-pre-start[2578]: selecting default "shared_buffers" ... 128MB