tribuchet: building on eliza
Machine state will be reset. To keep it, pass --keep-machine-state
start all VLans
(finished: start all VLans, in 0.00 seconds)
Test will time out and terminate in 3600.0 seconds
run the VM test script
start all VMs
builder: starting vm
server: starting vm
server # Disk image does not exist, creating the virtualisation disk image...
server # Formatting '/build/vm-state-server/tmp.sRhqXLKlrq', fmt=raw size=1073741824
server: QEMU running (pid 48)
server # mke2fs 1.47.4 (6-Mar-2025)
server # Discarding device blocks:      0/262144             done
server # Creating filesystem with 262144 4k blocks and 65536 inodes
server # Filesystem UUID: 6ef2e17c-4111-4ed8-bf6a-04c9050ad865
server # Superblock backups stored on blocks:
server # 	32768, 98304, 163840, 229376
server # 
server # Allocating group tables: 0/8   done
server # Writing inode tables: 0/8   done
server # Creating journal (8192 blocks): done
server # Writing superblocks and filesystem accounting information: 0/8   done
server # 
server # Virtualisation disk image created.
builder # Disk image does not exist, creating the virtualisation disk image...
builder: QEMU running (pid 47)
builder # Formatting '/build/vm-state-builder/tmp.olhZW0GU1o', fmt=raw size=1073741824
builder # mke2fs 1.47.4 (6-Mar-2025)
builder # Discarding device blocks:      0/262144             done
builder # Creating filesystem with 262144 4k blocks and 65536 inodes
builder # Filesystem UUID: dfaf080b-22e4-4442-88e3-d0a9cc76e72e
builder # Superblock backups stored on blocks:
builder # 	32768, 98304, 163840, 229376
builder # 
(finished: start all VMs, in 0.48 seconds)
builder # Allocating group tables: 0/8   done
server: waiting for unit postgresql.service
builder # Writing inode tables: 0/8   done
server: waiting for the VM to finish booting
builder # Creating journal (8192 blocks): done
builder # Writing superblocks and filesystem accounting information: 0/8   done
builder # 
builder # Virtualisation disk image created.
server # [    0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]
server # [    0.000000] Linux version 6.18.48 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Aug 28 06:22:54 UTC 2026
server # [    0.000000] KASLR enabled
server # [    0.000000] random: crng init done
server # [    0.000000] Machine model: linux,dummy-virt
server # [    0.000000] efi: UEFI not found.
server # [    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT
server # [    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]
server # [    0.000000] Zone ranges:
server # [    0.000000]   DMA      [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000]   DMA32    empty
server # [    0.000000]   Normal   empty
server # [    0.000000]   Device   empty
server # [    0.000000] Movable zone start for each node
server # [    0.000000] Early memory node ranges
server # [    0.000000]   node   0: [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000] cma: Reserved 32 MiB at 0x000000007cc00000
server # [    0.000000] psci: probing for conduit method from DT.
server # [    0.000000] psci: PSCIv1.3 detected in firmware.
server # [    0.000000] psci: Using standard PSCI v0.2 function IDs
server # [    0.000000] psci: Trusted OS migration not required
server # [    0.000000] psci: SMC Calling Convention v1.1
server # [    0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)
server # [    0.000000] percpu: Embedded 76 pages/cpu s186648 r8192 d116456 u311296
server # [    0.000000] Detected PIPT I-cache on CPU0
server # [    0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)
server # [    0.000000] CPU features: detected: GICv3 CPU interface
server # [    0.000000] CPU features: detected: Spectre-v4
server # [    0.000000] CPU features: detected: Spectre-BHB
server # [    0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38
server # [    0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23
server # [    0.000000] alternatives: applying boot alternatives
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/lgi6ys32kv3ng3cjms823dk722g1vb7f-nixos-system-server-test/init regInfo=/nix/store/9qb1wz6rip2m033m8swsgmziws70hini-closure-info/registration console=ttyAMA0,115200n8 console=tty0
server # [    0.000000] Unknown kernel command line parameters "regInfo=/nix/store/9qb1wz6rip2m033m8swsgmziws70hini-closure-info/registration", will be passed to user space.
server # [    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes
server # [    0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
server # [    0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
server # [    0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB
server # [    0.000000] software IO TLB: area num 1.
server # [    0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)
server # [    0.000000] Fallback order for Node 0: 0
server # [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 262144
server # [    0.000000] Policy zone: DMA
server # [    0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
server # [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
server # [    0.000000] allocated 2097152 bytes of page_ext
server # [    0.000000] ftrace: allocating 74886 entries in 294 pages
server # [    0.000000] ftrace: allocated 294 pages with 4 groups
server # [    0.000000] rcu: Hierarchical RCU implementation.
server # [    0.000000] rcu: 	RCU event tracing is enabled.
server # [    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
server # [    0.000000] 	Trampoline variant of Tasks RCU enabled.
server # [    0.000000] 	Rude variant of Tasks RCU enabled.
server # [    0.000000] 	Tracing variant of Tasks RCU enabled.
builder # [    0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]
server # [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
server # [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
builder # [    0.000000] Linux version 6.18.48 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Aug 28 06:22:54 UTC 2026
builder # [    0.000000] KASLR enabled
server # [    0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
builder # [    0.000000] random: crng init done
builder # [    0.000000] Machine model: linux,dummy-virt
builder # [    0.000000] efi: UEFI not found.
server # [    0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
builder # [    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT
server # [    0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
builder # [    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
server # [    0.000000] GICv3: 256 SPIs implemented
builder # [    0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]
builder # [    0.000000] Zone ranges:
server # [    0.000000] GICv3: 0 Extended SPIs implemented
server # [    0.000000] Root IRQ handler: gic_handle_irq
builder # [    0.000000]   DMA      [mem 0x0000000040000000-0x000000007fffffff]
builder # [    0.000000]   DMA32    empty
server # [    0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI
builder # [    0.000000]   Normal   empty
server # [    0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0
builder # [    0.000000]   Device   empty
builder # [    0.000000] Movable zone start for each node
server # [    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000
builder # [    0.000000] Early memory node ranges
server # [    0.000000] ITS [mem 0x08080000-0x0809ffff]
builder # [    0.000000]   node   0: [mem 0x0000000040000000-0x000000007fffffff]
server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44cf0000 (indirect, esz 8, psz 64K, shr 1)
builder # [    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]
builder # [    0.000000] cma: Reserved 32 MiB at 0x000000007cc00000
server # [    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44d00000 (flat, esz 8, psz 64K, shr 1)
builder # [    0.000000] psci: probing for conduit method from DT.
server # [    0.000000] GICv3: using LPI property table @0x0000000044d10000
builder # [    0.000000] psci: PSCIv1.3 detected in firmware.
server # [    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000
builder # [    0.000000] psci: Using standard PSCI v0.2 function IDs
builder # [    0.000000] psci: Trusted OS migration not required
builder # [    0.000000] psci: SMC Calling Convention v1.1
server # [    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
builder # [    0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)
server # [    0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
builder # [    0.000000] percpu: Embedded 76 pages/cpu s186648 r8192 d116456 u311296
server # [    0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).
builder # [    0.000000] Detected PIPT I-cache on CPU0
builder # [    0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)
server # [    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
builder # [    0.000000] CPU features: detected: GICv3 CPU interface
builder # [    0.000000] CPU features: detected: Spectre-v4
server # [    0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns
builder # [    0.000000] CPU features: detected: Spectre-BHB
server # [    0.000030] arm-pv: using stolen time PV
builder # [    0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38
server # [    0.000493] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
builder # [    0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23
server # [    0.000673] Console: colour dummy device 80x25
builder # [    0.000000] alternatives: applying boot alternatives
server # [    0.000681] printk: legacy console [tty0] enabled
server # [    0.000872] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)
server # [    0.000878] pid_max: default: 32768 minimum: 301
server # [    0.000948] LSM: initializing lsm=capability,landlock,yama,bpf,ima
server # [    0.001085] landlock: Up and running.
server # [    0.001087] Yama: becoming mindful.
builder # [    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/lpvbwjmvw2582gxzrsb7vj6malck0j35-nixos-system-builder-test/init regInfo=/nix/store/zgf7kr21c8x0kdivf2566gkx7jiyx5zg-closure-info/registration console=ttyAMA0,115200n8 console=tty0
server # [    0.001559] LSM support for eBPF active
server # [    0.001682] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
server # [    0.001701] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
builder # [    0.000000] Unknown kernel command line parameters "regInfo=/nix/store/zgf7kr21c8x0kdivf2566gkx7jiyx5zg-closure-info/registration", will be passed to user space.
server # [    0.002896] cacheinfo: Unable to detect cache hierarchy for CPU 0
builder # [    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes
server # [    0.003682] rcu: Hierarchical SRCU implementation.
server # [    0.003686] rcu: 	Max phase no-delay instances is 1000.
builder # [    0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
server # [    0.004905] fsl-mc MSI: its@8080000 domain created
builder # [    0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
server # [    0.004994] EFI services will not be available.
server # [    0.005058] smp: Bringing up secondary CPUs ...
builder # [    0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB
server # [    0.005066] smp: Brought up 1 node, 1 CPU
builder # [    0.000000] software IO TLB: area num 1.
server # [    0.005069] SMP: Total of 1 processors activated.
builder # [    0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)
server # [    0.005072] CPU: All CPU(s) started at EL1
builder # [    0.000000] Fallback order for Node 0: 0
server # [    0.005085] CPU features: detected: Branch Target Identification
builder # [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 262144
server # [    0.005089] CPU features: detected: ARMv8.4 Translation Table Level
builder # [    0.000000] Policy zone: DMA
builder # [    0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
server # [    0.005092] CPU features: detected: Instruction cache invalidation not required for I/D coherence
builder # [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
server # [    0.005096] CPU features: detected: Data cache clean to the PoU not required for I/D coherence
builder # [    0.000000] allocated 2097152 bytes of page_ext
builder # [    0.000000] ftrace: allocating 74886 entries in 294 pages
server # [    0.005100] CPU features: detected: Common not Private translations
builder # [    0.000000] ftrace: allocated 294 pages with 4 groups
server # [    0.005103] CPU features: detected: CRC32 instructions
builder # [    0.000000] rcu: Hierarchical RCU implementation.
server # [    0.005105] CPU features: detected: Data cache clean to Point of Deep Persistence
builder # [    0.000000] rcu: 	RCU event tracing is enabled.
server # [    0.005109] CPU features: detected: Data cache clean to Point of Persistence
builder # [    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
builder # [    0.000000] 	Trampoline variant of Tasks RCU enabled.
server # [    0.005112] CPU features: detected: Data independent timing control (DIT)
builder # [    0.000000] 	Rude variant of Tasks RCU enabled.
server # [    0.005115] CPU features: detected: E0PD
builder # [    0.000000] 	Tracing variant of Tasks RCU enabled.
server # [    0.005117] CPU features: detected: Enhanced Counter Virtualization
builder # [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
server # [    0.005121] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)
builder # [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
server # [    0.005124] CPU features: detected: Enhanced Virtualization Traps
server # [    0.005127] CPU features: detected: Fine Grained Traps
builder # [    0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.005131] CPU features: detected: Generic authentication (architected QARMA5 algorithm)
builder # [    0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.005136] CPU features: detected: RCpc load-acquire (LDAPR)
server # [    0.005139] CPU features: detected: LSE atomic instructions
builder # [    0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.005142] CPU features: detected: Privileged Access Never
builder # [    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
server # [    0.005145] CPU features: detected: PMUv3
builder # [    0.000000] GICv3: 256 SPIs implemented
server # [    0.005147] CPU features: detected: RAS Extension Support
builder # [    0.000000] GICv3: 0 Extended SPIs implemented
builder # [    0.000000] Root IRQ handler: gic_handle_irq
server # [    0.005150] CPU features: detected: RASv1p1 Extension Support
builder # [    0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI
server # [    0.005152] CPU features: detected: Random Number Generator
builder # [    0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0
server # [    0.005155] CPU features: detected: Speculation barrier (SB)
builder # [    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000
server # [    0.005158] CPU features: detected: Stage-2 Force Write-Back
builder # [    0.000000] ITS [mem 0x08080000-0x0809ffff]
server # [    0.005161] CPU features: detected: TLB range maintenance instructions
builder # [    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44cf0000 (indirect, esz 8, psz 64K, shr 1)
server # [    0.005165] CPU features: detected: Speculative Store Bypassing Safe (SSBS)
server # [    0.005203] alternatives: applying system-wide alternatives
builder # [    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44d00000 (flat, esz 8, psz 64K, shr 1)
server # [    0.008149] CPU features: detected: BBM Level 2 without TLB conflict abort
builder # [    0.000000] GICv3: using LPI property table @0x0000000044d10000
builder # [    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000
server # [    0.008515] Memory: 894236K/1048576K available (24448K kernel code, 7090K rwdata, 26344K rodata, 4736K init, 1107K bss, 113012K reserved, 32768K cma-reserved)
builder # [    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
server # [    0.008842] devtmpfs: initialized
server # [    0.010557] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
builder # [    0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
builder # [    0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).
server # [    0.010577] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
server # [    0.010746] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL
builder # [    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
server # [    0.010750] 0 pages in range for non-PLT usage
server # [    0.010751] 508288 pages in range for PLT usage
builder # [    0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns
server # [    0.010854] pinctrl core: initialized pinctrl subsystem
builder # [    0.000029] arm-pv: using stolen time PV
server # [    0.011656] DMI not present or invalid.
server # [    0.016280] NET: Registered PF_NETLINK/PF_ROUTE protocol family
builder # [    0.000394] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
builder # [    0.000561] Console: colour dummy device 80x25
server # [    0.018685] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
builder # [    0.000568] printk: legacy console [tty0] enabled
server # [    0.018826] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
builder # [    0.000793] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)
server # [    0.018983] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
builder # [    0.000801] pid_max: default: 32768 minimum: 301
server # [    0.019005] audit: initializing netlink subsys (disabled)
builder # [    0.000879] LSM: initializing lsm=capability,landlock,yama,bpf,ima
server # [    0.019582] thermal_sys: Registered thermal governor 'fair_share'
builder # [    0.001044] landlock: Up and running.
server # [    0.019584] thermal_sys: Registered thermal governor 'bang_bang'
builder # [    0.001047] Yama: becoming mindful.
builder # [    0.001531] LSM support for eBPF active
server # [    0.019587] thermal_sys: Registered thermal governor 'step_wise'
builder # [    0.001674] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
server # [    0.019590] thermal_sys: Registered thermal governor 'user_space'
server # [    0.019595] thermal_sys: Registered thermal governor 'power_allocator'
builder # [    0.001692] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
builder # [    0.003979] cacheinfo: Unable to detect cache hierarchy for CPU 0
server # [    0.019632] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1
builder # [    0.004708] rcu: Hierarchical SRCU implementation.
server # [    0.019642] cpuidle: using governor ladder
server # [    0.019647] cpuidle: using governor menu
builder # [    0.004712] rcu: 	Max phase no-delay instances is 1000.
builder # [    0.005871] fsl-mc MSI: its@8080000 domain created
server # [    0.019839] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.
builder # [    0.005961] EFI services will not be available.
server # [    0.019855] ASID allocator initialised with 65536 entries
builder # [    0.006035] smp: Bringing up secondary CPUs ...
server # [    0.021463] Serial: AMBA PL011 UART driver
builder # [    0.006043] smp: Brought up 1 node, 1 CPU
builder # [    0.006047] SMP: Total of 1 processors activated.
server # [    0.028056] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1
builder # [    0.006050] CPU: All CPU(s) started at EL1
server # [    0.028181] printk: console [ttyAMA0] enabled
builder # [    0.006064] CPU features: detected: Branch Target Identification
builder # [    0.006069] CPU features: detected: ARMv8.4 Translation Table Level
builder # [    0.006072] CPU features: detected: Instruction cache invalidation not required for I/D coherence
builder # [    0.006076] CPU features: detected: Data cache clean to the PoU not required for I/D coherence
builder # [    0.006080] CPU features: detected: Common not Private translations
builder # [    0.006083] CPU features: detected: CRC32 instructions
builder # [    0.006086] CPU features: detected: Data cache clean to Point of Deep Persistence
builder # [    0.006089] CPU features: detected: Data cache clean to Point of Persistence
builder # [    0.006092] CPU features: detected: Data independent timing control (DIT)
builder # [    0.006095] CPU features: detected: E0PD
builder # [    0.006098] CPU features: detected: Enhanced Counter Virtualization
server # [    0.154234] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
builder # [    0.006101] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)
server # [    0.154258] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page
builder # [    0.006105] CPU features: detected: Enhanced Virtualization Traps
builder # [    0.006107] CPU features: detected: Fine Grained Traps
server # [    0.154264] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages
server # [    0.154269] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page
builder # [    0.006110] CPU features: detected: Generic authentication (architected QARMA5 algorithm)
builder # [    0.006115] CPU features: detected: RCpc load-acquire (LDAPR)
server # [    0.154274] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
builder # [    0.006118] CPU features: detected: LSE atomic instructions
server # [    0.154278] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page
builder # [    0.006120] CPU features: detected: Privileged Access Never
server # [    0.154283] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages
builder # [    0.006123] CPU features: detected: PMUv3
server # [    0.154287] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page
builder # [    0.006126] CPU features: detected: RAS Extension Support
builder # [    0.006129] CPU features: detected: RASv1p1 Extension Support
builder # [    0.006131] CPU features: detected: Random Number Generator
builder # [    0.006134] CPU features: detected: Speculation barrier (SB)
builder # [    0.006136] CPU features: detected: Stage-2 Force Write-Back
server # [    0.162686] fbcon: Taking over console
server # [    0.162707] ACPI: Interpreter disabled.
builder # [    0.006139] CPU features: detected: TLB range maintenance instructions
builder # [    0.006144] CPU features: detected: Speculative Store Bypassing Safe (SSBS)
builder # [    0.006181] alternatives: applying system-wide alternatives
builder # [    0.009149] CPU features: detected: BBM Level 2 without TLB conflict abort
builder # [    0.009358] Memory: 894248K/1048576K available (24448K kernel code, 7090K rwdata, 26344K rodata, 4736K init, 1107K bss, 113020K reserved, 32768K cma-reserved)
builder # [    0.009702] devtmpfs: initialized
builder # [    0.011519] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
server # [    0.169927] iommu: Default domain type: Translated
server # [    0.169938] iommu: DMA domain TLB invalidation policy: strict mode
builder # [    0.011541] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
server # [    0.171789] SCSI subsystem initialized
builder # [    0.011734] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL
builder # [    0.011739] 0 pages in range for non-PLT usage
builder # [    0.011740] 508288 pages in range for PLT usage
server # [    0.172590] usbcore: registered new interface driver usbfs
builder # [    0.011845] pinctrl core: initialized pinctrl subsystem
server # [    0.172629] usbcore: registered new interface driver hub
builder # [    0.012677] DMI not present or invalid.
server # [    0.172646] usbcore: registered new device driver usb
builder # [    0.015803] NET: Registered PF_NETLINK/PF_ROUTE protocol family
server # [    0.172926] pps_core: LinuxPPS API ver. 1 registered
builder # [    0.018131] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
server # [    0.172933] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
builder # [    0.018298] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
server # [    0.172951] PTP clock support registered
server # [    0.173000] EDAC MC: Ver: 3.0.0
builder # [    0.018458] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
server # [    0.178074] scmi_core: SCMI protocol bus registered
server # [    0.179131] FPGA manager framework
server # [    0.182117] vgaarb: loaded
server # [    0.182859] clocksource: Switched to clocksource arch_sys_counter
server # [    0.184268] VFS: Disk quotas dquot_6.6.0
server # [    0.184308] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
server # [    0.185927] netfs: FS-Cache loaded
server # [    0.186038] pnp: PnP ACPI: disabled
builder # [    0.018483] audit: initializing netlink subsys (disabled)
builder # [    0.019031] thermal_sys: Registered thermal governor 'fair_share'
builder # [    0.019033] thermal_sys: Registered thermal governor 'bang_bang'
builder # [    0.019036] thermal_sys: Registered thermal governor 'step_wise'
builder # [    0.019039] thermal_sys: Registered thermal governor 'user_space'
builder # [    0.019044] thermal_sys: Registered thermal governor 'power_allocator'
builder # [    0.019069] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1
builder # [    0.019078] cpuidle: using governor ladder
builder # [    0.019084] cpuidle: using governor menu
builder # [    0.019281] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.
builder # [    0.019296] ASID allocator initialised with 65536 entries
builder # [    0.020428] Serial: AMBA PL011 UART driver
server # [    0.192708] NET: Registered PF_INET protocol family
builder # [    0.026029] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1
builder # [    0.026187] printk: console [ttyAMA0] enabled
server # [    0.192873] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
builder # [    0.153724] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
builder # [    0.153756] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page
builder # [    0.153762] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages
builder # [    0.153780] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page
builder # [    0.153790] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
builder # [    0.153795] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page
builder # [    0.153799] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages
builder # [    0.153803] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page
builder # [    0.162193] fbcon: Taking over console
builder # [    0.162215] ACPI: Interpreter disabled.
builder # [    0.164180] iommu: Default domain type: Translated
builder # [    0.164192] iommu: DMA domain TLB invalidation policy: strict mode
builder # [    0.170100] SCSI subsystem initialized
builder # [    0.171291] usbcore: registered new interface driver usbfs
builder # [    0.171326] usbcore: registered new interface driver hub
builder # [    0.171342] usbcore: registered new device driver usb
builder # [    0.171635] pps_core: LinuxPPS API ver. 1 registered
builder # [    0.171641] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
builder # [    0.171651] PTP clock support registered
builder # [    0.171717] EDAC MC: Ver: 3.0.0
builder # [    0.176957] scmi_core: SCMI protocol bus registered
builder # [    0.178013] FPGA manager framework
builder # [    0.179101] vgaarb: loaded
builder # [    0.182763] clocksource: Switched to clocksource arch_sys_counter
builder # [    0.183436] VFS: Disk quotas dquot_6.6.0
builder # [    0.183468] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
builder # [    0.185840] netfs: FS-Cache loaded
builder # [    0.185939] pnp: PnP ACPI: disabled
server # [    0.225402] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
server # [    0.225459] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
server # [    0.225490] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
server # [    0.225566] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
server # [    0.225648] TCP: Hash tables configured (established 8192 bind 8192)
server # [    0.225765] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
server # [    0.225810] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
server # [    0.225841] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
builder # [    0.192685] NET: Registered PF_INET protocol family
server # [    0.225933] NET: Registered PF_UNIX/PF_LOCAL protocol family
builder # [    0.192947] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
server # [    0.225962] NET: Registered PF_XDP protocol family
server # [    0.225991] PCI: CLS 0 bytes, default 64
server # [    0.226325] Trying to unpack rootfs image as initramfs...
server # [    0.240821] kvm [1]: HYP mode not available
builder # [    0.223125] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
builder # [    0.223196] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
builder # [    0.223226] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
builder # [    0.223273] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
builder # [    0.223350] TCP: Hash tables configured (established 8192 bind 8192)
builder # [    0.223447] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
builder # [    0.223487] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
builder # [    0.223515] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
builder # [    0.223612] NET: Registered PF_UNIX/PF_LOCAL protocol family
builder # [    0.223651] NET: Registered PF_XDP protocol family
builder # [    0.223672] PCI: CLS 0 bytes, default 64
builder # [    0.232912] Trying to unpack rootfs image as initramfs...
builder # [    0.239569] kvm [1]: HYP mode not available
server # [    0.347526] Initialise system trusted keyrings
server # [    0.348336] workingset: timestamp_bits=42 max_order=18 bucket_order=0
server # [    0.349684] squashfs: version 4.0 (2009/01/31) Phillip Lougher
server # [    0.350498] 9p: Installing v9fs 9p2000 file system support
server # [    0.379648] Key type asymmetric registered
server # [    0.379682] Asymmetric key parser 'x509' registered
server # [    0.379775] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)
server # [    0.382033] io scheduler mq-deadline registered
server # [    0.382067] io scheduler kyber registered
builder # [    0.347396] Initialise system trusted keyrings
builder # [    0.348192] workingset: timestamp_bits=42 max_order=18 bucket_order=0
builder # [    0.349532] squashfs: version 4.0 (2009/01/31) Phillip Lougher
builder # [    0.350342] 9p: Installing v9fs 9p2000 file system support
server # [    0.395676] pl061_gpio 9030000.pl061: PL061 GPIO chip registered
server # [    0.396310] ledtrig-cpu: registered to indicate activity on CPUs
server # [    0.396671] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:
server # [    0.396689] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000
server # [    0.396701] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000
server # [    0.396710] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000
server # [    0.396742] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits
server # [    0.396764] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]
server # [    0.396896] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00
server # [    0.396925] pci_bus 0000:00: root bus resource [bus 00-ff]
server # [    0.396952] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
server # [    0.396970] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]
server # [    0.396979] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]
server # [    0.397053] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint
server # [    0.397522] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.397716] pci 0000:00:01.0: BAR 0 [io  0x0000-0x001f]
server # [    0.397734] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.397767] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.397785] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]
server # [    0.398258] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
server # [    0.398456] pci 0000:00:02.0: BAR 0 [io  0x0000-0x001f]
server # [    0.398472] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.379204] Key type asymmetric registered
server # [    0.398502] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.379239] Asymmetric key parser 'x509' registered
server # [    0.398998] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
builder # [    0.379330] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)
server # [    0.399185] pci 0000:00:03.0: BAR 0 [io  0x0000-0x003f]
builder # [    0.381739] io scheduler mq-deadline registered
server # [    0.399201] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.381752] io scheduler kyber registered
server # [    0.399232] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.399693] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.399879] pci 0000:00:04.0: BAR 0 [io  0x0000-0x001f]
server # [    0.399905] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.399936] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.400467] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.400650] pci 0000:00:05.0: BAR 0 [io  0x0000-0x001f]
server # [    0.400667] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.400709] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.401168] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
server # [    0.401357] pci 0000:00:06.0: BAR 0 [io  0x0000-0x007f]
server # [    0.401373] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.401405] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.401865] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.402053] pci 0000:00:07.0: BAR 0 [io  0x0000-0x001f]
server # [    0.402070] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.402101] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.402119] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]
server # [    0.402590] pci 0000:00:08.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint
server # [    0.402778] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.402810] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.395711] pl061_gpio 9030000.pl061: PL061 GPIO chip registered
builder # [    0.396331] ledtrig-cpu: registered to indicate activity on CPUs
builder # [    0.396807] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:
builder # [    0.396827] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000
builder # [    0.396842] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000
builder # [    0.396851] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000
builder # [    0.396869] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits
builder # [    0.396892] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]
builder # [    0.396965] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00
builder # [    0.396977] pci_bus 0000:00: root bus resource [bus 00-ff]
builder # [    0.396983] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
server # [    0.451407] pci 0000:00:09.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
server # [    0.451622] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.396988] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]
server # [    0.451654] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.396994] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]
server # [    0.452063] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint
builder # [    0.397067] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint
server # [    0.452257] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]
builder # [    0.397553] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.452514] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
builder # [    0.397748] pci 0000:00:01.0: BAR 0 [io  0x0000-0x001f]
server # [    0.452822] pci 0000:00:0b.0: BAR 0 [io  0x0000-0x003f]
builder # [    0.397767] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.452840] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.397798] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.452873] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.397815] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]
server # [    0.453359] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
builder # [    0.398286] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
server # [    0.453548] pci 0000:00:0c.0: BAR 0 [io  0x0000-0x001f]
builder # [    0.398489] pci 0000:00:02.0: BAR 0 [io  0x0000-0x001f]
server # [    0.453565] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.398510] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.453597] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.398542] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.454191] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned
builder # [    0.399063] pci 0000:00:03.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.454203] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned
builder # [    0.399251] pci 0000:00:03.0: BAR 0 [io  0x0000-0x003f]
builder # [    0.399269] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.454210] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned
builder # [    0.399300] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.454256] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned
builder # [    0.399759] pci 0000:00:04.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.454305] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned
builder # [    0.399953] pci 0000:00:04.0: BAR 0 [io  0x0000-0x001f]
server # [    0.454354] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned
builder # [    0.399971] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.400002] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.454402] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned
builder # [    0.400499] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.454450] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned
builder # [    0.400691] pci 0000:00:05.0: BAR 0 [io  0x0000-0x001f]
server # [    0.454500] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned
builder # [    0.400708] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.454551] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned
builder # [    0.400739] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.454599] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned
builder # [    0.401192] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
builder # [    0.401384] pci 0000:00:06.0: BAR 0 [io  0x0000-0x007f]
server # [    0.454648] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned
builder # [    0.401402] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.454723] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned
builder # [    0.401432] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.454772] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned
builder # [    0.401887] pci 0000:00:07.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.454796] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned
builder # [    0.402072] pci 0000:00:07.0: BAR 0 [io  0x0000-0x001f]
server # [    0.454819] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned
builder # [    0.402089] pci 0000:00:07.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.454843] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned
builder # [    0.402120] pci 0000:00:07.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.402137] pci 0000:00:07.0: ROM [mem 0x00000000-0x0003ffff pref]
server # [    0.482758] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned
server # [    0.482806] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned
builder # [    0.402594] pci 0000:00:08.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint
server # [    0.482830] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned
server # [    0.482855] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned
server # [    0.486312] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned
server # [    0.486338] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned
server # [    0.486362] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned
server # [    0.486388] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned
server # [    0.486411] pci 0000:00:06.0: BAR 0 [io  0x1000-0x107f]: assigned
server # [    0.486435] pci 0000:00:03.0: BAR 0 [io  0x1080-0x10bf]: assigned
server # [    0.486471] pci 0000:00:0b.0: BAR 0 [io  0x10c0-0x10ff]: assigned
server # [    0.486504] pci 0000:00:01.0: BAR 0 [io  0x1100-0x111f]: assigned
server # [    0.486539] pci 0000:00:02.0: BAR 0 [io  0x1120-0x113f]: assigned
builder # [    0.446820] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.486573] pci 0000:00:04.0: BAR 0 [io  0x1140-0x115f]: assigned
builder # [    0.446863] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.486607] pci 0000:00:05.0: BAR 0 [io  0x1160-0x117f]: assigned
builder # [    0.447369] pci 0000:00:09.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
server # [    0.486630] pci 0000:00:07.0: BAR 0 [io  0x1180-0x119f]: assigned
builder # [    0.447564] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]
server # [    0.486653] pci 0000:00:0c.0: BAR 0 [io  0x11a0-0x11bf]: assigned
server # [    0.486685] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]
builder # [    0.447598] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.486695] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]
builder # [    0.448000] pci 0000:00:0a.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint
server # [    0.486700] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]
builder # [    0.448185] pci 0000:00:0a.0: BAR 0 [mem 0x00000000-0x00000fff]
builder # [    0.448437] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
builder # [    0.448736] pci 0000:00:0b.0: BAR 0 [io  0x0000-0x003f]
builder # [    0.448755] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.448786] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
server # [    0.500636] pci 0000:00:0a.0: enabling device (0000 -> 0002)
builder # [    0.449269] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
builder # [    0.449468] pci 0000:00:0c.0: BAR 0 [io  0x0000-0x001f]
builder # [    0.449488] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]
builder # [    0.449519] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]
builder # [    0.450141] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned
builder # [    0.450154] pci 0000:00:07.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned
builder # [    0.450160] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned
builder # [    0.450206] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned
builder # [    0.450262] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned
builder # [    0.450310] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned
builder # [    0.450358] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned
builder # [    0.450405] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned
builder # [    0.450453] pci 0000:00:07.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned
builder # [    0.450503] pci 0000:00:08.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned
builder # [    0.450551] pci 0000:00:09.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned
builder # [    0.450599] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned
builder # [    0.450669] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned
builder # [    0.450717] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned
builder # [    0.450740] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned
builder # [    0.482802] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned
builder # [    0.482843] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned
builder # [    0.482868] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned
server # [    0.527703] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
server # [    0.530039] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
builder # [    0.482895] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned
builder # [    0.482918] pci 0000:00:07.0: BAR 1 [mem 0x10086000-0x10086fff]: assigned
builder # [    0.482942] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned
builder # [    0.482966] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned
builder # [    0.482989] pci 0000:00:0a.0: BAR 0 [mem 0x10089000-0x10089fff]: assigned
builder # [    0.483012] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned
builder # [    0.483036] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned
builder # [    0.483220] pci 0000:00:06.0: BAR 0 [io  0x1000-0x107f]: assigned
builder # [    0.483247] pci 0000:00:03.0: BAR 0 [io  0x1080-0x10bf]: assigned
builder # [    0.483270] pci 0000:00:0b.0: BAR 0 [io  0x10c0-0x10ff]: assigned
builder # [    0.483295] pci 0000:00:01.0: BAR 0 [io  0x1100-0x111f]: assigned
builder # [    0.483319] pci 0000:00:02.0: BAR 0 [io  0x1120-0x113f]: assigned
builder # [    0.483342] pci 0000:00:04.0: BAR 0 [io  0x1140-0x115f]: assigned
builder # [    0.483371] pci 0000:00:05.0: BAR 0 [io  0x1160-0x117f]: assigned
builder # [    0.483394] pci 0000:00:07.0: BAR 0 [io  0x1180-0x119f]: assigned
builder # [    0.483418] pci 0000:00:0c.0: BAR 0 [io  0x11a0-0x11bf]: assigned
builder # [    0.483460] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]
builder # [    0.483472] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]
builder # [    0.483477] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]
builder # [    0.484661] pci 0000:00:0a.0: enabling device (0000 -> 0002)
server # [    0.548421] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)
server # [    0.550440] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
server # [    0.554110] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)
server # [    0.557211] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)
builder # [    0.524142] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
server # [    0.567402] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)
builder # [    0.526423] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
server # [    0.569598] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)
server # [    0.580187] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)
server # [    0.582036] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)
server # [    0.585933] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)
builder # [    0.544329] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)
builder # [    0.546324] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
builder # [    0.550069] virtio-pci 0000:00:05.0: enabling device (0000 -> 0003)
builder # [    0.553627] virtio-pci 0000:00:06.0: enabling device (0000 -> 0003)
server # [    0.605473] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
builder # [    0.564229] virtio-pci 0000:00:07.0: enabling device (0000 -> 0003)
server # [    0.608362] msm_serial: driver initialized
builder # [    0.566485] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)
server # [    0.608524] SuperH (H)SCI(F) driver initialized
server # [    0.608584] STM32 USART driver initialized
builder # [    0.578915] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)
builder # [    0.580948] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)
builder # [    0.591016] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)
builder # [    0.600914] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
server # [    0.644040] loop: module loaded
server # [    0.644254] virtio_blk virtio5: 1/0/0 default/read/poll queues
server # [    0.645081] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
builder # [    0.607945] msm_serial: driver initialized
builder # [    0.608140] SuperH (H)SCI(F) driver initialized
builder # [    0.608195] STM32 USART driver initialized
server # [    0.651573] megasas: 07.734.00.00-rc1
server # [    0.652458] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]
server # [    0.654655] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
server # [    0.654686] Intel/Sharp Extended Query Table at 0x0031
server # [    0.663907] Using buffer write method
server # [    0.663983] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]
server # [    0.674917] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
server # [    0.674963] Intel/Sharp Extended Query Table at 0x0031
server # [    0.676556] Using buffer write method
server # [    0.676598] Concatenating MTD devices:
server # [    0.676602] (0): "0.flash"
server # [    0.676606] (1): "0.flash"
server # [    0.676609] into device "0.flash"
builder # [    0.647726] loop: module loaded
builder # [    0.647938] virtio_blk virtio5: 1/0/0 default/read/poll queues
builder # [    0.648691] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
builder # [    0.652923] megasas: 07.734.00.00-rc1
builder # [    0.653774] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]
builder # [    0.656073] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
builder # [    0.656100] Intel/Sharp Extended Query Table at 0x0031
builder # [    0.657552] Using buffer write method
builder # [    0.657635] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]
builder # [    0.669046] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
builder # [    0.669089] Intel/Sharp Extended Query Table at 0x0031
builder # [    0.670755] Using buffer write method
builder # [    0.678834] Concatenating MTD devices:
builder # [    0.678839] (0): "0.flash"
builder # [    0.678843] (1): "0.flash"
builder # [    0.678846] into device "0.flash"
server # [    0.984337] Freeing initrd memory: 26152K
server # [    0.991612] tun: Universal TUN/TAP device driver, 1.6
server # [    0.996427] thunder_xcv, ver 1.0
server # [    0.996485] thunder_bgx, ver 1.0
server # [    0.996510] nicpf, ver 1.0
server # [    0.997691] e1000: Intel(R) PRO/1000 Network Driver
server # [    0.997703] e1000: Copyright (c) 1999-2006 Intel Corporation.
server # [    0.997734] e1000e: Intel(R) PRO/1000 Network Driver
server # [    0.997741] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
server # [    0.997776] igb: Intel(R) Gigabit Ethernet Network Driver
server # [    0.997784] igb: Copyright (c) 2007-2014 Intel Corporation.
server # [    0.997808] igbvf: Intel(R) Gigabit Virtual Function Network Driver
server # [    0.997815] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.
server # [    0.997952] sky2: driver version 1.30
server # [    1.007566] ehci-pci 0000:00:0a.0: EHCI Host Controller
server # [    1.007607] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1
server # [    1.007942] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000
server # [    1.010539] usbcore: registered new interface driver usb-storage
server # [    1.010610] usbcore: registered new interface driver usbserial_generic
builder # [    0.969409] Freeing initrd memory: 26160K
server # [    1.010624] usbserial: USB Serial support registered for generic
server # [    1.013537] hv_vmbus: registering driver hyperv_keyboard
server # [    1.015173] rtc-pl031 9010000.pl031: registered as rtc0
server # [    1.015196] rtc-pl031 9010000.pl031: setting system clock to 2026-09-10T17:37:04 UTC (1789061824)
server # [    1.015513] i2c_dev: i2c /dev entries driver
builder # [    0.976139] tun: Universal TUN/TAP device driver, 1.6
server # [    1.020878] sdhci: Secure Digital Host Controller Interface driver
server # [    1.020893] sdhci: Copyright(c) Pierre Ossman
server # [    1.021164] Synopsys Designware Multimedia Card Interface Driver
server # [    1.021562] sdhci-pltfm: SDHCI platform and OF driver helper
builder # [    0.980152] thunder_xcv, ver 1.0
server # [    1.025632] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00
builder # [    0.980198] thunder_bgx, ver 1.0
server # [    1.025978] hub 1-0:1.0: USB hub found
builder # [    0.980224] nicpf, ver 1.0
server # [    1.025998] hub 1-0:1.0: 6 ports detected
builder # [    0.980851] e1000: Intel(R) PRO/1000 Network Driver
builder # [    0.980859] e1000: Copyright (c) 1999-2006 Intel Corporation.
builder # [    0.980887] e1000e: Intel(R) PRO/1000 Network Driver
builder # [    0.980895] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
server # [    1.028791] hid: raw HID events driver (C) Jiri Kosina
builder # [    0.980919] igb: Intel(R) Gigabit Ethernet Network Driver
server # [    1.029136] usbcore: registered new interface driver usbhid
builder # [    0.980925] igb: Copyright (c) 2007-2014 Intel Corporation.
server # [    1.029146] usbhid: USB HID core driver
builder # [    0.980947] igbvf: Intel(R) Gigabit Virtual Function Network Driver
builder # [    0.980953] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.
builder # [    0.981135] sky2: driver version 1.30
builder # [    0.983502] ehci-pci 0000:00:0a.0: EHCI Host Controller
server # [    1.032139] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available
builder # [    0.983538] ehci-pci 0000:00:0a.0: new USB bus registered, assigned bus number 1
server # [    1.033723] drop_monitor: Initializing network drop monitor service
builder # [    0.983750] ehci-pci 0000:00:0a.0: irq 15, io mem 0x10089000
server # [    1.033892] NET: Registered PF_INET6 protocol family
server # [    1.037063] Segment Routing with IPv6
server # [    1.037081] In-situ OAM (IOAM) with IPv6
server # [    1.037110] NET: Registered PF_PACKET protocol family
builder # [    0.993627] usbcore: registered new interface driver usb-storage
server # [    1.038832] 9pnet: Installing 9P2000 support
builder # [    0.993693] usbcore: registered new interface driver usbserial_generic
builder # [    0.993707] usbserial: USB Serial support registered for generic
builder # [    0.994392] hv_vmbus: registering driver hyperv_keyboard
builder # [    0.994815] ehci-pci 0000:00:0a.0: USB 2.0 started, EHCI 1.00
builder # [    0.995282] hub 1-0:1.0: USB hub found
builder # [    0.999451] hub 1-0:1.0: 6 ports detected
server # [    1.041613] Key type dns_resolver registered
builder # [    1.000920] rtc-pl031 9010000.pl031: registered as rtc0
builder # [    1.000953] rtc-pl031 9010000.pl031: setting system clock to 2026-09-10T17:37:04 UTC (1789061824)
builder # [    1.001380] i2c_dev: i2c /dev entries driver
server # [    1.048622] registered taskstats version 1
server # [    1.048810] Loading compiled-in X.509 certificates
builder # [    1.007070] sdhci: Secure Digital Host Controller Interface driver
builder # [    1.007086] sdhci: Copyright(c) Pierre Ossman
builder # [    1.007394] Synopsys Designware Multimedia Card Interface Driver
builder # [    1.007793] sdhci-pltfm: SDHCI platform and OF driver helper
builder # [    1.009817] hid: raw HID events driver (C) Jiri Kosina
builder # [    1.010062] usbcore: registered new interface driver usbhid
builder # [    1.010069] usbhid: USB HID core driver
server # [    1.057927] Demotion targets for Node 0: null
server # [    1.058041] Key type .fscrypt registered
server # [    1.058048] Key type fscrypt-provisioning registered
server # [    1.058141] ima: No TPM chip found, activating TPM-bypass!
server # [    1.058162] ima: Allocated hash algorithm: sha1
server # [    1.058188] ima: No architecture policies found
builder # [    1.016010] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available
builder # [    1.017830] drop_monitor: Initializing network drop monitor service
server # [    1.062499] input: gpio-keys as /devices/platform/gpio-keys/input/input0
builder # [    1.018029] NET: Registered PF_INET6 protocol family
builder # [    1.021296] Segment Routing with IPv6
builder # [    1.021330] In-situ OAM (IOAM) with IPv6
builder # [    1.021373] NET: Registered PF_PACKET protocol family
builder # [    1.023349] 9pnet: Installing 9P2000 support
builder # [    1.025675] Key type dns_resolver registered
builder # [    1.033523] registered taskstats version 1
builder # [    1.033719] Loading compiled-in X.509 certificates
server # [    1.083245] clk: Disabling unused clocks
builder # [    1.042511] Demotion targets for Node 0: null
server # [    1.083275] PM: genpd: Disabling unused power domains
builder # [    1.042642] Key type .fscrypt registered
builder # [    1.042650] Key type fscrypt-provisioning registered
builder # [    1.044480] ima: No TPM chip found, activating TPM-bypass!
builder # [    1.044504] ima: Allocated hash algorithm: sha1
builder # [    1.044536] ima: No architecture policies found
server # [    1.088886] Freeing unused kernel memory: 4736K
server # [    1.089207] Run /init as init process
builder # [    1.047105] input: gpio-keys as /devices/platform/gpio-keys/input/input0
server # [    1.105810] systemd[1]: Successfully made /usr/ read-only.
builder # [    1.066699] clk: Disabling unused clocks
builder # [    1.066736] PM: genpd: Disabling unused power domains
builder # [    1.071954] Freeing unused kernel memory: 4736K
builder # [    1.072180] Run /init as init process
builder # [    1.089600] systemd[1]: Successfully made /usr/ read-only.
server # [    1.270989] usb 1-1: new high-speed USB device number 2 using ehci-pci
builder # [    1.246849] usb 1-1: new high-speed USB device number 2 using ehci-pci
server # [    1.427725] 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/input1
builder # [    1.401681] 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/input1
server # [    1.441561] systemd[1]: systemd 261.2 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)
server # [    1.454409] systemd[1]: Detected virtualization qemu.
server # [    1.456788] systemd[1]: Detected architecture arm64.
server # [    1.458842] systemd[1]: Running in initrd.
server # [    1.462450] systemd[1]: Initializing machine ID from random generator.
server # [    1.465835] systemd[1]: Hostname set to <server>.
builder # [    1.425040] systemd[1]: systemd 261.2 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)
builder # [    1.438249] systemd[1]: Detected virtualization qemu.
builder # [    1.440561] systemd[1]: Detected architecture arm64.
builder # [    1.442598] systemd[1]: Running in initrd.
builder # [    1.445924] systemd[1]: Initializing machine ID from random generator.
builder # [    1.449337] systemd[1]: Hostname set to <builder>.
server # [    1.519283] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0
builder # [    1.495273] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:0a.0-1/input0
server # [    1.642924] usb 1-2: new high-speed USB device number 3 using ehci-pci
builder # [    1.618824] usb 1-2: new high-speed USB device number 3 using ehci-pci
server # [    1.802315] 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/input2
server # [    1.809024] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0
builder # [    1.782315] 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/input2
server # [    1.834764] systemd[1]: bpf-restrict-fs: LSM BPF program attached
builder # [    1.788415] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:0a.0-2/input0
builder # [    1.812280] systemd[1]: bpf-restrict-fs: LSM BPF program attached
server # [    1.962437] systemd[1]: Queued start job for default target Initrd Default Target.
server # [    1.973984] systemd[1]: Created slice Slice /system/modprobe.
builder # [    1.932107] systemd[1]: Queued start job for default target Initrd Default Target.
server # [    1.975308] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
server # [    1.976694] systemd[1]: Expecting device /dev/disk/by-label/nixos...
server # [    1.977762] systemd[1]: Reached target Path Units.
server # [    1.978574] systemd[1]: Reached target Slice Units.
server # [    1.981246] systemd[1]: Reached target Swaps.
server # [    1.981994] systemd[1]: Reached target Timer Units.
server # [    1.983136] systemd[1]: Listening on D-Bus System Message Bus Socket.
builder # [    1.941591] systemd[1]: Created slice Slice /system/modprobe.
server # [    1.984493] systemd[1]: Listening on Journal Socket (/dev/log).
server # [    1.985641] systemd[1]: Listening on Journal Sockets.
builder # [    1.942763] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
server # [    1.986688] systemd[1]: Listening on udev Control Socket.
builder # [    1.944061] systemd[1]: Expecting device /dev/disk/by-label/nixos...
builder # [    1.946154] systemd[1]: Reached target Path Units.
server # [    1.987986] systemd[1]: Listening on udev Kernel Socket.
server # [    1.988032] systemd[1]: Reached target Socket Units.
builder # [    1.947553] systemd[1]: Reached target Slice Units.
builder # [    1.948783] systemd[1]: Reached target Swaps.
builder # [    1.949802] systemd[1]: Reached target Timer Units.
server # [    1.992212] systemd[1]: Starting Create List of Static Device Nodes...
builder # [    1.951053] systemd[1]: Listening on D-Bus System Message Bus Socket.
builder # [    1.952448] systemd[1]: Listening on Journal Socket (/dev/log).
builder # [    1.953733] systemd[1]: Listening on Journal Sockets.
builder # [    1.954945] systemd[1]: Listening on udev Control Socket.
builder # [    1.956096] systemd[1]: Listening on udev Kernel Socket.
builder # [    1.957089] systemd[1]: Reached target Socket Units.
server # [    2.001890] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
builder # [    1.960139] systemd[1]: Starting Create List of Static Device Nodes...
server # [    2.003187] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
server # [    2.006967] systemd[1]: Mounting Kernel Configuration File System...
builder # [    1.968549] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
builder # [    1.969852] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
server # [    2.022343] systemd[1]: Starting Journal Service...
builder # [    1.980561] systemd[1]: Mounting Kernel Configuration File System...
builder # [    2.009747] systemd[1]: Starting Journal Service...
server # [    2.060539] systemd[1]: Starting Load Kernel Modules...
server # [    2.060674] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
builder # [    2.027087] systemd[1]: Starting Load Kernel Modules...
builder # [    2.028069] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
builder # [    2.039110] systemd[1]: Starting Coldplug All udev Devices...
server # [    2.091097] systemd[1]: Starting Coldplug All udev Devices...
server # [    2.096429] systemd-journald[73]: Collecting audit messages is disabled.
server # [    2.108016] systemd[1]: Finished Create List of Static Device Nodes.
server # [    2.109197] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
builder # [    2.067385] systemd[1]: Finished Create List of Static Device Nodes.
server # [    2.123136] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
builder # [    2.083584] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
builder # [    2.087654] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
server # [    2.131410] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
builder # [    2.089263] systemd[1]: Mounted Kernel Configuration File System.
server # [    2.132750] systemd[1]: Mounted Kernel Configuration File System.
builder # [    2.107379] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
server # [    2.181004] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
builder # [    2.155385] systemd-journald[73]: Collecting audit messages is disabled.
server # [    2.200302] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
server # [    2.215454] [drm] pci: virtio-gpu-pci detected at 0000:00:08.0
builder # [    2.172568] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
server # [    2.215731] [drm] features: -virgl +edid -resource_blob -host_visible
server # [    2.215742] [drm] features: -context_init
server # [    2.216571] [drm] number of scanouts: 1
server # [    2.216589] [drm] number of cap sets: 0
builder # [    2.187642] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
builder # [    2.190267] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
server # [    2.235751] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
builder # [    2.195252] systemd[1]: Starting Create Static Device Nodes in /dev...
server # [    2.243575] systemd[1]: Starting Create Static Device Nodes in /dev...
server # [    2.247923] virtio-pci 0000:00:08.0: [drm] Registered 1 planes with drm panic
server # [    2.247946] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:08.0 on minor 0
builder # [    2.212911] [drm] pci: virtio-gpu-pci detected at 0000:00:08.0
builder # [    2.213185] [drm] features: -virgl +edid -resource_blob -host_visible
builder # [    2.213197] [drm] features: -context_init
builder # [    2.214031] [drm] number of scanouts: 1
builder # [    2.214049] [drm] number of cap sets: 0
builder # [    2.227245] virtio-pci 0000:00:08.0: [drm] Registered 1 planes with drm panic
builder # [    2.227264] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:08.0 on minor 0
server # [    2.271316] Console: switching to colour frame buffer device 160x50
server # [    2.305239] virtio-pci 0000:00:08.0: [drm] fb0: virtio_gpudrmfb frame buffer device
server # [    2.313845] systemd[1]: Finished Create Static Device Nodes in /dev.
builder # [    2.265488] Console: switching to colour frame buffer device 160x50
builder # [    2.272219] virtio-pci 0000:00:08.0: [drm] fb0: virtio_gpudrmfb frame buffer device
server # [    2.315557] systemd[1]: Reached target Preparation for Local File Systems.
server # [    2.315608] systemd[1]: Reached target Local File Systems.
server # [    2.320499] systemd[1]: Starting Rule-based Manager for Device Events and Files...
builder # [    2.278961] systemd[1]: Finished Create Static Device Nodes in /dev.
builder # [    2.279247] systemd[1]: Reached target Preparation for Local File Systems.
builder # [    2.279291] systemd[1]: Reached target Local File Systems.
builder # [    2.287350] systemd[1]: Starting Rule-based Manager for Device Events and Files...
server # [    2.317047] systemd-modules-load[75]: Inserted module 'dm_mod'
server # [    2.320210] systemd-modules-load[75]: Module 'virtio_balloon' is built in
server # [    2.321410] systemd-modules-load[75]: Module 'virtio_console' is built in
server # [    2.322516] systemd-modules-load[75]: Inserted module 'virtio_gpu'
server # [    2.323485] systemd-modules-load[75]: Module 'virtio_rng' is built in
server # [    2.343365] systemd[1]: Finished Load Kernel Modules.
server # [    2.343841] systemd[1]: Started Journal Service.
builder # [    2.311527] systemd[1]: Finished Load Kernel Modules.
builder # [    2.319404] systemd[1]: Starting Apply Kernel Variables...
server # [    2.357873] systemd[1]: Starting Apply Kernel Variables...
server # [    2.360215] systemd[1]: Starting Create System Files and Directories...
builder # [    2.360559] systemd-modules-load[74]: Inserted module 'dm_mod'
builder # [    2.361705] systemd-modules-load[74]: Module 'virtio_balloon' is built in
builder # [    2.381581] systemd[1]: Started Journal Service.
builder # [    2.368405] systemd-modules-load[74]: Module 'virtio_console' is built in
server # [    2.417704] systemd[1]: Finished Apply Kernel Variables.
builder # [    2.376325] systemd-modules-load[74]: Inserted module 'virtio_gpu'
builder # [    2.381099] systemd-modules-load[74]: Module 'virtio_rng' is built in
builder # [    2.387250] systemd[1]: Starting Create System Files and Directories...
server # [    2.433844] systemd-udevd[80]: Using default interface naming scheme 'v261'.
builder # [    2.393196] systemd[1]: Finished Apply Kernel Variables.
server # [    2.440155] systemd[1]: Finished Create System Files and Directories.
builder # [    2.404415] systemd-udevd[79]: Using default interface naming scheme 'v261'.
server # [    2.468642] systemd[1]: Started Rule-based Manager for Device Events and Files.
builder # [    2.435302] systemd[1]: Finished Create System Files and Directories.
builder # [    2.445626] systemd[1]: Started Rule-based Manager for Device Events and Files.
server # [    2.528972] systemd[1]: Starting Virtual Console Setup...
builder # [    2.512093] systemd[1]: Starting Virtual Console Setup...
server # [    2.584621] systemd-vconsole-setup[103]: Configuration of first virtual console was skipped, ignoring remaining ones.
server # [    2.588358] systemd[1]: Finished Virtual Console Setup.
builder # [    2.564575] systemd-vconsole-setup[103]: Configuration of first virtual console was skipped, ignoring remaining ones.
builder # [    2.568041] systemd[1]: Finished Virtual Console Setup.
server # [    3.186837] systemd[1]: Finished Coldplug All udev Devices.
server # [    3.192133] systemd[1]: Reached target System Initialization.
server # [    3.192990] systemd[1]: Reached target Basic System.
builder # [    3.175425] systemd[1]: Finished Coldplug All udev Devices.
builder # [    3.176831] systemd[1]: Reached target System Initialization.
builder # [    3.180123] systemd[1]: Reached target Basic System.
server # [    3.312410] (udev-worker)[102]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
builder # [    3.303977] (udev-worker)[102]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
server # [    3.359340] (udev-worker)[102]: Network interface NamePolicy= disabled on kernel command line.
server # [    3.373469] (udev-worker)[98]: Network interface NamePolicy= disabled on kernel command line.
builder # [    3.342917] (udev-worker)[102]: Network interface NamePolicy= disabled on kernel command line.
builder # [    3.354077] (udev-worker)[93]: Network interface NamePolicy= disabled on kernel command line.
server # [    3.437291] systemd[1]: Found device /dev/disk/by-label/nixos.
server # [    3.440556] systemd[1]: Reached target Initrd Root Device.
server # [    3.444152] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
builder # [    3.432557] systemd[1]: Found device /dev/disk/by-label/nixos.
builder # [    3.434650] systemd[1]: Reached target Initrd Root Device.
builder # [    3.444270] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
server # [    3.509168] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks
server # [    3.518400] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
server # [    3.528374] systemd[1]: Mounting /sysroot...
builder # [    3.502335] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks
builder # [    3.508816] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
builder # [    3.518042] systemd[1]: Mounting /sysroot...
server # [    3.590529] EXT4-fs (vda): mounted filesystem 6ef2e17c-4111-4ed8-bf6a-04c9050ad865 r/w with ordered data mode. Quota mode: none.
server # [    3.580934] systemd[1]: Mounted /sysroot.
server # [    3.582095] systemd[1]: Reached target Initrd Root File System.
server # [    3.588150] systemd[1]: Starting Mountpoints Configured in the Real Root...
builder # [    3.587006] EXT4-fs (vda): mounted filesystem dfaf080b-22e4-4442-88e3-d0a9cc76e72e r/w with ordered data mode. Quota mode: none.
builder # [    3.574885] systemd[1]: Mounted /sysroot.
builder # [    3.576286] systemd[1]: Reached target Initrd Root File System.
server # [    3.621080] systemd-sysroot-fstab-check[119]: /sysroot should be mounted in the initrd, will request daemon-reload.
builder # [    3.580497] systemd[1]: Starting Mountpoints Configured in the Real Root...
server # [    3.625849] systemd[1]: Reload requested from client PID 119 ('systemd-sysroot') (unit initrd-parse-etc.service)...
server # [    3.630696] systemd[1]: Reloading...
builder # [    3.621694] systemd-sysroot-fstab-check[119]: /sysroot should be mounted in the initrd, will request daemon-reload.
builder # [    3.627690] systemd[1]: Reload requested from client PID 119 ('systemd-sysroot') (unit initrd-parse-etc.service)...
builder # [    3.632730] systemd[1]: Reloading...
server # [    3.889638] systemd[1]: Reloading finished in 261 ms.
server # [    3.919481] systemd-sysroot-fstab-check[119]: Requesting initrd-fs.target/start/replace...
server # [    3.924315] systemd-sysroot-fstab-check[119]: Requesting swap.target/start/replace...
server # [    3.933479] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
server # [    3.936201] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
builder # [    3.893920] systemd[1]: Reloading finished in 263 ms.
server # [    3.940793] systemd[1]: Finished Mountpoints Configured in the Real Root.
server # [    3.942598] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
builder # [    3.923238] systemd-sysroot-fstab-check[119]: Requesting initrd-fs.target/start/replace...
builder # [    3.927426] systemd-sysroot-fstab-check[119]: Requesting swap.target/start/replace...
server # [    3.971410] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
server # [    3.973038] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
builder # [    3.934722] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
builder # [    3.943642] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
builder # [    3.945968] systemd[1]: Finished Mountpoints Configured in the Real Root.
builder # [    3.948787] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
builder # [    3.971122] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
builder # [    3.974837] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
builder # [    4.037404] systemd[1]: Mounting /sysroot/nix/.ro-store...
server # [    4.080891] systemd[1]: Mounting /sysroot/nix/.ro-store...
builder # [    4.056139] systemd[1]: Mounting /sysroot/nix/.rw-store...
server # [    4.099439] systemd[1]: Mounting /sysroot/nix/.rw-store...
builder # [    4.070633] systemd[1]: Mounting /sysroot/run...
server # [    4.120733] systemd[1]: Mounting /sysroot/run...
builder # [    4.090095] systemd[1]: Mounting /sysroot/tmp/shared...
server # [    4.138035] systemd[1]: Mounting /sysroot/tmp/shared...
server # [    4.151148] systemd[1]: Mounting /sysroot/tmp/xchg...
builder # [    4.128242] systemd[1]: Mounting /sysroot/tmp/xchg...
builder # [    4.143954] systemd[1]: Mounted /sysroot/nix/.rw-store.
builder # [    4.170460] systemd[1]: Mounted /sysroot/run.
builder # [    4.175935] systemd[1]: Mounted /sysroot/nix/.ro-store.
server # [    4.253262] systemd[1]: Mounted /sysroot/nix/.ro-store.
server # [    4.257618] systemd[1]: Mounted /sysroot/nix/.rw-store.
builder # [    4.220151] systemd[1]: Starting rw-sysroot-nix-store.service...
server # [    4.264307] systemd[1]: Mounted /sysroot/run.
builder # [    4.227942] systemd[1]: Mounted /sysroot/tmp/shared.
server # [    4.286844] systemd[1]: Mounted /sysroot/tmp/xchg.
builder # [    4.261913] systemd[1]: Mounted /sysroot/tmp/xchg.
server # [    4.318047] systemd[1]: Starting rw-sysroot-nix-store.service...
builder # [    4.302321] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
builder # [    4.311287] systemd[1]: Finished rw-sysroot-nix-store.service.
server # [    4.367899] systemd[1]: Mounted /sysroot/tmp/shared.
server # [    4.429612] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
server # [    4.436530] systemd[1]: Finished rw-sysroot-nix-store.service.
server # [    4.452846] systemd[1]: Mounting /sysroot/nix/store...
server # [    4.601112] systemd[1]: Mounted /sysroot/nix/store.
server # [    4.604774] systemd[1]: Reached target Initrd File Systems.
server # [    4.610098] systemd[1]: Starting Find NixOS closure...
server # [    4.624231] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
server # [    4.678418] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
server # [    4.699894] systemd[1]: Finished Find NixOS closure.
server # [    4.702772] systemd[1]: Reached target Initrd Default Target.
server # [    4.707910] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
server # [    4.757729] systemd[1]: Stopped target Initrd Default Target.
server # [    4.760454] systemd[1]: Stopped target Basic System.
server # [    4.768365] systemd[1]: Stopped target Initrd Root Device.
server # [    4.770318] systemd[1]: Stopped target Path Units.
server # [    4.771879] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
server # [    4.778018] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
server # [    4.779193] systemd[1]: Stopped target Slice Units.
server # [    4.781603] systemd[1]: Stopped target Socket Units.
server # [    4.785100] systemd[1]: Stopped target System Initialization.
server # [    4.788942] systemd[1]: Stopped target Swaps.
server # [    4.791534] systemd[1]: Stopped target Timer Units.
server # [    4.796268] systemd[1]: dbus.socket: Deactivated successfully.
server # [    4.797196] systemd[1]: Closed D-Bus System Message Bus Socket.
server # [    4.798099] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
server # [    4.799170] systemd[1]: Stopped Find NixOS closure.
server # [    4.799879] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
server # [    4.808446] systemd[1]: Starting rw-sysroot-nix-store.service...
server # [    4.809411] systemd[1]: systemd-sysctl.service: Deactivated successfully.
server # [    4.816176] systemd[1]: Stopped Apply Kernel Variables.
server # [    4.819105] systemd[1]: systemd-modules-load.service: Deactivated successfully.
server # [    4.820303] systemd[1]: Stopped Load Kernel Modules.
server # [    4.822965] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
server # [    4.837333] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
server # [    4.844498] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
server # [    4.848357] systemd[1]: Stopped Create System Files and Directories.
server # [    4.859420] systemd[1]: Stopped target Local File Systems.
server # [    4.861362] systemd[1]: Stopped target Preparation for Local File Systems.
server # [    4.864572] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
server # [    4.873783] systemd[1]: Stopped Coldplug All udev Devices.
server # [    4.875886] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
server # [    4.878635] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [    4.884937] systemd[1]: Stopped Virtual Console Setup.
server # [    4.885848] systemd[1]: initrd-cleanup.service: Deactivated successfully.
server # [    4.886806] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
server # [    4.887723] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
server # [    4.890092] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
server # [    4.892202] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
server # [    4.895285] systemd[1]: Finished rw-sysroot-nix-store.service.
server # [    4.902578] systemd[1]: systemd-udevd.service: Deactivated successfully.
server # [    4.905464] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
server # [    4.906815] systemd[1]: systemd-udevd.service: Consumed 1.139s CPU time over 2.602s wall clock time, 15.5M memory peak.
server # [    4.909908] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
server # [    4.912395] systemd[1]: Closed udev Control Socket.
server # [    4.916513] systemd[1]: Starting Cleanup udev Database...
server # [    4.917417] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
server # [    4.918491] systemd[1]: Stopped Create Static Device Nodes in /dev.
server # [    4.920225] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
server # [    4.922493] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
server # [    4.923641] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
server # [    4.924807] systemd[1]: Stopped Create List of Static Device Nodes.
server # [    4.958028] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
server # [    4.959953] systemd[1]: Finished Cleanup udev Database.
server # [    4.962270] systemd[1]: Reached target Switch Root.
server # [    4.965717] systemd[1]: Starting NixOS Activation...
builder # [    5.040552] systemd[1]: Mounting /sysroot/nix/store...
builder # [    5.086978] systemd[1]: Mounted /sysroot/nix/store.
builder # [    5.091382] systemd[1]: Reached target Initrd File Systems.
builder # [    5.095568] systemd[1]: Starting Find NixOS closure...
server # [    5.151125] initrd-nixos-activation-start[171]: booting system configuration /nix/store/lgi6ys32kv3ng3cjms823dk722g1vb7f-nixos-system-server-test
builder # [    5.116123] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
builder # [    5.157652] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
builder # [    5.158942] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.
server # [    5.222430] initrd-nixos-activation-start[171]: running activation script...
builder # [    5.197177] systemd[1]: Finished Find NixOS closure.
builder # [    5.198205] systemd[1]: Reached target Initrd Default Target.
builder # [    5.207147] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
builder # [    5.242843] systemd[1]: Stopped target Initrd Default Target.
builder # [    5.252089] systemd[1]: Stopped target Basic System.
builder # [    5.256201] systemd[1]: Stopped target Initrd Root Device.
builder # [    5.259100] systemd[1]: Stopped target Path Units.
builder # [    5.264127] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
builder # [    5.267269] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
builder # [    5.268598] systemd[1]: Stopped target Slice Units.
builder # [    5.272180] systemd[1]: Stopped target Socket Units.
builder # [    5.280176] systemd[1]: Stopped target System Initialization.
builder # [    5.298064] systemd[1]: Stopped target Swaps.
builder # [    5.298798] systemd[1]: Stopped target Timer Units.
builder # [    5.299522] systemd[1]: dbus.socket: Deactivated successfully.
builder # [    5.308168] systemd[1]: Closed D-Bus System Message Bus Socket.
builder # [    5.310180] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
builder # [    5.312699] systemd[1]: Stopped Find NixOS closure.
builder # [    5.317870] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
builder # [    5.318917] systemd[1]: Starting rw-sysroot-nix-store.service...
builder # [    5.324162] systemd[1]: systemd-sysctl.service: Deactivated successfully.
builder # [    5.325227] systemd[1]: Stopped Apply Kernel Variables.
builder # [    5.327596] systemd[1]: systemd-modules-load.service: Deactivated successfully.
builder # [    5.332319] systemd[1]: Stopped Load Kernel Modules.
builder # [    5.333073] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
builder # [    5.334148] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
builder # [    5.335216] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
builder # [    5.353604] systemd[1]: Stopped Create System Files and Directories.
builder # [    5.354600] systemd[1]: Stopped target Local File Systems.
builder # [    5.355566] systemd[1]: Stopped target Preparation for Local File Systems.
builder # [    5.368545] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
builder # [    5.372711] systemd[1]: Stopped Coldplug All udev Devices.
builder # [    5.376292] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
builder # [    5.377673] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
builder # [    5.380430] systemd[1]: Stopped Virtual Console Setup.
builder # [    5.382014] systemd[1]: initrd-cleanup.service: Deactivated successfully.
builder # [    5.384345] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
builder # [    5.388519] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
builder # [    5.389601] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
builder # [    5.390581] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
builder # [    5.393671] systemd[1]: Finished rw-sysroot-nix-store.service.
builder # [    5.404160] systemd[1]: systemd-udevd.service: Deactivated successfully.
builder # [    5.406278] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
builder # [    5.408173] systemd[1]: systemd-udevd.service: Consumed 1.729s CPU time over 3.134s wall clock time, 20M memory peak.
builder # [    5.412654] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
builder # [    5.413742] systemd[1]: Closed udev Control Socket.
builder # [    5.416222] systemd[1]: Starting Cleanup udev Database...
builder # [    5.417084] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
builder # [    5.419200] systemd[1]: Stopped Create Static Device Nodes in /dev.
builder # [    5.420419] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
builder # [    5.421562] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
builder # [    5.422574] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
builder # [    5.423540] systemd[1]: Stopped Create List of Static Device Nodes.
builder # [    5.467528] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
builder # [    5.470958] systemd[1]: Finished Cleanup udev Database.
builder # [    5.471761] systemd[1]: Reached target Switch Root.
builder # [    5.473703] systemd[1]: Starting NixOS Activation...
builder # [    5.653089] initrd-nixos-activation-start[173]: booting system configuration /nix/store/lpvbwjmvw2582gxzrsb7vj6malck0j35-nixos-system-builder-test
server # [    5.711792] initrd-nixos-activation-start[194]: setting up /etc...
builder # [    5.736391] initrd-nixos-activation-start[173]: running activation script...
server # [    6.011045] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
server # [    6.013983] systemd[1]: Finished NixOS Activation.
server # [    6.015081] systemd[1]: Starting Switch Root...
server # [    6.039606] systemd[1]: Switching root.
server # [    6.233018] systemd-journald[73]: Received SIGTERM from PID 1 (systemd).
builder # [    6.184497] initrd-nixos-activation-start[196]: setting up /etc...
builder # [    6.470237] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
builder # [    6.473158] systemd[1]: Finished NixOS Activation.
builder # [    6.476233] systemd[1]: Starting Switch Root...
builder # [    6.491873] systemd[1]: Switching root.
builder # [    6.695746] systemd-journald[73]: Received SIGTERM from PID 1 (systemd).
server # [    6.857491] systemd[1]: systemd 261.2 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)
server # [    6.869954] systemd[1]: Detected virtualization qemu.
server # [    6.873973] systemd[1]: Detected architecture arm64.
server # [    6.877300] systemd[1]: Detected first boot.
server # [    6.885091] systemd[1]: Initializing machine ID from random generator.
server # [    7.224923] systemd[1]: bpf-restrict-fs: LSM BPF program attached
builder # [    7.321017] systemd[1]: systemd 261.2 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)
builder # [    7.334477] systemd[1]: Detected virtualization qemu.
builder # [    7.336725] systemd[1]: Detected architecture arm64.
builder # [    7.340762] systemd[1]: Detected first boot.
builder # [    7.347663] systemd[1]: Initializing machine ID from random generator.
server # [    7.411321] systemd[1]: Applying preset policy.
builder # [    7.682909] systemd[1]: bpf-restrict-fs: LSM BPF program attached
builder # [    7.869380] systemd[1]: Applying preset policy.
server # [    7.942005] systemd[1]: Populated /etc with preset unit settings.
builder # [    8.360451] systemd[1]: Populated /etc with preset unit settings.
server # [    8.477345] systemd[1]: initrd-switch-root.service: Deactivated successfully.
server # [    8.478642] systemd[1]: Stopped initrd-switch-root.service.
server # [    8.482791] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
server # [    8.487314] systemd[1]: Created slice Slice /system/getty.
server # [    8.489837] systemd[1]: Created slice User and Session Slice.
server # [    8.491783] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
server # [    8.494853] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
server # [    8.496274] systemd[1]: Expecting device /dev/hvc0...
server # [    8.498466] systemd[1]: Expecting device /dev/ttyAMA0...
server # [    8.500387] systemd[1]: Reached target Local Encrypted Volumes.
server # [    8.502277] systemd[1]: Stopped target initrd-fs.target.
server # [    8.504181] systemd[1]: Stopped target initrd-root-fs.target.
server # [    8.506029] systemd[1]: Stopped target initrd-switch-root.target.
server # [    8.508038] systemd[1]: Reached target Virtual Machines and Containers.
server # [    8.509255] systemd[1]: Reached target Path Units.
server # [    8.511484] systemd[1]: Reached target Remote File Systems.
server # [    8.512556] systemd[1]: Reached target Slice Units.
server # [    8.513970] systemd[1]: Reached target Swaps.
server # [    8.518303] systemd[1]: Listening on Query the User Interactively for a Password.
server # [    8.523268] systemd[1]: Listening on Process Core Dump Socket.
server # [    8.527130] systemd[1]: Listening on Credential Encryption/Decryption.
server # [    8.531141] systemd[1]: Listening on Factory Reset Management.
server # [    8.531550] systemd[1]: Listening on Hostname Service Socket.
server # [    8.537616] systemd[1]: Starting Journal Log Access Socket...
server # [    8.540582] systemd[1]: Listening on Journal Audit Socket.
server # [    8.545002] systemd[1]: Listening on Console Output Muting Service Socket.
server # [    8.547438] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
server # [    8.550030] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os
server # [    8.552660] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
server # [    8.563688] systemd[1]: Listening on Disk Repartitioning Service Socket.
server # [    8.565085] systemd[1]: Listening on udev Control Socket.
server # [    8.566673] systemd[1]: Listening on udev Varlink Socket.
server # [    8.571046] systemd[1]: Mounting Huge Pages File System...
server # [    8.575091] systemd[1]: Mounting POSIX Message Queue File System...
server # [    8.587439] systemd[1]: Mounting Kernel Debug File System...
server # [    8.597867] systemd[1]: Mounting Kernel Trace File System...
server # [    8.612489] systemd[1]: Starting Create List of Static Device Nodes...
server # [    8.626587] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
server # [    8.628977] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
server # [    8.643975] systemd[1]: Mounting Kernel Configuration File System...
server # [    8.645960] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
server # [    8.648364] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
server # [    8.711186] systemd[1]: Starting Load Kernel Module fuse...
server # [    8.712720] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
server # [    8.744199] systemd[1]: Starting Journal Service...
server # [    8.760409] systemd[1]: Starting Load Kernel Modules...
server # [    8.779498] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
server # [    8.796858] systemd[1]: Starting Remount Root and Kernel File Systems...
server # [    8.804036] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
server # [    8.829387] systemd-journald[266]: Collecting audit messages is enabled.
server # [    8.819848] systemd[1]: Queued start job for default target Multi-User System.
server # [    8.843917] systemd[1]: Starting Coldplug All udev Devices...
server # [    8.846568] systemd[1]: Started Journal Service.
server # [    8.834649] systemd[1]: systemd-journald.service: Deactivated successfully.
server # [    8.871857] fuse: init (API version 7.45)
server # [    8.858729] systemd[1]: Listening on Journal Log Access Socket.
server # [    8.864654] systemd[1]: Mounted Huge Pages File System.
server # [    8.867862] systemd[1]: Mounted POSIX Message Queue File System.
server # [    8.874566] systemd[1]: Mounted Kernel Debug File System.
server # [    8.882352] systemd[1]: Mounted Kernel Trace File System.
server # [    8.887628] systemd-modules-load[267]: Module 'atkbd' is built in
builder # [    8.874343] systemd[1]: initrd-switch-root.service: Deactivated successfully.
builder # [    8.876001] systemd[1]: Stopped initrd-switch-root.service.
builder # [    8.877890] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
server # [    8.895529] systemd-modules-load[267]: Module 'loop' is built in[    8.922373] EXT4-fs (vda): re-mounted 6ef2e17c-4111-4ed8-bf6a-04c9050ad865.
server # 
builder # [    8.882523] systemd[1]: Created slice Slice /system/getty.
server # [    8.908407] systemd[1]: Finished Create List of Static Device Nodes.
builder # [    8.884387] systemd[1]: Created slice User and Session Slice.
server # [    8.909360] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
server # [    8.910345] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
server # [    8.911174] systemd[1]: Mounted Kernel Configuration File System.
builder # [    8.886231] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
builder # [    8.888247] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
builder # [    8.890745] systemd[1]: Expecting device /dev/hvc0...
builder # [    8.892635] systemd[1]: Expecting device /dev/ttyAMA0...
builder # [    8.893686] systemd[1]: Reached target Local Encrypted Volumes.
builder # [    8.895307] systemd[1]: Stopped target initrd-fs.target.
builder # [    8.897521] systemd[1]: Stopped target initrd-root-fs.target.
server # [    8.922299] systemd[1]: modprobe@fuse.service: Deactivated successfully.
builder # [    8.898595] systemd[1]: Stopped target initrd-switch-root.target.
builder # [    8.900200] systemd[1]: Reached target Virtual Machines and Containers.
builder # [    8.901827] systemd[1]: Reached target Path Units.
builder # [    8.904055] systemd[1]: Reached target Remote File Systems.
builder # [    8.905112] systemd[1]: Reached target Slice Units.
builder # [    8.906739] systemd[1]: Reached target Swaps.
server # [    8.932927] systemd[1]: Finished Load Kernel Module fuse.
server # [    8.933931] systemd-modules-load[267]: Inserted module 'tls'
server # [    8.934731] systemd[1]: Finished Load Kernel Modules.
server # [    8.935454] systemd[1]: Finished Remount Root and Kernel File Systems.
builder # [    8.911077] systemd[1]: Listening on Query the User Interactively for a Password.
builder # [    8.916252] systemd[1]: Listening on Process Core Dump Socket.
server # [    8.940210] systemd[1]: Listening on Disk Image Download Service Socket.
builder # [    8.920415] systemd[1]: Listening on Credential Encryption/Decryption.
server # [    8.946577] systemd[1]: Mounting FUSE Control File System...
builder # [    8.924439] systemd[1]: Listening on Factory Reset Management.
builder # [    8.926542] systemd[1]: Listening on Hostname Service Socket.
builder # [    8.932045] systemd[1]: Starting Journal Log Access Socket...
builder # [    8.934225] systemd[1]: Listening on Journal Audit Socket.
server # [    8.961601] systemd[1]: Starting Firewall...
builder # [    8.938485] systemd[1]: Listening on Console Output Muting Service Socket.
builder # [    8.941021] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
builder # [    8.943639] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os
server # [    8.970228] systemd[1]: Starting Flush Journal to Persistent Storage...
builder # [    8.946191] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
server # [    8.975112] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
builder # [    8.957511] systemd[1]: Listening on Disk Repartitioning Service Socket.
builder # [    8.959928] systemd[1]: Listening on udev Control Socket.
builder # [    8.962034] systemd[1]: Listening on udev Varlink Socket.
builder # [    8.967032] systemd[1]: Mounting Huge Pages File System...
server # [    8.992090] systemd-oomd[269]: No swap; memory pressure usage will be degraded
builder # [    8.972458] systemd[1]: Mounting POSIX Message Queue File System...
server # [    9.000551] systemd[1]: Starting Load/Save OS Random Seed...
builder # [    8.982979] systemd[1]: Mounting Kernel Debug File System...
server # [    9.014092] systemd[1]: Starting Apply Kernel Variables...
builder # [    8.992247] systemd[1]: Mounting Kernel Trace File System...
builder # [    9.008052] systemd[1]: Starting Create List of Static Device Nodes...
builder # [    9.024704] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
builder # [    9.029281] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
server # [    9.056101] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
server # [    9.058828] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
server # [    9.062056] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
builder # [    9.040526] systemd[1]: Mounting Kernel Configuration File System...
builder # [    9.043266] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
builder # [    9.050966] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
server # [    9.107084] systemd-journald[266]: Received client request to flush runtime journal.
builder # [    9.123985] systemd[1]: Starting Load Kernel Module fuse...
builder # [    9.131007] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
builder # [    9.146455] systemd[1]: Starting Journal Service...
server # [    9.190884] systemd[1]: Finished Load/Save OS Random Seed.
server # [    9.194766] systemd[1]: Reached target First Boot Complete.
server # [    9.204195] systemd[1]: Mounted FUSE Control File System.
server # [    9.206192] systemd[1]: Finished Flush Journal to Persistent Storage.
builder # [    9.182298] systemd[1]: Starting Load Kernel Modules...
server # [    9.218839] systemd[1]: Finished Apply Kernel Variables.
builder # [    9.207218] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
builder # [    9.212360] systemd[1]: Starting Remount Root and Kernel File Systems...
builder # [    9.214164] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
server # [    9.250917] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
server # [    9.258587] systemd[1]: Starting Create Static Device Nodes in /dev...
builder # [    9.241802] systemd[1]: Starting Coldplug All udev Devices...
builder # [    9.252870] systemd-journald[268]: Collecting audit messages is enabled.
builder # [    9.243209] systemd[1]: Queued start job for default target Multi-User System.
builder # [    9.247644] systemd[1]: systemd-journald.service: Deactivated successfully.
builder # [    9.259226] systemd-modules-load[270]: Module 'atkbd' is built in
builder # [    9.264604] systemd-modules-load[270]: Module 'loop' is built in
builder # [    9.286655] systemd[1]: Listening on Journal Log Access Socket.
builder # [    9.292925] systemd[1]: Started Journal Service.
builder # [    9.301699] fuse: init (API version 7.45)
builder # [    9.286110] systemd[1]: Mounted Huge Pages File System.
builder # [    9.287335] systemd[1]: Mounted POSIX Message Queue File System.
builder # [    9.290828] systemd[1]: Mounted Kernel Debug File System.
builder # [    9.295457] systemd[1]: Mounted Kernel Trace File System.
builder # [    9.302458] systemd[1]: Finished Create List of Static Device Nodes.
builder # [    9.310345] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
builder # [    9.316287] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
server # [    9.360120] systemd[1]: Finished Create Static Device Nodes in /dev.
builder # [    9.321903] systemd[1]: Mounted Kernel Configuration File System.
server # [    9.365397] systemd[1]: Reached target Preparation for Local File Systems.
server # [    9.367964] systemd[1]: Starting Rule-based Manager for Device Events and Files...
builder # [    9.328348] systemd[1]: Finished Load Kernel Modules.
builder # [    9.332249] systemd[1]: modprobe@fuse.service: Deactivated successfully.
builder # [    9.336423] systemd[1]: Finished Load Kernel Module fuse.
builder # [    9.349590] systemd[1]: Mounting FUSE Control File System...
builder # [    9.353927] systemd[1]: Starting Firewall...
builder # [    9.383083] EXT4-fs (vda): re-mounted dfaf080b-22e4-4442-88e3-d0a9cc76e72e.
builder # [    9.369469] systemd[1]: Starting Apply Kernel Variables...
builder # [    9.400463] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
builder # [    9.410308] systemd-oomd[271]: No swap; memory pressure usage will be degraded
builder # [    9.422432] systemd[1]: Finished Remount Root and Kernel File Systems.
server # [    9.470319] systemd[1]: Mounting /run/wrappers...
builder # [    9.439783] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
builder # [    9.448896] systemd[1]: Listening on Disk Image Download Service Socket.
builder # [    9.473716] systemd[1]: Starting Flush Journal to Persistent Storage...
builder # [    9.476668] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
builder # [    9.480790] systemd[1]: Starting Load/Save OS Random Seed...
builder # [    9.486916] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
server # [    9.547828] systemd[1]: Mounted /run/wrappers.
server # [    9.549361] systemd[1]: Reached target Local File Systems.
server # [    9.564069] systemd[1]: Listening on Boot Loader Control Service Socket.
server # [    9.570231] systemd[1]: Starting register-nix-paths.service...
builder # [    9.536603] systemd[1]: Finished Apply Kernel Variables.
server # [    9.594372] systemd[1]: Starting Create SUID/SGID Wrappers...
server # [    9.595384] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
builder # [    9.571098] systemd[1]: Mounted FUSE Control File System.
server # [    9.617580] systemd[1]: Starting Save Transient machine-id to Disk...
builder # [    9.599977] systemd-journald[268]: Received client request to flush runtime journal.
server # [    9.651490] systemd[1]: Starting Create System Files and Directories...
builder # [    9.664056] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
builder # [    9.668653] systemd[1]: Finished Load/Save OS Random Seed.
builder # [    9.672396] systemd[1]: Reached target First Boot Complete.
builder # [    9.673638] systemd[1]: Starting Create Static Device Nodes in /dev...
builder # [    9.680350] systemd[1]: Finished Flush Journal to Persistent Storage.
server # [    9.768478] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
server # [    9.771439] systemd[1]: Finished Save Transient machine-id to Disk.
builder # [    9.753267] systemd[1]: Finished Create Static Device Nodes in /dev.
builder # [    9.755271] systemd[1]: Reached target Preparation for Local File Systems.
builder # [    9.761859] systemd[1]: Starting Rule-based Manager for Device Events and Files...
server # [    9.876760] systemd-udevd[313]: Using default interface naming scheme 'v261'.
server # [    9.892855] systemd[1]: Finished Create System Files and Directories.
server # [    9.908115] systemd[1]: Starting Rebuild Journal Catalog...
builder # [    9.865941] systemd[1]: Mounting /run/wrappers...
server # [    9.939584] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
builder # [    9.906588] systemd-udevd[313]: Using default interface naming scheme 'v261'.
builder # [    9.928271] systemd[1]: Mounted /run/wrappers.
builder # [    9.929415] systemd[1]: Reached target Local File Systems.
builder # [    9.936240] systemd[1]: Listening on Boot Loader Control Service Socket.
builder # [    9.941864] systemd[1]: Starting register-nix-paths.service...
builder # [    9.946894] systemd[1]: Starting Create SUID/SGID Wrappers...
builder # [    9.952427] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
builder # [    9.956888] systemd[1]: Starting Save Transient machine-id to Disk...
builder # [   10.004191] systemd[1]: Starting Create System Files and Directories...
server # [   10.082122] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
server # [   10.139568] systemd[1]: Finished Rebuild Journal Catalog.
server # [   10.147399] systemd[1]: Starting Update is Completed...
builder # [   10.123459] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
server # [   10.176401] systemd[1]: Started Rule-based Manager for Device Events and Files.
builder # [   10.131333] systemd[1]: Finished Save Transient machine-id to Disk.
builder # [   10.192394] systemd[1]: Started Rule-based Manager for Device Events and Files.
server # [   10.239775] systemd[1]: Finished Update is Completed.
builder # [   10.235790] systemd[1]: Finished Create System Files and Directories.
builder # [   10.246986] systemd[1]: Starting Rebuild Journal Catalog...
builder # [   10.258408] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
builder # [   10.403981] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
builder # [   10.486951] systemd[1]: Finished Rebuild Journal Catalog.
builder # [   10.494452] systemd[1]: Starting Update is Completed...
builder # [   10.602313] systemd[1]: Finished Update is Completed.
server # [   10.720681] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
server # [   10.723757] systemd[1]: Finished Create SUID/SGID Wrappers.
server # [   11.110865] systemd[1]: Finished register-nix-paths.service.
builder # [   11.161371] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
builder # [   11.169938] systemd[1]: Finished Create SUID/SGID Wrappers.
server # [   11.296113] systemd[1]: Finished Coldplug All udev Devices.
server # [   11.297122] systemd[1]: Reached target System Initialization.
server # [   11.300855] systemd[1]: Started Discard unused filesystem blocks once a week.
server # [   11.305995] systemd[1]: Started niks3 garbage collection timer.
server # [   11.309092] systemd[1]: Started Daily Cleanup of Temporary Directories.
server # [   11.312762] systemd[1]: Reached target Timer Units.
server # [   11.313602] systemd[1]: Listening on D-Bus System Message Bus Socket.
server # [   11.320398] systemd[1]: Listening on niks3 server socket.
server # [   11.321210] systemd[1]: Listening on Nix Daemon Socket.
server # [   11.321983] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
server # [   11.323132] systemd[1]: Reached target Socket Units.
server # [   11.323851] systemd[1]: Reached target Basic System.
server # [   11.331043] systemd[1]: Starting Import lastlog data into lastlog2 database...
server # [   11.334923] systemd[1]: Starting Generate test mTLS certs...
server # [   11.341524] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
server # [   11.372807] systemd[1]: Starting Post-Boot Actions...
server # [   11.393127] systemd[1]: Started Reset console on configuration changes.
server # [   11.446680] systemd[1]: Starting resolvconf update...
server # [   11.459098] systemd[1]: Finished Firewall.
builder # [   11.465574] systemd[1]: Finished register-nix-paths.service.
server # [   11.513295] niks3-test-certs-start[501]: -----
server # [   11.520290] nsncd[489]: Sep 10 17:37:15.023 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
server # [   11.527589] systemd[1]: Started Name Service Cache Daemon (nsncd).
server # [   11.534530] systemd[1]: Finished Post-Boot Actions.
server # [   11.552111] systemd[1]: Reached target Host and Network Name Lookups.
server # [   11.558238] systemd[1]: Reached target User and Group Name Lookups.
server # [   11.565205] niks3-test-certs-start[514]: -----
server # [   11.568420] systemd[1]: Starting D-Bus System Message Bus...
server # [   11.595122] systemd[1]: Starting User Login Management...
server # [   11.602499] systemd[1]: Finished Import lastlog data into lastlog2 database.
builder # [   11.600803] systemd[1]: Finished Firewall.
server # [   11.727902] niks3-test-certs-start[519]: Certificate request self-signature ok
server # [   11.731227] niks3-test-certs-start[519]: subject=CN=server
builder # [   11.705677] systemd[1]: Finished Coldplug All udev Devices.
builder # [   11.706692] systemd[1]: Reached target System Initialization.
builder # [   11.710470] systemd[1]: Started Discard unused filesystem blocks once a week.
builder # [   11.711529] systemd[1]: Started Daily Cleanup of Temporary Directories.
builder # [   11.712552] systemd[1]: Reached target Timer Units.
builder # [   11.717316] systemd[1]: Listening on D-Bus System Message Bus Socket.
builder # [   11.718298] systemd[1]: Starting niks3 auto-upload socket...
builder # [   11.719125] systemd[1]: Listening on Nix Daemon Socket.
builder # [   11.724314] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
builder # [   11.729747] systemd[1]: Starting D-Bus System Message Bus...
builder # [   11.732527] systemd[1]: Listening on niks3 auto-upload socket.
builder # [   11.733568] systemd[1]: Reached target Socket Units.
server # [   11.788722] niks3-test-certs-start[541]: -----
server # [   11.808885] dbus-broker-launch[518]: Looking up NSS user entry for 'systemd-timesync'...
server # [   11.818553] systemd-logind[520]: New seat seat0.
server # [   11.831313] dbus-broker-launch[518]: NSS returned no entry for 'systemd-timesync'
server # [   11.835000] dbus-broker-launch[518]: Invalid user-name in /nix/store/a7vmlc5wb5bkkqcqfdzw5qg6gqybqy1w-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
server # [   11.848262] systemd[1]: Started User Login Management.
server # [   11.860442] systemd[1]: Starting linger-users.service...
builder # [   11.838728] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
builder # [   11.850741] systemd[1]: Starting Virtual Console Setup...
server # [   11.895708] systemd[1]: Started D-Bus System Message Bus.
builder # [   11.859638] dbus-broker-launch[486]: Looking up NSS user entry for 'systemd-timesync'...
server # [   11.913151] systemd[1]: Stopped target Host and Network Name Lookups.
builder # [   11.872089] dbus-broker-launch[486]: NSS returned no entry for 'systemd-timesync'
server # [   11.918683] systemd[1]: Stopping Host and Network Name Lookups...
builder # [   11.875082] dbus-broker-launch[486]: Invalid user-name in /nix/store/zwm02fpqc5pnyq6qcdnbxayqr0janh56-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
server # [   11.923628] systemd[1]: Stopped target User and Group Name Lookups.
builder # [   11.883522] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
builder # [   11.888281] systemd[1]: Stopped Virtual Console Setup.
server # [   11.934278] systemd[1]: Stopping User and Group Name Lookups...
server # [   11.939412] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
builder # [   11.896866] systemd[1]: Starting Virtual Console Setup...
server # [   11.948331] systemd[1]: nscd.service: Deactivated successfully.
server # [   11.949195] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
builder # [   11.913388] systemd[1]: Started D-Bus System Message Bus.
server # [   11.959761] niks3-test-certs-start[552]: Certificate request self-signature ok
builder # [   11.917802] systemd[1]: Reached target Basic System.
server # [   11.969230] niks3-test-certs-start[552]: subject=CN=niks3 test client
server # [   11.972586] dbus-broker-launch[518]: Ready
builder # [   11.931886] systemd[1]: Starting Import lastlog data into lastlog2 database...
server # [   11.977328] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
server # [   11.983359] systemd[1]: linger-users.service: Deactivated successfully.
server # [   11.990123] systemd[1]: Finished linger-users.service.
builder # [   11.952396] dbus-broker-launch[486]: Ready
builder # [   11.959321] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
builder # [   11.965404] systemd[1]: Starting Post-Boot Actions...
server # [   12.022356] systemd[1]: Finished Generate test mTLS certs.
builder # [   11.985550] systemd[1]: Started Reset console on configuration changes.
builder # [   12.004658] systemd[1]: Starting resolvconf update...
server # [   12.069980] systemd[1]: Started Name Service Cache Daemon (nsncd).
server # [   12.074141] nsncd[572]: Sep 10 17:37:15.571 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
server # [   12.079670] systemd[1]: Reached target Host and Network Name Lookups.
server # [   12.082550] systemd[1]: Reached target User and Group Name Lookups.
server # [   12.097319] systemd[1]: Finished resolvconf update.
server # [   12.100615] systemd[1]: Reached target Preparation for Network.
server # [   12.108298] systemd[1]: Starting DHCP Client...
server # [   12.113892] systemd[1]: Starting Extra networking commands....
builder # [   12.103085] nsncd[493]: Sep 10 17:37:15.618 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
builder # [   12.115090] systemd[1]: Finished Post-Boot Actions.
builder # [   12.122539] systemd[1]: Started Name Service Cache Daemon (nsncd).
builder # [   12.145582] systemd[1]: Reached target Host and Network Name Lookups.
builder # [   12.147943] systemd[1]: Reached target User and Group Name Lookups.
builder # [   12.164157] systemd[1]: Starting User Login Management...
builder # [   12.188658] systemd[1]: Finished Import lastlog data into lastlog2 database.
server # [   12.340473] dhcpcd[605]: dhcpcd-10.3.2 starting
server # [   12.356527] dhcpcd[643]: dev: loaded udev
server # [   12.363171] dhcpcd[643]: no valid interfaces found
server # [   12.365307] dhcpcd[643]: no valid interfaces found
builder # [   12.352924] systemd-logind[513]: New seat seat0.
server # [   12.400256] systemd[1]: Finished Extra networking commands..
builder # [   12.358477] systemd[1]: Started User Login Management.
server # [   12.402351] systemd[1]: Reached target Network.
server # [   12.406793] systemd[1]: Started Mock OIDC server for testing.
builder # [   12.370220] systemd[1]: Stopped target Host and Network Name Lookups.
builder # [   12.374180] systemd[1]: Stopping Host and Network Name Lookups...
server # [   12.417693] systemd[1]: Starting Nginx Web Server...
builder # [   12.381096] systemd[1]: Stopped target User and Group Name Lookups.
builder # [   12.385535] systemd[1]: Stopping User and Group Name Lookups...
builder # [   12.392326] systemd[1]: Starting linger-users.service...
builder # [   12.394881] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
builder # [   12.398059] systemd[1]: nscd.service: Deactivated successfully.
server # [   12.441089] systemd[1]: Starting PostgreSQL Server...
builder # [   12.401948] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
server # [   12.447639] systemd[1]: Started RustFS S3-compatible object storage.
builder # [   12.424537] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
server # [   12.467764] systemd[1]: Starting Setup RustFS bucket...
builder # [   12.443320] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
server # [   12.491476] systemd[1]: Starting Permit User Sessions...
builder # [   12.505535] systemd[1]: linger-users.service: Deactivated successfully.
builder # [   12.512636] systemd[1]: Finished linger-users.service.
builder # [   12.521022] systemd[1]: Finished resolvconf update.
builder # [   12.525317] systemd[1]: Reached target Preparation for Network.
builder # [   12.534285] systemd[1]: Starting DHCP Client...
builder # [   12.542566] nsncd[570]: Sep 10 17:37:16.058 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
builder # [   12.558225] systemd[1]: Starting Extra networking commands....
server # [   12.606501] systemd[1]: Finished Permit User Sessions.
builder # [   12.572163] systemd[1]: Started Name Service Cache Daemon (nsncd).
server # [   12.623156] systemd[1]: Started Getty on tty1.
server # [   12.625405] systemd[1]: Reached target Login Prompts.
builder # [   12.586880] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.
builder # [   12.588802] systemd[1]: Reached target Host and Network Name Lookups.
builder # [   12.591149] systemd[1]: Reached target User and Group Name Lookups.
builder # [   12.601888] systemd[1]: Started backdoor.service.
builder # [   12.672400] systemd-vconsole-setup[490]: Configuration of first virtual console was skipped, ignoring remaining ones.
builder # [   12.683040] systemd[1]: Finished Virtual Console Setup.
server # [   12.791059] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:09.0/virtio8/input/input3
builder # connecting to host...
server # [   12.797653] mock-oidc-server[655]: Mock OIDC Server running
builder # [   12.761986] (udev-worker)[354]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
server # [   12.806433] mock-oidc-server[655]:   OIDC Address: 127.0.0.1:8080
server # [   12.809825] mock-oidc-server[655]:   Issue Address: 127.0.0.1:8081
server # [   12.816491] mock-oidc-server[655]:   Issuer: http://127.0.0.1:8080/oidc
server # [   12.817444] mock-oidc-server[655]:   JWKS: http://127.0.0.1:8080/oidc/.well-known/jwks.json
server # [   12.818539] mock-oidc-server[655]:   Discovery: http://127.0.0.1:8080/oidc/.well-known/openid-configuration
server # [   12.819851] mock-oidc-server[655]:   Issue tokens: http://127.0.0.1:8081/issue?sub=...
builder # [   12.771664] (udev-worker)[354]: Network interface NamePolicy= disabled on kernel command line.
builder # [   12.804362] (udev-worker)[350]: Network interface NamePolicy= disabled on kernel command line.
builder # [   12.910120] dhcpcd[599]: dhcpcd-10.3.2 starting
builder # [   12.926814] dhcpcd[643]: dev: loaded udev
builder # [   12.968637] systemd[1]: Condition check resulted in Virtio network device being skipped.
builder # [   12.973022] systemd[1]: Finished Extra networking commands..
builder # [   12.995561] 8021q: 802.1Q VLAN Support v1.8
builder # [   12.981268] systemd[1]: Reached target Network.
server # [   13.027373] nginx-pre-start[673]: nginx: the configuration file /nix/store/jng0r1mayb40igwr8rprzglm5dh9fz5x-nginx.conf syntax is ok
builder # [   12.987781] systemd[1]: Starting Address configuration of eth1...
server # [   13.035057] nginx-pre-start[673]: nginx: configuration file /nix/store/jng0r1mayb40igwr8rprzglm5dh9fz5x-nginx.conf test is successful
builder # [   13.003406] systemd[1]: Starting Permit User Sessions...
server # [   13.049420] systemd[1]: Started Nginx Web Server.
server # [   13.067825] postgresql-pre-start[682]: The files belonging to this database system will be owned by user "postgres".
server # [   13.075700] postgresql-pre-start[682]: This user must also own the server process.
server # [   13.086398] postgresql-pre-start[682]: The database cluster will be initialized with locale "en_US.UTF-8".
server # [   13.091559] postgresql-pre-start[682]: The default database encoding has accordingly been set to "UTF8".
server # [   13.097928] postgresql-pre-start[682]: The default text search configuration will be set to "english".
server # [   13.106256] postgresql-pre-start[682]: Data page checksums are enabled.
server # [   13.110732] postgresql-pre-start[682]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok
server # [   13.115170] postgresql-pre-start[682]: creating subdirectories ... ok
server # [   13.118275] postgresql-pre-start[682]: selecting dynamic shared memory implementation ... posix
builder # [   13.090071] systemd[1]: Finished Permit User Sessions.
builder # [   13.108626] systemd[1]: Started Getty on tty1.
builder # [   13.116271] systemd[1]: Reached target Login Prompts.
builder # [   13.166064] cfg80211: Loading compiled-in X.509 certificates for regulatory database
builder # [   13.169894] 8021q: adding VLAN 0 to HW filter on device eth1
builder # [   13.176414] network-addresses-eth1-start[655]: adding address 192.168.1.1/24... done
builder # [   13.210190] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
builder # [   13.210743] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
builder # [   13.218470] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
builder # [   13.220209] cfg80211: failed to load regulatory.db
builder # [   13.204949] network-addresses-eth1-start[655]: adding address 2001:db8:1::1/64... done
builder # [   13.235341] systemd[1]: Finished Address configuration of eth1.
server # [   13.323575] postgresql-pre-start[682]: selecting default "max_connections" ... 100
builder # [   13.328167] 8021q: adding VLAN 0 to HW filter on device eth0
builder # [   13.314993] dhcpcd[643]: eth0: waiting for carrier
builder # [   13.317135] dhcpcd[643]: eth0: waiting for carrier
builder # [   13.317854] dhcpcd[643]: eth0: carrier acquired
builder # [   13.334124] dhcpcd[643]: DUID 00:01:00:01:32:35:a7:4c:52:54:00:12:34:56
builder # [   13.335194] dhcpcd[643]: eth0: IAID 00:12:34:56
builder # [   13.335856] dhcpcd[643]: eth0: adding address fe80::5054:ff:fe12:3456
builder # [   13.423054] systemd-logind[513]: Watching system buttons on /dev/input/event0 (gpio-keys)
server # [   13.509466] postgresql-pre-start[682]: selecting default "shared_buffers" ... 128MB
builder # [   13.583819] mousedev: PS/2 mouse device common for all mice
builder # [   13.628107] systemd-logind[513]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)
server # [   13.963090] systemd[1]: Starting Virtual Console Setup...
server # [   13.991636] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [   13.998431] systemd[1]: Stopped Virtual Console Setup.
server # [   14.010017] systemd[1]: Starting Virtual Console Setup...
server # [   14.035056] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs
builder # [   14.225305] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:09.0/virtio8/input/input3
server # [   14.342757] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
builder # [   14.330654] dhcpcd[643]: eth0: soliciting a DHCP lease
builder # [   14.340607] dhcpcd[643]: eth0: offered 10.0.2.15 from 10.0.2.2
builder # [   14.348246] dhcpcd[643]: eth0: probing address 10.0.2.15/24
server # [   14.404959] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.
server # [   14.414204] systemd[1]: Started backdoor.service.
server # [   14.506289] 8021q: 802.1Q VLAN Support v1.8
server # connecting to host...
server # [   14.539132] (udev-worker)[697]: Network interface NamePolicy= disabled on kernel command line.
server # [   14.557789] (udev-worker)[696]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
builder # [   14.526100] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
server # [   14.568758] (udev-worker)[696]: Network interface NamePolicy= disabled on kernel command line.
server: Guest shell says: b'Spawning backdoor root shell...\n'
builder # [   14.542659] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
builder # [   14.543701] systemd[1]: Stopped Virtual Console Setup.
builder # [   14.546368] systemd[1]: Stopping Virtual Console Setup...
builder # [   14.549197] systemd[1]: Starting Virtual Console Setup...
builder # [   14.576337] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
builder # [   14.581875] systemd[1]: Stopped Virtual Console Setup.
builder # [   14.584548] systemd[1]: Starting Virtual Console Setup...
server: connected to guest root shell
server: (connecting took 14.95 seconds)
server: (finished: waiting for the VM to finish booting, in 14.95 seconds)
server # [   14.665094] cfg80211: Loading compiled-in X.509 certificates for regulatory database
builder # [   14.607364] systemd-logind[513]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
server # [   14.659303] systemd-vconsole-setup[723]: Configuration of first virtual console was skipped, ignoring remaining ones.
server # [   14.671340] systemd[1]: Finished Virtual Console Setup.
server # [   14.712758] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
server # [   14.713250] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
server # [   14.717978] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
server # [   14.718294] cfg80211: failed to load regulatory.db
server # [   14.850101] systemd[1]: Condition check resulted in Virtio network device being skipped.
server # [   14.857892] systemd[1]: Starting Address configuration of eth1...
builder # [   14.898588] systemd-vconsole-setup[697]: Configuration of first virtual console was skipped, ignoring remaining ones.
builder # [   14.902994] systemd[1]: Finished Virtual Console Setup.
server # [   14.966270] 8021q: adding VLAN 0 to HW filter on device eth0
server # [   14.951993] dhcpcd[643]: eth0: waiting for carrier
server # [   14.956543] dhcpcd[643]: eth0: carrier acquired
server # [   14.986653] 8021q: adding VLAN 0 to HW filter on device eth1
server # [   14.978429] dhcpcd[643]: DUID 00:01:00:01:32:35:a7:4e:52:54:00:12:34:56
server # [   14.981025] dhcpcd[643]: eth0: IAID 00:12:34:56
server # [   14.983405] dhcpcd[643]: eth0: adding address fe80::5054:ff:fe12:3456
server # [   14.995682] network-addresses-eth1-start[747]: adding address 192.168.1.2/24... done
server # [   15.011293] network-addresses-eth1-start[747]: adding address 2001:db8:1::2/64... done
server # [   15.034678] systemd[1]: Finished Address configuration of eth1.
server # [   15.095465] systemd-logind[520]: Watching system buttons on /dev/input/event0 (gpio-keys)
server # [   15.198278] mousedev: PS/2 mouse device common for all mice
server # [   15.335226] systemd-logind[520]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)
builder # [   15.521498] dhcpcd[643]: eth0: soliciting an IPv6 router
builder # [   15.525242] dhcpcd[643]: eth0: Router Advertisement from fe80::2
builder # [   15.527768] dhcpcd[643]: eth0: adding address fec0::5054:ff:fe12:3456/64
builder # [   15.530792] dhcpcd[643]: eth0: adding route to fec0::/64
builder # [   15.533103] dhcpcd[643]: eth0: adding default route via fe80::2
server # [   16.239395] dhcpcd[643]: eth0: soliciting a DHCP lease
server # [   16.244601] dhcpcd[643]: eth0: offered 10.0.2.15 from 10.0.2.2
server # [   16.252257] dhcpcd[643]: eth0: probing address 10.0.2.15/24
server # [   16.658966] postgresql-pre-start[682]: selecting default time zone ... UTC
server # [   16.665615] postgresql-pre-start[682]: creating configuration files ... ok
server # [   16.906337] dhcpcd[643]: eth0: soliciting an IPv6 router
server # [   16.909409] dhcpcd[643]: eth0: Router Advertisement from fe80::2
server # [   16.910289] dhcpcd[643]: eth0: adding address fec0::5054:ff:fe12:3456/64
server # [   16.911163] dhcpcd[643]: eth0: adding route to fec0::/64
server # [   16.911891] dhcpcd[643]: eth0: adding default route via fe80::2
server # [   17.205458] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
server # [   17.209309] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [   17.213907] systemd[1]: Stopped Virtual Console Setup.
server # [   17.214655] systemd[1]: Stopping Virtual Console Setup...
server # [   17.217384] systemd[1]: Starting Virtual Console Setup...
server # [   17.235047] postgresql-pre-start[682]: running bootstrap script ... ok
server # [   17.262925] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [   17.266273] systemd[1]: Stopped Virtual Console Setup.
server # [   17.277897] systemd[1]: Starting Virtual Console Setup...
server # [   17.314697] systemd-logind[520]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
server # [   17.697041] systemd-vconsole-setup[792]: Configuration of first virtual console was skipped, ignoring remaining ones.
server # [   17.707532] systemd[1]: Finished Virtual Console Setup.
server # [   18.019442] postgresql-pre-start[682]: performing post-bootstrap initialization ... ok
server # [   18.162165] postgresql-pre-start[682]: syncing data to disk ... ok
server # [   18.164379] postgresql-pre-start[682]: initdb: warning: enabling "trust" authentication for local connections
server # [   18.165872] postgresql-pre-start[682]: 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.
server # [   18.167978] postgresql-pre-start[682]: Success. You can now start the database server using:
server # [   18.169230] postgresql-pre-start[682]:     pg_ctl -D /var/lib/postgresql/18 -l logfile start
server # [   18.294100] postgres[803]: [803] LOG:  starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit
server # [   18.297787] postgres[803]: [803] LOG:  listening on IPv6 address "::1", port 5432
server # [   18.298976] postgres[803]: [803] LOG:  listening on IPv4 address "127.0.0.1", port 5432
server # [   18.301622] postgres[803]: [803] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
server # [   18.314487] postgres[812]: [812] LOG:  database system was shut down at 2026-09-10 17:37:21 GMT
server # [   18.319613] postgres[803]: [803] LOG:  database system is ready to accept connections
server # [   18.325921] systemd[1]: Started PostgreSQL Server.
server # [   18.333818] systemd[1]: Starting PostgreSQL Setup Scripts...
server # [   18.554355] postgresql-setup-start[823]: CREATE DATABASE
server # [   18.605929] postgresql-setup-start[828]: CREATE ROLE
server # [   18.633931] postgresql-setup-start[830]: ALTER DATABASE
server # [   18.643541] systemd[1]: Finished PostgreSQL Setup Scripts.
server # [   18.645897] systemd[1]: Reached target PostgreSQL.
server: (finished: waiting for unit postgresql.service, in 19.44 seconds)
server: waiting for unit rustfs.service
server: (finished: waiting for unit rustfs.service, in 0.08 seconds)
server: waiting for unit rustfs-setup.service
builder # [   19.181270] dhcpcd[643]: eth0: leased 10.0.2.15 for 86400 seconds
builder # [   19.185305] dhcpcd[643]: eth0: adding route to 10.0.2.0/24
builder # [   19.185471] dhcpcd[643]: eth0: adding default route via 10.0.2.2
builder # [   19.340763] systemd[1]: Started DHCP Client.
builder # [   19.345569] systemd[1]: Reached target Multi-User System.
builder # [   19.346500] systemd[1]: Startup finished in 1.058s (kernel) + 5.752s (initrd) + 12.533s (userspace) = 19.345s.
server # [   21.356514] dhcpcd[643]: eth0: leased 10.0.2.15 for 86400 seconds
server # [   21.358009] dhcpcd[643]: eth0: adding route to 10.0.2.0/24
server # [   21.360314] dhcpcd[643]: eth0: adding default route via 10.0.2.2
server # [   21.489518] systemd[1]: Started DHCP Client.
server # [   26.977822] rustfs-setup-start[935]: mb s3://niks3-test
server # [   26.989980] systemd[1]: Finished Setup RustFS bucket.
server # [   26.999151] systemd[1]: Starting niks3 server...
server # [   27.201772] postgres[948]: [948] ERROR:  relation "goose_db_version" does not exist at character 36
server # [   27.203060] postgres[948]: [948] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
server # [   27.235426] niks3-server[943]: 2026/09/10 17:37:30 OK   20241026095416_initial_model.sql (20.02ms)
server # [   27.249035] niks3-server[943]: 2026/09/10 17:37:30 OK   20251210153512_drop_unused_gin_index.sql (3.53ms)
server # [   27.252126] niks3-server[943]: 2026/09/10 17:37:30 OK   20251218171726_add_pins.sql (5.1ms)
server # [   27.253605] niks3-server[943]: 2026/09/10 17:37:30 OK   20260628120000_add_object_size_and_stats.sql (3.23ms)
server # [   27.255255] niks3-server[943]: 2026/09/10 17:37:30 OK   20260905000000_add_claims.sql (6.43ms)
server # [   27.256670] niks3-server[943]: 2026/09/10 17:37:30 goose: successfully migrated database to version: 20260905000000
server # [   27.261601] niks3-server[943]: 2026/09/10 17:37:30 OK   1_commit_pending_closure.sql (8.01ms)
server # [   27.263979] niks3-server[943]: 2026/09/10 17:37:30 OK   2_object_stats_trigger.sql (2.25ms)
server # [   27.265312] niks3-server[943]: 2026/09/10 17:37:30 goose: up to current file version: 2
server # [   27.281021] niks3-server[943]: 2026/09/10 17:37:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:8080/oidc
server # [   27.282684] niks3-server[943]: 2026/09/10 17:37:30 INFO OIDC authentication enabled config=/nix/store/gjm6ix1ylawv64wrx364p4919034hfij-niks3-oidc.json
server # [   27.285297] niks3-server[943]: 2026/09/10 17:37:30 INFO Loaded signing key name=niks3-test-1 path=/nix/store/sh6q7v7d4a2i1wj41dsx16kh2fwxvkk8-niks3-signing-key
server # [   27.324197] niks3-server[943]: 2026/09/10 17:37:30 INFO Using socket-activated listener address=0.0.0.0:5751
server # [   27.328120] systemd[1]: Started niks3 server.
server # [   27.328845] niks3-server[943]: 2026/09/10 17:37:30 INFO systemd watchdog enabled interval=15s
server # [   27.329959] systemd[1]: Reached target Multi-User System.
server # [   27.331622] systemd[1]: Startup finished in 1.075s (kernel) + 5.275s (initrd) + 20.980s (userspace) = 27.331s.
server # [   27.333506] niks3-server[943]: 2026/09/10 17:37:30 INFO Starting HTTP server address=0.0.0.0:5751
server: (finished: waiting for unit rustfs-setup.service, in 8.70 seconds)
server: waiting for unit mock-oidc.service
server: (finished: waiting for unit mock-oidc.service, in 0.09 seconds)
server: waiting for unit niks3.service
server: (finished: waiting for unit niks3.service, in 0.06 seconds)
server: waiting for TCP port 5751 on localhost
server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!
server: (finished: waiting for TCP port 5751 on localhost, in 0.06 seconds)
server: waiting for TCP port 8080 on localhost
server # Connection to localhost (127.0.0.1) 8080 port [tcp/http-alt] succeeded!
server: (finished: waiting for TCP port 8080 on localhost, in 0.04 seconds)
server: waiting for TCP port 9000 on localhost
server # Connection to localhost (127.0.0.1) 9000 port [tcp/cslistener] succeeded!
server: (finished: waiting for TCP port 9000 on localhost, in 0.04 seconds)
server: must succeed: mkdir -p /tmp/test-config
server: (finished: must succeed: mkdir -p /tmp/test-config, in 0.03 seconds)
server: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token
server: (finished: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token, in 0.02 seconds)
server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # [   28.495935] niks3-server[943]: 2026/09/10 17:37:31 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:32.029Z level=INFO msg="Uploading 5 paths to server (0 already cached)"
server # time=2026-09-10T17:37:32.030Z level=INFO msg="Uploading lq5dy7clx12d63rp6yz8zwwpk8qdf736-libidn2-2.3.8 (366.1KB)"
server # time=2026-09-10T17:37:32.032Z level=INFO msg="Uploading h46id9241lp1g4zprx23fg6489x14lqb-xgcc-15.3.0-libgcc (150.1KB)"
server # time=2026-09-10T17:37:32.037Z level=INFO msg="Uploading r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3 (287.5KB)"
server # time=2026-09-10T17:37:32.039Z level=INFO msg="Uploading q7mfklgx6r8bm2ybkv0rj3vsgl71b1hf-libunistring-1.4.2 (2.0MB)"
server # time=2026-09-10T17:37:32.041Z level=INFO msg="Uploading 6wjykzqf6w3kzfhjc4z7dcd84j0dzsgm-glibc-2.42-84 (44.4MB)"
server # [   28.624124] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=nar/0x48iv4crw96wayixvwmbhz9znvm9djawdf9j0wszdqdxpn92kw1.nar.zst
server # [   28.644465] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=h46id9241lp1g4zprx23fg6489x14lqb.ls
server # [   28.705949] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=nar/1hdxl1xcchj4axg81p17fvpnxajgrxznjb5i1jzsm89dgm6mlj0q.nar.zst
server # [   28.720254] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=q7mfklgx6r8bm2ybkv0rj3vsgl71b1hf.ls
server # [   28.803793] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=nar/053l9g60ivv02rvj2rvpfzvn2p75yskga4qj6dfp48cm14spmw78.nar.zst
server # [   28.814067] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=lq5dy7clx12d63rp6yz8zwwpk8qdf736.ls
server # [   28.892531] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=nar/1s0v059mi0yamikpqwisam6qcx41iyv2fz6sgk69fk9z6avxni7r.nar.zst
server # [   28.901486] niks3-server[943]: 2026/09/10 17:37:32 INFO Registered completed upload object_key=r6kacndzxprd8xcz5kdf037ganb3yhxq.ls
server # [   30.400666] niks3-server[943]: 2026/09/10 17:37:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
server # [   30.416244] niks3-server[943]: 2026/09/10 17:37:33 INFO Completed multipart upload object_key=nar/1z9cybznka24hixqs4qi1mwa6q4hkyl933jlb4812a6ivkxlmibq.nar.zst upload_id=ZjBiYTI0ZjctZWMzYi00MTNhLWE1ZTUtZDJhMTc0YmE3ZDViLjJmYWMyZTM0LWNkY2UtNDE5OC05OGI4LTcxMDA1NDM2OWE3M3gxNzg5MDYxODUyMDE5ODI3MTAw parts=1
server # [   30.431936] niks3-server[943]: 2026/09/10 17:37:33 INFO Registered completed upload object_key=6wjykzqf6w3kzfhjc4z7dcd84j0dzsgm.ls
server # [   30.433693] niks3-server[943]: 2026/09/10 17:37:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
server # time=2026-09-10T17:37:33.941Z level=INFO msg="Uploading 5 narinfos"
server # [   30.439164] niks3-server[943]: 2026/09/10 17:37:33 INFO Signed narinfos id=1 count=5
server # [   30.468445] niks3-server[943]: 2026/09/10 17:37:33 INFO Registered completed upload object_key=lq5dy7clx12d63rp6yz8zwwpk8qdf736.narinfo
server # [   30.476394] niks3-server[943]: 2026/09/10 17:37:33 INFO Registered completed upload object_key=r6kacndzxprd8xcz5kdf037ganb3yhxq.narinfo
server # [   30.484071] niks3-server[943]: 2026/09/10 17:37:33 INFO Registered completed upload object_key=6wjykzqf6w3kzfhjc4z7dcd84j0dzsgm.narinfo
server # [   30.500925] niks3-server[943]: 2026/09/10 17:37:34 INFO Registered completed upload object_key=h46id9241lp1g4zprx23fg6489x14lqb.narinfo
server # [   30.506363] niks3-server[943]: 2026/09/10 17:37:34 INFO Registered completed upload object_key=q7mfklgx6r8bm2ybkv0rj3vsgl71b1hf.narinfo
server # [   30.507973] niks3-server[943]: 2026/09/10 17:37:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
server # time=2026-09-10T17:37:34.014Z level=INFO msg="Upload complete. (2.108s)"
server # [   30.511271] niks3-server[943]: 2026/09/10 17:37:34 INFO Completed upload id=1
server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 2.29 seconds)
server: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token
server: (finished: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token, in 0.02 seconds)
server: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # [   30.748888] niks3-server[943]: 2026/09/10 17:37:34 WARN Authentication failed token_preview=invalid-token token_length=13 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]
server # time=2026-09-10T17:37:34.255Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating pending closure: server returned 401: Unauthorized\n"
server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 0.22 seconds)
server: waiting for unit nginx.service
server: (finished: waiting for unit nginx.service, in 0.06 seconds)
server: waiting for TCP port 443 on localhost
server # Connection to localhost (::1) 443 port [tcp/https] succeeded!
server: (finished: waiting for TCP port 443 on localhost, in 0.04 seconds)
server: must succeed: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem --client-cert /etc/niks3-test-certs/client.pem --client-key /etc/niks3-test-certs/client.key /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # time=2026-09-10T17:37:34.458Z level=INFO msg="Configuring client TLS" cert=/etc/niks3-test-certs/client.pem key=/etc/niks3-test-certs/client.key ca=/etc/niks3-test-certs/ca.pem
server # [   31.056988] niks3-server[943]: 2026/09/10 17:37:34 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:34.565Z level=INFO msg="Uploading 0 paths to server (5 already cached)"
server # [   31.063542] niks3-server[943]: 2026/09/10 17:37:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete
server # time=2026-09-10T17:37:34.570Z level=INFO msg="Upload complete. (108ms)"
server # [   31.067900] niks3-server[943]: 2026/09/10 17:37:34 INFO Completed upload id=2
server: (finished: must succeed: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem --client-cert /etc/niks3-test-certs/client.pem --client-key /etc/niks3-test-certs/client.key /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 0.22 seconds)
server: must fail: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # time=2026-09-10T17:37:34.597Z level=ERROR msg="Fatal error" error="auth token is required (use --auth-token-path, --auth-token-script, NIKS3_AUTH_TOKEN_FILE, or $XDG_CONFIG_HOME/niks3/auth-token)"
server: (finished: must fail: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 0.03 seconds)
server: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # time=2026-09-10T17:37:34.707Z level=INFO msg="Configuring client TLS" cert="" key="" ca=/etc/niks3-test-certs/ca.pem
server # [   31.316200] niks3-server[943]: 2026/09/10 17:37:34 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:34.823Z level=INFO msg="Uploading 0 paths to server (5 already cached)"
server # [   31.322390] niks3-server[943]: 2026/09/10 17:37:34 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete
server # time=2026-09-10T17:37:34.828Z level=INFO msg="Upload complete. (119ms)"
server # [   31.325750] niks3-server[943]: 2026/09/10 17:37:34 INFO Completed upload id=3
server: (finished: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 0.23 seconds)
server: must succeed: cd /etc/niks3-test-certs && /nix/store/9ibakafsh3z4y7q3nvs44mz5vwhh67ch-openssl-3.6.3-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client'
server # -----
server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/9ibakafsh3z4y7q3nvs44mz5vwhh67ch-openssl-3.6.3-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client', in 0.03 seconds)
server: must succeed: cd /etc/niks3-test-certs && /nix/store/9ibakafsh3z4y7q3nvs44mz5vwhh67ch-openssl-3.6.3-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem
server # Certificate request self-signature ok
server # subject=CN=other client
server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/9ibakafsh3z4y7q3nvs44mz5vwhh67ch-openssl-3.6.3-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem, in 0.05 seconds)
server: must fail: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem --client-cert /etc/niks3-test-certs/other.pem --client-key /etc/niks3-test-certs/other.key /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # time=2026-09-10T17:37:35.015Z level=INFO msg="Configuring client TLS" cert=/etc/niks3-test-certs/other.pem key=/etc/niks3-test-certs/other.key ca=/etc/niks3-test-certs/ca.pem
server # [   31.603016] niks3-server[943]: 2026/09/10 17:37:35 WARN mTLS auth: subject not in bound subjects subject="CN=other client"
server # time=2026-09-10T17:37:35.108Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating pending closure: server returned 401: Unauthorized\n"
server: (finished: must fail: /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem --client-cert /etc/niks3-test-certs/other.pem --client-key /etc/niks3-test-certs/other.key /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3, in 0.20 seconds)
server: must succeed: mkdir -p /tmp/test-store
server: (finished: must succeed: mkdir -p /tmp/test-store, in 0.03 seconds)
server: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/test-store /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3

