nixbot

1these 4 derivations will be built:2  /nix/store/m8z1ifh3aapypcxmm1rdawlsnachchji-test-script.drv3  /nix/store/xbh4ldlx3vvdm4qrcnm0d45gspvswdg8-driverConfiguration.json.drv4  /nix/store/c366d8dsn862bd37pyghwpw7yhal7yd8-nixos-test-driver-wal2json.drv5  /nix/store/s368g6kg6a0ixzkwjcgayqgp963xv8vc-vm-test-run-wal2json.drv6building '/nix/store/m8z1ifh3aapypcxmm1rdawlsnachchji-test-script.drv' on 'ssh-ng://nixbot-remote-build@78.232.36.247'7building '/nix/store/m8z1ifh3aapypcxmm1rdawlsnachchji-test-script.drv'8building '/nix/store/xbh4ldlx3vvdm4qrcnm0d45gspvswdg8-driverConfiguration.json.drv' on 'ssh-ng://nixbot-remote-build@78.232.36.247'9building '/nix/store/xbh4ldlx3vvdm4qrcnm0d45gspvswdg8-driverConfiguration.json.drv'10driverConfiguration.json> structuredAttrs is enabled11building '/nix/store/c366d8dsn862bd37pyghwpw7yhal7yd8-nixos-test-driver-wal2json.drv' on 'ssh-ng://nixbot-remote-build@78.232.36.247'12building '/nix/store/c366d8dsn862bd37pyghwpw7yhal7yd8-nixos-test-driver-wal2json.drv'13nixos-test-driver-wal2json> Running type check (enable/disable: config.skipTypeCheck)14nixos-test-driver-wal2json> See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck15nixos-test-driver-wal2json> All checks passed!16nixos-test-driver-wal2json> Linting test script (enable/disable: config.skipLint)17nixos-test-driver-wal2json> See https://nixos.org/manual/nixos/stable/#test-opt-skipLint18nixos-test-driver-wal2json> All checks passed!19building '/nix/store/s368g6kg6a0ixzkwjcgayqgp963xv8vc-vm-test-run-wal2json.drv' on 'ssh-ng://builder@mac-linux-builder'20building '/nix/store/s368g6kg6a0ixzkwjcgayqgp963xv8vc-vm-test-run-wal2json.drv'21vm-test-run-wal2json> Machine state will be reset. To keep it, pass --keep-machine-state22vm-test-run-wal2json> start all VLans23vm-test-run-wal2json> (finished: start all VLans, in 0.00 seconds)24vm-test-run-wal2json> Test will time out and terminate in 3600 seconds25vm-test-run-wal2json> run the VM test script26vm-test-run-wal2json> additionally exposed symbols:27vm-test-run-wal2json>     server,28vm-test-run-wal2json>     vlan1,29vm-test-run-wal2json>     start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh30vm-test-run-wal2json> Running tests for extension: wal2json31vm-test-run-wal2json> start all VMs32vm-test-run-wal2json> server: starting vm33vm-test-run-wal2json> server # Disk image does not exist, creating the virtualisation disk image...34vm-test-run-wal2json> server # Formatting '/build/vm-state-server/tmp.LxaTMoVmMF', fmt=raw size=107374182435vm-test-run-wal2json> server # mke2fs 1.47.4 (6-Mar-2025)36vm-test-run-wal2json> server # Discarding device blocks:      0/262144             done37vm-test-run-wal2json> server # Creating filesystem with 262144 4k blocks and 65536 inodes38vm-test-run-wal2json> server # Filesystem UUID: 4c52b437-666d-4b31-a9a9-eded65af282239vm-test-run-wal2json> server # Superblock backups stored on blocks:40vm-test-run-wal2json> server # 	32768, 98304, 163840, 22937641vm-test-run-wal2json> server # 42vm-test-run-wal2json> server # Allocating group tables: 0/8   done43vm-test-run-wal2json> server # Writing inode tables: 0/8   done44vm-test-run-wal2json> server # Creating journal (8192 blocks): done45vm-test-run-wal2json> server # Writing superblocks and filesystem accounting information: 0/8   done46vm-test-run-wal2json> server # 47vm-test-run-wal2json> server # Virtualisation disk image created.48vm-test-run-wal2json> server # qemu-system-aarch64: Could not access KVM kernel module: No such file or directory49vm-test-run-wal2json> server # qemu-system-aarch64: failed to initialize kvm: No such file or directory50vm-test-run-wal2json> server # qemu-system-aarch64: falling back to tcg51vm-test-run-wal2json> server: QEMU running (pid 13)52vm-test-run-wal2json> (finished: start all VMs, in 0.18 seconds)53vm-test-run-wal2json> server: waiting for unit multi-user.target54vm-test-run-wal2json> server: waiting for the VM to finish booting55vm-test-run-wal2json> server # [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]56vm-test-run-wal2json> server # [    0.000000] Linux version 6.18.54 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Sep 25 14:35:54 UTC 202657vm-test-run-wal2json> server # [    0.000000] KASLR enabled58vm-test-run-wal2json> server # [    0.000000] random: crng init done59vm-test-run-wal2json> server # [    0.000000] Machine model: linux,dummy-virt60vm-test-run-wal2json> server # [    0.000000] efi: UEFI not found.61vm-test-run-wal2json> server # [    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT62vm-test-run-wal2json> server # [    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]63vm-test-run-wal2json> server # [    0.000000] NODE_DATA(0) allocated [mem 0x13f6031c0-0x13f60693f]64vm-test-run-wal2json> server # [    0.000000] Zone ranges:65vm-test-run-wal2json> server # [    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]66vm-test-run-wal2json> server # [    0.000000]   DMA32    empty67vm-test-run-wal2json> server # [    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]68vm-test-run-wal2json> server # [    0.000000]   Device   empty69vm-test-run-wal2json> server # [    0.000000] Movable zone start for each node70vm-test-run-wal2json> server # [    0.000000] Early memory node ranges71vm-test-run-wal2json> server # [    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]72vm-test-run-wal2json> server # [    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]73vm-test-run-wal2json> server # [    0.000000] cma: Reserved 32 MiB at 0x00000000fe00000074vm-test-run-wal2json> server # [    0.000000] psci: probing for conduit method from DT.75vm-test-run-wal2json> server # [    0.000000] psci: PSCIv1.1 detected in firmware.76vm-test-run-wal2json> server # [    0.000000] psci: Using standard PSCI v0.2 function IDs77vm-test-run-wal2json> server # [    0.000000] psci: Trusted OS migration not required78vm-test-run-wal2json> server # [    0.000000] psci: SMC Calling Convention v1.079vm-test-run-wal2json> server # [    0.000000] percpu: Embedded 76 pages/cpu s186520 r8192 d116584 u31129680vm-test-run-wal2json> server # [    0.000000] Detected PIPT I-cache on CPU081vm-test-run-wal2json> server # [    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)82vm-test-run-wal2json> server # [    0.000000] CPU features: detected: GICv3 CPU interface83vm-test-run-wal2json> server # [    0.000000] CPU features: detected: HCRX_EL2 register84vm-test-run-wal2json> server # [    0.000000] CPU features: detected: Stage-1 Permission Indirection Extension (S1PIE)85vm-test-run-wal2json> server # [    0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)86vm-test-run-wal2json> server # [    0.000000] CPU features: detected: Spectre-v487vm-test-run-wal2json> server # [    0.000000] alternatives: applying boot alternatives88vm-test-run-wal2json> server # [    0.000000] Kernel command line: console=ttyAMA0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/h426kxg3mnpfhvs5sgb977wxrzr7y67d-nixos-system-server-test/init regInfo=/nix/store/xnv62nn1gl98hmgf93fid72d6sn3j3zl-closure-info/registration console=ttyAMA0,115200n8 console=tty089vm-test-run-wal2json> server # [    0.000000] Unknown kernel command line parameters "regInfo=/nix/store/xnv62nn1gl98hmgf93fid72d6sn3j3zl-closure-info/registration", will be passed to user space.90vm-test-run-wal2json> server # [    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes91vm-test-run-wal2json> server # [    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)92vm-test-run-wal2json> server # [    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)93vm-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] Fallback order for Node 0: 096vm-test-run-wal2json> server # [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 104857697vm-test-run-wal2json> server # [    0.000000] Policy zone: Normal98vm-test-run-wal2json> server # [    0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off99vm-test-run-wal2json> server # [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1100vm-test-run-wal2json> server # [    0.000000] allocated 8388608 bytes of page_ext101vm-test-run-wal2json> server # [    0.000000] ftrace: allocating 74832 entries in 294 pages102vm-test-run-wal2json> server # [    0.000000] ftrace: allocated 294 pages with 4 groups103vm-test-run-wal2json> server # [    0.000000] rcu: Hierarchical RCU implementation.104vm-test-run-wal2json> server # [    0.000000] rcu: 	RCU event tracing is enabled.105vm-test-run-wal2json> server # [    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=2.106vm-test-run-wal2json> server # [    0.000000] 	Trampoline variant of Tasks RCU enabled.107vm-test-run-wal2json> server # [    0.000000] 	Rude variant of Tasks RCU enabled.108vm-test-run-wal2json> server # [    0.000000] 	Tracing variant of Tasks RCU enabled.109vm-test-run-wal2json> server # [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.110vm-test-run-wal2json> server # [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2111vm-test-run-wal2json> server # [    0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.112vm-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.113vm-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.114vm-test-run-wal2json> server # [    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0115vm-test-run-wal2json> server # [    0.000000] GICv3: 256 SPIs implemented116vm-test-run-wal2json> server # [    0.000000] GICv3: 0 Extended SPIs implemented117vm-test-run-wal2json> server # [    0.000000] Root IRQ handler: gic_handle_irq118vm-test-run-wal2json> server # [    0.000000] GICv3: GICv3 features: 16 PPIs119vm-test-run-wal2json> server # [    0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0120vm-test-run-wal2json> server # [    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000121vm-test-run-wal2json> server # [    0.000000] ITS [mem 0x08080000-0x0809ffff]122vm-test-run-wal2json> server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @100b10000 (indirect, esz 8, psz 64K, shr 1)123vm-test-run-wal2json> server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @100b20000 (flat, esz 8, psz 64K, shr 1)124vm-test-run-wal2json> server # [    0.000000] GICv3: using LPI property table @0x0000000100b30000125vm-test-run-wal2json> server # [    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000100b40000126vm-test-run-wal2json> server # [    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.127vm-test-run-wal2json> server # [    0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns128vm-test-run-wal2json> server # [    0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).129vm-test-run-wal2json> server # [    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns130vm-test-run-wal2json> server # [    0.000047] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns131vm-test-run-wal2json> server # [    0.005472] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)132vm-test-run-wal2json> server # [    0.019119] Console: colour dummy device 80x25133vm-test-run-wal2json> server # [    0.020919] printk: legacy console [tty0] enabled134vm-test-run-wal2json> server # [    0.027083] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)135vm-test-run-wal2json> server # [    0.027531] pid_max: default: 32768 minimum: 301136vm-test-run-wal2json> server # [    0.030339] LSM: initializing lsm=capability,landlock,yama,bpf,ima137vm-test-run-wal2json> server # [    0.032816] landlock: Up and running.138vm-test-run-wal2json> server # [    0.032891] Yama: becoming mindful.139vm-test-run-wal2json> server # [    0.035204] LSM support for eBPF active140vm-test-run-wal2json> server # [    0.039413] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)141vm-test-run-wal2json> server # [    0.039591] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)142vm-test-run-wal2json> server # [    0.086914] rcu: Hierarchical SRCU implementation.143vm-test-run-wal2json> server # [    0.087040] rcu: 	Max phase no-delay instances is 1000.144vm-test-run-wal2json> server # [    0.088682] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level145vm-test-run-wal2json> server # [    0.096203] fsl-mc MSI: its@8080000 domain created146vm-test-run-wal2json> server # [    0.098234] EFI services will not be available.147vm-test-run-wal2json> server # [    0.100376] smp: Bringing up secondary CPUs ...148vm-test-run-wal2json> server # [    0.105032] Detected PIPT I-cache on CPU1149vm-test-run-wal2json> server # [    0.106794] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000150vm-test-run-wal2json> server # [    0.107544] GICv3: CPU1: using allocated LPI pending table @0x0000000100b50000151vm-test-run-wal2json> server # [    0.109305] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]152vm-test-run-wal2json> server # [    0.113933] smp: Brought up 1 node, 2 CPUs153vm-test-run-wal2json> server # [    0.114120] SMP: Total of 2 processors activated.154vm-test-run-wal2json> server # [    0.114172] CPU: All CPU(s) started at EL1155vm-test-run-wal2json> server # [    0.114438] CPU features: detected: Branch Target Identification156vm-test-run-wal2json> server # [    0.114519] CPU features: detected: 32-bit EL0 Support157vm-test-run-wal2json> server # [    0.114564] CPU features: detected: 32-bit EL1 Support158vm-test-run-wal2json> server # [    0.114599] CPU features: detected: ARMv8.4 Translation Table Level159vm-test-run-wal2json> server # [    0.114643] CPU features: detected: Instruction cache invalidation not required for I/D coherence160vm-test-run-wal2json> server # [    0.114692] CPU features: detected: Data cache clean to the PoU not required for I/D coherence161vm-test-run-wal2json> server # [    0.114755] CPU features: detected: Common not Private translations162vm-test-run-wal2json> server # [    0.114787] CPU features: detected: CRC32 instructions163vm-test-run-wal2json> server # [    0.114818] CPU features: detected: Data cache clean to Point of Deep Persistence164vm-test-run-wal2json> server # [    0.114850] CPU features: detected: Data cache clean to Point of Persistence165vm-test-run-wal2json> server # [    0.114879] CPU features: detected: Data independent timing control (DIT)166vm-test-run-wal2json> server # [    0.114911] CPU features: detected: E0PD167vm-test-run-wal2json> server # [    0.114938] CPU features: detected: Enhanced Counter Virtualization168vm-test-run-wal2json> server # [    0.114967] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)169vm-test-run-wal2json> server # [    0.114999] CPU features: detected: Enhanced Privileged Access Never170vm-test-run-wal2json> server # [    0.115029] CPU features: detected: Enhanced Virtualization Traps171vm-test-run-wal2json> server # [    0.115058] CPU features: detected: Fine Grained Traps172vm-test-run-wal2json> server # [    0.115084] CPU features: detected: Guarded Control Stack (GCS)173vm-test-run-wal2json> server # [    0.115148] CPU features: detected: Generic authentication (IMP DEF algorithm)174vm-test-run-wal2json> server # [    0.115244] CPU features: detected: RCpc load-acquire (LDAPR)175vm-test-run-wal2json> server # [    0.115298] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)176vm-test-run-wal2json> server # [    0.115330] CPU features: detected: LSE atomic instructions177vm-test-run-wal2json> server # [    0.115355] CPU features: detected: Memory Copy and Memory Set instructions178vm-test-run-wal2json> server # [    0.115385] CPU features: detected: Privileged Access Never179vm-test-run-wal2json> server # [    0.115436] CPU features: detected: PMUv3180vm-test-run-wal2json> server # [    0.115464] CPU features: detected: SCTLR2181vm-test-run-wal2json> server # [    0.115492] CPU features: detected: RAS Extension Support182vm-test-run-wal2json> server # [    0.115570] CPU features: detected: RASv1p1 Extension Support183vm-test-run-wal2json> server # [    0.115602] CPU features: detected: Random Number Generator184vm-test-run-wal2json> server # [    0.115632] CPU features: detected: Speculation barrier (SB)185vm-test-run-wal2json> server # [    0.115662] CPU features: detected: Stage-2 Force Write-Back186vm-test-run-wal2json> server # [    0.115693] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality187vm-test-run-wal2json> server # [    0.115728] CPU features: detected: TLB range maintenance instructions188vm-test-run-wal2json> server # [    0.115761] CPU features: detected: WFx with timeout189vm-test-run-wal2json> server # [    0.115852] CPU features: detected: Scalable Matrix Extension190vm-test-run-wal2json> server # [    0.115886] CPU features: detected: FA64191vm-test-run-wal2json> server # [    0.115935] CPU features: detected: SME2192vm-test-run-wal2json> server # [    0.116165] CPU features: detected: Speculative Store Bypassing Safe (SSBS)193vm-test-run-wal2json> server # [    0.116200] CPU features: detected: Scalable Vector Extension194vm-test-run-wal2json> server # [    0.122758] alternatives: applying system-wide alternatives195vm-test-run-wal2json> server # [    0.137392] CPU features: detected: Hardware dirty bit management on CPU0-1196vm-test-run-wal2json> server # [    0.138055] SVE: maximum available vector length 256 bytes per vector197vm-test-run-wal2json> server # [    0.138140] SVE: default vector length 64 bytes per vector198vm-test-run-wal2json> server # [    0.139370] SME: minimum available vector length 16 bytes per vector199vm-test-run-wal2json> server # [    0.139441] SME: maximum available vector length 256 bytes per vector200vm-test-run-wal2json> server # [    0.139488] SME: default vector length 32 bytes per vector201vm-test-run-wal2json> server # [    0.155185] Memory: 3904012K/4194304K available (24320K kernel code, 7090K rwdata, 26572K rodata, 4736K init, 1103K bss, 241772K reserved, 32768K cma-reserved)202vm-test-run-wal2json> server # [    0.181793] devtmpfs: initialized203vm-test-run-wal2json> server # [    0.218135] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)204vm-test-run-wal2json> server # [    0.218817] futex hash table entries: 512 (32768 bytes on 1 NUMA nodes, total 32 KiB, linear).205vm-test-run-wal2json> server # [    0.221798] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL206vm-test-run-wal2json> server # [    0.221892] 0 pages in range for non-PLT usage207vm-test-run-wal2json> server # [    0.221942] 508272 pages in range for PLT usage208vm-test-run-wal2json> server # [    0.225048] pinctrl core: initialized pinctrl subsystem209vm-test-run-wal2json> server # [    0.237440] DMI not present or invalid.210vm-test-run-wal2json> server # [    0.259685] NET: Registered PF_NETLINK/PF_ROUTE protocol family211vm-test-run-wal2json> server # [    0.272140] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations212vm-test-run-wal2json> server # [    0.273276] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations213vm-test-run-wal2json> server # [    0.274847] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations214vm-test-run-wal2json> server # [    0.275192] audit: initializing netlink subsys (disabled)215vm-test-run-wal2json> server # [    0.277882] audit: type=2000 audit(0.212:1): state=initialized audit_enabled=0 res=1216vm-test-run-wal2json> server # [    0.284349] thermal_sys: Registered thermal governor 'fair_share'217vm-test-run-wal2json> server # [    0.284417] thermal_sys: Registered thermal governor 'bang_bang'218vm-test-run-wal2json> server # [    0.284478] thermal_sys: Registered thermal governor 'step_wise'219vm-test-run-wal2json> server # [    0.284510] thermal_sys: Registered thermal governor 'user_space'220vm-test-run-wal2json> server # [    0.284544] thermal_sys: Registered thermal governor 'power_allocator'221vm-test-run-wal2json> server # [    0.285561] cpuidle: using governor ladder222vm-test-run-wal2json> server # [    0.286116] cpuidle: using governor menu223vm-test-run-wal2json> server # [    0.288530] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.224vm-test-run-wal2json> server # [    0.289366] ASID allocator initialised with 65536 entries225vm-test-run-wal2json> server # [    0.297914] Serial: AMBA PL011 UART driver226vm-test-run-wal2json> server # [    0.360477] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1227vm-test-run-wal2json> server # [    0.363823] printk: console [ttyAMA0] enabled228vm-test-run-wal2json> server # [    0.420337] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages229vm-test-run-wal2json> server # [    0.420432] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page230vm-test-run-wal2json> server # [    0.420483] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages231vm-test-run-wal2json> server # [    0.420514] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page232vm-test-run-wal2json> server # [    0.421204] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages233vm-test-run-wal2json> server # [    0.421242] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page234vm-test-run-wal2json> server # [    0.421275] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages235vm-test-run-wal2json> server # [    0.421304] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page236vm-test-run-wal2json> server # [    0.444892] fbcon: Taking over console237vm-test-run-wal2json> server # [    0.445178] ACPI: Interpreter disabled.238vm-test-run-wal2json> server # [    0.453296] iommu: Default domain type: Translated239vm-test-run-wal2json> server # [    0.453711] iommu: DMA domain TLB invalidation policy: strict mode240vm-test-run-wal2json> server # [    0.467874] SCSI subsystem initialized241vm-test-run-wal2json> server # [    0.475208] usbcore: registered new interface driver usbfs242vm-test-run-wal2json> server # [    0.475550] usbcore: registered new interface driver hub243vm-test-run-wal2json> server # [    0.475734] usbcore: registered new device driver usb244vm-test-run-wal2json> server # [    0.479722] pps_core: LinuxPPS API ver. 1 registered245vm-test-run-wal2json> server # [    0.479804] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>246vm-test-run-wal2json> server # [    0.479904] PTP clock support registered247vm-test-run-wal2json> server # [    0.480239] EDAC MC: Ver: 3.0.0248vm-test-run-wal2json> server # [    0.484135] scmi_core: SCMI protocol bus registered249vm-test-run-wal2json> server # [    0.488846] FPGA manager framework250vm-test-run-wal2json> server # [    0.500083] vgaarb: loaded251vm-test-run-wal2json> server # [    0.507803] clocksource: Switched to clocksource arch_sys_counter252vm-test-run-wal2json> server # [    0.538942] VFS: Disk quotas dquot_6.6.0253vm-test-run-wal2json> server # [    0.539155] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)254vm-test-run-wal2json> server # [    0.541868] netfs: FS-Cache loaded255vm-test-run-wal2json> server # [    0.543394] pnp: PnP ACPI: disabled256vm-test-run-wal2json> server # [    0.615570] NET: Registered PF_INET protocol family257vm-test-run-wal2json> server # [    0.617516] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)258vm-test-run-wal2json> server # [    0.733679] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)259vm-test-run-wal2json> server # [    0.733899] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)260vm-test-run-wal2json> server # [    0.734051] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)261vm-test-run-wal2json> server # [    0.734594] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)262vm-test-run-wal2json> server # [    0.734939] TCP: Hash tables configured (established 32768 bind 32768)263vm-test-run-wal2json> server # [    0.737191] MPTCP token hash table entries: 4096 (order: 5, 98304 bytes, linear)264vm-test-run-wal2json> server # [    0.737588] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)265vm-test-run-wal2json> server # [    0.737855] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)266vm-test-run-wal2json> server # [    0.739479] NET: Registered PF_UNIX/PF_LOCAL protocol family267vm-test-run-wal2json> server # [    0.741149] NET: Registered PF_XDP protocol family268vm-test-run-wal2json> server # [    0.741395] PCI: CLS 0 bytes, default 64269vm-test-run-wal2json> server # [    0.746392] Trying to unpack rootfs image as initramfs...270vm-test-run-wal2json> server # [    0.748770] kvm [1]: HYP mode not available271vm-test-run-wal2json> server # [    0.912295] Initialise system trusted keyrings272vm-test-run-wal2json> server # [    0.915445] workingset: timestamp_bits=42 max_order=20 bucket_order=0273vm-test-run-wal2json> server # [    0.921509] squashfs: version 4.0 (2009/01/31) Phillip Lougher274vm-test-run-wal2json> server # [    0.922034] 9p: Installing v9fs 9p2000 file system support275vm-test-run-wal2json> server # [    0.986430] Key type asymmetric registered276vm-test-run-wal2json> server # [    0.986582] Asymmetric key parser 'x509' registered277vm-test-run-wal2json> server # [    0.988137] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)278vm-test-run-wal2json> server # [    0.989660] io scheduler mq-deadline registered279vm-test-run-wal2json> server # [    0.989755] io scheduler kyber registered280vm-test-run-wal2json> server # [    1.037571] pl061_gpio 9030000.pl061: PL061 GPIO chip registered281vm-test-run-wal2json> server # [    1.044529] ledtrig-cpu: registered to indicate activity on CPUs282vm-test-run-wal2json> server # [    1.049331] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:283vm-test-run-wal2json> server # [    1.049942] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000284vm-test-run-wal2json> server # [    1.050484] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000285vm-test-run-wal2json> server # [    1.050587] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000286vm-test-run-wal2json> server # [    1.051126] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits287vm-test-run-wal2json> server # [    1.051642] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]288vm-test-run-wal2json> server # [    1.056424] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00289vm-test-run-wal2json> server # [    1.056798] pci_bus 0000:00: root bus resource [bus 00-ff]290vm-test-run-wal2json> server # [    1.056910] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]291vm-test-run-wal2json> server # [    1.056979] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]292vm-test-run-wal2json> server # [    1.057022] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]293vm-test-run-wal2json> server # [    1.058129] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint294vm-test-run-wal2json> server # [    1.064791] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint295vm-test-run-wal2json> server # [    1.065076] pci 0000:00:01.0: BAR 0 [io  0x0000-0x001f]296vm-test-run-wal2json> server # [    1.065164] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]297vm-test-run-wal2json> server # [    1.065232] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]298vm-test-run-wal2json> server # [    1.065328] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]299vm-test-run-wal2json> server # [    1.065910] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint300vm-test-run-wal2json> server # [    1.066002] pci 0000:00:02.0: BAR 0 [io  0x0000-0x001f]301vm-test-run-wal2json> server # [    1.066041] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]302vm-test-run-wal2json> server # [    1.066082] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]303vm-test-run-wal2json> server # [    1.066820] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint304vm-test-run-wal2json> server # [    1.066915] pci 0000:00:03.0: BAR 0 [io  0x0000-0x003f]305vm-test-run-wal2json> server # [    1.066960] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]306vm-test-run-wal2json> server # [    1.067010] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]307vm-test-run-wal2json> server # [    1.067528] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint308vm-test-run-wal2json> server # [    1.067623] pci 0000:00:04.0: BAR 0 [io  0x0000-0x001f]309vm-test-run-wal2json> server # [    1.071053] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]310vm-test-run-wal2json> server # [    1.071136] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]311vm-test-run-wal2json> server # [    1.073120] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint312vm-test-run-wal2json> server # [    1.073232] pci 0000:00:05.0: BAR 0 [io  0x0000-0x001f]313vm-test-run-wal2json> server # [    1.073274] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]314vm-test-run-wal2json> server # [    1.073316] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]315vm-test-run-wal2json> server # [    1.073858] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint316vm-test-run-wal2json> server # [    1.073959] pci 0000:00:06.0: BAR 0 [io  0x0000-0x007f]317vm-test-run-wal2json> server # [    1.074214] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]318vm-test-run-wal2json> server # [    1.074499] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]319vm-test-run-wal2json> server # [    1.075501] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint320vm-test-run-wal2json> server # [    1.079301] pci 0000:00:07.0: BAR 0 [io  0x0000-0x001f]321vm-test-run-wal2json> server # [    1.079470] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]322vm-test-run-wal2json> server # [    1.079643] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]323vm-test-run-wal2json> server # [    1.082068] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]324vm-test-run-wal2json> server # [    1.082857] pci 0000:00:08.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint325vm-test-run-wal2json> server # [    1.082977] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]326vm-test-run-wal2json> server # [    1.083030] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]327vm-test-run-wal2json> server # [    1.083531] pci 0000:00:09.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint328vm-test-run-wal2json> server # [    1.083631] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]329vm-test-run-wal2json> server # [    1.083678] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]330vm-test-run-wal2json> server # [    1.086750] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint331vm-test-run-wal2json> server # [    1.086894] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]332vm-test-run-wal2json> server # [    1.087539] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint333vm-test-run-wal2json> server # [    1.089157] pci 0000:00:0b.0: BAR 0 [io  0x0000-0x003f]334vm-test-run-wal2json> server # [    1.089228] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]335vm-test-run-wal2json> server # [    1.089274] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]336vm-test-run-wal2json> server # [    1.089899] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint337vm-test-run-wal2json> server # [    1.090151] pci 0000:00:0c.0: BAR 0 [io  0x0000-0x001f]338vm-test-run-wal2json> server # [    1.090214] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]339vm-test-run-wal2json> server # [    1.090263] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]340vm-test-run-wal2json> server # [    1.096913] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned341vm-test-run-wal2json> server # [    1.097366] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned342vm-test-run-wal2json> server # [    1.097799] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned343vm-test-run-wal2json> server # [    1.098027] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned344vm-test-run-wal2json> server # [    1.098118] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned345vm-test-run-wal2json> server # [    1.098176] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned346vm-test-run-wal2json> server # [    1.098231] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned347vm-test-run-wal2json> server # [    1.098286] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned348vm-test-run-wal2json> server # [    1.098341] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned349vm-test-run-wal2json> server # [    1.098429] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned350vm-test-run-wal2json> server # [    1.098484] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned351vm-test-run-wal2json> server # [    1.098539] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned352vm-test-run-wal2json> server # [    1.098622] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned353vm-test-run-wal2json> server # [    1.098687] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned354vm-test-run-wal2json> server # [    1.098746] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned355vm-test-run-wal2json> server # [    1.098797] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned356vm-test-run-wal2json> server # [    1.098839] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned357vm-test-run-wal2json> server # [    1.098886] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned358vm-test-run-wal2json> server # [    1.098933] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned359vm-test-run-wal2json> server # [    1.098975] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned360vm-test-run-wal2json> server # [    1.099016] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned361vm-test-run-wal2json> server # [    1.099058] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned362vm-test-run-wal2json> server # [    1.099106] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned363vm-test-run-wal2json> server # [    1.099148] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned364vm-test-run-wal2json> server # [    1.099190] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned365vm-test-run-wal2json> server # [    1.099238] pci 0000:00:06.0: BAR 0 [io  0x1000-0x107f]: assigned366vm-test-run-wal2json> server # [    1.099299] pci 0000:00:03.0: BAR 0 [io  0x1080-0x10bf]: assigned367vm-test-run-wal2json> server # [    1.099340] pci 0000:00:0b.0: BAR 0 [io  0x10c0-0x10ff]: assigned368vm-test-run-wal2json> server # [    1.099380] pci 0000:00:01.0: BAR 0 [io  0x1100-0x111f]: assigned369vm-test-run-wal2json> server # [    1.099420] pci 0000:00:02.0: BAR 0 [io  0x1120-0x113f]: assigned370vm-test-run-wal2json> server # [    1.099460] pci 0000:00:04.0: BAR 0 [io  0x1140-0x115f]: assigned371vm-test-run-wal2json> server # [    1.099500] pci 0000:00:05.0: BAR 0 [io  0x1160-0x117f]: assigned372vm-test-run-wal2json> server # [    1.099540] pci 0000:00:07.0: BAR 0 [io  0x1180-0x119f]: assigned373vm-test-run-wal2json> server # [    1.099580] pci 0000:00:0c.0: BAR 0 [io  0x11a0-0x11bf]: assigned374vm-test-run-wal2json> server # [    1.099876] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]375vm-test-run-wal2json> server # [    1.099929] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]376vm-test-run-wal2json> server # [    1.099967] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]377vm-test-run-wal2json> server # [    1.101325] pci 0000:00:0a.0: enabling device (0000 -> 0002)378vm-test-run-wal2json> server # [    1.113932] pci 0000:00:0a.0: quirk_usb_early_handoff+0x0/0xa60 took 12563 usecs379vm-test-run-wal2json> server # [    1.202297] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)380vm-test-run-wal2json> server # [    1.208218] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)381vm-test-run-wal2json> server # [    1.211701] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)382vm-test-run-wal2json> server # [    1.217176] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)383vm-test-run-wal2json> server # [    1.219383] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)384vm-test-run-wal2json> server # [    1.224992] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)385vm-test-run-wal2json> server # [    1.229284] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)386vm-test-run-wal2json> server # [    1.233031] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)387vm-test-run-wal2json> server # [    1.234987] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)388vm-test-run-wal2json> server # [    1.240596] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)389vm-test-run-wal2json> server # [    1.242304] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)390vm-test-run-wal2json> server # [    1.269742] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled391vm-test-run-wal2json> server # [    1.281899] msm_serial: driver initialized392vm-test-run-wal2json> server # [    1.283003] SuperH (H)SCI(F) driver initialized393vm-test-run-wal2json> server # [    1.283442] STM32 USART driver initialized394vm-test-run-wal2json> server # [    1.345698] loop: module loaded395vm-test-run-wal2json> server # [    1.346319] virtio_blk virtio5: 2/0/0 default/read/poll queues396vm-test-run-wal2json> server # [    1.351753] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)397vm-test-run-wal2json> server # [    1.366199] megasas: 07.734.00.00-rc1398vm-test-run-wal2json> server # [    1.373708] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]399vm-test-run-wal2json> server # [    1.376115] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000400vm-test-run-wal2json> server # [    1.378759] Intel/Sharp Extended Query Table at 0x0031401vm-test-run-wal2json> server # [    1.381707] Using buffer write method402vm-test-run-wal2json> server # [    1.382270] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]403vm-test-run-wal2json> server # [    1.383784] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000404vm-test-run-wal2json> server # [    1.385935] Intel/Sharp Extended Query Table at 0x0031405vm-test-run-wal2json> server # [    1.387249] Using buffer write method406vm-test-run-wal2json> server # [    1.389162] Concatenating MTD devices:407vm-test-run-wal2json> server # [    1.389262] (0): "0.flash"408vm-test-run-wal2json> server # [    1.389297] (1): "0.flash"409vm-test-run-wal2json> server # [    1.389587] into device "0.flash"410vm-test-run-wal2json> server # [    1.972335] Freeing initrd memory: 25488K411vm-test-run-wal2json> server # [    2.094299] tun: Universal TUN/TAP device driver, 1.6412vm-test-run-wal2json> server # [    2.109977] thunder_xcv, ver 1.0413vm-test-run-wal2json> server # [    2.110198] thunder_bgx, ver 1.0414vm-test-run-wal2json> server # [    2.110409] nicpf, ver 1.0415vm-test-run-wal2json> server # [    2.114899] e1000: Intel(R) PRO/1000 Network Driver416vm-test-run-wal2json> server # [    2.114983] e1000: Copyright (c) 1999-2006 Intel Corporation.417vm-test-run-wal2json> server # [    2.115164] e1000e: Intel(R) PRO/1000 Network Driver418vm-test-run-wal2json> server # [    2.115201] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.419vm-test-run-wal2json> server # [    2.115357] igb: Intel(R) Gigabit Ethernet Network Driver420vm-test-run-wal2json> server # [    2.115395] igb: Copyright (c) 2007-2014 Intel Corporation.421vm-test-run-wal2json> server # [    2.115563] igbvf: Intel(R) Gigabit Virtual Function Network Driver422vm-test-run-wal2json> server # [    2.115597] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.423vm-test-run-wal2json> server # [    2.117212] sky2: driver version 1.30424vm-test-run-wal2json> server # [    2.127405] ehci-pci 0000:00:0a.0: EHCI Host Controller425vm-test-run-wal2json> server # [    2.128558] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1426vm-test-run-wal2json> server # [    2.129086] usbcore: registered new interface driver usb-storage427vm-test-run-wal2json> server # [    2.129545] usbcore: registered new interface driver usbserial_generic428vm-test-run-wal2json> server # [    2.129756] usbserial: USB Serial support registered for generic429vm-test-run-wal2json> server # [    2.130596] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000430vm-test-run-wal2json> server # [    2.135017] hv_vmbus: registering driver hyperv_keyboard431vm-test-run-wal2json> server # [    2.140404] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00432vm-test-run-wal2json> server # [    2.143160] rtc-pl031 9010000.pl031: registered as rtc0433vm-test-run-wal2json> server # [    2.144144] rtc-pl031 9010000.pl031: setting system clock to 2026-10-20T16:50:49 UTC (1792515049)434vm-test-run-wal2json> server # [    2.146150] i2c_dev: i2c /dev entries driver435vm-test-run-wal2json> server # [    2.149934] hub 1-0:1.0: USB hub found436vm-test-run-wal2json> server # [    2.152187] hub 1-0:1.0: 6 ports detected437vm-test-run-wal2json> server # [    2.168740] sdhci: Secure Digital Host Controller Interface driver438vm-test-run-wal2json> server # [    2.168830] sdhci: Copyright(c) Pierre Ossman439vm-test-run-wal2json> server # [    2.170620] Synopsys Designware Multimedia Card Interface Driver440vm-test-run-wal2json> server # [    2.173846] sdhci-pltfm: SDHCI platform and OF driver helper441vm-test-run-wal2json> server # [    2.182849] hid: raw HID events driver (C) Jiri Kosina442vm-test-run-wal2json> server # [    2.185095] usbcore: registered new interface driver usbhid443vm-test-run-wal2json> server # [    2.185165] usbhid: USB HID core driver444vm-test-run-wal2json> server # [    2.194277] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available445vm-test-run-wal2json> server # [    2.204861] drop_monitor: Initializing network drop monitor service446vm-test-run-wal2json> server # [    2.206128] NET: Registered PF_INET6 protocol family447vm-test-run-wal2json> server # [    2.216087] Segment Routing with IPv6448vm-test-run-wal2json> server # [    2.216353] In-situ OAM (IOAM) with IPv6449vm-test-run-wal2json> server # [    2.216932] NET: Registered PF_PACKET protocol family450vm-test-run-wal2json> server # [    2.218278] 9pnet: Installing 9P2000 support451vm-test-run-wal2json> server # [    2.225424] Key type dns_resolver registered452vm-test-run-wal2json> server # [    2.270782] registered taskstats version 1453vm-test-run-wal2json> server # [    2.274701] Loading compiled-in X.509 certificates454vm-test-run-wal2json> server # [    2.351294] Demotion targets for Node 0: null455vm-test-run-wal2json> server # [    2.352811] Key type .fscrypt registered456vm-test-run-wal2json> server # [    2.352881] Key type fscrypt-provisioning registered457vm-test-run-wal2json> server # [    2.355565] ima: No TPM chip found, activating TPM-bypass!458vm-test-run-wal2json> server # [    2.355780] ima: Allocated hash algorithm: sha1459vm-test-run-wal2json> server # [    2.358077] ima: No architecture policies found460vm-test-run-wal2json> server # [    2.368210] input: gpio-keys as /devices/platform/gpio-keys/input/input0461vm-test-run-wal2json> server # [    2.408790] usb 1-1: new high-speed USB device number 2 using ehci-pci462vm-test-run-wal2json> server # [    2.417916] clk: Disabling unused clocks463vm-test-run-wal2json> server # [    2.418152] PM: genpd: Disabling unused power domains464vm-test-run-wal2json> server # [    2.630166] 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/input1465vm-test-run-wal2json> server # [    2.702156] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0466vm-test-run-wal2json> server # [    2.780029] Freeing unused kernel memory: 4736K467vm-test-run-wal2json> server # [    2.781609] Run /init as init process468vm-test-run-wal2json> server # [    2.820203] usb 1-2: new high-speed USB device number 3 using ehci-pci469vm-test-run-wal2json> server # [    2.944115] systemd[1]: Successfully made /usr/ read-only.470vm-test-run-wal2json> server # [    3.002103] 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/input2471vm-test-run-wal2json> server # [    3.003547] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0472vm-test-run-wal2json> server # [    3.295002] systemd[1]: systemd 260.4 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)473vm-test-run-wal2json> server # [    3.295246] systemd[1]: Detected virtualization qemu.474vm-test-run-wal2json> server # [    3.295622] systemd[1]: Detected architecture arm64.475vm-test-run-wal2json> server # [    3.295681] systemd[1]: Running in initrd.476vm-test-run-wal2json> server # [    3.308018] systemd[1]: Initializing machine ID from random generator.477vm-test-run-wal2json> server # [    3.310469] systemd[1]: Hostname set to <server>.478vm-test-run-wal2json> server # [    4.113930] systemd[1]: Queued start job for default target Initrd Default Target.479vm-test-run-wal2json> server # [    4.162476] systemd[1]: Created slice Slice /system/modprobe.480vm-test-run-wal2json> server # [    4.169534] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.481vm-test-run-wal2json> server # [    4.170453] systemd[1]: Expecting device /dev/disk/by-label/nixos...482vm-test-run-wal2json> server # [    4.170920] systemd[1]: Reached target Path Units.483vm-test-run-wal2json> server # [    4.171114] systemd[1]: Reached target Slice Units.484vm-test-run-wal2json> server # [    4.171284] systemd[1]: Reached target Swaps.485vm-test-run-wal2json> server # [    4.171447] systemd[1]: Reached target Timer Units.486vm-test-run-wal2json> server # [    4.177917] systemd[1]: Listening on D-Bus System Message Bus Socket.487vm-test-run-wal2json> server # [    4.180497] systemd[1]: Listening on Journal Socket (/dev/log).488vm-test-run-wal2json> server # [    4.182354] systemd[1]: Listening on Journal Sockets.489vm-test-run-wal2json> server # [    4.185454] systemd[1]: Listening on udev Control Socket.490vm-test-run-wal2json> server # [    4.186705] systemd[1]: Listening on udev Kernel Socket.491vm-test-run-wal2json> server # [    4.187008] systemd[1]: Reached target Socket Units.492vm-test-run-wal2json> server # [    4.213607] systemd[1]: Starting Create List of Static Device Nodes...493vm-test-run-wal2json> server # [    4.241731] systemd[1]: Starting Load Kernel Module 9pnet_virtio...494vm-test-run-wal2json> server # [    4.243353] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs495vm-test-run-wal2json> server # [    4.285175] systemd[1]: Mounting Kernel Configuration File System...496vm-test-run-wal2json> server # [    4.385095] systemd[1]: Starting Journal Service...497vm-test-run-wal2json> server # [    4.425542] systemd[1]: Starting Load Kernel Modules...498vm-test-run-wal2json> server # [    4.427481] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki499vm-test-run-wal2json> server # [    4.479288] systemd[1]: Starting Coldplug All udev Devices...500vm-test-run-wal2json> server # [    4.594313] systemd[1]: Finished Create List of Static Device Nodes.501vm-test-run-wal2json> server # [    4.651564] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.502vm-test-run-wal2json> server # [    4.664477] systemd[1]: Finished Load Kernel Module 9pnet_virtio.503vm-test-run-wal2json> server # [    4.700965] systemd[1]: Mounted Kernel Configuration File System.504vm-test-run-wal2json> server # [    4.736975] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...505vm-test-run-wal2json> server # [    4.814805] systemd-journald[81]: Collecting audit messages is disabled.506vm-test-run-wal2json> server # [    4.882475] [drm] pci: virtio-gpu-pci detected at 0000:00:09.0507vm-test-run-wal2json> server # [    4.883061] [drm] features: -virgl +edid -resource_blob -host_visible508vm-test-run-wal2json> server # [    4.883091] [drm] features: -context_init509vm-test-run-wal2json> server # [    4.891269] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.510vm-test-run-wal2json> server # [    4.897353] [drm] number of scanouts: 1511vm-test-run-wal2json> server # [    4.897469] [drm] number of cap sets: 0512vm-test-run-wal2json> server # [    4.902835] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev513vm-test-run-wal2json> server # [    4.911787] virtio-pci 0000:00:09.0: [drm] Registered 1 planes with drm panic514vm-test-run-wal2json> server # [    4.912511] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:09.0 on minor 0515vm-test-run-wal2json> server # [    4.954307] Console: switching to colour frame buffer device 160x50516vm-test-run-wal2json> server # [    4.963546] virtio-pci 0000:00:09.0: [drm] fb0: virtio_gpudrmfb frame buffer device517vm-test-run-wal2json> server # [    5.012928] systemd[1]: Finished Load Kernel Modules.518vm-test-run-wal2json> server # [    5.049365] systemd[1]: Starting Apply Kernel Variables...519vm-test-run-wal2json> server # [    5.133517] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.520vm-test-run-wal2json> server # [    5.150958] systemd[1]: Starting Create Static Device Nodes in /dev...521vm-test-run-wal2json> server # [    5.345980] systemd[1]: Finished Apply Kernel Variables.522vm-test-run-wal2json> server # [    5.361484] systemd[1]: Finished Create Static Device Nodes in /dev.523vm-test-run-wal2json> server # [    5.366792] systemd[1]: Reached target Preparation for Local File Systems.524vm-test-run-wal2json> server # [    5.373313] systemd[1]: Reached target Local File Systems.525vm-test-run-wal2json> server # [    5.406355] systemd[1]: Starting Rule-based Manager for Device Events and Files...526vm-test-run-wal2json> server # [    6.021585] systemd[1]: Started Journal Service.527vm-test-run-wal2json> server # [    5.919702] systemd-modules-load[82]: Using 2 probe threads528vm-test-run-wal2json> server # [    5.931285] systemd-modules-load[82]: Module 'virtio_balloon' is built in529vm-test-run-wal2json> server # [    5.939540] systemd-modules-load[82]: Module 'virtio_console' is built in530vm-test-run-wal2json> server # [    5.947186] systemd-modules-load[82]: Inserted module 'dm_mod'531vm-test-run-wal2json> server # [    5.954678] systemd-modules-load[82]: Module 'virtio_rng' is built in532vm-test-run-wal2json> server # [    5.959647] systemd-modules-load[82]: Inserted module 'virtio_gpu'533vm-test-run-wal2json> server # [    5.979060] systemd-udevd[90]: Using default interface naming scheme 'v260'.534vm-test-run-wal2json> server # [    5.997594] systemd[1]: Starting Create System Files and Directories...535vm-test-run-wal2json> server # [    6.241830] systemd[1]: Finished Create System Files and Directories.536vm-test-run-wal2json> server # [    6.341827] systemd[1]: Started Rule-based Manager for Device Events and Files.537vm-test-run-wal2json> server # [    6.822576] systemd[1]: Starting Virtual Console Setup...538vm-test-run-wal2json> server # [    7.160267] systemd-vconsole-setup[112]: Configuration of first virtual console was skipped, ignoring remaining ones.539vm-test-run-wal2json> server # [    7.202384] systemd[1]: Finished Virtual Console Setup.540vm-test-run-wal2json> server # [   11.673842] systemd[1]: Finished Coldplug All udev Devices.541vm-test-run-wal2json> server # [   11.679381] systemd[1]: Reached target System Initialization.542vm-test-run-wal2json> server # [   11.686233] systemd[1]: Reached target Basic System.543vm-test-run-wal2json> server # [   14.398654] (udev-worker)[145]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.544vm-test-run-wal2json> server # [   14.404595] (udev-worker)[145]: Network interface NamePolicy= disabled on kernel command line.545vm-test-run-wal2json> server # [   14.413601] (udev-worker)[147]: Network interface NamePolicy= disabled on kernel command line.546vm-test-run-wal2json> server # [   14.747102] systemd[1]: Found device /dev/disk/by-label/nixos.547vm-test-run-wal2json> server # [   14.841540] systemd[1]: Reached target Initrd Root Device.548vm-test-run-wal2json> server # [   14.857252] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...549vm-test-run-wal2json> server # [   15.243652] systemd-fsck[160]: nixos: clean, 12/65536 files, 13019/262144 blocks550vm-test-run-wal2json> server # [   15.303691] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.551vm-test-run-wal2json> server # [   15.356666] systemd[1]: Mounting /sysroot...552vm-test-run-wal2json> server # [   15.721680] EXT4-fs (vda): mounted filesystem 4c52b437-666d-4b31-a9a9-eded65af2822 r/w with ordered data mode. Quota mode: none.553vm-test-run-wal2json> server # [   15.663376] systemd[1]: Mounted /sysroot.554vm-test-run-wal2json> server # [   15.682676] systemd[1]: Reached target Initrd Root File System.555vm-test-run-wal2json> server # [   15.710029] systemd[1]: Starting Mountpoints Configured in the Real Root...556vm-test-run-wal2json> server # [   15.884986] systemd-sysroot-fstab-check[168]: /sysroot should be mounted in the initrd, will request daemon-reload.557vm-test-run-wal2json> server # [   15.896474] systemd[1]: Reload requested from client PID 168 ('systemd-sysroot') (unit initrd-parse-etc.service)...558vm-test-run-wal2json> server # [   15.905266] systemd[1]: Reloading...559vm-test-run-wal2json> server # [   17.233543] systemd[1]: Reloading finished in 1329 ms.560vm-test-run-wal2json> server # [   17.293339] systemd-sysroot-fstab-check[168]: Requesting initrd-fs.target/start/replace...561vm-test-run-wal2json> server # [   17.308348] systemd-sysroot-fstab-check[168]: Requesting swap.target/start/replace...562vm-test-run-wal2json> server # [   17.342976] systemd[1]: Mounting /sysroot/nix/.rw-store...563vm-test-run-wal2json> server # [   17.362621] systemd[1]: Mounting /sysroot/run...564vm-test-run-wal2json> server # [   17.421091] systemd[1]: Starting Load Kernel Module 9pnet_virtio...565vm-test-run-wal2json> server # [   17.438540] systemd[1]: initrd-parse-etc.service: Deactivated successfully.566vm-test-run-wal2json> server # [   17.456961] systemd[1]: Finished Mountpoints Configured in the Real Root.567vm-test-run-wal2json> server # [   17.459714] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.568vm-test-run-wal2json> server # [   17.562585] systemd[1]: Mounted /sysroot/nix/.rw-store.569vm-test-run-wal2json> server # [   17.571922] systemd[1]: Mounted /sysroot/run.570vm-test-run-wal2json> server # [   17.622313] systemd[1]: Starting rw-sysroot-nix-store.service...571vm-test-run-wal2json> server # [   17.633066] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.572vm-test-run-wal2json> server # [   17.645566] systemd[1]: Finished Load Kernel Module 9pnet_virtio.573vm-test-run-wal2json> server # [   17.711049] systemd[1]: Mounting /sysroot/nix/.ro-store...574vm-test-run-wal2json> server # [   17.750710] systemd[1]: Mounting /sysroot/tmp/shared...575vm-test-run-wal2json> server # [   17.778132] systemd[1]: Mounting /sysroot/tmp/xchg...576vm-test-run-wal2json> server # [   17.797413] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.577vm-test-run-wal2json> server # [   17.806029] systemd[1]: Finished rw-sysroot-nix-store.service.578vm-test-run-wal2json> server # [   17.966085] systemd[1]: Mounted /sysroot/nix/.ro-store.579vm-test-run-wal2json> server # [   18.009676] systemd[1]: Mounted /sysroot/tmp/xchg.580vm-test-run-wal2json> server # [   18.017850] systemd[1]: Mounted /sysroot/tmp/shared.581vm-test-run-wal2json> server # [   18.349839] systemd[1]: Mounting /sysroot/nix/store...582vm-test-run-wal2json> server # [   18.683650] systemd[1]: Mounted /sysroot/nix/store.583vm-test-run-wal2json> server # [   18.703075] systemd[1]: Reached target Initrd File Systems.584vm-test-run-wal2json> server # [   18.749042] systemd[1]: Starting Find NixOS closure...585vm-test-run-wal2json> server # [   18.803717] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...586vm-test-run-wal2json> server # [   19.059234] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.587vm-test-run-wal2json> server # [   19.083706] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.588vm-test-run-wal2json> server # [   19.229734] systemd[1]: Finished Find NixOS closure.589vm-test-run-wal2json> server # [   19.240876] systemd[1]: Reached target Initrd Default Target.590vm-test-run-wal2json> server # [   19.253711] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...591vm-test-run-wal2json> server # [   19.490316] systemd[1]: Stopped target Initrd Default Target.592vm-test-run-wal2json> server # [   19.491807] systemd[1]: Stopped target Basic System.593vm-test-run-wal2json> server # [   19.497723] systemd[1]: Stopped target Initrd Root Device.594vm-test-run-wal2json> server # [   19.499451] systemd[1]: Stopped target Path Units.595vm-test-run-wal2json> server # [   19.507405] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.596vm-test-run-wal2json> server # [   19.521603] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.597vm-test-run-wal2json> server # [   19.523002] systemd[1]: Stopped target Slice Units.598vm-test-run-wal2json> server # [   19.526633] systemd[1]: Stopped target Socket Units.599vm-test-run-wal2json> server # [   19.531790] systemd[1]: Stopped target System Initialization.600vm-test-run-wal2json> server # [   19.537396] systemd[1]: Stopped target Swaps.601vm-test-run-wal2json> server # [   19.541846] systemd[1]: Stopped target Timer Units.602vm-test-run-wal2json> server # [   19.549446] systemd[1]: dbus.socket: Deactivated successfully.603vm-test-run-wal2json> server # [   19.550787] systemd[1]: Closed D-Bus System Message Bus Socket.604vm-test-run-wal2json> server # [   19.561257] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.605vm-test-run-wal2json> server # [   19.563762] systemd[1]: Stopped Find NixOS closure.606vm-test-run-wal2json> server # [   19.629186] systemd[1]: Starting Load Kernel Module 9pnet_virtio...607vm-test-run-wal2json> server # [   19.689065] systemd[1]: Starting rw-sysroot-nix-store.service...608vm-test-run-wal2json> server # [   19.690795] systemd[1]: systemd-sysctl.service: Deactivated successfully.609vm-test-run-wal2json> server # [   19.705634] systemd[1]: Stopped Apply Kernel Variables.610vm-test-run-wal2json> server # [   19.715985] systemd[1]: systemd-modules-load.service: Deactivated successfully.611vm-test-run-wal2json> server # [   19.752962] systemd[1]: Stopped Load Kernel Modules.612vm-test-run-wal2json> server # [   19.779168] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.613vm-test-run-wal2json> server # [   19.811770] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.614vm-test-run-wal2json> server # [   19.819588] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.615vm-test-run-wal2json> server # [   19.831699] systemd[1]: Stopped Create System Files and Directories.616vm-test-run-wal2json> server # [   19.857105] systemd[1]: Stopped target Local File Systems.617vm-test-run-wal2json> server # [   19.874936] systemd[1]: Stopped target Preparation for Local File Systems.618vm-test-run-wal2json> server # [   19.885237] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.619vm-test-run-wal2json> server # [   19.904958] systemd[1]: Stopped Coldplug All udev Devices.620vm-test-run-wal2json> server # [   19.917146] systemd[1]: systemd-udev-trigger.service: Consumed 5.928s CPU time over 15.533s wall clock time, 9.3M memory peak.621vm-test-run-wal2json> server # [   19.928923] systemd[1]: Stopping Rule-based Manager for Device Events and Files...622vm-test-run-wal2json> server # [   19.934269] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.623vm-test-run-wal2json> server # [   19.941457] systemd[1]: Stopped Virtual Console Setup.624vm-test-run-wal2json> server # [   19.993048] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.625vm-test-run-wal2json> server # [   20.000644] systemd[1]: Finished Load Kernel Module 9pnet_virtio.626vm-test-run-wal2json> server # [   20.078861] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.627vm-test-run-wal2json> server # [   20.086346] systemd[1]: Finished rw-sysroot-nix-store.service.628vm-test-run-wal2json> server # [   20.107501] systemd[1]: initrd-cleanup.service: Deactivated successfully.629vm-test-run-wal2json> server # [   20.116120] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.630vm-test-run-wal2json> server # [   20.659401] systemd[1]: systemd-udevd.service: Deactivated successfully.631vm-test-run-wal2json> server # [   20.664123] systemd[1]: Stopped Rule-based Manager for Device Events and Files.632vm-test-run-wal2json> server # [   20.666288] systemd[1]: systemd-udevd.service: Consumed 11.190s CPU time over 15.360s wall clock time, 31M memory peak.633vm-test-run-wal2json> server # [   20.669586] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.634vm-test-run-wal2json> server # [   20.673312] systemd[1]: Closed udev Control Socket.635vm-test-run-wal2json> server # [   20.688996] systemd[1]: Starting Cleanup udev Database...636vm-test-run-wal2json> server # [   20.693108] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.637vm-test-run-wal2json> server # [   20.695931] systemd[1]: Stopped Create Static Device Nodes in /dev.638vm-test-run-wal2json> server # [   20.703051] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.639vm-test-run-wal2json> server # [   20.706665] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.640vm-test-run-wal2json> server # [   20.708236] systemd[1]: kmod-static-nodes.service: Deactivated successfully.641vm-test-run-wal2json> server # [   20.711335] systemd[1]: Stopped Create List of Static Device Nodes.642vm-test-run-wal2json> server # [   20.861478] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.643vm-test-run-wal2json> server # [   20.864991] systemd[1]: Finished Cleanup udev Database.644vm-test-run-wal2json> server # [   20.876765] systemd[1]: Reached target Switch Root.645vm-test-run-wal2json> server # [   20.891990] systemd[1]: Starting NixOS Activation...646vm-test-run-wal2json> server # [   22.818800] initrd-nixos-activation-start[260]: booting system configuration /nix/store/h426kxg3mnpfhvs5sgb977wxrzr7y67d-nixos-system-server-test647vm-test-run-wal2json> server # [   23.558051] initrd-nixos-activation-start[260]: running activation script...648vm-test-run-wal2json> server # [   28.155666] initrd-nixos-activation-start[283]: setting up /etc...649vm-test-run-wal2json> server: Guest root shell did not produce any data yet...650vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.651vm-test-run-wal2json> server # [   30.792999] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.652vm-test-run-wal2json> server # [   30.794655] systemd[1]: Finished NixOS Activation.653vm-test-run-wal2json> server # [   30.796052] systemd[1]: initrd-nixos-activation.service: Consumed 4.941s CPU time over 9.895s wall clock time, 22.6M memory peak.654vm-test-run-wal2json> server # [   30.815302] systemd[1]: Starting Switch Root...655vm-test-run-wal2json> server # [   30.953215] systemd[1]: Switching root.656vm-test-run-wal2json> server # [   31.223694] systemd-journald[81]: Received SIGTERM from PID 1 (systemd).657vm-test-run-wal2json> server # [   33.580311] systemd[1]: systemd 260.4 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)658vm-test-run-wal2json> server # [   33.581677] systemd[1]: Detected virtualization qemu.659vm-test-run-wal2json> server # [   33.583263] systemd[1]: Detected architecture arm64.660vm-test-run-wal2json> server # [   33.586442] systemd[1]: Detected first boot.661vm-test-run-wal2json> server # [   33.625857] systemd[1]: Initializing machine ID from random generator.662vm-test-run-wal2json> server # [   34.883421] systemd[1]: bpf-restrict-fs: LSM BPF program attached663vm-test-run-wal2json> server # [   36.366790] NET: Registered PF_VSOCK protocol family664vm-test-run-wal2json> server # [   36.415533] Guest personality initialized and is inactive665vm-test-run-wal2json> server # [   36.417698] VMCI host device registered (name=vmci, major=10, minor=261)666vm-test-run-wal2json> server # [   36.418265] Initialized host personality667vm-test-run-wal2json> server # [   36.653936] systemd[1]: Applying preset policy.668vm-test-run-wal2json> server # [   41.065215] systemd[1]: Populated /etc with preset unit settings.669vm-test-run-wal2json> server # [   46.133534] systemd[1]: initrd-switch-root.service: Deactivated successfully.670vm-test-run-wal2json> server # [   46.141099] systemd[1]: Stopped initrd-switch-root.service.671vm-test-run-wal2json> server # [   46.168752] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.672vm-test-run-wal2json> server # [   46.187718] systemd[1]: Created slice Slice /system/getty.673vm-test-run-wal2json> server # [   46.201486] systemd[1]: Created slice User and Session Slice.674vm-test-run-wal2json> server # [   46.207416] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.675vm-test-run-wal2json> server # [   46.214280] systemd[1]: Started Forward Password Requests to Wall Directory Watch.676vm-test-run-wal2json> server # [   46.219161] systemd[1]: Expecting device /dev/hvc0...677vm-test-run-wal2json> server # [   46.223595] systemd[1]: Expecting device /dev/ttyAMA0...678vm-test-run-wal2json> server # [   46.227308] systemd[1]: Reached target Local Encrypted Volumes.679vm-test-run-wal2json> server # [   46.231990] systemd[1]: Stopped target initrd-fs.target.680vm-test-run-wal2json> server # [   46.235679] systemd[1]: Stopped target initrd-root-fs.target.681vm-test-run-wal2json> server # [   46.239392] systemd[1]: Stopped target initrd-switch-root.target.682vm-test-run-wal2json> server # [   46.243910] systemd[1]: Reached target Virtual Machines and Containers.683vm-test-run-wal2json> server # [   46.249066] systemd[1]: Reached target Path Units.684vm-test-run-wal2json> server # [   46.251739] systemd[1]: Reached target Remote File Systems.685vm-test-run-wal2json> server # [   46.255437] systemd[1]: Reached target Slice Units.686vm-test-run-wal2json> server # [   46.258907] systemd[1]: Reached target Swaps.687vm-test-run-wal2json> server # [   46.295414] systemd[1]: Listening on Process Core Dump Socket.688vm-test-run-wal2json> server # [   46.321464] systemd[1]: Listening on Credential Encryption/Decryption.689vm-test-run-wal2json> server # [   46.363744] systemd[1]: Starting Journal Log Access Socket...690vm-test-run-wal2json> server # [   46.378015] systemd[1]: Listening on Journal Audit Socket.691vm-test-run-wal2json> server # [   46.389913] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.692vm-test-run-wal2json> server # [   46.395716] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki693vm-test-run-wal2json> server # [   46.407600] systemd[1]: Listening on udev Control Socket.694vm-test-run-wal2json> server # [   46.442440] systemd[1]: Mounting Huge Pages File System...695vm-test-run-wal2json> server # [   46.497881] systemd[1]: Mounting POSIX Message Queue File System...696vm-test-run-wal2json> server # [   46.540972] systemd[1]: Mounting Kernel Debug File System...697vm-test-run-wal2json> server # [   46.681972] systemd[1]: Mounting Kernel Trace File System...698vm-test-run-wal2json> server # [   46.789555] systemd[1]: Starting Create List of Static Device Nodes...699vm-test-run-wal2json> server # [   46.897233] systemd[1]: Starting Load Kernel Module 9pnet_virtio...700vm-test-run-wal2json> server # [   46.905463] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs701vm-test-run-wal2json> server # [   47.006664] systemd[1]: Mounting Kernel Configuration File System...702vm-test-run-wal2json> server # [   47.017850] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm703vm-test-run-wal2json> server # [   47.028927] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore704vm-test-run-wal2json> server # [   47.101786] systemd[1]: Starting Load Kernel Module fuse...705vm-test-run-wal2json> server # [   47.111092] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67706vm-test-run-wal2json> server # [   47.178518] systemd[1]: Starting Journal Service...707vm-test-run-wal2json> server # [   47.586812] systemd[1]: Starting Load Kernel Modules...708vm-test-run-wal2json> server # [   47.818881] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...709vm-test-run-wal2json> server # [   48.091542] systemd[1]: Starting Remount Root and Kernel File Systems...710vm-test-run-wal2json> server # [   48.145766] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki711vm-test-run-wal2json> server # [   48.386280] fuse: init (API version 7.45)712vm-test-run-wal2json> server # [   48.393954] systemd[1]: Starting Coldplug All udev Devices...713vm-test-run-wal2json> server # [   48.686593] systemd-journald[355]: Collecting audit messages is enabled.714vm-test-run-wal2json> server # [   48.741869] systemd[1]: Listening on Journal Log Access Socket.715vm-test-run-wal2json> server # [   48.777558] systemd[1]: Mounted Huge Pages File System.716vm-test-run-wal2json> server # [   48.827151] systemd[1]: Mounted POSIX Message Queue File System.717vm-test-run-wal2json> server # [   48.927613] systemd[1]: Mounted Kernel Debug File System.718vm-test-run-wal2json> server # [   48.944073] systemd[1]: Mounted Kernel Trace File System.719vm-test-run-wal2json> server # [   48.954164] systemd[1]: Started Journal Service.720vm-test-run-wal2json> server # [   48.875355] systemd[1]: Queued start job for default target Multi-User System.721vm-test-run-wal2json> server # [   48.883281] systemd[1]: systemd-journald.service: Deactivated successfully.722vm-test-run-wal2json> server # [   48.957440] systemd[1]: systemd-journald.service: Consumed 1.318s CPU time over 41.665s wall clock time, 9.9M memory peak.723vm-test-run-wal2json> server # [   49.017751] systemd-modules-load[356]: Using 2 probe threads724vm-test-run-wal2json> server # [   49.041820] systemd-modules-load[356]: Module 'atkbd' is built in725vm-test-run-wal2json> server # [   49.074512] systemd[1]: Finished Create List of Static Device Nodes.726vm-test-run-wal2json> server # [   49.093741] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.727vm-test-run-wal2json> server # [   49.107207] systemd[1]: Finished Load Kernel Module 9pnet_virtio.728vm-test-run-wal2json> server # [   49.115908] systemd[1]: Mounted Kernel Configuration File System.729vm-test-run-wal2json> server # [   49.148055] systemd-modules-load[356]: Module 'loop' is built in730vm-test-run-wal2json> server # [   49.170948] systemd[1]: modprobe@fuse.service: Deactivated successfully.731vm-test-run-wal2json> server # [   49.175940] systemd[1]: Finished Load Kernel Module fuse.732vm-test-run-wal2json> server # [   49.199193] systemd[1]: Finished Load Kernel Modules.733vm-test-run-wal2json> server # [   49.505589] EXT4-fs (vda): re-mounted 4c52b437-666d-4b31-a9a9-eded65af2822.734vm-test-run-wal2json> server # [   49.538173] systemd[1]: Mounting FUSE Control File System...735vm-test-run-wal2json> server # [   49.643414] systemd-oomd[357]: No swap; memory pressure usage will be degraded736vm-test-run-wal2json> server # [   49.659512] systemd[1]: Starting Firewall...737vm-test-run-wal2json> server # [   49.733907] systemd[1]: Starting Apply Kernel Variables...738vm-test-run-wal2json> server # [   49.815620] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...739vm-test-run-wal2json> server # [   49.863238] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.740vm-test-run-wal2json> server # [   49.933591] systemd[1]: Finished Remount Root and Kernel File Systems.741vm-test-run-wal2json> server # [   50.730937] systemd[1]: Starting Flush Journal to Persistent Storage...742vm-test-run-wal2json> server # [   50.744908] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore743vm-test-run-wal2json> server # [   50.918003] systemd[1]: Starting Load/Save OS Random Seed...744vm-test-run-wal2json> server # [   50.936979] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki745vm-test-run-wal2json> server # [   51.187211] systemd[1]: Mounted FUSE Control File System.746vm-test-run-wal2json> server # [   51.439863] systemd[1]: Finished Apply Kernel Variables.747vm-test-run-wal2json> server # [   51.918628] systemd-journald[355]: Received client request to flush runtime journal.748vm-test-run-wal2json> server # [   52.414550] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.749vm-test-run-wal2json> server # [   52.429641] systemd[1]: Starting Create Static Device Nodes in /dev...750vm-test-run-wal2json> server # [   52.441700] systemd[1]: Finished Load/Save OS Random Seed.751vm-test-run-wal2json> server # [   52.443221] systemd[1]: Reached target First Boot Complete.752vm-test-run-wal2json> server # [   52.491218] systemd[1]: Finished Flush Journal to Persistent Storage.753vm-test-run-wal2json> server # [   53.325148] systemd[1]: Finished Create Static Device Nodes in /dev.754vm-test-run-wal2json> server # [   53.349773] systemd[1]: Reached target Preparation for Local File Systems.755vm-test-run-wal2json> server # [   53.398309] systemd[1]: Mounting /run/wrappers...756vm-test-run-wal2json> server # [   53.481852] systemd[1]: Starting Rule-based Manager for Device Events and Files...757vm-test-run-wal2json> server # [   53.919756] systemd[1]: Mounted /run/wrappers.758vm-test-run-wal2json> server # [   53.957409] systemd[1]: Reached target Local File Systems.759vm-test-run-wal2json> server # [   54.019603] systemd[1]: Listening on Boot Loader Control Service Socket.760vm-test-run-wal2json> server # [   54.086641] systemd[1]: Starting register-nix-paths.service...761vm-test-run-wal2json> server # [   54.289176] systemd[1]: Starting Create SUID/SGID Wrappers...762vm-test-run-wal2json> server # [   54.318462] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.763vm-test-run-wal2json> server # [   54.554323] systemd[1]: Starting Save Transient machine-id to Disk...764vm-test-run-wal2json> server # [   54.849063] systemd[1]: Starting Create System Files and Directories...765vm-test-run-wal2json> server # [   56.175948] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.766vm-test-run-wal2json> server # [   56.242352] systemd[1]: Finished Save Transient machine-id to Disk.767vm-test-run-wal2json> server # [   58.074959] systemd[1]: Finished Create System Files and Directories.768vm-test-run-wal2json> server # [   58.290250] systemd[1]: Starting Rebuild Journal Catalog...769vm-test-run-wal2json> server # [   58.473763] systemd[1]: Starting Record System Boot/Shutdown in UTMP...770vm-test-run-wal2json> server: Guest root shell did not produce any data yet...771vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.772vm-test-run-wal2json> server # [   59.923323] systemd[1]: Finished Record System Boot/Shutdown in UTMP.773vm-test-run-wal2json> server # [   60.901369] systemd[1]: Finished Rebuild Journal Catalog.774vm-test-run-wal2json> server # [   61.072108] systemd[1]: Starting Update is Completed...775vm-test-run-wal2json> server # [   61.981114] systemd[1]: Finished Update is Completed.776vm-test-run-wal2json> server # [   67.067593] systemd-udevd[405]: Using default interface naming scheme 'v260'.777vm-test-run-wal2json> server # [   67.366696] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.778vm-test-run-wal2json> server # [   67.435206] systemd[1]: Finished Create SUID/SGID Wrappers.779vm-test-run-wal2json> server # [   67.438652] systemd[1]: suid-sgid-wrappers.service: Consumed 3.265s CPU time over 13.120s wall clock time, 5.5M memory peak.780vm-test-run-wal2json> server # [   68.916185] systemd[1]: Finished register-nix-paths.service.781vm-test-run-wal2json> server # [   69.199546] systemd[1]: Started Rule-based Manager for Device Events and Files.782vm-test-run-wal2json> server # [   71.519068] systemd[1]: Finished Firewall.783vm-test-run-wal2json> server # [   74.170971] systemd[1]: Finished Coldplug All udev Devices.784vm-test-run-wal2json> server # [   74.185099] systemd[1]: Reached target System Initialization.785vm-test-run-wal2json> server # [   74.197037] systemd[1]: Started Discard unused filesystem blocks once a week.786vm-test-run-wal2json> server # [   74.198669] systemd[1]: Started Daily Cleanup of Temporary Directories.787vm-test-run-wal2json> server # [   74.206941] systemd[1]: Reached target Timer Units.788vm-test-run-wal2json> server # [   74.211870] systemd[1]: Listening on D-Bus System Message Bus Socket.789vm-test-run-wal2json> server # [   74.221227] systemd[1]: Listening on Nix Daemon Socket.790vm-test-run-wal2json> server # [   74.255399] systemd[1]: Listening on OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local).791vm-test-run-wal2json> server # [   74.263046] systemd[1]: Listening on Hostname Service Socket.792vm-test-run-wal2json> server # [   74.270994] systemd[1]: Reached target Socket Units.793vm-test-run-wal2json> server # [   74.273139] systemd[1]: Reached target Basic System.794vm-test-run-wal2json> server # [   74.304956] systemd[1]: Starting Import lastlog data into lastlog2 database...795vm-test-run-wal2json> server # [   74.375326] systemd[1]: Starting Name Service Cache Daemon (nsncd)...796vm-test-run-wal2json> server # [   74.450457] systemd[1]: Starting Post-Boot Actions...797vm-test-run-wal2json> server # [   74.557959] systemd[1]: Started Reset console on configuration changes.798vm-test-run-wal2json> server # [   74.800944] systemd[1]: Starting resolvconf update...799vm-test-run-wal2json> server # [   74.962268] systemd[1]: Starting SSH Host Keys Generation...800vm-test-run-wal2json> server # [   75.692009] systemd[1]: Finished Post-Boot Actions.801vm-test-run-wal2json> server # [   75.961263] systemd[1]: Starting D-Bus System Message Bus...802vm-test-run-wal2json> server # [   76.015591] nsncd[614]: Oct 20 16:52:03.411 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"803vm-test-run-wal2json> server # [   76.039922] systemd[1]: Started Name Service Cache Daemon (nsncd).804vm-test-run-wal2json> server # [   76.051563] systemd[1]: Reached target Host and Network Name Lookups.805vm-test-run-wal2json> server # [   76.074430] systemd[1]: Reached target User and Group Name Lookups.806vm-test-run-wal2json> server # [   76.385034] systemd[1]: Starting User Login Management...807vm-test-run-wal2json> server # [   76.475650] systemd[1]: Finished Import lastlog data into lastlog2 database.808vm-test-run-wal2json> server # [   77.924120] dbus-broker-launch[625]: Looking up NSS user entry for 'systemd-timesync'...809vm-test-run-wal2json> server # [   78.239438] dbus-broker-launch[625]: NSS returned no entry for 'systemd-timesync'810vm-test-run-wal2json> server # [   78.250683] dbus-broker-launch[625]: Invalid user-name in /nix/store/5h856rbg3k083wvxcyxah3pai9zw58rx-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"811vm-test-run-wal2json> server # [   78.670283] systemd-logind[638]: New seat seat0.812vm-test-run-wal2json> server # [   78.751421] systemd[1]: Started D-Bus System Message Bus.813vm-test-run-wal2json> server # [   78.777845] systemd[1]: Started User Login Management.814vm-test-run-wal2json> server # [   78.869508] systemd[1]: Starting linger-users.service...815vm-test-run-wal2json> server # [   79.400565] dbus-broker-launch[625]: Ready816vm-test-run-wal2json> server # [   79.534300] systemd[1]: linger-users.service: Deactivated successfully.817vm-test-run-wal2json> server # [   79.545605] systemd[1]: Finished linger-users.service.818vm-test-run-wal2json> server # [   79.989361] systemd[1]: Stopped target Host and Network Name Lookups.819vm-test-run-wal2json> server # [   80.004005] systemd[1]: Stopping Host and Network Name Lookups...820vm-test-run-wal2json> server # [   80.014962] systemd[1]: Stopped target User and Group Name Lookups.821vm-test-run-wal2json> server # [   80.023239] systemd[1]: Stopping User and Group Name Lookups...822vm-test-run-wal2json> server # [   80.032011] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...823vm-test-run-wal2json> server # [   80.078202] systemd[1]: nscd.service: Deactivated successfully.824vm-test-run-wal2json> server # [   80.092993] systemd[1]: Stopped Name Service Cache Daemon (nsncd).825vm-test-run-wal2json> server # [   80.381948] systemd[1]: Starting Name Service Cache Daemon (nsncd)...826vm-test-run-wal2json> server # [   81.045033] nsncd[714]: Oct 20 16:52:08.481 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"827vm-test-run-wal2json> server # [   81.067711] systemd[1]: Started Name Service Cache Daemon (nsncd).828vm-test-run-wal2json> server # [   81.079661] systemd[1]: Reached target Host and Network Name Lookups.829vm-test-run-wal2json> server # [   81.089969] systemd[1]: Reached target User and Group Name Lookups.830vm-test-run-wal2json> server # [   81.509608] systemd[1]: Finished resolvconf update.831vm-test-run-wal2json> server # [   81.545111] systemd[1]: Reached target Preparation for Network.832vm-test-run-wal2json> server # [   81.662867] systemd[1]: Starting DHCP Client...833vm-test-run-wal2json> server # [   81.762088] systemd[1]: Starting Extra networking commands....834vm-test-run-wal2json> server # [   84.282531] dhcpcd[759]: dhcpcd-10.3.1 starting835vm-test-run-wal2json> server # [   84.455561] dhcpcd[794]: dev: loaded udev836vm-test-run-wal2json> server # [   84.569358] dhcpcd[794]: no valid interfaces found837vm-test-run-wal2json> server # [   84.571505] dhcpcd[794]: no valid interfaces found838vm-test-run-wal2json> server # [   84.790435] sshd-keygen-start[648]: Generating public/private rsa key pair.839vm-test-run-wal2json> server # [   84.797968] sshd-keygen-start[648]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key840vm-test-run-wal2json> server # [   84.810500] sshd-keygen-start[648]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub841vm-test-run-wal2json> server # [   84.818726] sshd-keygen-start[648]: The key fingerprint is:842vm-test-run-wal2json> server # [   84.825079] sshd-keygen-start[648]: SHA256:ngQYzLoMYefbAHAhg5qdkVAahm1ASWLurCWIpsO5mi4 root@server843vm-test-run-wal2json> server # [   84.831525] sshd-keygen-start[648]: The key's randomart image is:844vm-test-run-wal2json> server # [   84.834102] sshd-keygen-start[648]: +---[RSA 4096]----+845vm-test-run-wal2json> server # [   84.837684] sshd-keygen-start[648]: |#X==.            |846vm-test-run-wal2json> server # [   84.841052] sshd-keygen-start[648]: |OX=.oo           |847vm-test-run-wal2json> server # [   84.844933] sshd-keygen-start[648]: |+*++. .          |848vm-test-run-wal2json> server # [   84.850084] sshd-keygen-start[648]: |O +o   .         |849vm-test-run-wal2json> server # [   84.853622] sshd-keygen-start[648]: |+*..+   S        |850vm-test-run-wal2json> server # [   84.859258] sshd-keygen-start[648]: |=o+. . o .       |851vm-test-run-wal2json> server # [   84.864838] sshd-keygen-start[648]: |+o      o        |852vm-test-run-wal2json> server # [   84.870090] sshd-keygen-start[648]: |Eo.              |853vm-test-run-wal2json> server # [   84.876617] sshd-keygen-start[648]: |*o               |854vm-test-run-wal2json> server # [   84.881815] sshd-keygen-start[648]: +----[SHA256]-----+855vm-test-run-wal2json> server # [   85.459652] systemd[1]: Finished Extra networking commands..856vm-test-run-wal2json> server # [   85.474537] systemd[1]: Reached target Network.857vm-test-run-wal2json> server # [   85.523892] sshd-keygen-start[819]: Generating public/private ed25519 key pair.858vm-test-run-wal2json> server # [   85.535918] sshd-keygen-start[819]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key859vm-test-run-wal2json> server # [   85.547433] sshd-keygen-start[819]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub860vm-test-run-wal2json> server # [   85.555272] sshd-keygen-start[819]: The key fingerprint is:861vm-test-run-wal2json> server # [   85.563041] sshd-keygen-start[819]: SHA256:a70V9qBSfinWKj0ZR5SoOWwvulAi+Ijl6lKctE3GUn0 root@server862vm-test-run-wal2json> server # [   85.570576] sshd-keygen-start[819]: The key's randomart image is:863vm-test-run-wal2json> server # [   85.578175] sshd-keygen-start[819]: +--[ED25519 256]--+864vm-test-run-wal2json> server # [   85.579470] sshd-keygen-start[819]: |     .     . .   |865vm-test-run-wal2json> server # [   85.581652] sshd-keygen-start[819]: |    . . E . o    |866vm-test-run-wal2json> server # [   85.590525] sshd-keygen-start[819]: |   o   o o .     |867vm-test-run-wal2json> server # [   85.597919] sshd-keygen-start[819]: | .o +   *   .    |868vm-test-run-wal2json> server # [   85.601413] sshd-keygen-start[819]: |.ooB. ..So..+    |869vm-test-run-wal2json> server # [   85.603500] sshd-keygen-start[819]: |.==..o  .=o+.=   |870vm-test-run-wal2json> server # [   85.607650] sshd-keygen-start[819]: |o.o .  .+o*+= .  |871vm-test-run-wal2json> server # [   85.614718] sshd-keygen-start[819]: |..   ....o+*     |872vm-test-run-wal2json> server # [   85.616357] sshd-keygen-start[819]: |+.    .. .o.     |873vm-test-run-wal2json> server # [   85.623493] sshd-keygen-start[819]: +----[SHA256]-----+874vm-test-run-wal2json> server # [   85.629064] systemd[1]: Starting PostgreSQL Server...875vm-test-run-wal2json> server # [   85.697506] systemd[1]: Starting Permit User Sessions...876vm-test-run-wal2json> server # [   85.759867] systemd[1]: sshd-keygen.service: Deactivated successfully.877vm-test-run-wal2json> server # [   85.789422] systemd[1]: Finished SSH Host Keys Generation.878vm-test-run-wal2json> server # [   85.809494] systemd[1]: sshd-keygen.service: Consumed 4.340s CPU time over 10.809s wall clock time, 3.1M memory peak.879vm-test-run-wal2json> server # [   85.964894] systemd[1]: Starting SSH Daemon...880vm-test-run-wal2json> server # [   86.322991] systemd[1]: Finished Permit User Sessions.881vm-test-run-wal2json> server # [   86.492940] systemd[1]: Started Getty on tty1.882vm-test-run-wal2json> server # [   86.504958] systemd[1]: Reached target Login Prompts.883vm-test-run-wal2json> server # [   86.890732] sshd[832]: Server listening on 0.0.0.0 port 22.884vm-test-run-wal2json> server # [   86.899069] sshd[832]: Server listening on :: port 22.885vm-test-run-wal2json> server # [   86.907321] systemd[1]: Started SSH Daemon.886vm-test-run-wal2json> server: Guest root shell did not produce any data yet...887vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.888vm-test-run-wal2json> server # [   88.963458] postgresql-pre-start[848]: The files belonging to this database system will be owned by user "postgres".889vm-test-run-wal2json> server # [   88.977601] postgresql-pre-start[848]: This user must also own the server process.890vm-test-run-wal2json> server # [   89.040759] postgresql-pre-start[848]: The database cluster will be initialized with locale "en_US.UTF-8".891vm-test-run-wal2json> server # [   89.042860] postgresql-pre-start[848]: The default database encoding has accordingly been set to "UTF8".892vm-test-run-wal2json> server # [   89.045248] postgresql-pre-start[848]: The default text search configuration will be set to "english".893vm-test-run-wal2json> server # [   89.050552] postgresql-pre-start[848]: Data page checksums are disabled.894vm-test-run-wal2json> server # [   89.058039] postgresql-pre-start[848]: fixing permissions on existing directory /var/lib/postgresql/15 ... ok895vm-test-run-wal2json> server # [   89.063813] postgresql-pre-start[848]: creating subdirectories ... ok896vm-test-run-wal2json> server # [   89.071443] postgresql-pre-start[848]: selecting dynamic shared memory implementation ... posix897vm-test-run-wal2json> server # [   89.916528] postgresql-pre-start[848]: selecting default max_connections ... 100898vm-test-run-wal2json> server # [   90.510188] postgresql-pre-start[848]: selecting default shared_buffers ... 128MB899vm-test-run-wal2json> server # [  100.155936] postgresql-pre-start[848]: selecting default time zone ... UTC900vm-test-run-wal2json> server # [  100.197139] postgresql-pre-start[848]: creating configuration files ... ok901vm-test-run-wal2json> server # [  104.139414] postgresql-pre-start[848]: running bootstrap script ... ok902vm-test-run-wal2json> server # [  113.047748] postgresql-pre-start[848]: performing post-bootstrap initialization ... ok903vm-test-run-wal2json> server # [  114.602556] dhcpcd[794]: timed out904vm-test-run-wal2json> server # [  114.657909] systemd[1]: Started DHCP Client.905vm-test-run-wal2json> server # [  114.665654] dhcpcd[794]: timed out906vm-test-run-wal2json> server # [  115.310061] postgresql-pre-start[848]: syncing data to disk ... ok907vm-test-run-wal2json> server # [  115.315270] postgresql-pre-start[848]: initdb: warning: enabling "trust" authentication for local connections908vm-test-run-wal2json> server # [  115.333818] postgresql-pre-start[848]: 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.909vm-test-run-wal2json> server # [  115.347894] postgresql-pre-start[848]: Success. You can now start the database server using:910vm-test-run-wal2json> server # [  115.355918] postgresql-pre-start[848]:     /nix/store/yc8mba6q0898z0nh96fnp8jggdq7jk2a-postgresql-15-wal2json/bin/pg_ctl -D /var/lib/postgresql/15 -l logfile start911vm-test-run-wal2json> server # [  116.953785] postgres[1053]: [1053] LOG:  starting PostgreSQL 15.19 on aarch64-unknown-linux-gnu, compiled by gcc (GCC) 15.3.0, 64-bit912vm-test-run-wal2json> server # [  116.957915] postgres[1053]: [1053] LOG:  listening on IPv4 address "0.0.0.0", port 5432913vm-test-run-wal2json> server # [  116.961120] postgres[1053]: [1053] LOG:  listening on IPv6 address "::", port 5432914vm-test-run-wal2json> server # [  116.971291] postgres[1053]: [1053] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"915vm-test-run-wal2json> server # [  117.092074] postgres[1068]: [1068] LOG:  database system was shut down at 2026-10-20 16:52:40 GMT916vm-test-run-wal2json> server # [  117.220000] postgres[1053]: [1053] LOG:  database system is ready to accept connections917vm-test-run-wal2json> server # [  117.283622] systemd[1]: Started PostgreSQL Server.918vm-test-run-wal2json> server # [  117.327036] systemd[1]: Starting PostgreSQL Setup Scripts...919vm-test-run-wal2json> server: Guest root shell did not produce any data yet...920vm-test-run-wal2json> server:   To debug, enter the VM and run 'systemctl status backdoor.service'.921vm-test-run-wal2json> server # [  119.062507] postgresql-setup-start[1087]: CREATE ROLE922vm-test-run-wal2json> server # [  119.351501] postgresql-setup-start[1095]: ALTER ROLE923vm-test-run-wal2json> server # [  119.437415] systemd[1]: Finished PostgreSQL Setup Scripts.924vm-test-run-wal2json> server # [  119.453682] systemd[1]: Reached target PostgreSQL.925vm-test-run-wal2json> server # [  120.277613] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:08.0/virtio7/input/input3926vm-test-run-wal2json> server # [  124.355861] systemd[1]: Starting Virtual Console Setup...927vm-test-run-wal2json> server # [  124.626593] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.928vm-test-run-wal2json> server # [  124.643379] systemd[1]: Stopped Virtual Console Setup.929vm-test-run-wal2json> server # [  124.820289] systemd[1]: Starting Virtual Console Setup...930vm-test-run-wal2json> server # [  125.655081] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs931vm-test-run-wal2json> server # [  128.969967] systemd-vconsole-setup[1151]: Configuration of first virtual console was skipped, ignoring remaining ones.932vm-test-run-wal2json> server # [  128.995230] systemd[1]: Finished Virtual Console Setup.933vm-test-run-wal2json> server # [  130.921271] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.934vm-test-run-wal2json> server # [  131.559718] 8021q: 802.1Q VLAN Support v1.8935vm-test-run-wal2json> server # [  131.499775] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.936vm-test-run-wal2json> server # [  131.603818] systemd[1]: Started backdoor.service.937vm-test-run-wal2json> server # [  131.643440] systemd[1]: Reached target Multi-User System.938vm-test-run-wal2json> server # [  131.659161] systemd[1]: Startup finished in 2.702s (kernel) + 29.391s (initrd) + 1min 39.559s (userspace) = 2min 11.653s.939vm-test-run-wal2json> server # [  132.273404] cfg80211: Loading compiled-in X.509 certificates for regulatory database940vm-test-run-wal2json> server # [  132.390386] (udev-worker)[1184]: Network interface NamePolicy= disabled on kernel command line.941vm-test-run-wal2json> server # connecting to host...942vm-test-run-wal2json> server # [  132.426771] (udev-worker)[1190]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.943vm-test-run-wal2json> server # [  132.437257] (udev-worker)[1190]: Network interface NamePolicy= disabled on kernel command line.944vm-test-run-wal2json> server # [  132.622833] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'945vm-test-run-wal2json> server # [  132.631831] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'946vm-test-run-wal2json> server # [  132.670540] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2947vm-test-run-wal2json> server # [  132.671001] cfg80211: failed to load regulatory.db948vm-test-run-wal2json> server: Guest shell says: b'Spawning backdoor root shell...\n'949vm-test-run-wal2json> server: connected to guest root shell950vm-test-run-wal2json> server: (connecting took 134.07 seconds)951vm-test-run-wal2json> server: (finished: waiting for the VM to finish booting, in 134.07 seconds)952vm-test-run-wal2json> server # [  133.304310] systemd[1]: Condition check resulted in Virtio network device being skipped.953vm-test-run-wal2json> server # [  133.368011] systemd[1]: Starting Address configuration of eth1...954vm-test-run-wal2json> server # [  134.407018] 8021q: adding VLAN 0 to HW filter on device eth0955vm-test-run-wal2json> server # [  134.319514] dhcpcd[794]: eth0: waiting for carrier956vm-test-run-wal2json> server # [  134.335225] dhcpcd[794]: eth0: carrier acquired957vm-test-run-wal2json> server: (finished: waiting for unit multi-user.target, in 135.69 seconds)958vm-test-run-wal2json> server: waiting for unit postgresql.service959vm-test-run-wal2json> server # [  134.583015] 8021q: adding VLAN 0 to HW filter on device eth1960vm-test-run-wal2json> server # [  134.616182] dhcpcd[794]: DUID 00:01:00:01:32:6a:58:ee:52:54:00:12:34:56961vm-test-run-wal2json> server # [  134.632938] dhcpcd[794]: eth0: IAID 00:12:34:56962vm-test-run-wal2json> server # [  134.634281] dhcpcd[794]: eth0: adding address fe80::5054:ff:fe12:3456963vm-test-run-wal2json> server # [  134.769727] network-addresses-eth1-start[1215]: adding address 192.168.1.1/24... done964vm-test-run-wal2json> server # [  134.917655] network-addresses-eth1-start[1215]: adding address 2001:db8:1::1/64... done965vm-test-run-wal2json> server # [  135.414526] dhcpcd[794]: eth0: soliciting a DHCP lease966vm-test-run-wal2json> server # [  135.440989] dhcpcd[794]: eth0: offered 10.0.2.15 from 10.0.2.2967vm-test-run-wal2json> server # [  135.455527] dhcpcd[794]: eth0: probing address 10.0.2.15/24968vm-test-run-wal2json> server # [  135.493142] systemd[1]: Finished Address configuration of eth1.969vm-test-run-wal2json> server: (finished: waiting for unit postgresql.service, in 1.17 seconds)970vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE SCHEMA IF NOT EXISTS public;" 971vm-test-run-wal2json> server # NOTICE:  schema "public" already exists, skipping972vm-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.56 seconds)973vm-test-run-wal2json> subtest: Check upgrade path with postgresql 15974vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 975vm-test-run-wal2json> server # [  136.280644] dhcpcd[794]: eth0: soliciting an IPv6 router976vm-test-run-wal2json> server # [  136.303626] dhcpcd[794]: eth0: Router Advertisement from fe80::2977vm-test-run-wal2json> server # [  136.315235] dhcpcd[794]: eth0: adding address fec0::5054:ff:fe12:3456/64978vm-test-run-wal2json> server # [  136.319000] dhcpcd[794]: eth0: adding route to fec0::/64979vm-test-run-wal2json> server # [  136.326001] dhcpcd[794]: eth0: adding default route via fe80::2980vm-test-run-wal2json> server # NOTICE:  extension "wal2json" does not exist, skipping981vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.50 seconds)982vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 983vm-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.61 seconds)984vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 985vm-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.66 seconds)986vm-test-run-wal2json> (finished: subtest: Check upgrade path with postgresql 15, in 1.77 seconds)987vm-test-run-wal2json> subtest: Check pg_regress with postgresql 15 after extension upgrade988vm-test-run-wal2json> server: must succeed: sudo -u postgres /nix/store/yc8mba6q0898z0nh96fnp8jggdq7jk2a-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/zac95w19k2pmv8h37rv16a4v92mjiajm-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 "wal2json" 989vm-test-run-wal2json> server # [  139.097862] sudo[1272]:     root : TTY=hvc0 ; PWD=/tmp ; USER=postgres ; COMMAND=/nix/store/yc8mba6q0898z0nh96fnp8jggdq7jk2a-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/zac95w19k2pmv8h37rv16a4v92mjiajm-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 wal2json990vm-test-run-wal2json> server # [  139.295601] sudo[1272]: pam_unix(sudo:session): session opened for user postgres(uid=71) by (uid=0)991vm-test-run-wal2json> server # pg_regress: could not set core size: disallowed by hard limit992vm-test-run-wal2json> server # [  139.863584] postgres[1284]: [1284] LOG:  logical decoding found consistent point at 0/152AC80993vm-test-run-wal2json> server # [  139.869916] postgres[1284]: [1284] DETAIL:  There are no running transactions.994vm-test-run-wal2json> server # [  139.871296] postgres[1284]: [1284] STATEMENT:  select995vm-test-run-wal2json> server # [  139.873912] postgres[1284]: 	  1996vm-test-run-wal2json> server # [  139.876634] postgres[1284]: 	from997vm-test-run-wal2json> server # [  139.877538] postgres[1284]: 	  pg_create_logical_replication_slot('reg_test', 'wal2json', false);998vm-test-run-wal2json> server # [  139.928043] postgres[1284]: [1284] LOG:  starting logical decoding for slot "reg_test"999vm-test-run-wal2json> server # [  139.931960] postgres[1284]: [1284] DETAIL:  Streaming transactions committing after 0/152ACB8, reading WAL from 0/152AC80.1000vm-test-run-wal2json> server # [  139.934984] postgres[1284]: [1284] STATEMENT:  select1001vm-test-run-wal2json> server # [  139.938562] postgres[1284]: 	  data1002vm-test-run-wal2json> server # [  139.940067] postgres[1284]: 	from1003vm-test-run-wal2json> server # [  139.941396] postgres[1284]: 	  pg_logical_slot_get_changes(1004vm-test-run-wal2json> server # [  139.941890] postgres[1284]: 		'reg_test',1005vm-test-run-wal2json> server # [  139.942196] postgres[1284]: 	    null,1006vm-test-run-wal2json> server # [  139.942798] postgres[1284]: 	    null,1007vm-test-run-wal2json> server # [  139.943744] postgres[1284]: 		'include-pk', 'true',1008vm-test-run-wal2json> server # [  139.945387] postgres[1284]: 		'include-transaction', 'false',1009vm-test-run-wal2json> server # [  139.946081] postgres[1284]: 		'include-timestamp', 'false',1010vm-test-run-wal2json> server # [  139.947096] postgres[1284]: 		'include-type-oids', 'true',1011vm-test-run-wal2json> server # [  139.947802] postgres[1284]: 		'format-version', '2',1012vm-test-run-wal2json> server # [  139.948260] postgres[1284]: 		'actions', 'insert,update,delete',1013vm-test-run-wal2json> server # [  139.949884] postgres[1284]: 		'add-tables', 'v.foo'1014vm-test-run-wal2json> server # [  139.951728] postgres[1284]: 	  ) x;1015vm-test-run-wal2json> server # [  139.953446] postgres[1284]: [1284] LOG:  logical decoding found consistent point at 0/152AC801016vm-test-run-wal2json> server # [  139.954521] postgres[1284]: [1284] DETAIL:  There are no running transactions.1017vm-test-run-wal2json> server # [  139.955840] postgres[1284]: [1284] STATEMENT:  select1018vm-test-run-wal2json> server # [  139.956189] postgres[1284]: 	  data1019vm-test-run-wal2json> server # [  139.957603] postgres[1284]: 	from1020vm-test-run-wal2json> server # [  139.958072] postgres[1284]: 	  pg_logical_slot_get_changes(1021vm-test-run-wal2json> server # [  139.958567] postgres[1284]: 		'reg_test',1022vm-test-run-wal2json> server # [  139.958991] postgres[1284]: 	    null,1023vm-test-run-wal2json> server # [  139.959352] postgres[1284]: 	    null,1024vm-test-run-wal2json> server # [  139.959666] postgres[1284]: 		'include-pk', 'true',1025vm-test-run-wal2json> server # [  139.961336] postgres[1284]: 		'include-transaction', 'false',1026vm-test-run-wal2json> server # [  139.963081] postgres[1284]: 		'include-timestamp', 'false',1027vm-test-run-wal2json> server # [  139.964065] postgres[1284]: 		'include-type-oids', 'true',1028vm-test-run-wal2json> server # [  139.964768] postgres[1284]: 		'format-version', '2',1029vm-test-run-wal2json> server # [  139.965457] postgres[1284]: 		'actions', 'insert,update,delete',1030vm-test-run-wal2json> server # [  139.965906] postgres[1284]: 		'add-tables', 'v.foo'1031vm-test-run-wal2json> server # [  139.967591] postgres[1284]: 	  ) x;1032vm-test-run-wal2json> server # [  140.378208] sudo[1272]: pam_unix(sudo:session): session closed for user postgres1033vm-test-run-wal2json> server: (finished: must succeed: sudo -u postgres /nix/store/yc8mba6q0898z0nh96fnp8jggdq7jk2a-postgresql-15-wal2json/lib/pgxs/src/test/regress/pg_regress --inputdir=/nix/store/zac95w19k2pmv8h37rv16a4v92mjiajm-tests --debug --use-existing --dbname=postgres --outputdir=/tmp/regression_output_15 "wal2json" , in 2.54 seconds)1034vm-test-run-wal2json> (using postmaster on Unix socket, default port)1035vm-test-run-wal2json> ============== running regression test queries        ==============1036vm-test-run-wal2json> test wal2json                     ... ok          702 ms1037vm-test-run-wal2json> 1038vm-test-run-wal2json> =====================1039vm-test-run-wal2json>  All 1 tests passed. 1040vm-test-run-wal2json> =====================1041vm-test-run-wal2json> 1042vm-test-run-wal2json> 1043vm-test-run-wal2json> (finished: subtest: Check pg_regress with postgresql 15 after extension upgrade, in 2.54 seconds)1044vm-test-run-wal2json> subtest: Check the install of the last version of the extension1045vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" 1046vm-test-run-wal2json> server # [  140.934179] dhcpcd[794]: eth0: leased 10.0.2.15 for 86400 seconds1047vm-test-run-wal2json> server # [  140.950750] dhcpcd[794]: eth0: adding route to 10.0.2.0/241048vm-test-run-wal2json> server # [  140.962121] dhcpcd[794]: eth0: adding default route via 10.0.2.21049vm-test-run-wal2json> server: (finished: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "DROP EXTENSION IF EXISTS wal2json;" , in 0.69 seconds)1050vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "CREATE EXTENSION wal2json WITH VERSION '2.6' CASCADE;" 1051vm-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.80 seconds)1052vm-test-run-wal2json> server: must succeed: psql -U supabase_admin -d postgres -t -A -F"," -c "SELECT extversion FROM pg_extension WHERE extname = 'wal2json';" 1053vm-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.70 seconds)1054vm-test-run-wal2json> (finished: subtest: Check the install of the last version of the extension, in 2.19 seconds)1055vm-test-run-wal2json> subtest: switch to postgresql 171056vm-test-run-wal2json> server # Checking switch inhibitors... done1057vm-test-run-wal2json> server # [  148.658651] systemd-logind[638]: Watching system buttons on /dev/input/event0 (gpio-keys)1058vm-test-run-wal2json> server # stopping the following units: postgresql-setup.service, postgresql.service1059vm-test-run-wal2json> server # [  150.368256] nixos[1361]: switching to system configuration /nix/store/5sxi3x1710p1sm6y7pa0cw1k11ycd5sc-nixos-system-server-test1060vm-test-run-wal2json> server # [  150.412363] systemd[1]: Stopped target PostgreSQL.1061vm-test-run-wal2json> server # [  150.417853] systemd[1]: postgresql-setup.service: Deactivated successfully.1062vm-test-run-wal2json> server # [  150.419646] systemd[1]: Stopped PostgreSQL Setup Scripts.1063vm-test-run-wal2json> server # [  150.432517] postgres[1053]: [1053] LOG:  received fast shutdown request1064vm-test-run-wal2json> server # [  150.442173] systemd[1]: Stopping PostgreSQL Server...1065vm-test-run-wal2json> server # [  150.476784] postgres[1053]: [1053] LOG:  aborting any active transactions1066vm-test-run-wal2json> server # [  150.489664] systemd[1]: Stopped target Remote File Systems.1067vm-test-run-wal2json> server # [  150.558896] postgres[1053]: [1053] LOG:  background worker "logical replication launcher" (PID 1071) exited with exit code 11068vm-test-run-wal2json> server # [  150.596302] postgres[1066]: [1066] LOG:  shutting down1069vm-test-run-wal2json> server # [  150.607652] postgres[1066]: [1066] LOG:  checkpoint starting: shutdown immediate1070vm-test-run-wal2json> server # [  150.617874] systemd[1]: Stopped target Local File Systems.1071vm-test-run-wal2json> server # [  150.918066] postgres[1066]: [1066] LOG:  checkpoint complete: wrote 54 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.089 s, sync=0.155 s, total=0.347 s; sync files=48, longest=0.018 s, average=0.004 s; distance=149 kB, estimate=149 kB1072vm-test-run-wal2json> server # [  151.053146] postgres[1053]: [1053] LOG:  database system is shut down1073vm-test-run-wal2json> server # [  151.161269] systemd[1]: postgresql.service: Deactivated successfully.1074vm-test-run-wal2json> server # [  151.181591] systemd[1]: Stopped PostgreSQL Server.1075vm-test-run-wal2json> server # activating the configuration...1076vm-test-run-wal2json> server # [  151.189684] systemd[1]: postgresql.service: Consumed 18.301s CPU time over 1min 5.535s wall clock time, 94.3M memory peak, 38.8M written to disk.1077vm-test-run-wal2json> server # [  152.177800] mousedev: PS/2 mouse device common for all mice1078vm-test-run-wal2json> server # [  154.244523] systemd-logind[638]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1079vm-test-run-wal2json> server # setting up /etc...1080vm-test-run-wal2json> server # [  158.283443] systemd[1]: Reload requested from client PID 1361 ('.switch-to-conf') (unit backdoor.service)...1081vm-test-run-wal2json> server # [  158.287045] systemd[1]: Reloading...1082vm-test-run-wal2json> server # [  163.679754] systemd[1]: Reloading finished in 5383 ms.1083vm-test-run-wal2json> server # restarting sysinit-reactivation.target1084vm-test-run-wal2json> server # [  164.063777] systemd[1]: Starting Re-setup tmpfiles on a system that is already running....1085vm-test-run-wal2json> server # [  165.482647] systemd[1]: Finished Re-setup tmpfiles on a system that is already running..1086vm-test-run-wal2json> server # [  165.517329] systemd[1]: Reached target Reactivate sysinit units.1087vm-test-run-wal2json> server # reloading the following units: dbus-broker.service1088vm-test-run-wal2json> server # [  165.578317] dbus-broker-launch[625]: Caught SIGHUP, trigger reload.1089vm-test-run-wal2json> server # [  165.591851] systemd[1]: Reloading D-Bus System Message Bus...1090vm-test-run-wal2json> server # [  165.813319] dbus-broker-launch[625]: Looking up NSS user entry for 'systemd-timesync'...1091vm-test-run-wal2json> server # [  165.851414] dbus-broker-launch[625]: NSS returned no entry for 'systemd-timesync'1092vm-test-run-wal2json> server # [  165.854079] dbus-broker-launch[625]: Invalid user-name in /nix/store/2fj70ayyy54042qn2ndc5nrr39ziyhzj-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1093vm-test-run-wal2json> server # [  166.146743] systemd[1]: Reloaded D-Bus System Message Bus.1094vm-test-run-wal2json> server # starting the following units: postgresql-setup.service, postgresql.service1095vm-test-run-wal2json> server # [  166.351553] systemd[1]: Starting postgresql-migrate.service...1096vm-test-run-wal2json> server # [  166.617302] systemd[1]: Reached target Local File Systems.1097vm-test-run-wal2json> server # [  166.618695] systemd[1]: Reached target Remote File Systems.1098vm-test-run-wal2json> server # [  166.619955] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1099vm-test-run-wal2json> server # [  166.667826] systemd[1]: Starting Create SUID/SGID Wrappers...1100vm-test-run-wal2json> server # [  166.675436] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1101vm-test-run-wal2json> server # [  166.683010] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671102vm-test-run-wal2json> server # [  166.690582] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1103vm-test-run-wal2json> server # [  166.713451] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki1104vm-test-run-wal2json> server # [  166.726931] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki1105vm-test-run-wal2json> server # [  166.948847] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1106vm-test-run-wal2json> server # [  168.699570] postgresql-migrate-start[1574]: The files belonging to this database system will be owned by user "postgres".1107vm-test-run-wal2json> server # [  168.718717] postgresql-migrate-start[1574]: This user must also own the server process.1108vm-test-run-wal2json> server # [  168.789416] postgresql-migrate-start[1574]: The database cluster will be initialized with locale "en_US.UTF-8".1109vm-test-run-wal2json> server # [  168.790556] postgresql-migrate-start[1574]: The default database encoding has accordingly been set to "UTF8".1110vm-test-run-wal2json> server # [  168.791689] postgresql-migrate-start[1574]: The default text search configuration will be set to "english".1111vm-test-run-wal2json> server # [  168.802432] postgresql-migrate-start[1574]: Data page checksums are disabled.1112vm-test-run-wal2json> server # [  168.806393] postgresql-migrate-start[1574]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok1113vm-test-run-wal2json> server # [  168.816116] postgresql-migrate-start[1574]: creating subdirectories ... ok1114vm-test-run-wal2json> server # [  168.820217] postgresql-migrate-start[1574]: selecting dynamic shared memory implementation ... posix1115vm-test-run-wal2json> server # [  170.190880] postgresql-migrate-start[1574]: selecting default "max_connections" ... 1001116vm-test-run-wal2json> server # [  171.099569] postgresql-migrate-start[1574]: selecting default "shared_buffers" ... 128MB1117vm-test-run-wal2json> server # [  172.893721] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1118vm-test-run-wal2json> server # [  172.898176] systemd[1]: Finished Create SUID/SGID Wrappers.1119vm-test-run-wal2json> server # [  172.910014] systemd[1]: suid-sgid-wrappers.service: Consumed 2.462s CPU time over 6.212s wall clock time, 3.2M memory peak.1120vm-test-run-wal2json> server # [  172.957898] systemd[1]: Starting linger-users.service...1121vm-test-run-wal2json> server # [  172.959229] systemd[1]: SSH Host Keys Generation skipped, no trigger condition checks were met.1122vm-test-run-wal2json> server # [  173.408721] systemd[1]: linger-users.service: Deactivated successfully.1123vm-test-run-wal2json> server # [  173.426437] systemd[1]: Finished linger-users.service.1124vm-test-run-wal2json> server # [  180.233055] postgresql-migrate-start[1574]: selecting default time zone ... UTC1125vm-test-run-wal2json> server # [  180.274555] postgresql-migrate-start[1574]: creating configuration files ... ok1126vm-test-run-wal2json> server # [  183.260962] postgresql-migrate-start[1574]: running bootstrap script ... ok1127vm-test-run-wal2json> server # [  191.381104] postgresql-migrate-start[1574]: performing post-bootstrap initialization ... ok1128vm-test-run-wal2json> server # [  193.774049] postgresql-migrate-start[1574]: syncing data to disk ... ok1129vm-test-run-wal2json> server # [  193.776014] postgresql-migrate-start[1574]: initdb: warning: enabling "trust" authentication for local connections1130vm-test-run-wal2json> server # [  193.779012] postgresql-migrate-start[1574]: 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.1131vm-test-run-wal2json> server # [  193.781661] postgresql-migrate-start[1574]: Success. You can now start the database server using:1132vm-test-run-wal2json> server # [  193.783389] postgresql-migrate-start[1574]:     /nix/store/202c8ksjy7p2ygpyaqkbjbjfdr51w8fv-postgresql-17-wal2json/bin/pg_ctl -D /var/lib/postgresql/17 -l logfile start1133vm-test-run-wal2json> server # [  199.194788] postgresql-migrate-start[1808]: Performing Consistency Checks1134vm-test-run-wal2json> server # [  199.205356] postgresql-migrate-start[1808]: -----------------------------1135vm-test-run-wal2json> server # [  199.207144] postgresql-migrate-start[1808]: Checking cluster versions                                     ok1136vm-test-run-wal2json> server # [  202.702745] postgresql-migrate-start[1808]: Checking database user is the install user                    ok1137vm-test-run-wal2json> server # [  202.767209] postgresql-migrate-start[1808]: Checking database connection settings                         ok1138vm-test-run-wal2json> server # [  202.876049] postgresql-migrate-start[1808]: Checking for prepared transactions                            ok1139vm-test-run-wal2json> server # [  202.883955] postgresql-migrate-start[1808]: Checking for contrib/isn with bigint-passing mismatch         ok1140vm-test-run-wal2json> server # [  204.104991] postgresql-migrate-start[1808]: Checking data type usage                                      ok1141vm-test-run-wal2json> server # [  204.366921] postgresql-migrate-start[1808]: Checking for not-null constraint inconsistencies              ok1142vm-test-run-wal2json> server # [  205.166756] postgresql-migrate-start[1808]: Creating dump of global objects                               ok1143vm-test-run-wal2json> server # [  208.275943] postgresql-migrate-start[1808]: Creating dump of database schemas                             ok1144vm-test-run-wal2json> server # [  211.512143] postgresql-migrate-start[1808]: Checking for presence of required libraries                   ok1145vm-test-run-wal2json> server # [  211.640623] postgresql-migrate-start[1808]: Checking database user is the install user                    ok1146vm-test-run-wal2json> server # [  211.748198] postgresql-migrate-start[1808]: Checking for prepared transactions                            ok1147vm-test-run-wal2json> server # [  211.757608] postgresql-migrate-start[1808]: Checking for new cluster tablespace directories               ok1148vm-test-run-wal2json> server # [  211.759157] postgresql-migrate-start[1808]: If pg_upgrade fails after this point, you must re-initdb the1149vm-test-run-wal2json> server # [  211.776353] postgresql-migrate-start[1808]: new cluster before continuing.1150vm-test-run-wal2json> server # [  211.778236] postgresql-migrate-start[1808]: Performing Upgrade1151vm-test-run-wal2json> server # [  211.779455] postgresql-migrate-start[1808]: ------------------1152vm-test-run-wal2json> server # [  211.870342] postgresql-migrate-start[1808]: Setting locale and encoding for new cluster                   ok1153vm-test-run-wal2json> server # [  215.067447] postgresql-migrate-start[1808]: Analyzing all rows in the new cluster                         ok1154vm-test-run-wal2json> server # [  216.645328] postgresql-migrate-start[1808]: Freezing all rows in the new cluster                          ok1155vm-test-run-wal2json> server # [  217.261629] postgresql-migrate-start[1808]: Deleting files from new pg_xact                               ok1156vm-test-run-wal2json> server # [  217.517090] postgresql-migrate-start[1808]: Copying old pg_xact to new server                             ok1157vm-test-run-wal2json> server # [  218.011996] postgresql-migrate-start[1808]: Setting oldest XID for new cluster                            ok1158vm-test-run-wal2json> server # [  219.399431] postgresql-migrate-start[1808]: Setting next transaction ID and epoch for new cluster         ok1159vm-test-run-wal2json> server # [  219.404729] postgresql-migrate-start[1808]: Deleting files from new pg_multixact/offsets                  ok1160vm-test-run-wal2json> server # [  219.685521] postgresql-migrate-start[1808]: Copying old pg_multixact/offsets to new server                ok1161vm-test-run-wal2json> server # [  219.687963] postgresql-migrate-start[1808]: Deleting files from new pg_multixact/members                  ok1162vm-test-run-wal2json> server # [  219.917142] postgresql-migrate-start[1808]: Copying old pg_multixact/members to new server                ok1163vm-test-run-wal2json> server # [  220.252573] postgresql-migrate-start[1808]: Setting next multixact ID and offset for new cluster          ok1164vm-test-run-wal2json> server # [  220.641197] postgresql-migrate-start[1808]: Resetting WAL archives                                        ok1165vm-test-run-wal2json> server # [  221.399574] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1166vm-test-run-wal2json> server # [  221.406978] systemd[1]: Stopped Virtual Console Setup.1167vm-test-run-wal2json> server # [  221.415337] systemd[1]: systemd-vconsole-setup.service: Consumed 1.004s CPU time over 1min 36.574s wall clock time, 2.7M memory peak.1168vm-test-run-wal2json> server # [  221.428889] systemd[1]: Stopping Virtual Console Setup...1169vm-test-run-wal2json> server # [  221.466512] systemd[1]: Starting Virtual Console Setup...1170vm-test-run-wal2json> server # [  225.038515] systemd-vconsole-setup[2100]: Configuration of first virtual console was skipped, ignoring remaining ones.1171vm-test-run-wal2json> server # [  225.085884] systemd[1]: Finished Virtual Console Setup.1172vm-test-run-wal2json> server # [  225.104495] postgresql-migrate-start[1808]: Setting frozenxid and minmxid counters in new cluster         ok1173vm-test-run-wal2json> server # [  225.563185] postgresql-migrate-start[1808]: Restoring global objects in the new cluster                   ok1174vm-test-run-wal2json> server # [  227.147820] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1175vm-test-run-wal2json> server # [  227.439684] systemd-logind[638]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1176vm-test-run-wal2json> server # [  228.769618] postgresql-migrate-start[1808]: Restoring database schemas in the new cluster                 ok1177vm-test-run-wal2json> server # [  229.438301] postgresql-migrate-start[1808]: Copying user relation files                                   ok1178vm-test-run-wal2json> server # [  229.711542] postgresql-migrate-start[1808]: Setting next OID for new cluster                              ok1179vm-test-run-wal2json> server # [  231.227325] postgresql-migrate-start[1808]: Sync data directory to disk                                   ok1180vm-test-run-wal2json> server # [  231.231995] postgresql-migrate-start[1808]: Creating script to delete old cluster                         ok1181vm-test-run-wal2json> server # [  233.169680] postgresql-migrate-start[1808]: Checking for extension updates                                ok1182vm-test-run-wal2json> server # [  233.441688] postgresql-migrate-start[1808]: Upgrade Complete1183vm-test-run-wal2json> server # [  233.443043] postgresql-migrate-start[1808]: ----------------1184vm-test-run-wal2json> server # [  233.443665] postgresql-migrate-start[1808]: Optimizer statistics are not transferred by pg_upgrade.1185vm-test-run-wal2json> server # [  233.444082] postgresql-migrate-start[1808]: Once you start the new server, consider running:1186vm-test-run-wal2json> server # [  233.446013] postgresql-migrate-start[1808]:     /nix/store/202c8ksjy7p2ygpyaqkbjbjfdr51w8fv-postgresql-17-wal2json/bin/vacuumdb --all --analyze-in-stages1187vm-test-run-wal2json> server # [  233.449163] postgresql-migrate-start[1808]: Running this script will delete the old cluster's data files:1188vm-test-run-wal2json> server # [  233.451045] postgresql-migrate-start[1808]:     ./delete_old_cluster.sh1189vm-test-run-wal2json> server # [  233.502035] systemd[1]: Finished postgresql-migrate.service.1190vm-test-run-wal2json> server # [  233.554580] systemd[1]: Starting PostgreSQL Server...