server # copying 5 paths...
server # copying path '/nix/store/h46id9241lp1g4zprx23fg6489x14lqb-xgcc-15.3.0-libgcc' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server # copying path '/nix/store/q7mfklgx6r8bm2ybkv0rj3vsgl71b1hf-libunistring-1.4.2' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server # copying path '/nix/store/lq5dy7clx12d63rp6yz8zwwpk8qdf736-libidn2-2.3.8' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server # copying path '/nix/store/6wjykzqf6w3kzfhjc4z7dcd84j0dzsgm-glibc-2.42-84' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server # copying path '/nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server: (finished: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/test-store /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
, in 0.56 seconds)
server: must succeed: 
cat > /tmp/test-drv.nix << 'EOF'
derivation {
  name = "test-build-log";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];
}
EOF

server: (finished: must succeed: 
cat > /tmp/test-drv.nix << 'EOF'
derivation {
  name = "test-build-log";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];
}
EOF
, in 0.03 seconds)
server: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix
server # this derivation will be built:
server #   /nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv
server # building '/nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv'...
server # test-build-log> test build log output
server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix, in 0.27 seconds)
server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log
server # [   32.701220] niks3-server[943]: 2026/09/10 17:37:36 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:36.219Z level=INFO msg="Uploading 1 paths to server (0 already cached)"
server # time=2026-09-10T17:37:36.220Z level=INFO msg="Uploading z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log (128B)"
server # [   32.733852] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=nar/00zns3gj9hwz2a4b0i07y7nmxybq59lh24bl3xsxblcl6333mjil.nar.zst
server # [   32.740097] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=log/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv
server # [   32.746940] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.ls
server # time=2026-09-10T17:37:36.253Z level=INFO msg="Uploading 1 narinfos"
server # [   32.751459] niks3-server[943]: 2026/09/10 17:37:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/4/sign
server # [   32.753960] niks3-server[943]: 2026/09/10 17:37:36 INFO Signed narinfos id=4 count=1
server # [   32.760327] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo
server # [   32.762020] niks3-server[943]: 2026/09/10 17:37:36 INFO Received complete upload request method=POST path=/api/pending_closures/4/complete
server # time=2026-09-10T17:37:36.268Z level=INFO msg="Upload complete. (150ms)"
server # [   32.766143] niks3-server[943]: 2026/09/10 17:37:36 INFO Completed upload id=4
server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log, in 0.27 seconds)
server: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix log --store 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log

server # got build log for '/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'
server: (finished: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix log --store 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log
, in 0.17 seconds)
subtest: push --stdin streams paths and reports each one
server: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }'
server # this derivation will be built:
server #   /nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv
server # building '/nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv'...
server: (finished: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }', in 0.24 seconds)
server: must succeed: printf '%s\n\n%s\n' /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log | NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --stdin
server # [   33.374656] niks3-server[943]: 2026/09/10 17:37:36 INFO Received uploads request method=POST path=/api/pending_closures
server # [   33.378311] niks3-server[943]: 2026/09/10 17:37:36 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:36.884Z level=INFO msg="Uploading 1 paths to server (1 already cached)"
server # time=2026-09-10T17:37:36.886Z level=INFO msg="Uploading 7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test (120B)"
server # [   33.396963] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=nar/1hj1r0g515rfxjx685mfn3dgr6akqbn4gf64snlv6bxaxph69lna.nar.zst
server # [   33.404086] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=log/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv
server # [   33.411481] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.ls
server # time=2026-09-10T17:37:36.918Z level=INFO msg="Uploading 1 narinfos"
server # [   33.415459] niks3-server[943]: 2026/09/10 17:37:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/5/sign
server # [   33.419441] niks3-server[943]: 2026/09/10 17:37:36 INFO Signed narinfos id=5 count=1
server # [   33.421654] niks3-server[943]: 2026/09/10 17:37:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/6/sign
server # [   33.423190] niks3-server[943]: 2026/09/10 17:37:36 INFO Signed narinfos id=6 count=0
server # [   33.428346] niks3-server[943]: 2026/09/10 17:37:36 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.narinfo
server # [   33.430943] niks3-server[943]: 2026/09/10 17:37:36 INFO Received complete upload request method=POST path=/api/pending_closures/5/complete
server # [   33.433836] niks3-server[943]: 2026/09/10 17:37:36 INFO Completed upload id=5
server # [   33.434804] niks3-server[943]: 2026/09/10 17:37:36 INFO Received complete upload request method=POST path=/api/pending_closures/6/complete
server # time=2026-09-10T17:37:36.940Z level=INFO msg="Upload complete. (149ms)"
server # [   33.437919] niks3-server[943]: 2026/09/10 17:37:36 INFO Completed upload id=6
server: (finished: must succeed: printf '%s\n\n%s\n' /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log | NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --stdin, in 0.26 seconds)
server: must succeed: 
      export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
      nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test
    
server # copying 1 paths...
server # copying path '/nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server: (finished: must succeed: 
      export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
      nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test
    , in 0.20 seconds)
(finished: subtest: push --stdin streams paths and reports each one, in 0.70 seconds)
server: must succeed: 
cat > /tmp/ca-test.nix << 'EOF'
derivation {
  name = "ca-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'Hello from CA derivation' > $out" ];
  __contentAddressed = true;
  outputHashMode = "recursive";
  outputHashAlgo = "sha256";
}
EOF

server: (finished: must succeed: 
cat > /tmp/ca-test.nix << 'EOF'
derivation {
  name = "ca-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'Hello from CA derivation' > $out" ];
  __contentAddressed = true;
  outputHashMode = "recursive";
  outputHashAlgo = "sha256";
}
EOF
, in 0.04 seconds)
server: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link
server # this derivation will be built:
server #   /nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv
server # building '/nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv'...
server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link, in 0.25 seconds)
server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test
server # [   34.204261] niks3-server[943]: 2026/09/10 17:37:37 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:37.712Z level=INFO msg="Uploading 1 paths to server (0 already cached)"
server # time=2026-09-10T17:37:37.713Z level=INFO msg="Uploading 5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test (144B)"
server # [   34.226107] niks3-server[943]: 2026/09/10 17:37:37 INFO Registered completed upload object_key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst
server # [   34.237107] niks3-server[943]: 2026/09/10 17:37:37 INFO Registered completed upload object_key=log/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv
server # [   34.241511] niks3-server[943]: 2026/09/10 17:37:37 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.ls
server # [   34.243059] niks3-server[943]: 2026/09/10 17:37:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/7/sign
server # time=2026-09-10T17:37:37.749Z level=INFO msg="Uploading 1 narinfos"
server # [   34.247965] niks3-server[943]: 2026/09/10 17:37:37 INFO Signed narinfos id=7 count=1
server # [   34.255335] niks3-server[943]: 2026/09/10 17:37:37 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.narinfo
server # [   34.257656] niks3-server[943]: 2026/09/10 17:37:37 INFO Received complete upload request method=POST path=/api/pending_closures/7/complete
server # time=2026-09-10T17:37:37.763Z level=INFO msg="Upload complete. (224ms)"
server # [   34.263014] niks3-server[943]: 2026/09/10 17:37:37 INFO Completed upload id=7
server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.34 seconds)
server: must succeed: mkdir -p /tmp/chroot-store
server: (finished: must succeed: mkdir -p /tmp/chroot-store, in 0.03 seconds)
server: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test

server # copying 1 paths...
server # copying path '/nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server: (finished: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test
, in 0.21 seconds)
server: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test
server: (finished: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.13 seconds)
server: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test
server # warning: 'realisation' is a deprecated alias for 'store build-trace'
server: (finished: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.10 seconds)
server: must succeed: readlink /etc/niks3-test/symlink-wrapper
server: (finished: must succeed: readlink /etc/niks3-test/symlink-wrapper, in 0.03 seconds)
server: must succeed: readlink /etc/static/niks3-test/symlink-wrapper
server: (finished: must succeed: readlink /etc/static/niks3-test/symlink-wrapper, in 0.03 seconds)
server: must succeed: test -L /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper
server: (finished: must succeed: test -L /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper, in 0.02 seconds)
server: must succeed: readlink /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper
server: (finished: must succeed: readlink /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper, in 0.03 seconds)
server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper
server # [   35.026336] niks3-server[943]: 2026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:38.533Z level=INFO msg="Uploading 2 paths to server (0 already cached)"
server # time=2026-09-10T17:37:38.534Z level=INFO msg="Uploading b18w2ysl1rv656nyvlazbkss3mfmn94x-base-package (536B)"
server # time=2026-09-10T17:37:38.536Z level=INFO msg="Uploading dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper (192B)"
server # [   35.048257] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=nar/1qqdkr06n1wh2vnlrw6bq7fqyq3b900fsvqdv3dkld43xkkw9arg.nar.zst
server # [   35.057192] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=dh0km1jfdxg339dwkpsyhpcbsvn3za4f.ls
server # [   35.062731] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=nar/0820av37plmfgrxw6pcbym6phk1sv14dilyrablrnkzb7z1fd5js.nar.zst
server # [   35.069736] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=b18w2ysl1rv656nyvlazbkss3mfmn94x.ls
server # [   35.071287] niks3-server[943]: 2026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/8/sign
server # time=2026-09-10T17:37:38.577Z level=INFO msg="Uploading 2 narinfos"
server # [   35.074959] niks3-server[943]: 2026/09/10 17:37:38 INFO Signed narinfos id=8 count=2
server # [   35.087734] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=dh0km1jfdxg339dwkpsyhpcbsvn3za4f.narinfo
server # [   35.091261] niks3-server[943]: 2026/09/10 17:37:38 INFO Registered completed upload object_key=b18w2ysl1rv656nyvlazbkss3mfmn94x.narinfo
server # [   35.093544] niks3-server[943]: 2026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/8/complete
server # time=2026-09-10T17:37:38.599Z level=INFO msg="Upload complete. (155ms)"
server # [   35.096610] niks3-server[943]: 2026/09/10 17:37:38 INFO Completed upload id=8
server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper, in 0.27 seconds)
server: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/test-store /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper

server # copying 2 paths...
server # copying path '/nix/store/b18w2ysl1rv656nyvlazbkss3mfmn94x-base-package' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server # copying path '/nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server: (finished: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/test-store /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper
, in 0.19 seconds)
server: must succeed: 
cat > /tmp/oidc-test.nix << 'EOF'
derivation {
  name = "oidc-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'OIDC test derivation' > $out" ];
}
EOF

server: (finished: must succeed: 
cat > /tmp/oidc-test.nix << 'EOF'
derivation {
  name = "oidc-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'OIDC test derivation' > $out" ];
}
EOF
, in 0.03 seconds)
server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link
server # this derivation will be built:
server #   /nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv
server # building '/nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv'...
server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link, in 0.23 seconds)
server: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:myorg/myrepo:ref:refs/heads/main&aud=http://server:5751&repository_owner=myorg'
server: (finished: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:myorg/myrepo:ref:refs/heads/main&aud=http://server:5751&repository_owner=myorg', in 0.06 seconds)
server: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3ODkwNjU0NTksImlhdCI6MTc4OTA2MTg1OSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.TbmSNt3nqGApfTaZPIll8r_dolpYEtedL3yFfrTfML8Ro6UmMjriuzRmnaHDkoUgXa2Uy1crINdc8sOLAfZsZ3JxhMcAEgJm-_ESQnJkQqnTA3nPd6XUrqtCgjKTC12L6kD6wqdF4GwNSjlEoFXK0SVimG8S3dajNBD-HRzFGSCN7ax5_u4hUZrv4boJeEWDbhhKmfE1LRzPhE0fGNto7692mGSFzPbSoKVCidkw5u7wf836ZF0II9-0BhKYoVzTNy3IVfYgYzxwmFpUIQPc9QI2Nvkv3vr-GEezzK_UMzM8wWUuL2NA56YQLcOA3MaP_LDA4ro_oFdHmUOWKkTzgQ' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test
server # time=2026-09-10T17:37:39.131Z level=WARN msg="--auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script"
server # [   35.800125] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.802695] niks3-server[943]: 2026/09/10 17:37:39 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:39.308Z level=INFO msg="Uploading 1 paths to server (0 already cached)"
server # time=2026-09-10T17:37:39.310Z level=INFO msg="Uploading x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test (136B)"
server # [   35.818620] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.823606] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.828464] niks3-server[943]: 2026/09/10 17:37:39 INFO Registered completed upload object_key=log/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv
server # [   35.831596] niks3-server[943]: 2026/09/10 17:37:39 INFO Registered completed upload object_key=nar/17h0qgwf5334wia961ibqy9hmpsyvfhrvj5ji9m031klp6sx4v0q.nar.zst
server # [   35.836831] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.840578] niks3-server[943]: 2026/09/10 17:37:39 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.ls
server # [   35.842143] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.843346] niks3-server[943]: 2026/09/10 17:37:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/9/sign
server # time=2026-09-10T17:37:39.349Z level=INFO msg="Uploading 1 narinfos"
server # [   35.848128] niks3-server[943]: 2026/09/10 17:37:39 INFO Signed narinfos id=9 count=1
server # [   35.851992] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.855578] niks3-server[943]: 2026/09/10 17:37:39 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.narinfo
server # [   35.857859] niks3-server[943]: 2026/09/10 17:37:39 INFO OIDC auth successful provider=test scopes=[write]
server # [   35.859117] niks3-server[943]: 2026/09/10 17:37:39 INFO Received complete upload request method=POST path=/api/pending_closures/9/complete
server # time=2026-09-10T17:37:39.364Z level=INFO msg="Upload complete. (149ms)"
server # [   35.862185] niks3-server[943]: 2026/09/10 17:37:39 INFO Completed upload id=9
server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3ODkwNjU0NTksImlhdCI6MTc4OTA2MTg1OSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.TbmSNt3nqGApfTaZPIll8r_dolpYEtedL3yFfrTfML8Ro6UmMjriuzRmnaHDkoUgXa2Uy1crINdc8sOLAfZsZ3JxhMcAEgJm-_ESQnJkQqnTA3nPd6XUrqtCgjKTC12L6kD6wqdF4GwNSjlEoFXK0SVimG8S3dajNBD-HRzFGSCN7ax5_u4hUZrv4boJeEWDbhhKmfE1LRzPhE0fGNto7692mGSFzPbSoKVCidkw5u7wf836ZF0II9-0BhKYoVzTNy3IVfYgYzxwmFpUIQPc9QI2Nvkv3vr-GEezzK_UMzM8wWUuL2NA56YQLcOA3MaP_LDA4ro_oFdHmUOWKkTzgQ' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test, in 0.26 seconds)
server: must succeed: 
cat > /tmp/oidc-test2.nix << 'EOF'
derivation {
  name = "oidc-test2";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'OIDC test 2' > $out" ];
}
EOF

server: (finished: must succeed: 
cat > /tmp/oidc-test2.nix << 'EOF'
derivation {
  name = "oidc-test2";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'OIDC test 2' > $out" ];
}
EOF
, in 0.03 seconds)
server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link
server # this derivation will be built:
server #   /nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv
server # building '/nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv'...
server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link, in 0.24 seconds)
server: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:otherorg/repo:ref:refs/heads/main&aud=http://server:5751&repository_owner=otherorg'
server: (finished: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:otherorg/repo:ref:refs/heads/main&aud=http://server:5751&repository_owner=otherorg', in 0.05 seconds)
server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3ODkwNjU0NTksImlhdCI6MTc4OTA2MTg1OSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.kl43ps_SPSUEitRYL2OhnWqYM36M3XBmDkaY8MZcEhb3rKFjLmk-JZuWYxND3AescFFdXeKh7442zaEYBIVY3QN5EG9ms9vVEbwyyI8T1LDF5bRVbAj5USoHyv4YXEQD0aaVkLZfTXVs3PnIF_AzzYy4xf4sKAU_R3v-7pBh2gD4SdHGOAEF3xjd0U9yBUP6feLTwElrpm0jPypjI7lIzRxWdU1fupk-2CuTCgRtYkNJ7geelhMoglTYGcFnuZoiiShHh-A1e1OEoQX2zHSrMsM5-BMVSXU45MNJO3gG1aZXCVRCd5lfNtRIkJ0ggXYuVswMRJ9JVorsWg28pF6IIw' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2
server # time=2026-09-10T17:37:39.705Z level=WARN msg="--auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script"
server # [   36.370129] niks3-server[943]: 2026/09/10 17:37:39 WARN Authentication failed token_preview=eyJhbGciOi...Wg28pF6IIw token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]
server # time=2026-09-10T17:37:39.877Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating pending closure: server returned 401: Unauthorized\n"
server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3ODkwNjU0NTksImlhdCI6MTc4OTA2MTg1OSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.kl43ps_SPSUEitRYL2OhnWqYM36M3XBmDkaY8MZcEhb3rKFjLmk-JZuWYxND3AescFFdXeKh7442zaEYBIVY3QN5EG9ms9vVEbwyyI8T1LDF5bRVbAj5USoHyv4YXEQD0aaVkLZfTXVs3PnIF_AzzYy4xf4sKAU_R3v-7pBh2gD4SdHGOAEF3xjd0U9yBUP6feLTwElrpm0jPypjI7lIzRxWdU1fupk-2CuTCgRtYkNJ7geelhMoglTYGcFnuZoiiShHh-A1e1OEoQX2zHSrMsM5-BMVSXU45MNJO3gG1aZXCVRCd5lfNtRIkJ0ggXYuVswMRJ9JVorsWg28pF6IIw' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.20 seconds)
server: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:myorg/myrepo:ref:refs/heads/main&aud=http://wrong:5751&repository_owner=myorg'
server: (finished: must succeed: curl -s 'http://127.0.0.1:8081/issue?sub=repo:myorg/myrepo:ref:refs/heads/main&aud=http://wrong:5751&repository_owner=myorg', in 0.05 seconds)
server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc4OTA2NTQ1OSwiaWF0IjoxNzg5MDYxODU5LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.CHJSAvoH63F1n6v0QiDW0-OnfVwFKylgbHiPYLvF4TQavTgSrp9mpbYpzpp84n3i7_FnFu2WW0-1w-GAQ1mdzI8HJFh55RXmJkHARNO9rfZDGqlTgdqf3ALS6o33FAZJACClLQFOO2xgA0LMocsnI1kMtmLgM3i1h61R2Gwt6sEa6ClWN1qG2zcL9mrNQwoQOp1Z3vzrHQMClE6DxyEV_qyYw7UHdgOuzyNB1VR0mJNP4Sz1jOSgBmMw0AOxI8nLg81oQz_r995o0QAbH92EGym6MiKupNXrqgRk44wtnIJPkvHpr76-KYCYG9yZgu5JLzH_7GbmuTkt_VHKh7OkuQ' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2
server # time=2026-09-10T17:37:39.950Z level=WARN msg="--auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script"
server # [   36.616185] niks3-server[943]: 2026/09/10 17:37:40 WARN Authentication failed token_preview=eyJhbGciOi..._VHKh7OkuQ token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]
server # time=2026-09-10T17:37:40.122Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating pending closure: server returned 401: Unauthorized\n"
server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImRIWFRTQ3lvdXE2RGlXYVF3bFh0TlA1NC1DNzVtdzNJY29Za0VSZmwzZlEiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc4OTA2NTQ1OSwiaWF0IjoxNzg5MDYxODU5LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.CHJSAvoH63F1n6v0QiDW0-OnfVwFKylgbHiPYLvF4TQavTgSrp9mpbYpzpp84n3i7_FnFu2WW0-1w-GAQ1mdzI8HJFh55RXmJkHARNO9rfZDGqlTgdqf3ALS6o33FAZJACClLQFOO2xgA0LMocsnI1kMtmLgM3i1h61R2Gwt6sEa6ClWN1qG2zcL9mrNQwoQOp1Z3vzrHQMClE6DxyEV_qyYw7UHdgOuzyNB1VR0mJNP4Sz1jOSgBmMw0AOxI8nLg81oQz_r995o0QAbH92EGym6MiKupNXrqgRk44wtnIJPkvHpr76-KYCYG9yZgu5JLzH_7GbmuTkt_VHKh7OkuQ' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.20 seconds)
server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2
server # time=2026-09-10T17:37:40.149Z level=WARN msg="--auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script"
server # [   36.817589] niks3-server[943]: 2026/09/10 17:37:40 WARN Authentication failed token_preview=not-a-valid-jwt-token token_length=21 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]
server # time=2026-09-10T17:37:40.324Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating pending closure: server returned 401: Unauthorized\n"
server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.20 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins create hello-pin /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3

server # [   36.934820] niks3-server[943]: 2026/09/10 17:37:40 INFO Received create pin request method=POST path=/api/pins/hello-pin
server # time=2026-09-10T17:37:40.446Z level=INFO msg="Created pin" name=hello-pin store_path=/nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
server # [   36.944321] niks3-server[943]: 2026/09/10 17:37:40 INFO Created/updated pin name=hello-pin store_path=/nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3 narinfo_key=r6kacndzxprd8xcz5kdf037ganb3yhxq.narinfo
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins create hello-pin /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
, in 0.12 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list

server # [   37.057046] niks3-server[943]: 2026/09/10 17:37:40 INFO Received list pins request method=GET path=/api/pins
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list
, in 0.11 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only

server # [   37.168541] niks3-server[943]: 2026/09/10 17:37:40 INFO Received list pins request method=GET path=/api/pins
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only
, in 0.11 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --json

server # [   37.278827] niks3-server[943]: 2026/09/10 17:37:40 INFO Received list pins request method=GET path=/api/pins
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --json
, in 0.11 seconds)
server: must succeed: 
  export S3_ENDPOINT_URL=http://localhost:9000
  export AWS_ACCESS_KEY_ID=rustfsadmin
  export AWS_SECRET_ACCESS_KEY=rustfsadmin
  /nix/store/gm6drhsfa5mkw06mlnvki17xz3bjbav9-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin

server: (finished: must succeed: 
  export S3_ENDPOINT_URL=http://localhost:9000
  export AWS_ACCESS_KEY_ID=rustfsadmin
  export AWS_SECRET_ACCESS_KEY=rustfsadmin
  /nix/store/gm6drhsfa5mkw06mlnvki17xz3bjbav9-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin
, in 0.04 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log

server # [   37.512605] niks3-server[943]: 2026/09/10 17:37:41 INFO Received uploads request method=POST path=/api/pending_closures
server # time=2026-09-10T17:37:41.019Z level=INFO msg="Uploading 0 paths to server (1 already cached)"
server # [   37.517080] niks3-server[943]: 2026/09/10 17:37:41 INFO Received complete upload request method=POST path=/api/pending_closures/10/complete
server # time=2026-09-10T17:37:41.023Z level=INFO msg="Upload complete. (93ms)"
server # [   37.520951] niks3-server[943]: 2026/09/10 17:37:41 INFO Completed upload id=10
server # [   37.523736] niks3-server[943]: 2026/09/10 17:37:41 INFO Received create pin request method=POST path=/api/pins/ca-pin
server # time=2026-09-10T17:37:41.033Z level=INFO msg="Created pin" name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log
server # [   37.531348] niks3-server[943]: 2026/09/10 17:37:41 INFO Created/updated pin name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log narinfo_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log
, in 0.22 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only

server # [   37.648743] niks3-server[943]: 2026/09/10 17:37:41 INFO Received list pins request method=GET path=/api/pins
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only
, in 0.12 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins delete hello-pin

server # [   37.770185] niks3-server[943]: 2026/09/10 17:37:41 INFO Received delete pin request method=DELETE path=/api/pins/hello-pin
server # [   37.777399] niks3-server[943]: 2026/09/10 17:37:41 INFO Deleted pin name=hello-pin
server # time=2026-09-10T17:37:41.282Z level=INFO msg="Deleted pin" name=hello-pin
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins delete hello-pin
, in 0.13 seconds)
server: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only

server # [   37.917431] niks3-server[943]: 2026/09/10 17:37:41 INFO Received list pins request method=GET path=/api/pins
server: (finished: must succeed: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins list --names-only
, in 0.14 seconds)
server: must fail: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent

server # [   38.047626] niks3-server[943]: 2026/09/10 17:37:41 INFO Received create pin request method=POST path=/api/pins/bad-pin
server # time=2026-09-10T17:37:41.553Z level=ERROR msg="Fatal error" error="creating pin: server returned 404: closure not found: store path must be pushed before pinning\n"
server # [   38.051564] niks3-server[943]: 2026/09/10 17:37:41 ERROR Failed to get closure for pin narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo error="no rows in result set"
server: (finished: must fail: 
  NIKS3_SERVER_URL=http://server:5751   NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token   /nix/store/mdj8fmc03riga29dxfmw1jymqdgl6pw8-niks3-1.10.1/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent
, in 0.13 seconds)
server: must succeed: systemctl start niks3-gc.service
server # [   38.094726] systemd[1]: Starting niks3 garbage collection...
server # [   38.156292] niks3[1535]: time=2026-09-10T17:37:41.659Z level=INFO msg="Starting garbage collection" older-than=720h failed-uploads-older-than=6h force=false
server # [   38.159648] niks3-server[943]: 2026/09/10 17:37:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures
server # [   38.163392] niks3[1535]: time=2026-09-10T17:37:41.665Z level=INFO msg="Garbage collection started"
server # [   38.165672] niks3-server[943]: 2026/09/10 17:37:41 INFO Aborted multipart uploads count=0
server # [   38.175155] niks3-server[943]: 2026/09/10 17:37:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=4 objects-deleted-after-grace-period=0 objects-failed-to-delete=0
server # [   38.181703] niks3-server[943]: 2026/09/10 17:37:41 INFO Vacuumed table table=pending_closures
server # [   38.185394] niks3-server[943]: 2026/09/10 17:37:41 INFO Vacuumed table table=pending_objects
server # [   38.189371] niks3-server[943]: 2026/09/10 17:37:41 INFO Vacuumed table table=multipart_uploads
server # [   38.192440] niks3-server[943]: 2026/09/10 17:37:41 INFO Vacuumed table table=closures
server # [   38.196302] niks3-server[943]: 2026/09/10 17:37:41 INFO Vacuumed table table=objects
server # [   40.165175] niks3[1535]: time=2026-09-10T17:37:43.667Z level=INFO msg="Garbage collection progress" phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=4 objects_deleted=0 objects_failed=0
server # [   40.175067] niks3[1535]: time=2026-09-10T17:37:43.667Z level=INFO msg="Garbage collection completed successfully" failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=4 objects-deleted-after-grace-period=0 objects-failed-to-delete=0
server # [   40.189914] systemd[1]: niks3-gc.service: Deactivated successfully.
server # [   40.199435] systemd[1]: Finished niks3 garbage collection.
server # [   40.205748] systemd[1]: niks3-gc.service: Consumed 41ms CPU time over 2.099s wall clock time, 2.4M memory peak, 1.2K incoming IP traffic, 823B outgoing IP traffic.
server: (finished: must succeed: systemctl start niks3-gc.service, in 2.16 seconds)
builder: waiting for unit niks3-auto-upload.socket
builder: waiting for the VM to finish booting
builder: Guest shell says: b'Spawning backdoor root shell...\n'
builder: connected to guest root shell
builder: (connecting took 0.00 seconds)
builder: (finished: waiting for the VM to finish booting, in 0.00 seconds)
builder: (finished: waiting for unit niks3-auto-upload.socket, in 0.11 seconds)
builder: must succeed: test -S /run/niks3/upload-to-cache.sock
builder: (finished: must succeed: test -S /run/niks3/upload-to-cache.sock, in 0.03 seconds)
builder: must succeed: grep post-build-hook /etc/nix/nix.conf
builder: (finished: must succeed: grep post-build-hook /etc/nix/nix.conf, in 0.03 seconds)
builder: must succeed: 
cat > /tmp/test-drv.nix << 'EOF'
derivation {
  name = "post-build-hook-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];
}
EOF

builder: (finished: must succeed: 
cat > /tmp/test-drv.nix << 'EOF'
derivation {
  name = "post-build-hook-test";
  system = builtins.currentSystem;
  builder = "/bin/sh";
  args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];
}
EOF
, in 0.03 seconds)
builder: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link
builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 84 ms (attempt 1/5)
builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 57 ms (attempt 2/5)
builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 69 ms (attempt 3/5)
builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 45 ms (attempt 4/5)
builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org
builder # this derivation will be built:
builder #   /nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv
builder # building '/nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv'...
builder # [   41.044912] systemd[1]: Started niks3 auto-upload daemon.
builder # [   41.234616] niks3-hook[804]: time=2026-09-10T17:37:44.751Z level=INFO msg="niks3-hook serve starting" socket=/run/niks3/upload-to-cache.sock socket-activated=true db-path=/var/lib/niks3-hook/upload-queue.db batch-size=5 idle-exit-timeout=5s drain-timeout=0s
builder # [   41.246161] niks3-hook[804]: time=2026-09-10T17:37:44.763Z level=INFO msg="Upload queue status" pending=1
builder # [   41.248309] niks3-hook[804]: time=2026-09-10T17:37:44.763Z level=INFO msg="Uploading batch" count=1
builder: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link, in 0.89 seconds)
builder: waiting for unit niks3-auto-upload.service
builder: (finished: waiting for unit niks3-auto-upload.service, in 0.11 seconds)
??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/j90z8dcvcjd2i05kicxx9a79lq0iay4y-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39
builder: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive
??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.
    File "/nix/store/j90z8dcvcjd2i05kicxx9a79lq0iay4y-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39
builder # [   41.381771] systemd[1]: Started Nix Daemon.
builder # [   41.492081] nix-daemon[822]: accepted connection from pid 815, user root (trusted)
builder # [   41.507358] nix-daemon[822]: reaped child process 829, status = succeeded
server # [   41.578506] niks3-server[943]: 2026/09/10 17:37:45 INFO Received uploads request method=POST path=/api/pending_closures
builder # [   41.552293] niks3-hook[804]: time=2026-09-10T17:37:45.069Z level=INFO msg="Uploading 1 paths to server (0 already cached)"
builder # [   41.554726] niks3-hook[804]: time=2026-09-10T17:37:45.072Z level=INFO msg="Uploading 1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test (144B)"
server # [   41.632428] niks3-server[943]: 2026/09/10 17:37:45 INFO Registered completed upload object_key=log/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv
server # [   41.643954] niks3-server[943]: 2026/09/10 17:37:45 INFO Registered completed upload object_key=nar/1a0vfw93shmvlz6lac7d1lv82jxzfdswigh5s32hpvncf74i1i0y.nar.zst
server # [   41.664601] niks3-server[943]: 2026/09/10 17:37:45 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.ls
server # [   41.669949] niks3-server[943]: 2026/09/10 17:37:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/11/sign
server # [   41.675995] niks3-server[943]: 2026/09/10 17:37:45 INFO Signed narinfos id=11 count=1
builder # [   41.634226] niks3-hook[804]: time=2026-09-10T17:37:45.150Z level=INFO msg="Uploading 1 narinfos"
server # [   41.690987] niks3-server[943]: 2026/09/10 17:37:45 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.narinfo
server # [   41.698614] niks3-server[943]: 2026/09/10 17:37:45 INFO Received complete upload request method=POST path=/api/pending_closures/11/complete
server # [   41.703975] niks3-server[943]: 2026/09/10 17:37:45 INFO Completed upload id=11
builder # [   41.662166] niks3-hook[804]: time=2026-09-10T17:37:45.179Z level=INFO msg="Upload complete. (415ms)"
builder # [   46.246495] niks3-hook[804]: time=2026-09-10T17:37:49.762Z level=INFO msg="Idle timeout reached and queue is empty, shutting down"
builder # [   46.252583] niks3-hook[804]: time=2026-09-10T17:37:49.765Z level=INFO msg="niks3-hook serve stopped"
builder # [   46.266729] systemd[1]: niks3-auto-upload.service: Deactivated successfully.
builder # [   46.280077] systemd[1]: niks3-auto-upload.service: Consumed 165ms CPU time over 5.228s wall clock time, 19.3M memory peak, 68K written to disk, 4.9K incoming IP traffic, 7.1K outgoing IP traffic.
builder: (finished: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive, in 5.38 seconds)
server: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/hook-test-store /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test

server # copying 1 paths...
server # copying path '/nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test' from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1'...
server: (finished: must succeed: 
  export AWS_ACCESS_KEY_ID=rustfsadmin
export AWS_SECRET_ACCESS_KEY=rustfsadmin
  nix copy --from 's3://niks3-test?endpoint=http://server:9000&region=us-east-1' --to /tmp/hook-test-store /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test
, in 0.24 seconds)
server: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test
server: (finished: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test, in 0.10 seconds)
(finished: run the VM test script, in 47.94 seconds)
test script finished in 48.08s
cleanup
kill QemuMachine (pid 47)
builder # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/bin/python3.14)
kill QemuMachine (pid 48)
server # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lfh101cfjj8p8npcari9hk0lbqi33yvh-python3-3.14.7/bin/python3.14)
(finished: cleanup, in 0.48 seconds)
additionally exposed symbols:
    builder, server,
    vlan1,
    start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh
Hello store path: /nix/store/r6kacndzxprd8xcz5kdf037ganb3yhxq-hello-2.12.3
Test output path: /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log
CA derivation output path: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test
Realisation info in chroot store: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test

Symlink wrapper store path: /nix/store/dh0km1jfdxg339dwkpsyhpcbsvn3za4f-symlink-wrapper
Symlink wrapper points to: /nix/store/b18w2ysl1rv656nyvlazbkss3mfmn94x-base-package/bin/test-program
OIDC test store path: /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test
Valid OIDC token obtained (length=677)
OIDC push with valid token: SUCCESS
Invalid OIDC token obtained (wrong org)
OIDC push with wrong org: correctly rejected
Wrong audience OIDC token obtained
OIDC push with wrong audience: correctly rejected
OIDC push with malformed token: correctly rejected
All OIDC tests passed!
All pin tests passed!
Built store path: /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test
Post-build-hook pipeline test passed!