vm-test-run-nixos-test-niks3
checks.aarch64-linux.nixos-test-niks3
· build #443
· raw
1tribuchet: building on eliza2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.01 seconds)5Test will time out and terminate in 3600.0 seconds6run the VM test script7start all VMs8builder: starting vm9server: starting vm10builder # Disk image does not exist, creating the virtualisation disk image...11builder # Formatting '/build/vm-state-builder/tmp.mkt3j4sjmd', fmt=raw size=107374182412builder # mke2fs 1.47.4 (6-Mar-2025)13builder: QEMU running (pid 47)14builder # Discarding device blocks: 0/262144 done15builder # Creating filesystem with 262144 4k blocks and 65536 inodes16builder # Filesystem UUID: 4c892e5d-6757-4e4f-bb3b-4331d4ca9d0317builder # Superblock backups stored on blocks:18builder # 32768, 98304, 163840, 22937619builder # 20builder # Allocating group tables: 0/8 done21builder # Writing inode tables: 0/8 done22builder # Creating journal (8192 blocks): done23builder # Writing superblocks and filesystem accounting information: 0/8 done24builder # 25builder # Virtualisation disk image created.26builder # Starting virtiofs daemons...27builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)28builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether29builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)30builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether31builder # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...32builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)33builder # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether34builder # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...35builder # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...36builder # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests37builder # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests38builder # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests39builder # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]40builder # [ 0.000000] Linux version 6.18.58 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT @179257154941builder # [ 0.000000] KASLR enabled42builder # [ 0.000000] random: crng init done43builder # [ 0.000000] Machine model: linux,dummy-virt44builder # [ 0.000000] efi: UEFI not found.45builder # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT46builder # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]47builder # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]48builder # [ 0.000000] Zone ranges:49builder # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]50builder # [ 0.000000] DMA32 empty51builder # [ 0.000000] Normal empty52builder # [ 0.000000] Device empty53builder # [ 0.000000] Movable zone start for each node54builder # [ 0.000000] Early memory node ranges55builder # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]56builder # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]57builder # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc0000058builder # [ 0.000000] psci: probing for conduit method from DT.59builder # [ 0.000000] psci: PSCIv1.3 detected in firmware.60builder # [ 0.000000] psci: Using standard PSCI v0.2 function IDs61builder # [ 0.000000] psci: Trusted OS migration not required62builder # [ 0.000000] psci: SMC Calling Convention v1.163builder # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)64builder # [ 0.000000] percpu: Embedded 76 pages/cpu s187672 r8192 d115432 u31129665builder # [ 0.000000] Detected PIPT I-cache on CPU066builder # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)67builder # [ 0.000000] CPU features: detected: GICv3 CPU interface68builder # [ 0.000000] CPU features: detected: Spectre-v469builder # [ 0.000000] CPU features: detected: Spectre-BHB70builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_3871builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_2372builder # [ 0.000000] alternatives: applying boot alternatives73builder # [ 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/3dp66d245s61azq9qczrvzkif5d614q9-nixos-system-builder-test/init regInfo=/nix/.ro-store/wnvdj460dy25pdqcfjqiqi9l908j8d42-closure-info/registration console=ttyAMA0,115200n8 console=tty074builder # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/wnvdj460dy25pdqcfjqiqi9l908j8d42-closure-info/registration", will be passed to user space.75builder # [ 0.000000] printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes76builder # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)77builder # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)78builder # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB79builder # [ 0.000000] software IO TLB: area num 1.80builder # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)81builder # [ 0.000000] Fallback order for Node 0: 082builder # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 26214483builder # [ 0.000000] Policy zone: DMA84builder # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off85builder # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=186builder # [ 0.000000] allocated 2097152 bytes of page_ext87builder # [ 0.000000] ftrace: allocating 75304 entries in 296 pages88builder # [ 0.000000] ftrace: allocated 296 pages with 3 groups89builder # [ 0.000000] rcu: Hierarchical RCU implementation.90builder # [ 0.000000] rcu: RCU event tracing is enabled.91builder # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=1.92builder # [ 0.000000] Trampoline variant of Tasks RCU enabled.93builder # [ 0.000000] Rude variant of Tasks RCU enabled.94builder # [ 0.000000] Tracing variant of Tasks RCU enabled.95builder # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.96builder # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=197builder # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.98builder # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.99builder # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.100builder # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0101builder # [ 0.000000] GICv3: 256 SPIs implemented102builder # [ 0.000000] GICv3: 0 Extended SPIs implemented103builder # [ 0.000000] Root IRQ handler: gic_handle_irq104builder # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI105builder # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0106builder # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000107builder # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]108builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @450f0000 (indirect, esz 8, psz 64K, shr 1)109builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45100000 (flat, esz 8, psz 64K, shr 1)110builder # [ 0.000000] GICv3: using LPI property table @0x0000000045110000111builder # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045120000112builder # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.113builder # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns114builder # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).115builder # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns116builder # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns117builder # [ 0.000037] arm-pv: using stolen time PV118builder # [ 0.000483] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)119builder # [ 0.001254] Console: colour dummy device 80x25120builder # [ 0.001263] printk: legacy console [tty0] enabled121builder # [ 0.001452] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)122builder # [ 0.001460] pid_max: default: 32768 minimum: 301123builder # [ 0.001556] LSM: initializing lsm=lockdown,capability,landlock,yama,bpf,ima124builder # [ 0.001703] landlock: Up and running.125builder # [ 0.001707] Yama: becoming mindful.126builder # [ 0.002212] LSM support for eBPF active127builder # [ 0.002350] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)128builder # [ 0.002377] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)129builder # [ 0.004835] rcu: Hierarchical SRCU implementation.130builder # [ 0.004842] rcu: Max phase no-delay instances is 1000.131builder # [ 0.006148] fsl-mc MSI: its@8080000 domain created132builder # [ 0.006273] EFI services will not be available.133builder # [ 0.006361] smp: Bringing up secondary CPUs ...134builder # [ 0.006371] smp: Brought up 1 node, 1 CPU135builder # [ 0.006375] SMP: Total of 1 processors activated.136builder # [ 0.006378] CPU: All CPU(s) started at EL1137builder # [ 0.006389] CPU features: detected: Branch Target Identification138builder # [ 0.006394] CPU features: detected: ARMv8.4 Translation Table Level139builder # [ 0.006397] CPU features: detected: Instruction cache invalidation not required for I/D coherence140builder # [ 0.006401] CPU features: detected: Data cache clean to the PoU not required for I/D coherence141builder # [ 0.006409] CPU features: detected: Common not Private translations142builder # [ 0.006413] CPU features: detected: CRC32 instructions143builder # [ 0.006416] CPU features: detected: Data cache clean to Point of Deep Persistence144builder # [ 0.006419] CPU features: detected: Data cache clean to Point of Persistence145builder # [ 0.006422] CPU features: detected: Data independent timing control (DIT)146builder # [ 0.006425] CPU features: detected: E0PD147builder # [ 0.006428] CPU features: detected: Enhanced Counter Virtualization148builder # [ 0.006430] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)149builder # [ 0.006434] CPU features: detected: Enhanced Virtualization Traps150builder # [ 0.006437] CPU features: detected: Fine Grained Traps151builder # [ 0.006441] CPU features: detected: Generic authentication (architected QARMA5 algorithm)152builder # [ 0.006445] CPU features: detected: RCpc load-acquire (LDAPR)153builder # [ 0.006448] CPU features: detected: LSE atomic instructions154builder # [ 0.006452] CPU features: detected: Privileged Access Never155builder # [ 0.006454] CPU features: detected: PMUv3156builder # [ 0.006457] CPU features: detected: RAS Extension Support157builder # [ 0.006460] CPU features: detected: RASv1p1 Extension Support158builder # [ 0.006463] CPU features: detected: Random Number Generator159builder # [ 0.006468] CPU features: detected: Speculation barrier (SB)160builder # [ 0.006471] CPU features: detected: Stage-2 Force Write-Back161builder # [ 0.006474] CPU features: detected: TLB range maintenance instructions162builder # [ 0.006480] CPU features: detected: Speculative Store Bypassing Safe (SSBS)163builder # [ 0.006519] alternatives: applying system-wide alternatives164builder # [ 0.009634] CPU features: detected: BBM Level 2 without TLB conflict abort165builder # [ 0.016630] Memory: 887488K/1048576K available (24640K kernel code, 10246K rwdata, 26664K rodata, 7808K init, 2086K bss, 119776K reserved, 32768K cma-reserved)166builder # [ 0.017059] devtmpfs: initialized167builder # [ 0.018903] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)168builder # [ 0.018928] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).169builder # [ 0.019115] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL170builder # [ 0.019120] 0 pages in range for non-PLT usage171builder # [ 0.019121] 506368 pages in range for PLT usage172builder # [ 0.019227] pinctrl core: initialized pinctrl subsystem173builder # [ 0.020172] DMI not present or invalid.174builder # [ 0.023901] NET: Registered PF_NETLINK/PF_ROUTE protocol family175builder # [ 0.026390] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations176builder # [ 0.026531] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations177builder # [ 0.026693] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations178builder # [ 0.026719] audit: initializing netlink subsys (disabled)179builder # [ 0.027750] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1180builder # [ 0.027781] thermal_sys: Registered thermal governor 'fair_share'181builder # [ 0.027783] thermal_sys: Registered thermal governor 'bang_bang'182builder # [ 0.027787] thermal_sys: Registered thermal governor 'step_wise'183builder # [ 0.027790] thermal_sys: Registered thermal governor 'user_space'184builder # [ 0.027793] thermal_sys: Registered thermal governor 'power_allocator'185builder # [ 0.027955] cpuidle: using governor ladder186builder # [ 0.027964] cpuidle: using governor menu187builder # [ 0.028451] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.188builder # [ 0.028471] ASID allocator initialised with 65536 entries189builder # [ 0.029806] Serial: AMBA PL011 UART driver190builder # [ 0.035603] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1191builder # [ 0.035821] printk: console [ttyAMA0] enabled192builder # [ 0.154714] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages193builder # [ 0.154729] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page194builder # [ 0.154733] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages195builder # [ 0.154736] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page196builder # [ 0.154738] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages197builder # [ 0.154741] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page198builder # [ 0.154744] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages199builder # [ 0.154746] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page200builder # [ 0.168964] fbcon: Taking over console201builder # [ 0.168978] ACPI: Interpreter disabled.202builder # [ 0.170616] iommu: Default domain type: Translated203builder # [ 0.170622] iommu: DMA domain TLB invalidation policy: strict mode204builder # [ 0.171518] SCSI subsystem initialized205builder # [ 0.171731] usbcore: registered new interface driver usbfs206builder # [ 0.171769] usbcore: registered new interface driver hub207builder # [ 0.171783] usbcore: registered new device driver usb208builder # [ 0.183453] pps_core: LinuxPPS API ver. 1 registered209builder # [ 0.183460] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>210builder # [ 0.183469] PTP clock support registered211builder # [ 0.183749] EDAC MC: Ver: 3.0.0212builder # [ 0.183965] scmi_core: SCMI protocol bus registered213builder # [ 0.187621] FPGA manager framework214builder # [ 0.188710] vgaarb: loaded215builder # [ 0.189006] clocksource: Switched to clocksource arch_sys_counter216builder # [ 0.189969] VFS: Disk quotas dquot_6.6.0217builder # [ 0.190008] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)218builder # [ 0.190432] netfs: FS-Cache loaded219builder # [ 0.190558] pnp: PnP ACPI: disabled220builder # [ 0.199426] NET: Registered PF_INET protocol family221builder # [ 0.199604] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)222builder # [ 0.234545] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)223builder # [ 0.234594] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)224builder # [ 0.234621] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)225builder # [ 0.234675] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)226builder # [ 0.234750] TCP: Hash tables configured (established 8192 bind 8192)227builder # [ 0.234849] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)228builder # [ 0.234911] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)229builder # [ 0.234959] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)230builder # [ 0.235039] NET: Registered PF_UNIX/PF_LOCAL protocol family231builder # [ 0.235059] NET: Registered PF_XDP protocol family232builder # [ 0.235078] PCI: CLS 0 bytes, default 64233builder # [ 0.235332] Trying to unpack rootfs image as initramfs...234builder # [ 0.247275] kvm [1]: HYP mode not available235builder # [ 0.371235] Initialise system trusted keyrings236builder # [ 0.371279] Key type blacklist registered237builder # [ 0.371415] workingset: timestamp_bits=42 max_order=18 bucket_order=0238builder # [ 0.371935] squashfs: version 4.0 (2009/01/31) Phillip Lougher239builder # [ 0.371993] 9p: Installing v9fs 9p2000 file system support240builder # [ 0.372090] integrity: Platform Keyring initialized241builder # [ 0.372100] integrity: Machine keyring initialized242builder # [ 0.404263] Key type asymmetric registered243builder # [ 0.404287] Asymmetric key parser 'x509' registered244builder # [ 0.404381] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)245builder # [ 0.404557] io scheduler mq-deadline registered246builder # [ 0.404562] io scheduler kyber registered247builder # [ 0.426700] pl061_gpio 9030000.pl061: PL061 GPIO chip registered248builder # [ 0.427452] ledtrig-cpu: registered to indicate activity on CPUs249builder # [ 0.427898] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:250builder # [ 0.427912] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000251builder # [ 0.427927] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000252builder # [ 0.427933] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000253builder # [ 0.427957] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits254builder # [ 0.427984] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]255builder # [ 0.428093] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00256builder # [ 0.428101] pci_bus 0000:00: root bus resource [bus 00-ff]257builder # [ 0.428105] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]258builder # [ 0.428108] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]259builder # [ 0.428111] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]260builder # [ 0.428215] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint261builder # [ 0.428669] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint262builder # [ 0.428856] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]263builder # [ 0.428868] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]264builder # [ 0.428894] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]265builder # [ 0.428906] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]266builder # [ 0.429422] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint267builder # [ 0.429606] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]268builder # [ 0.429618] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]269builder # [ 0.429644] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]270builder # [ 0.430108] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint271builder # [ 0.430293] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]272builder # [ 0.430304] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]273builder # [ 0.430329] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]274builder # [ 0.430801] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint275builder # [ 0.430985] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]276builder # [ 0.430997] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]277builder # [ 0.431023] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]278builder # [ 0.431035] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]279builder # [ 0.431503] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint280builder # [ 0.431693] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]281builder # [ 0.431719] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]282builder # [ 0.432223] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint283builder # [ 0.432412] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]284builder # [ 0.432437] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]285builder # [ 0.432854] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint286builder # [ 0.433071] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]287builder # [ 0.433324] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint288builder # [ 0.433513] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]289builder # [ 0.433539] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]290builder # [ 0.434014] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint291builder # [ 0.434205] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]292builder # [ 0.434232] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]293builder # [ 0.434711] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint294builder # [ 0.434902] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]295builder # [ 0.434929] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]296builder # [ 0.435435] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint297builder # [ 0.435748] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]298builder # [ 0.435765] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]299builder # [ 0.435792] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]300builder # [ 0.436272] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint301builder # [ 0.436459] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]302builder # [ 0.436470] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]303builder # [ 0.436496] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]304builder # [ 0.485448] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned305builder # [ 0.485461] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned306builder # [ 0.485465] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned307builder # [ 0.485515] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned308builder # [ 0.485559] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned309builder # [ 0.485605] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned310builder # [ 0.485650] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned311builder # [ 0.485698] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned312builder # [ 0.485742] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned313builder # [ 0.485790] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned314builder # [ 0.485835] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned315builder # [ 0.485880] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned316builder # [ 0.486002] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned317builder # [ 0.486046] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned318builder # [ 0.486064] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned319builder # [ 0.486081] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned320builder # [ 0.486099] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned321builder # [ 0.486117] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned322builder # [ 0.486134] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned323builder # [ 0.486151] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned324builder # [ 0.486171] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned325builder # [ 0.486189] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned326builder # [ 0.486206] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned327builder # [ 0.486225] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned328builder # [ 0.486247] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned329builder # [ 0.486265] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned330builder # [ 0.486282] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned331builder # [ 0.486300] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned332builder # [ 0.486318] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned333builder # [ 0.486335] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned334builder # [ 0.486353] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned335builder # [ 0.486381] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]336builder # [ 0.486387] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]337builder # [ 0.486389] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]338builder # [ 0.487267] pci 0000:00:07.0: enabling device (0000 -> 0002)339builder # [ 0.545711] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)340builder # [ 1.270759] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)341builder # [ 1.272963] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)342builder # [ 1.283493] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)343builder # [ 1.286730] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)344builder # [ 1.288972] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)345builder # [ 1.303270] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)346server # Disk image does not exist, creating the virtualisation disk image...347server: QEMU running (pid 48)348server # Formatting '/build/vm-state-server/tmp.2cAKJwlweN', fmt=raw size=1073741824349server # mke2fs 1.47.4 (6-Mar-2025)350server # Discarding device blocks: 0/262144 done351server # Creating filesystem with 262144 4k blocks and 65536 inodes352(finished: start all VMs, in 4.34 seconds)353server # Filesystem UUID: 1e2fc562-cb7c-4cc9-bf9d-1a30f8c811bd354server: waiting for unit postgresql.service355server # Superblock backups stored on blocks:356server: waiting for the VM to finish booting357server # 32768, 98304, 163840, 229376358server # 359server # Allocating group tables: 0/8 done360server # Writing inode tables: 0/8 done361server # Creating journal (8192 blocks): done362server # Writing superblocks and filesystem accounting information: 0/8 done363server # 364server # Virtualisation disk image created.365server # Starting virtiofs daemons...366server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)367server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether368server # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...369server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)370server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether371server # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...372server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)373server # [2026-10-27T08:55:36Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether374server # [2026-10-27T08:55:36Z INFO virtiofsd] Waiting for vhost-user socket connection...375server # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests376server # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests377server # [2026-10-27T08:55:37Z INFO virtiofsd] Client connected, servicing requests378builder # [ 1.313477] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)379builder # [ 1.315848] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)380builder # [ 1.359118] Freeing initrd memory: 25236K381builder # [ 1.359956] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)382builder # [ 1.364041] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)383builder # [ 1.370959] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled384builder # [ 1.372701] msm_serial: driver initialized385builder # [ 1.372835] SuperH (H)SCI(F) driver initialized386builder # [ 1.372895] STM32 USART driver initialized387builder # [ 1.393946] loop: module loaded388builder # [ 1.394135] virtio_blk virtio2: 1/0/0 default/read/poll queues389builder # [ 1.394980] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)390builder # [ 1.400427] megasas: 07.734.00.00-rc1391builder # [ 1.401815] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]392builder # [ 1.404780] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000393builder # [ 1.404800] Intel/Sharp Extended Query Table at 0x0031394builder # [ 1.409707] Using buffer write method395builder # [ 1.409752] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]396builder # [ 1.468417] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000397builder # [ 1.468446] Intel/Sharp Extended Query Table at 0x0031398builder # [ 1.471834] Using buffer write method399builder # [ 1.471857] Concatenating MTD devices:400builder # [ 1.471860] (0): "0.flash"401builder # [ 1.471863] (1): "0.flash"402builder # [ 1.471865] into device "0.flash"403builder # [ 1.481196] tun: Universal TUN/TAP device driver, 1.6404builder # [ 1.484591] thunder_xcv, ver 1.0405builder # [ 1.484622] thunder_bgx, ver 1.0406builder # [ 1.484644] nicpf, ver 1.0407builder # [ 1.487251] e1000: Intel(R) PRO/1000 Network Driver408builder # [ 1.487257] e1000: Copyright (c) 1999-2006 Intel Corporation.409builder # [ 1.487285] e1000e: Intel(R) PRO/1000 Network Driver410builder # [ 1.487292] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.411builder # [ 1.487319] igb: Intel(R) Gigabit Ethernet Network Driver412builder # [ 1.487323] igb: Copyright (c) 2007-2014 Intel Corporation.413builder # [ 1.487345] igbvf: Intel(R) Gigabit Virtual Function Network Driver414builder # [ 1.487349] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.415builder # [ 1.487498] sky2: driver version 1.30416builder # [ 1.496282] ehci-pci 0000:00:07.0: EHCI Host Controller417builder # [ 1.496301] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1418builder # [ 1.496478] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000419builder # [ 1.496868] usbcore: registered new interface driver usb-storage420builder # [ 1.496916] usbcore: registered new interface driver usbserial_generic421builder # [ 1.496933] usbserial: USB Serial support registered for generic422builder # [ 1.502430] hv_vmbus: registering driver hyperv_keyboard423builder # [ 1.503402] rtc-pl031 9010000.pl031: registered as rtc0424builder # [ 1.503432] rtc-pl031 9010000.pl031: setting system clock to 2026-10-27T08:55:41 UTC (1793091341)425builder # [ 1.503754] i2c_dev: i2c /dev entries driver426builder # [ 1.507473] sdhci: Secure Digital Host Controller Interface driver427builder # [ 1.507478] sdhci: Copyright(c) Pierre Ossman428builder # [ 1.507784] Synopsys Designware Multimedia Card Interface Driver429builder # [ 1.508205] sdhci-pltfm: SDHCI platform and OF driver helper430builder # [ 1.509083] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00431builder # [ 1.509461] hub 1-0:1.0: USB hub found432builder # [ 1.509530] hub 1-0:1.0: 6 ports detected433builder # [ 1.519099] hid: raw HID events driver (C) Jiri Kosina434builder # [ 1.519381] usbcore: registered new interface driver usbhid435builder # [ 1.519386] usbhid: USB HID core driver436builder # [ 1.520685] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available437builder # [ 1.525823] drop_monitor: Initializing network drop monitor service438builder # [ 1.525965] NET: Registered PF_INET6 protocol family439builder # [ 1.526547] Segment Routing with IPv6440builder # [ 1.526574] In-situ OAM (IOAM) with IPv6441builder # [ 1.526609] NET: Registered PF_PACKET protocol family442builder # [ 1.526668] 9pnet: Installing 9P2000 support443builder # [ 1.526709] Key type dns_resolver registered444builder # [ 1.538485] registered taskstats version 1445builder # [ 1.538650] Loading compiled-in X.509 certificates446builder # [ 1.548404] Demotion targets for Node 0: null447builder # [ 1.548535] Key type .fscrypt registered448builder # [ 1.548539] Key type fscrypt-provisioning registered449builder # [ 1.548644] ima: No TPM chip found, activating TPM-bypass!450builder # [ 1.548666] ima: Allocated hash algorithm: sha1451builder # [ 1.548691] ima: No architecture policies found452builder # [ 1.549441] input: gpio-keys as /devices/platform/gpio-keys/input/input0453builder # [ 1.573918] clk: Disabling unused clocks454builder # [ 1.573939] PM: genpd: Disabling unused power domains455builder # [ 1.583269] Freeing unused kernel memory: 7808K456builder # [ 1.583617] Run /init as init process457builder # [ 1.607693] systemd[1]: Successfully made /usr/ read-only.458server # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]459server # [ 0.000000] Linux version 6.18.58 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT @1792571549460server # [ 0.000000] KASLR enabled461server # [ 0.000000] random: crng init done462server # [ 0.000000] Machine model: linux,dummy-virt463server # [ 0.000000] efi: UEFI not found.464server # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT465server # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]466server # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]467server # [ 0.000000] Zone ranges:468server # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]469server # [ 0.000000] DMA32 empty470server # [ 0.000000] Normal empty471server # [ 0.000000] Device empty472server # [ 0.000000] Movable zone start for each node473server # [ 0.000000] Early memory node ranges474server # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]475server # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]476server # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc00000477server # [ 0.000000] psci: probing for conduit method from DT.478server # [ 0.000000] psci: PSCIv1.3 detected in firmware.479server # [ 0.000000] psci: Using standard PSCI v0.2 function IDs480server # [ 0.000000] psci: Trusted OS migration not required481server # [ 0.000000] psci: SMC Calling Convention v1.1482server # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)483server # [ 0.000000] percpu: Embedded 76 pages/cpu s187672 r8192 d115432 u311296484server # [ 0.000000] Detected PIPT I-cache on CPU0485server # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)486server # [ 0.000000] CPU features: detected: GICv3 CPU interface487server # [ 0.000000] CPU features: detected: Spectre-v4488server # [ 0.000000] CPU features: detected: Spectre-BHB489server # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38490server # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23491server # [ 0.000000] alternatives: applying boot alternatives492server # [ 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/byn65s094i0dksy2hsw5l11zhyb96wzb-nixos-system-server-test/init regInfo=/nix/.ro-store/vca9i3hw4psw7mw6w49l4srwrswv7r83-closure-info/registration console=ttyAMA0,115200n8 console=tty0493server # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/vca9i3hw4psw7mw6w49l4srwrswv7r83-closure-info/registration", will be passed to user space.494server # [ 0.000000] printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes495server # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)496server # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)497server # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB498server # [ 0.000000] software IO TLB: area num 1.499server # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)500server # [ 0.000000] Fallback order for Node 0: 0501server # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 262144502server # [ 0.000000] Policy zone: DMA503server # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off504server # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1505server # [ 0.000000] allocated 2097152 bytes of page_ext506server # [ 0.000000] ftrace: allocating 75304 entries in 296 pages507server # [ 0.000000] ftrace: allocated 296 pages with 3 groups508server # [ 0.000000] rcu: Hierarchical RCU implementation.509server # [ 0.000000] rcu: RCU event tracing is enabled.510server # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=1.511server # [ 0.000000] Trampoline variant of Tasks RCU enabled.512server # [ 0.000000] Rude variant of Tasks RCU enabled.513server # [ 0.000000] Tracing variant of Tasks RCU enabled.514server # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.515server # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1516server # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.517server # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.518server # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.519server # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0520server # [ 0.000000] GICv3: 256 SPIs implemented521server # [ 0.000000] GICv3: 0 Extended SPIs implemented522server # [ 0.000000] Root IRQ handler: gic_handle_irq523server # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI524server # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0525server # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000526server # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]527server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @450f0000 (indirect, esz 8, psz 64K, shr 1)528server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @45100000 (flat, esz 8, psz 64K, shr 1)529server # [ 0.000000] GICv3: using LPI property table @0x0000000045110000530server # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000045120000531server # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.532server # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns533server # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).534server # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns535server # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns536server # [ 0.000037] arm-pv: using stolen time PV537server # [ 0.000495] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)538server # [ 0.000697] Console: colour dummy device 80x25539server # [ 0.000706] printk: legacy console [tty0] enabled540server # [ 0.001000] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)541server # [ 0.001008] pid_max: default: 32768 minimum: 301542server # [ 0.001120] LSM: initializing lsm=lockdown,capability,landlock,yama,bpf,ima543server # [ 0.001303] landlock: Up and running.544server # [ 0.001306] Yama: becoming mindful.545server # [ 0.001797] LSM support for eBPF active546server # [ 0.001921] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)547server # [ 0.001947] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)548server # [ 0.005433] rcu: Hierarchical SRCU implementation.549server # [ 0.005439] rcu: Max phase no-delay instances is 1000.550server # [ 0.006808] fsl-mc MSI: its@8080000 domain created551server # [ 0.006930] EFI services will not be available.552server # [ 0.007013] smp: Bringing up secondary CPUs ...553server # [ 0.007026] smp: Brought up 1 node, 1 CPU554server # [ 0.007030] SMP: Total of 1 processors activated.555server # [ 0.007033] CPU: All CPU(s) started at EL1556server # [ 0.007046] CPU features: detected: Branch Target Identification557server # [ 0.007051] CPU features: detected: ARMv8.4 Translation Table Level558server # [ 0.007054] CPU features: detected: Instruction cache invalidation not required for I/D coherence559server # [ 0.007058] CPU features: detected: Data cache clean to the PoU not required for I/D coherence560server # [ 0.007065] CPU features: detected: Common not Private translations561server # [ 0.007068] CPU features: detected: CRC32 instructions562server # [ 0.007071] CPU features: detected: Data cache clean to Point of Deep Persistence563server # [ 0.007074] CPU features: detected: Data cache clean to Point of Persistence564server # [ 0.007078] CPU features: detected: Data independent timing control (DIT)565builder # [ 1.757083] usb 1-1: new high-speed USB device number 2 using ehci-pci566server # [ 0.007081] CPU features: detected: E0PD567server # [ 0.007083] CPU features: detected: Enhanced Counter Virtualization568server # [ 0.007086] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)569server # [ 0.007090] CPU features: detected: Enhanced Virtualization Traps570server # [ 0.007093] CPU features: detected: Fine Grained Traps571server # [ 0.007096] CPU features: detected: Generic authentication (architected QARMA5 algorithm)572server # [ 0.007102] CPU features: detected: RCpc load-acquire (LDAPR)573server # [ 0.007105] CPU features: detected: LSE atomic instructions574server # [ 0.007108] CPU features: detected: Privileged Access Never575server # [ 0.007110] CPU features: detected: PMUv3576server # [ 0.007113] CPU features: detected: RAS Extension Support577server # [ 0.007116] CPU features: detected: RASv1p1 Extension Support578server # [ 0.007119] CPU features: detected: Random Number Generator579server # [ 0.007127] CPU features: detected: Speculation barrier (SB)580server # [ 0.007129] CPU features: detected: Stage-2 Force Write-Back581server # [ 0.007132] CPU features: detected: TLB range maintenance instructions582server # [ 0.007137] CPU features: detected: Speculative Store Bypassing Safe (SSBS)583server # [ 0.007174] alternatives: applying system-wide alternatives584server # [ 0.010717] CPU features: detected: BBM Level 2 without TLB conflict abort585server # [ 0.010928] Memory: 887476K/1048576K available (24640K kernel code, 10246K rwdata, 26664K rodata, 7808K init, 2086K bss, 119764K reserved, 32768K cma-reserved)586server # [ 0.011495] devtmpfs: initialized587server # [ 0.013355] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)588server # [ 0.014922] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).589server # [ 0.015133] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL590server # [ 0.015137] 0 pages in range for non-PLT usage591server # [ 0.015139] 506368 pages in range for PLT usage592server # [ 0.015247] pinctrl core: initialized pinctrl subsystem593server # [ 0.016144] DMI not present or invalid.594server # [ 0.019940] NET: Registered PF_NETLINK/PF_ROUTE protocol family595server # [ 0.022614] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations596server # [ 0.022809] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations597server # [ 0.023321] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations598server # [ 0.023354] audit: initializing netlink subsys (disabled)599server # [ 0.024402] thermal_sys: Registered thermal governor 'fair_share'600server # [ 0.024404] thermal_sys: Registered thermal governor 'bang_bang'601server # [ 0.024408] thermal_sys: Registered thermal governor 'step_wise'602server # [ 0.024410] thermal_sys: Registered thermal governor 'user_space'603server # [ 0.024413] thermal_sys: Registered thermal governor 'power_allocator'604server # [ 0.024439] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1605server # [ 0.024451] cpuidle: using governor ladder606server # [ 0.024458] cpuidle: using governor menu607server # [ 0.024655] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.608server # [ 0.024672] ASID allocator initialised with 65536 entries609server # [ 0.025948] Serial: AMBA PL011 UART driver610server # [ 0.032754] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1611server # [ 0.032992] printk: console [ttyAMA0] enabled612server # [ 0.161744] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages613server # [ 0.161756] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page614server # [ 0.161760] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages615server # [ 0.161763] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page616server # [ 0.161765] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages617server # [ 0.161768] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page618server # [ 0.161771] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages619server # [ 0.161774] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page620server # [ 0.163013] fbcon: Taking over console621server # [ 0.163023] ACPI: Interpreter disabled.622server # [ 0.173038] iommu: Default domain type: Translated623server # [ 0.173045] iommu: DMA domain TLB invalidation policy: strict mode624server # [ 0.173544] SCSI subsystem initialized625server # [ 0.174190] usbcore: registered new interface driver usbfs626server # [ 0.174219] usbcore: registered new interface driver hub627server # [ 0.174237] usbcore: registered new device driver usb628server # [ 0.174565] pps_core: LinuxPPS API ver. 1 registered629server # [ 0.174569] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>630server # [ 0.174577] PTP clock support registered631server # [ 0.174622] EDAC MC: Ver: 3.0.0632server # [ 0.186191] scmi_core: SCMI protocol bus registered633server # [ 0.186580] FPGA manager framework634server # [ 0.187139] vgaarb: loaded635server # [ 0.187416] clocksource: Switched to clocksource arch_sys_counter636server # [ 0.189916] VFS: Disk quotas dquot_6.6.0637server # [ 0.189948] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)638server # [ 0.196024] netfs: FS-Cache loaded639server # [ 0.196155] pnp: PnP ACPI: disabled640server # [ 0.200453] NET: Registered PF_INET protocol family641server # [ 0.200610] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)642server # [ 0.232305] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)643server # [ 0.232348] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)644server # [ 0.232374] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)645server # [ 0.232419] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)646server # [ 0.232492] TCP: Hash tables configured (established 8192 bind 8192)647server # [ 0.232580] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)648server # [ 0.232611] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)649server # [ 0.232660] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)650server # [ 0.232764] NET: Registered PF_UNIX/PF_LOCAL protocol family651server # [ 0.232832] NET: Registered PF_XDP protocol family652server # [ 0.232850] PCI: CLS 0 bytes, default 64653server # [ 0.233185] Trying to unpack rootfs image as initramfs...654server # [ 0.245571] kvm [1]: HYP mode not available655builder # [ 1.906742] input: QEMU QEMU USB Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input1656builder # [ 1.942199] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -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)657builder # [ 1.942228] systemd[1]: Detected virtualization qemu.658builder # [ 1.942274] systemd[1]: Detected architecture arm64.659builder # [ 1.942283] systemd[1]: Running in initrd.660builder # [ 1.942847] systemd[1]: Initializing machine ID from random generator.661builder # [ 1.943015] systemd[1]: Hostname set to <builder>.662builder # [ 2.001384] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0663builder # [ 2.087439] systemd[1]: bpf-restrict-fs: LSM BPF program attached664server # [ 0.460110] Initialise system trusted keyrings665server # [ 0.460167] Key type blacklist registered666server # [ 0.460343] workingset: timestamp_bits=42 max_order=18 bucket_order=0667server # [ 0.460894] squashfs: version 4.0 (2009/01/31) Phillip Lougher668server # [ 0.460973] 9p: Installing v9fs 9p2000 file system support669server # [ 0.461076] integrity: Platform Keyring initialized670server # [ 0.461087] integrity: Machine keyring initialized671builder # [ 2.121138] usb 1-2: new high-speed USB device number 3 using ehci-pci672server # [ 0.493885] Key type asymmetric registered673server # [ 0.493903] Asymmetric key parser 'x509' registered674server # [ 0.493989] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)675server # [ 0.494171] io scheduler mq-deadline registered676server # [ 0.494176] io scheduler kyber registered677builder # [ 2.143861] systemd[1]: Queued start job for default target Initrd Default Target.678builder # [ 2.148128] systemd[1]: Created slice Slice /system/modprobe.679builder # [ 2.148303] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.680builder # [ 2.148330] systemd[1]: Expecting device /dev/disk/by-label/nixos...681builder # [ 2.148350] systemd[1]: Reached target Path Units.682builder # [ 2.148363] systemd[1]: Reached target Slice Units.683builder # [ 2.148377] systemd[1]: Reached target Swaps.684builder # [ 2.148392] systemd[1]: Reached target Timer Units.685builder # [ 2.148519] systemd[1]: Listening on D-Bus System Message Bus Socket.686builder # [ 2.148658] systemd[1]: Listening on Journal Socket (/dev/log).687server # [ 0.507562] pl061_gpio 9030000.pl061: PL061 GPIO chip registered688builder # [ 2.148792] systemd[1]: Listening on Journal Sockets.689builder # [ 2.148862] systemd[1]: Listening on udev Kernel Socket.690server # [ 0.508174] ledtrig-cpu: registered to indicate activity on CPUs691server # [ 0.508559] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:692server # [ 0.508574] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000693server # [ 0.508588] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000694server # [ 0.508594] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000695builder # [ 2.157210] systemd[1]: Listening on udev Varlink Socket.696builder # [ 2.157243] systemd[1]: Reached target Socket Units.697server # [ 0.508613] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits698builder # [ 2.158705] systemd[1]: Starting Create List of Static Device Nodes...699server # [ 0.508637] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]700builder # [ 2.158771] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs701builder # [ 2.168906] systemd[1]: Mounting Kernel Configuration File System...702server # [ 0.508712] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00703server # [ 0.508720] pci_bus 0000:00: root bus resource [bus 00-ff]704server # [ 0.508724] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]705server # [ 0.508727] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]706server # [ 0.508730] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]707server # [ 0.508818] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint708server # [ 0.509302] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint709server # [ 0.509493] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]710server # [ 0.509505] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]711server # [ 0.509531] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]712server # [ 0.509544] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]713server # [ 0.510026] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint714server # [ 0.510213] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]715server # [ 0.510224] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]716server # [ 0.510250] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]717server # [ 0.510723] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint718builder # [ 2.177493] systemd[1]: Starting Journal Service...719server # [ 0.510911] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]720server # [ 0.510922] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]721server # [ 0.510948] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]722server # [ 0.543525] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint723server # [ 0.543725] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]724server # [ 0.543738] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]725server # [ 0.543764] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]726server # [ 0.543776] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]727server # [ 0.544329] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint728server # [ 0.544516] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]729server # [ 0.544541] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]730server # [ 0.545071] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint731server # [ 0.545258] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]732server # [ 0.545284] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]733server # [ 0.545716] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint734server # [ 0.545897] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]735server # [ 0.546150] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint736server # [ 0.546337] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]737server # [ 0.546362] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]738server # [ 0.546825] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint739builder # [ 2.197358] systemd[1]: Starting Load Kernel Modules...740server # [ 0.547012] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]741server # [ 0.547038] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]742builder # [ 2.197485] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os743builder # [ 2.208500] systemd[1]: Starting Coldplug All udev Devices...744server # [ 0.564107] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint745server # [ 0.564301] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]746server # [ 0.564328] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]747server # [ 0.564821] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint748server # [ 0.565115] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]749server # [ 0.565131] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]750server # [ 0.565158] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]751server # [ 0.565641] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint752server # [ 0.565825] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]753server # [ 0.565836] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]754server # [ 0.565862] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]755server # [ 0.566492] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned756server # [ 0.566498] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned757server # [ 0.566502] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned758server # [ 0.566547] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned759server # [ 0.566591] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned760builder # [ 2.221285] systemd[1]: Finished Create List of Static Device Nodes.761server # [ 0.566635] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned762builder # [ 2.222083] systemd[1]: Mounted Kernel Configuration File System.763server # [ 0.566679] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned764server # [ 0.566725] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned765server # [ 0.566768] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned766server # [ 0.566811] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned767server # [ 0.566854] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned768server # [ 0.566896] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned769server # [ 0.566966] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned770server # [ 0.567008] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned771server # [ 0.567025] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned772server # [ 0.567043] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned773server # [ 0.567060] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned774server # [ 0.567077] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned775server # [ 0.567095] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned776server # [ 0.567113] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned777server # [ 0.567132] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned778server # [ 0.567150] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned779server # [ 0.567168] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned780server # [ 0.567186] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned781server # [ 0.567204] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned782server # [ 0.567221] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned783server # [ 0.567239] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned784server # [ 0.567256] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned785server # [ 0.567273] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned786server # [ 0.567290] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned787server # [ 0.567307] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned788server # [ 0.567329] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]789server # [ 0.567334] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]790server # [ 0.567338] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]791builder # [ 2.253475] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...792server # [ 0.616345] pci 0000:00:07.0: enabling device (0000 -> 0002)793builder # [ 2.262569] systemd-journald[70]: Collecting audit messages is disabled.794builder # [ 2.268883] dm_mod: module verification failed: signature and/or required key missing - tainting kernel795builder # [ 2.279263] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.796server # [ 0.638127] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)797builder # [ 2.285499] input: QEMU QEMU USB Tablet as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input2798builder # [ 2.285647] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0799server # [ 0.648127] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)800server # [ 0.650999] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)801server # [ 0.654629] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)802builder # [ 2.299599] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev803server # [ 0.664850] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)804builder # [ 2.307031] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0805builder # [ 2.307270] [drm] features: -virgl +edid -resource_blob -host_visible806builder # [ 2.307272] [drm] features: -context_init807builder # [ 2.307996] [drm] number of scanouts: 1808builder # [ 2.308007] [drm] number of cap sets: 0809server # [ 0.669089] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)810builder # [ 2.309180] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.811server # [ 0.670906] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)812server # [ 0.680989] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)813server # [ 0.682909] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)814builder # [ 2.317828] systemd[1]: Starting Create Static Device Nodes in /dev...815server # [ 0.686462] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)816builder # [ 2.330325] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic817builder # [ 2.330340] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0818server # [ 0.697403] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)819server # [ 0.708240] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled820server # [ 0.710164] msm_serial: driver initialized821server # [ 0.710337] SuperH (H)SCI(F) driver initialized822server # [ 0.710396] STM32 USART driver initialized823builder # [ 2.377289] Console: switching to colour frame buffer device 160x50824builder # [ 2.378008] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device825builder # [ 2.380009] systemd[1]: Finished Create Static Device Nodes in /dev.826builder # [ 2.380475] systemd[1]: Reached target Preparation for Local File Systems.827builder # [ 2.380506] systemd[1]: Reached target Local File Systems.828builder # [ 2.393428] systemd[1]: Starting Rule-based Manager for Device Events and Files...829server # [ 0.753254] loop: module loaded830server # [ 0.753451] virtio_blk virtio2: 1/0/0 default/read/poll queues831builder # [ 2.398270] systemd[1]: Finished Load Kernel Modules.832server # [ 0.755394] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)833server # [ 0.760184] megasas: 07.734.00.00-rc1834server # [ 0.761171] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]835builder # [ 2.429331] systemd[1]: Starting Apply Kernel Variables...836builder # [ 2.459411] systemd[1]: Started Journal Service.837builder # [ 2.449300] systemd-modules-load[71]: Inserted module 'dm_mod'838builder # [ 2.452757] systemd-modules-load[71]: Module 'virtio_balloon' is built in839builder # [ 2.454343] systemd-modules-load[71]: Module 'virtio_console' is built in840builder # [ 2.455497] systemd-modules-load[71]: Inserted module 'virtio_gpu'841builder # [ 2.480591] systemd-modules-load[71]: Module 'virtio_rng' is built in842builder # [ 2.481733] systemd[1]: Starting Create System Files and Directories...843builder # [ 2.493335] systemd[1]: Finished Apply Kernel Variables.844builder # [ 2.541841] systemd-udevd[77]: Using default interface naming scheme 'v261'.845builder # [ 2.551651] systemd[1]: Finished Create System Files and Directories.846builder # [ 2.577166] systemd[1]: Started Rule-based Manager for Device Events and Files.847server # [ 0.771464] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000848server # [ 0.771493] Intel/Sharp Extended Query Table at 0x0031849builder # [ 2.658515] systemd[1]: Starting Virtual Console Setup...850server # [ 1.039495] Using buffer write method851server # [ 1.039579] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]852server # [ 1.042188] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000853server # [ 1.042248] Intel/Sharp Extended Query Table at 0x0031854server # [ 1.047307] Using buffer write method855server # [ 1.047334] Concatenating MTD devices:856server # [ 1.047337] (0): "0.flash"857server # [ 1.047340] (1): "0.flash"858server # [ 1.047342] into device "0.flash"859builder # [ 2.736550] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.860builder # [ 2.740601] systemd[1]: Finished Virtual Console Setup.861server # [ 1.178437] Freeing initrd memory: 25224K862server # [ 1.185222] tun: Universal TUN/TAP device driver, 1.6863server # [ 1.189226] thunder_xcv, ver 1.0864server # [ 1.189254] thunder_bgx, ver 1.0865server # [ 1.189277] nicpf, ver 1.0866server # [ 1.189853] e1000: Intel(R) PRO/1000 Network Driver867server # [ 1.189858] e1000: Copyright (c) 1999-2006 Intel Corporation.868server # [ 1.189884] e1000e: Intel(R) PRO/1000 Network Driver869server # [ 1.189891] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.870server # [ 1.189920] igb: Intel(R) Gigabit Ethernet Network Driver871server # [ 1.189924] igb: Copyright (c) 2007-2014 Intel Corporation.872server # [ 1.189946] igbvf: Intel(R) Gigabit Virtual Function Network Driver873server # [ 1.189950] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.874server # [ 1.190087] sky2: driver version 1.30875server # [ 1.192164] ehci-pci 0000:00:07.0: EHCI Host Controller876server # [ 1.192195] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1877server # [ 1.192417] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000878server # [ 1.202855] usbcore: registered new interface driver usb-storage879server # [ 1.202910] usbcore: registered new interface driver usbserial_generic880server # [ 1.202926] usbserial: USB Serial support registered for generic881server # [ 1.205815] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00882server # [ 1.206151] hub 1-0:1.0: USB hub found883server # [ 1.206176] hub 1-0:1.0: 6 ports detected884server # [ 1.206772] hv_vmbus: registering driver hyperv_keyboard885server # [ 1.210230] rtc-pl031 9010000.pl031: registered as rtc0886server # [ 1.210254] rtc-pl031 9010000.pl031: setting system clock to 2026-10-27T08:55:42 UTC (1793091342)887server # [ 1.210572] i2c_dev: i2c /dev entries driver888server # [ 1.216406] sdhci: Secure Digital Host Controller Interface driver889server # [ 1.216412] sdhci: Copyright(c) Pierre Ossman890server # [ 1.216701] Synopsys Designware Multimedia Card Interface Driver891server # [ 1.217182] sdhci-pltfm: SDHCI platform and OF driver helper892server # [ 1.218781] hid: raw HID events driver (C) Jiri Kosina893server # [ 1.219047] usbcore: registered new interface driver usbhid894server # [ 1.219052] usbhid: USB HID core driver895server # [ 1.225030] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available896server # [ 1.226637] drop_monitor: Initializing network drop monitor service897server # [ 1.226850] NET: Registered PF_INET6 protocol family898server # [ 1.230237] Segment Routing with IPv6899server # [ 1.230250] In-situ OAM (IOAM) with IPv6900server # [ 1.230281] NET: Registered PF_PACKET protocol family901server # [ 1.230340] 9pnet: Installing 9P2000 support902server # [ 1.230386] Key type dns_resolver registered903server # [ 1.239048] registered taskstats version 1904server # [ 1.239207] Loading compiled-in X.509 certificates905server # [ 1.247732] Demotion targets for Node 0: null906server # [ 1.247843] Key type .fscrypt registered907server # [ 1.247847] Key type fscrypt-provisioning registered908server # [ 1.247961] ima: No TPM chip found, activating TPM-bypass!909server # [ 1.247985] ima: Allocated hash algorithm: sha1910server # [ 1.248012] ima: No architecture policies found911server # [ 1.248699] input: gpio-keys as /devices/platform/gpio-keys/input/input0912server # [ 1.271204] clk: Disabling unused clocks913server # [ 1.271222] PM: genpd: Disabling unused power domains914server # [ 1.277366] Freeing unused kernel memory: 7808K915server # [ 1.277578] Run /init as init process916server # [ 1.293978] systemd[1]: Successfully made /usr/ read-only.917server # [ 1.451488] usb 1-1: new high-speed USB device number 2 using ehci-pci918server # [ 1.601227] input: QEMU QEMU USB Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input1919server # [ 1.627955] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -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)920server # [ 1.627986] systemd[1]: Detected virtualization qemu.921server # [ 1.628040] systemd[1]: Detected architecture arm64.922server # [ 1.628050] systemd[1]: Running in initrd.923server # [ 1.628572] systemd[1]: Initializing machine ID from random generator.924server # [ 1.628719] systemd[1]: Hostname set to <server>.925server # [ 1.691648] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0926builder # [ 3.386627] systemd[1]: Finished Coldplug All udev Devices.927builder # [ 3.388160] systemd[1]: Reached target System Initialization.928server # [ 1.760081] systemd[1]: bpf-restrict-fs: LSM BPF program attached929builder # [ 3.392491] systemd[1]: Reached target Basic System.930server # [ 1.811483] usb 1-2: new high-speed USB device number 3 using ehci-pci931server # [ 1.816579] systemd[1]: Queued start job for default target Initrd Default Target.932server # [ 1.825666] systemd[1]: Created slice Slice /system/modprobe.933server # [ 1.825850] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.934server # [ 1.825879] systemd[1]: Expecting device /dev/disk/by-label/nixos...935server # [ 1.825901] systemd[1]: Reached target Path Units.936server # [ 1.825916] systemd[1]: Reached target Slice Units.937server # [ 1.825932] systemd[1]: Reached target Swaps.938server # [ 1.825948] systemd[1]: Reached target Timer Units.939server # [ 1.826088] systemd[1]: Listening on D-Bus System Message Bus Socket.940server # [ 1.826252] systemd[1]: Listening on Journal Socket (/dev/log).941server # [ 1.826370] systemd[1]: Listening on Journal Sockets.942server # [ 1.826443] systemd[1]: Listening on udev Kernel Socket.943server # [ 1.826625] systemd[1]: Listening on udev Varlink Socket.944server # [ 1.826643] systemd[1]: Reached target Socket Units.945server # [ 1.838289] systemd[1]: Starting Create List of Static Device Nodes...946server # [ 1.838357] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs947server # [ 1.843897] systemd[1]: Mounting Kernel Configuration File System...948server # [ 1.857896] systemd[1]: Starting Journal Service...949server # [ 1.865597] systemd[1]: Starting Load Kernel Modules...950server # [ 1.865697] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os951server # [ 1.869792] systemd[1]: Starting Coldplug All udev Devices...952builder # [ 3.530697] (udev-worker)[96]: Network interface NamePolicy= disabled on kernel command line.953server # [ 1.907672] systemd[1]: Finished Create List of Static Device Nodes.954server # [ 1.911061] systemd-journald[71]: Collecting audit messages is disabled.955builder # [ 3.562919] (udev-worker)[92]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.956server # [ 1.927588] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...957builder # [ 3.570350] (udev-worker)[92]: Network interface NamePolicy= disabled on kernel command line.958server # [ 1.943923] systemd[1]: Mounted Kernel Configuration File System.959server # [ 1.950275] dm_mod: module verification failed: signature and/or required key missing - tainting kernel960server # [ 1.963177] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.961server # [ 1.971545] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev962server # [ 1.981162] input: QEMU QEMU USB Tablet as /devices/platform/4010000000.pcie/pci0000:00/0000:00:07.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input2963server # [ 1.981361] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0964server # [ 1.995022] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0965server # [ 1.995270] [drm] features: -virgl +edid -resource_blob -host_visible966server # [ 1.995273] [drm] features: -context_init967server # [ 1.997771] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.968builder # [ 3.626875] systemd[1]: Found device /dev/disk/by-label/nixos.969builder # [ 3.630344] systemd[1]: Reached target Initrd Root Device.970server # [ 2.000574] systemd[1]: Starting Create Static Device Nodes in /dev...971builder # [ 3.634675] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...972server # [ 2.012151] [drm] number of scanouts: 1973server # [ 2.012169] [drm] number of cap sets: 0974server # [ 2.012700] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic975server # [ 2.012710] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0976server # [ 2.039877] Console: switching to colour frame buffer device 160x50977server # [ 2.060173] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device978server # [ 2.061771] systemd[1]: Finished Create Static Device Nodes in /dev.979builder # [ 3.691887] systemd-fsck[109]: nixos: clean, 12/65536 files, 13019/262144 blocks980server # [ 2.062005] systemd[1]: Reached target Preparation for Local File Systems.981server # [ 2.062036] systemd[1]: Reached target Local File Systems.982builder # [ 3.700376] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.983builder # [ 3.705357] systemd[1]: Mounting /sysroot...984server # [ 2.076637] systemd[1]: Starting Rule-based Manager for Device Events and Files...985server # [ 2.087822] systemd[1]: Started Journal Service.986server # [ 2.063885] systemd-modules-load[72]: Inserted module 'dm_mod'987server # [ 2.073796] systemd-modules-load[72]: Module 'virtio_balloon' is built in988server # [ 2.077587] systemd-modules-load[72]: Module 'virtio_console' is built in989server # [ 2.083341] systemd-modules-load[72]: Inserted module 'virtio_gpu'990server # [ 2.088389] systemd-modules-load[72]: Module 'virtio_rng' is built in991server # [ 2.096862] systemd[1]: Finished Load Kernel Modules.992server # [ 2.104403] systemd[1]: Starting Apply Kernel Variables...993server # [ 2.112446] systemd[1]: Starting Create System Files and Directories...994builder # [ 3.778739] EXT4-fs (vda): mounted filesystem 4c892e5d-6757-4e4f-bb3b-4331d4ca9d03 r/w with ordered data mode. Quota mode: none.995builder # [ 3.766761] systemd[1]: Mounted /sysroot.996builder # [ 3.770153] systemd[1]: Reached target Initrd Root File System.997builder # [ 3.776178] systemd[1]: Starting Mountpoints Configured in the Real Root...998builder # [ 3.811956] systemd-sysroot-fstab-check[117]: /sysroot should be mounted in the initrd, will request daemon-reload.999server # [ 2.173681] systemd[1]: Finished Apply Kernel Variables.1000builder # [ 3.819993] systemd[1]: Reload requested from client PID 117 ('systemd-sysroot') (unit initrd-parse-etc.service)...1001builder # [ 3.823828] systemd[1]: Reloading...1002server # [ 2.184602] systemd-udevd[78]: Using default interface naming scheme 'v261'.1003server # [ 2.197867] systemd[1]: Finished Create System Files and Directories.1004server # [ 2.223292] systemd[1]: Started Rule-based Manager for Device Events and Files.1005server # [ 2.310286] systemd[1]: Starting Virtual Console Setup...1006server # [ 2.385063] systemd-vconsole-setup[100]: Configuration of first virtual console was skipped, ignoring remaining ones.1007server # [ 2.388910] systemd[1]: Finished Virtual Console Setup.1008builder # [ 4.036231] systemd[1]: Reloading finished in 217 ms.1009builder # [ 4.062705] systemd-sysroot-fstab-check[117]: Requesting initrd-fs.target/start/replace...1010builder # [ 4.069880] systemd-sysroot-fstab-check[117]: Requesting swap.target/start/replace...1011builder # [ 4.073128] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1012builder # [ 4.076202] systemd[1]: Finished Mountpoints Configured in the Real Root.1013builder # [ 4.078394] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1014builder # [ 4.199473] systemd[1]: Mounting /sysroot/nix/.ro-store...1015builder # [ 4.216886] systemd[1]: Mounting /sysroot/nix/.rw-store...1016builder # [ 4.219976] systemd[1]: Mounting /sysroot/run...1017builder # [ 4.233843] systemd[1]: Mounting /sysroot/tmp/shared...1018builder # [ 4.264318] systemd[1]: Mounting /sysroot/tmp/xchg...1019builder # [ 4.339802] fuse: init (API version 7.45)1020builder # [ 4.329016] systemd[1]: Mounted /sysroot/nix/.rw-store.1021builder # [ 4.357574] virtiofs virtio6: discovered new tag: nix-store1022builder # [ 4.358378] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1023builder # [ 4.374935] virtiofs virtio7: discovered new tag: shared1024builder # [ 4.375774] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1025builder # [ 4.367053] systemd[1]: Starting rw-sysroot-nix-store.service...1026builder # [ 4.382215] virtiofs virtio8: discovered new tag: xchg1027builder # [ 4.383007] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1028builder # [ 4.375395] systemd[1]: Mounted /sysroot/run.1029builder # [ 4.388315] systemd[1]: Mounted /sysroot/nix/.ro-store.1030builder # [ 4.393608] systemd[1]: Mounted /sysroot/tmp/shared.1031builder # [ 4.409702] systemd[1]: Mounted /sysroot/tmp/xchg.1032builder # [ 4.418585] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1033builder # [ 4.420733] systemd[1]: Finished rw-sysroot-nix-store.service.1034server # [ 2.980471] systemd[1]: Finished Coldplug All udev Devices.1035server # [ 2.982230] systemd[1]: Reached target System Initialization.1036server # [ 2.983146] systemd[1]: Reached target Basic System.1037server # [ 3.107532] (udev-worker)[99]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1038server # [ 3.133378] (udev-worker)[91]: Network interface NamePolicy= disabled on kernel command line.1039server # [ 3.146981] (udev-worker)[99]: Network interface NamePolicy= disabled on kernel command line.1040server # [ 3.212494] systemd[1]: Found device /dev/disk/by-label/nixos.1041server # [ 3.216580] systemd[1]: Reached target Initrd Root Device.1042server # [ 3.218906] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...1043server # [ 3.276052] systemd-fsck[109]: nixos: clean, 12/65536 files, 13019/262144 blocks1044server # [ 3.283590] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.1045server # [ 3.293189] systemd[1]: Mounting /sysroot...1046server # [ 3.345482] EXT4-fs (vda): mounted filesystem 1e2fc562-cb7c-4cc9-bf9d-1a30f8c811bd r/w with ordered data mode. Quota mode: none.1047server # [ 3.329871] systemd[1]: Mounted /sysroot.1048server # [ 3.331386] systemd[1]: Reached target Initrd Root File System.1049server # [ 3.340373] systemd[1]: Starting Mountpoints Configured in the Real Root...1050builder # [ 5.003920] (udev-worker)[89]: mtd0ro: Failed to find and pin callout binary "/nix/store/rzzrvlm7r31iq3im3h66nhxc2zh996l9-systemd-262/lib/udev/mtd_probe": No such file or directory1051builder # [ 5.009897] (udev-worker)[89]: mtd0ro: /etc/udev/rules.d/75-probe_mtd.rules:5 IMPORT{program}="mtd_probe $devnode": Failed to execute "mtd_probe /dev/mtd0ro", ignoring: No such file or directory1052server # [ 3.364498] systemd-sysroot-fstab-check[117]: /sysroot should be mounted in the initrd, will request daemon-reload.1053server # [ 3.371826] systemd[1]: Reload requested from client PID 117 ('systemd-sysroot') (unit initrd-parse-etc.service)...1054server # [ 3.376208] systemd[1]: Reloading...1055builder # [ 5.040551] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1056builder # [ 5.045170] systemd[1]: Stopped Virtual Console Setup.1057builder # [ 5.048204] systemd[1]: Stopping Virtual Console Setup...1058builder # [ 5.051293] systemd[1]: Starting Virtual Console Setup...1059builder # [ 5.069340] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1060builder # [ 5.070986] systemd[1]: Stopped Virtual Console Setup.1061builder # [ 5.079918] systemd[1]: Starting Virtual Console Setup...1062builder # [ 5.107553] systemd-vconsole-setup[153]: Configuration of first virtual console was skipped, ignoring remaining ones.1063builder # [ 5.111347] systemd[1]: Finished Virtual Console Setup.1064builder # [ 5.201100] systemd[1]: Mounting /sysroot/nix/store...1065server # [ 3.597272] systemd[1]: Reloading finished in 221 ms.1066builder # [ 5.247891] systemd[1]: Mounted /sysroot/nix/store.1067builder # [ 5.252674] systemd[1]: Reached target Initrd File Systems.1068builder # [ 5.255742] systemd[1]: Starting Find NixOS closure...1069server # [ 3.621875] systemd-sysroot-fstab-check[117]: Requesting initrd-fs.target/start/replace...1070builder # [ 5.269119] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1071server # [ 3.626926] systemd-sysroot-fstab-check[117]: Requesting swap.target/start/replace...1072server # [ 3.638329] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1073server # [ 3.640595] systemd[1]: Finished Mountpoints Configured in the Real Root.1074server # [ 3.642846] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1075builder # [ 5.312194] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1076builder # [ 5.317397] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.1077builder # [ 5.330999] systemd[1]: Finished Find NixOS closure.1078builder # [ 5.332848] systemd[1]: Reached target Initrd Default Target.1079builder # [ 5.335586] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1080builder # [ 5.362936] systemd[1]: Stopped target Initrd Default Target.1081builder # [ 5.364647] systemd[1]: Stopped target Basic System.1082builder # [ 5.365895] systemd[1]: Stopped target Initrd Root Device.1083builder # [ 5.368329] systemd[1]: Stopped target Path Units.1084builder # [ 5.370040] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1085builder # [ 5.373469] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1086builder # [ 5.375310] systemd[1]: Stopped target Slice Units.1087builder # [ 5.380447] systemd[1]: Stopped target Socket Units.1088builder # [ 5.381273] systemd[1]: Stopped target System Initialization.1089builder # [ 5.382108] systemd[1]: Stopped target Swaps.1090builder # [ 5.382767] systemd[1]: Stopped target Timer Units.1091builder # [ 5.383491] systemd[1]: dbus.socket: Deactivated successfully.1092builder # [ 5.387101] systemd[1]: Closed D-Bus System Message Bus Socket.1093builder # [ 5.391874] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1094builder # [ 5.396425] systemd[1]: Stopped Find NixOS closure.1095builder # [ 5.400359] systemd[1]: Starting rw-sysroot-nix-store.service...1096builder # [ 5.402355] systemd[1]: systemd-sysctl.service: Deactivated successfully.1097builder # [ 5.411482] systemd[1]: Stopped Apply Kernel Variables.1098builder # [ 5.415539] systemd[1]: systemd-modules-load.service: Deactivated successfully.1099builder # [ 5.420603] systemd[1]: Stopped Load Kernel Modules.1100builder # [ 5.422743] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1101builder # [ 5.426814] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1102builder # [ 5.430837] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1103builder # [ 5.432515] systemd[1]: Stopped Create System Files and Directories.1104builder # [ 5.436610] systemd[1]: Stopped target Local File Systems.1105builder # [ 5.437554] systemd[1]: Stopped target Preparation for Local File Systems.1106builder # [ 5.440320] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1107builder # [ 5.441401] systemd[1]: Stopped Coldplug All udev Devices.1108builder # [ 5.444349] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1109builder # [ 5.445531] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1110builder # [ 5.447255] systemd[1]: Stopped Virtual Console Setup.1111builder # [ 5.448429] systemd[1]: initrd-cleanup.service: Deactivated successfully.1112builder # [ 5.449433] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1113builder # [ 5.450392] systemd[1]: systemd-udevd.service: Deactivated successfully.1114builder # [ 5.451360] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1115builder # [ 5.452618] systemd[1]: systemd-udevd.service: Consumed 1.522s CPU time over 3.048s wall clock time, 22.8M memory peak.1116builder # [ 5.454096] systemd[1]: systemd-udevd-varlink.socket: Deactivated successfully.1117builder # [ 5.455157] systemd[1]: Closed udev Varlink Socket.1118builder # [ 5.455894] systemd[1]: Starting Cleanup udev Database...1119builder # [ 5.460443] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1120builder # [ 5.462793] systemd[1]: Stopped Create Static Device Nodes in /dev.1121builder # [ 5.464892] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1122builder # [ 5.468325] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1123builder # [ 5.469414] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1124builder # [ 5.472250] systemd[1]: Stopped Create List of Static Device Nodes.1125builder # [ 5.476142] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1126builder # [ 5.477134] systemd[1]: Finished rw-sysroot-nix-store.service.1127server # [ 3.855865] systemd[1]: Mounting /sysroot/nix/.ro-store...1128builder # [ 5.507199] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1129builder # [ 5.510921] systemd[1]: Finished Cleanup udev Database.1130builder # [ 5.511759] systemd[1]: Reached target Switch Root.1131builder # [ 5.516772] systemd[1]: Starting NixOS Activation...1132server # [ 3.877397] systemd[1]: Mounting /sysroot/nix/.rw-store...1133server # [ 3.886306] systemd[1]: Mounting /sysroot/run...1134server # [ 3.905313] systemd[1]: Mounting /sysroot/tmp/shared...1135server # [ 3.947981] systemd[1]: Mounting /sysroot/tmp/xchg...1136builder # [ 5.605545] initrd-nixos-activation-start[176]: booting system configuration /nix/store/3dp66d245s61azq9qczrvzkif5d614q9-nixos-system-builder-test1137server # [ 3.971630] systemd[1]: Mounted /sysroot/nix/.rw-store.1138builder # [ 5.638782] initrd-nixos-activation-start[176]: running activation script...1139server # [ 4.016285] fuse: init (API version 7.45)1140server # [ 4.026376] virtiofs virtio6: discovered new tag: nix-store1141server # [ 4.027242] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1142server # [ 4.014957] systemd[1]: Starting rw-sysroot-nix-store.service...1143server # [ 4.042107] virtiofs virtio7: discovered new tag: shared1144server # [ 4.042960] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1145server # [ 4.049189] virtiofs virtio8: discovered new tag: xchg1146server # [ 4.049985] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1147server # [ 4.049288] systemd[1]: Mounted /sysroot/run.1148server # [ 4.073859] systemd[1]: Mounted /sysroot/nix/.ro-store.1149server # [ 4.074831] systemd[1]: Mounted /sysroot/tmp/shared.1150server # [ 4.082924] systemd[1]: Mounted /sysroot/tmp/xchg.1151server # [ 4.084736] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1152server # [ 4.087936] systemd[1]: Finished rw-sysroot-nix-store.service.1153builder # [ 5.908826] initrd-nixos-activation-start[199]: setting up /etc...1154builder # [ 6.051913] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1155builder # [ 6.055290] systemd[1]: Finished NixOS Activation.1156builder # [ 6.056707] systemd[1]: Starting Switch Root...1157builder # [ 6.081123] systemd[1]: Switching root.1158builder # [ 6.267259] systemd-journald[70]: Received SIGTERM from PID 1 (systemd).1159server # [ 4.693752] (udev-worker)[90]: mtd0ro: Failed to find and pin callout binary "/nix/store/rzzrvlm7r31iq3im3h66nhxc2zh996l9-systemd-262/lib/udev/mtd_probe": No such file or directory1160server # [ 4.700386] (udev-worker)[90]: mtd0ro: /etc/udev/rules.d/75-probe_mtd.rules:5 IMPORT{program}="mtd_probe $devnode": Failed to execute "mtd_probe /dev/mtd0ro", ignoring: No such file or directory1161server # [ 4.740144] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1162server # [ 4.741602] systemd[1]: Stopped Virtual Console Setup.1163server # [ 4.746181] systemd[1]: Stopping Virtual Console Setup...1164server # [ 4.748186] systemd[1]: Starting Virtual Console Setup...1165server # [ 4.769534] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1166server # [ 4.772201] systemd[1]: Stopped Virtual Console Setup.1167server # [ 4.773799] systemd[1]: Starting Virtual Console Setup...1168server # [ 4.800840] systemd-vconsole-setup[151]: Configuration of first virtual console was skipped, ignoring remaining ones.1169server # [ 4.804879] systemd[1]: Finished Virtual Console Setup.1170server # [ 4.855348] systemd[1]: Mounting /sysroot/nix/store...1171server # [ 4.899193] systemd[1]: Mounted /sysroot/nix/store.1172server # [ 4.901763] systemd[1]: Reached target Initrd File Systems.1173server # [ 4.905268] systemd[1]: Starting Find NixOS closure...1174server # [ 4.916412] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1175server # [ 4.957929] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1176server # [ 4.965776] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.1177server # [ 4.978011] systemd[1]: Finished Find NixOS closure.1178server # [ 4.979923] systemd[1]: Reached target Initrd Default Target.1179server # [ 4.984676] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1180server # [ 5.015966] systemd[1]: Stopped target Initrd Default Target.1181server # [ 5.017926] systemd[1]: Stopped target Basic System.1182server # [ 5.020324] systemd[1]: Stopped target Initrd Root Device.1183server # [ 5.024381] systemd[1]: Stopped target Path Units.1184server # [ 5.025290] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1185server # [ 5.026489] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1186server # [ 5.028983] systemd[1]: Stopped target Slice Units.1187server # [ 5.032879] systemd[1]: Stopped target Socket Units.1188server # [ 5.037013] systemd[1]: Stopped target System Initialization.1189server # [ 5.038966] systemd[1]: Stopped target Swaps.1190server # [ 5.040668] systemd[1]: Stopped target Timer Units.1191server # [ 5.044234] systemd[1]: dbus.socket: Deactivated successfully.1192server # [ 5.046753] systemd[1]: Closed D-Bus System Message Bus Socket.1193server # [ 5.055981] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1194server # [ 5.058840] systemd[1]: Stopped Find NixOS closure.1195server # [ 5.063690] systemd[1]: Starting rw-sysroot-nix-store.service...1196server # [ 5.065093] systemd[1]: systemd-sysctl.service: Deactivated successfully.1197server # [ 5.067263] systemd[1]: Stopped Apply Kernel Variables.1198server # [ 5.068180] systemd[1]: systemd-modules-load.service: Deactivated successfully.1199server # [ 5.069243] systemd[1]: Stopped Load Kernel Modules.1200server # [ 5.070100] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1201server # [ 5.071247] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1202server # [ 5.079381] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1203server # [ 5.085845] systemd[1]: Stopped Create System Files and Directories.1204server # [ 5.088778] systemd[1]: Stopped target Local File Systems.1205server # [ 5.092245] systemd[1]: Stopped target Preparation for Local File Systems.1206server # [ 5.095545] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1207server # [ 5.098838] systemd[1]: Stopped Coldplug All udev Devices.1208server # [ 5.099695] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1209server # [ 5.104355] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1210server # [ 5.105510] systemd[1]: Stopped Virtual Console Setup.1211server # [ 5.106269] systemd[1]: systemd-udevd.service: Deactivated successfully.1212server # [ 5.107222] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1213server # [ 5.112220] systemd[1]: systemd-udevd.service: Consumed 1.604s CPU time over 3.009s wall clock time, 24.1M memory peak.1214server # [ 5.113770] systemd[1]: initrd-cleanup.service: Deactivated successfully.1215builder # [ 6.770851] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -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)1216server # [ 5.115042] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1217builder # [ 6.770929] systemd[1]: Detected virtualization qemu.1218server # [ 5.116422] systemd[1]: systemd-udevd-varlink.socket: Deactivated successfully.1219builder # [ 6.771055] systemd[1]: Detected architecture arm64.1220server # [ 5.117651] systemd[1]: Closed udev Varlink Socket.1221builder # [ 6.771212] systemd[1]: Detected first boot.1222server # [ 5.118406] systemd[1]: Starting Cleanup udev Database...1223server # [ 5.119271] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1224server # [ 5.120603] systemd[1]: Stopped Create Static Device Nodes in /dev.1225server # [ 5.121575] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1226builder # [ 6.782841] systemd[1]: Initializing machine ID from random generator.1227server # [ 5.122818] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1228server # [ 5.123863] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1229server # [ 5.128303] systemd[1]: Stopped Create List of Static Device Nodes.1230server # [ 5.131376] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1231server # [ 5.136434] systemd[1]: Finished rw-sysroot-nix-store.service.1232server # [ 5.177859] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1233server # [ 5.180551] systemd[1]: Finished Cleanup udev Database.1234server # [ 5.182245] systemd[1]: Reached target Switch Root.1235server # [ 5.183445] systemd[1]: Starting NixOS Activation...1236builder # [ 6.924644] systemd[1]: bpf-restrict-fs: LSM BPF program attached1237server # [ 5.276966] initrd-nixos-activation-start[174]: booting system configuration /nix/store/byn65s094i0dksy2hsw5l11zhyb96wzb-nixos-system-server-test1238server # [ 5.316202] initrd-nixos-activation-start[174]: running activation script...1239builder # [ 7.115360] systemd[1]: Applying preset policy.1240server # [ 5.635986] initrd-nixos-activation-start[197]: setting up /etc...1241builder # [ 7.387099] systemd[1]: Populated /etc with preset unit settings.1242server # [ 5.795414] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1243server # [ 5.799100] systemd[1]: Finished NixOS Activation.1244server # [ 5.800548] systemd[1]: Starting Switch Root...1245server # [ 5.828245] systemd[1]: Switching root.1246builder # [ 7.624848] systemd[1]: initrd-switch-root.service: Deactivated successfully.1247builder # [ 7.626875] systemd[1]: Stopped initrd-switch-root.service.1248builder # [ 7.630963] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1249builder # [ 7.634452] systemd[1]: Created slice Slice /system/getty.1250builder # [ 7.636060] systemd[1]: Created slice User and Session Slice.1251builder # [ 7.636620] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1252builder # [ 7.640618] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1253builder # [ 7.642672] systemd[1]: Expecting device /dev/hvc0...1254builder # [ 7.643059] systemd[1]: Expecting device /dev/ttyAMA0...1255builder # [ 7.643980] systemd[1]: Reached target Local Encrypted Volumes.1256builder # [ 7.644602] systemd[1]: Stopped target initrd-fs.target.1257builder # [ 7.648544] systemd[1]: Stopped target initrd-root-fs.target.1258builder # [ 7.648939] systemd[1]: Stopped target initrd-switch-root.target.1259builder # [ 7.651776] systemd[1]: Reached target Virtual Machines and Containers.1260builder # [ 7.652191] systemd[1]: Reached target Path Units.1261builder # [ 7.652815] systemd[1]: Reached target Remote File Systems.1262builder # [ 7.656780] systemd[1]: Reached target Slice Units.1263server # [ 6.012345] systemd-journald[71]: Received SIGTERM from PID 1 (systemd).1264builder # [ 7.658279] systemd[1]: Reached target Swaps.1265builder # [ 7.660492] systemd[1]: Listening on Query the User Interactively for a Password.1266builder # [ 7.665406] systemd[1]: Listening on Process Core Dump Socket.1267builder # [ 7.666914] systemd[1]: Listening on Credential Encryption/Decryption.1268builder # [ 7.668510] systemd[1]: Listening on Factory Reset Management.1269builder # [ 7.672247] systemd[1]: Listening on Hostname Service Socket.1270builder # [ 7.678700] systemd[1]: Starting Journal Log Access Socket...1271builder # [ 7.680454] systemd[1]: Listening on Journal Audit Socket.1272builder # [ 7.686809] systemd[1]: Listening on Console Output Muting Service Socket.1273builder # [ 7.687743] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1274builder # [ 7.688196] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1275builder # [ 7.694685] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1276builder # [ 7.702802] systemd[1]: Listening on Disk Repartitioning Service Socket.1277builder # [ 7.703482] systemd[1]: Listening on udev Varlink Socket.1278builder # [ 7.709091] systemd[1]: Mounting Huge Pages File System...1279builder # [ 7.714200] systemd[1]: Mounting POSIX Message Queue File System...1280builder # [ 7.727014] systemd[1]: Mounting Kernel Debug File System...1281builder # [ 7.737664] systemd[1]: Mounting Kernel Trace File System...1282builder # [ 7.757669] systemd[1]: Starting Create List of Static Device Nodes...1283builder # [ 7.759520] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1284builder # [ 7.785414] systemd[1]: Mounting Kernel Configuration File System...1285builder # [ 7.791872] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1286builder # [ 7.792509] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1287builder # [ 7.801444] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1288builder # [ 7.842085] systemd[1]: Mounting FUSE Control File System...1289builder # [ 7.842754] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671290builder # [ 7.897594] systemd[1]: Starting Journal Service...1291builder # [ 7.918582] systemd[1]: Starting Load Kernel Modules...1292builder # [ 7.945675] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1293builder # [ 7.973930] systemd[1]: Starting Remount Root and Kernel File Systems...1294builder # [ 7.974520] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1295builder # [ 7.990106] systemd[1]: Starting Coldplug All udev Devices...1296builder # [ 8.014138] systemd[1]: Listening on Journal Log Access Socket.1297builder # [ 8.014809] systemd[1]: Mounted Huge Pages File System.1298builder # [ 8.015507] systemd[1]: Mounted POSIX Message Queue File System.1299builder # [ 8.016169] systemd[1]: Mounted Kernel Debug File System.1300builder # [ 8.016802] systemd[1]: Mounted Kernel Trace File System.1301builder # [ 8.037989] systemd-journald[270]: Collecting audit messages is enabled.1302builder # [ 8.073752] systemd[1]: Finished Create List of Static Device Nodes.1303builder # [ 8.075647] systemd[1]: Started Journal Service.1304builder # [ 8.055932] systemd[1]: Queued start job for default target Multi-User System.1305builder # [ 8.068166] systemd[1]: systemd-journald.service: Deactivated successfully.1306builder # [ 8.086349] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1307builder # [ 8.089675] systemd-modules-load[271]: Module 'atkbd' is built in1308builder # [ 8.098257] systemd-modules-load[271]: Module 'loop' is built in1309builder # [ 8.120161] systemd[1]: Finished Load Kernel Modules.1310builder # [ 8.154617] EXT4-fs (vda): re-mounted 4c892e5d-6757-4e4f-bb3b-4331d4ca9d03.1311builder # [ 8.154036] systemd[1]: Starting Firewall...1312builder # [ 8.158734] systemd-oomd[272]: No swap; memory pressure usage will be degraded1313builder # [ 8.167872] systemd[1]: Starting Apply Kernel Variables...1314server # [ 6.541573] systemd[1]: systemd 262 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP -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)1315server # [ 6.541633] systemd[1]: Detected virtualization qemu.1316server # [ 6.541699] systemd[1]: Detected architecture arm64.1317server # [ 6.541839] systemd[1]: Detected first boot.1318builder # [ 8.180160] systemd[1]: Finished Remount Root and Kernel File Systems.1319builder # [ 8.181271] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1320server # [ 6.552882] systemd[1]: Initializing machine ID from random generator.1321builder # [ 8.198867] systemd[1]: Listening on Disk Image Download Service Socket.1322builder # [ 8.222207] systemd[1]: Starting Flush Journal to Persistent Storage...1323builder # [ 8.223345] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1324builder # [ 8.235655] systemd[1]: Starting Load/Save OS Random Seed...1325builder # [ 8.242127] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1326builder # [ 8.256439] systemd[1]: Mounted Kernel Configuration File System.1327builder # [ 8.275797] systemd[1]: Mounted FUSE Control File System.1328server # [ 6.697643] systemd[1]: bpf-restrict-fs: LSM BPF program attached1329builder # [ 8.366300] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1330builder # [ 8.379949] systemd[1]: Starting Create Static Device Nodes in /dev...1331builder # [ 8.391085] systemd[1]: Finished Load/Save OS Random Seed.1332builder # [ 8.416088] systemd-journald[270]: Received client request to flush runtime journal.1333server # [ 6.850506] systemd[1]: Applying preset policy.1334builder # [ 8.479772] systemd[1]: Reached target First Boot Complete.1335builder # [ 8.483310] systemd[1]: Finished Apply Kernel Variables.1336builder # [ 8.488763] systemd[1]: Finished Flush Journal to Persistent Storage.1337builder # [ 8.581065] systemd[1]: Finished Create Static Device Nodes in /dev.1338builder # [ 8.588171] systemd[1]: Reached target Preparation for Local File Systems.1339builder # [ 8.590300] systemd[1]: Starting Rule-based Manager for Device Events and Files...1340builder # [ 8.617934] systemd[1]: Mounting /run/wrappers...1341builder # [ 8.696066] systemd[1]: Mounted /run/wrappers.1342builder # [ 8.697017] systemd[1]: Reached target Local File Systems.1343server # [ 7.070534] systemd[1]: Populated /etc with preset unit settings.1344builder # [ 8.704226] systemd[1]: Listening on Boot Loader Control Service Socket.1345builder # [ 8.714335] systemd[1]: Starting register-nix-paths.service...1346builder # [ 8.722967] systemd[1]: Starting Create SUID/SGID Wrappers...1347builder # [ 8.729581] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1348builder # [ 8.735552] systemd[1]: Starting Save Transient machine-id to Disk...1349builder # [ 8.755012] systemd[1]: Starting Create System Files and Directories...1350builder # [ 8.781105] systemd-udevd[307]: Using default interface naming scheme 'v261'.1351server # [ 7.318981] systemd[1]: initrd-switch-root.service: Deactivated successfully.1352server # [ 7.321903] systemd[1]: Stopped initrd-switch-root.service.1353server # [ 7.326072] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1354server # [ 7.329734] systemd[1]: Created slice Slice /system/getty.1355server # [ 7.331058] systemd[1]: Created slice User and Session Slice.1356server # [ 7.333827] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1357server # [ 7.334320] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1358server # [ 7.334957] systemd[1]: Expecting device /dev/hvc0...1359server # [ 7.338893] systemd[1]: Expecting device /dev/ttyAMA0...1360server # [ 7.339297] systemd[1]: Reached target Local Encrypted Volumes.1361server # [ 7.342148] systemd[1]: Stopped target initrd-fs.target.1362server # [ 7.342538] systemd[1]: Stopped target initrd-root-fs.target.1363server # [ 7.343204] systemd[1]: Stopped target initrd-switch-root.target.1364server # [ 7.346727] systemd[1]: Reached target Virtual Machines and Containers.1365server # [ 7.347370] systemd[1]: Reached target Path Units.1366server # [ 7.350023] systemd[1]: Reached target Remote File Systems.1367server # [ 7.350397] systemd[1]: Reached target Slice Units.1368server # [ 7.351067] systemd[1]: Reached target Swaps.1369server # [ 7.355569] systemd[1]: Listening on Query the User Interactively for a Password.1370server # [ 7.357513] systemd[1]: Listening on Process Core Dump Socket.1371server # [ 7.358787] systemd[1]: Listening on Credential Encryption/Decryption.1372builder # [ 8.990589] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1373server # [ 7.363052] systemd[1]: Listening on Factory Reset Management.1374server # [ 7.365090] systemd[1]: Listening on Hostname Service Socket.1375server # [ 7.368751] systemd[1]: Starting Journal Log Access Socket...1376server # [ 7.370638] systemd[1]: Listening on Journal Audit Socket.1377server # [ 7.374356] systemd[1]: Listening on Console Output Muting Service Socket.1378server # [ 7.375075] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1379builder # [ 9.006880] systemd[1]: Finished Save Transient machine-id to Disk.1380server # [ 7.379106] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1381server # [ 7.382433] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1382server # [ 7.387081] systemd[1]: Listening on Disk Repartitioning Service Socket.1383server # [ 7.389266] systemd[1]: Listening on udev Varlink Socket.1384server # [ 7.392902] systemd[1]: Mounting Huge Pages File System...1385server # [ 7.397121] systemd[1]: Mounting POSIX Message Queue File System...1386server # [ 7.411730] systemd[1]: Mounting Kernel Debug File System...1387builder # [ 9.049672] systemd[1]: Started Rule-based Manager for Device Events and Files.1388server # [ 7.423258] systemd[1]: Mounting Kernel Trace File System...1389server # [ 7.448387] systemd[1]: Starting Create List of Static Device Nodes...1390server # [ 7.452703] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1391server # [ 7.474546] systemd[1]: Mounting Kernel Configuration File System...1392server # [ 7.475044] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1393server # [ 7.475419] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1394server # [ 7.489069] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1395builder # [ 9.120207] systemd[1]: Finished Create System Files and Directories.1396server # [ 7.506634] systemd[1]: Mounting FUSE Control File System...1397server # [ 7.507203] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671398builder # [ 9.139343] systemd[1]: Starting Rebuild Journal Catalog...1399builder # [ 9.157148] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1400server # [ 7.542651] systemd[1]: Starting Journal Service...1401server # [ 7.561521] systemd[1]: Starting Load Kernel Modules...1402server # [ 7.589888] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1403server # [ 7.627929] systemd[1]: Starting Remount Root and Kernel File Systems...1404server # [ 7.628435] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1405server # [ 7.642901] systemd[1]: Starting Coldplug All udev Devices...1406server # [ 7.650568] systemd[1]: Listening on Journal Log Access Socket.1407server # [ 7.651155] systemd[1]: Mounted Huge Pages File System.1408server # [ 7.672187] systemd[1]: Mounted POSIX Message Queue File System.1409server # [ 7.672907] systemd[1]: Mounted Kernel Debug File System.1410server # [ 7.673817] systemd[1]: Mounted Kernel Trace File System.1411server # [ 7.692538] systemd[1]: Finished Create List of Static Device Nodes.1412builder # [ 9.337399] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1413server # [ 7.721476] systemd-journald[268]: Collecting audit messages is enabled.1414server # [ 7.729576] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1415builder # [ 9.363685] systemd[1]: Finished Rebuild Journal Catalog.1416server # [ 7.740035] systemd[1]: Finished Load Kernel Modules.1417builder # [ 9.377052] systemd[1]: Starting Update is Completed...1418server # [ 7.733543] systemd[1]: Queued start job for default target Multi-User System.1419server # [ 7.755771] EXT4-fs (vda): re-mounted 1e2fc562-cb7c-4cc9-bf9d-1a30f8c811bd.1420server # [ 7.757784] systemd[1]: Starting Firewall...1421server # [ 7.748263] systemd[1]: systemd-journald.service: Deactivated successfully.1422server # [ 7.749828] systemd-modules-load[269]: Module 'atkbd' is built in1423server # [ 7.750894] systemd-modules-load[269]: Module 'loop' is built in1424server # [ 7.751902] systemd-modules-load[269]: Inserted module 'tls'1425server # [ 7.778798] systemd[1]: Starting Apply Kernel Variables...1426server # [ 7.789835] systemd[1]: Started Journal Service.1427server # [ 7.775055] systemd[1]: Mounted Kernel Configuration File System.1428server # [ 7.793089] systemd-oomd[270]: No swap; memory pressure usage will be degraded1429server # [ 7.809435] systemd[1]: Finished Remount Root and Kernel File Systems.1430server # [ 7.810529] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1431builder # [ 9.482401] systemd[1]: Finished Update is Completed.1432server # [ 7.865095] systemd[1]: Listening on Disk Image Download Service Socket.1433server # [ 7.886968] systemd[1]: Starting Flush Journal to Persistent Storage...1434server # [ 7.889585] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1435server # [ 7.900284] systemd[1]: Starting Load/Save OS Random Seed...1436server # [ 7.901288] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1437server # [ 7.902641] systemd[1]: Mounted FUSE Control File System.1438server # [ 7.972428] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1439server # [ 7.981828] systemd[1]: Finished Apply Kernel Variables.1440server # [ 7.996469] systemd[1]: Starting Create Static Device Nodes in /dev...1441server # [ 8.023716] systemd-journald[268]: Received client request to flush runtime journal.1442server # [ 8.095011] systemd[1]: Finished Load/Save OS Random Seed.1443server # [ 8.101741] systemd[1]: Reached target First Boot Complete.1444server # [ 8.106099] systemd[1]: Finished Flush Journal to Persistent Storage.1445server # [ 8.202781] systemd[1]: Finished Create Static Device Nodes in /dev.1446server # [ 8.203922] systemd[1]: Reached target Preparation for Local File Systems.1447server # [ 8.209750] systemd[1]: Starting Rule-based Manager for Device Events and Files...1448server # [ 8.310287] systemd[1]: Mounting /run/wrappers...1449server # [ 8.360277] systemd-udevd[307]: Using default interface naming scheme 'v261'.1450server # [ 8.382363] systemd[1]: Mounted /run/wrappers.1451server # [ 8.383390] systemd[1]: Reached target Local File Systems.1452server # [ 8.396372] systemd[1]: Listening on Boot Loader Control Service Socket.1453server # [ 8.401755] systemd[1]: Starting register-nix-paths.service...1454server # [ 8.416209] systemd[1]: Starting Create SUID/SGID Wrappers...1455server # [ 8.417259] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1456server # [ 8.442371] systemd[1]: Starting Save Transient machine-id to Disk...1457server # [ 8.463490] systemd[1]: Starting Create System Files and Directories...1458builder # [ 10.186277] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1459builder # [ 10.197354] systemd[1]: Finished Create SUID/SGID Wrappers.1460server # [ 8.620782] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1461server # [ 8.639668] systemd[1]: Finished Save Transient machine-id to Disk.1462server # [ 8.693000] systemd[1]: Started Rule-based Manager for Device Events and Files.1463server # [ 8.768612] systemd[1]: Finished Create System Files and Directories.1464server # [ 8.786937] systemd[1]: Starting Rebuild Journal Catalog...1465server # [ 8.799493] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1466builder # [ 10.490080] systemd[1]: Finished Coldplug All udev Devices.1467builder # [ 10.505493] systemd[1]: Finished register-nix-paths.service.1468builder # [ 10.506833] systemd[1]: Reached target System Initialization.1469builder # [ 10.512583] systemd[1]: Started Discard unused filesystem blocks once a week.1470builder # [ 10.518602] systemd[1]: Started Daily Cleanup of Temporary Directories.1471builder # [ 10.519718] systemd[1]: Reached target Timer Units.1472builder # [ 10.524825] systemd[1]: Listening on D-Bus System Message Bus Socket.1473builder # [ 10.525783] systemd[1]: Starting niks3 auto-upload socket...1474builder # [ 10.526652] systemd[1]: Listening on Nix Daemon Socket.1475builder # [ 10.527451] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1476builder # [ 10.540204] systemd[1]: Starting D-Bus System Message Bus...1477builder # [ 10.556424] systemd[1]: Listening on niks3 auto-upload socket.1478builder # [ 10.560338] systemd[1]: Reached target Socket Units.1479server # [ 8.942495] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1480builder # [ 10.622587] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1481server # [ 8.997194] systemd[1]: Finished Rebuild Journal Catalog.1482server # [ 9.006454] systemd[1]: Starting Update is Completed...1483builder # [ 10.662434] dbus-broker-launch[444]: Looking up NSS user entry for 'systemd-timesync'...1484builder # [ 10.668828] dbus-broker-launch[444]: NSS returned no entry for 'systemd-timesync'1485builder # [ 10.671561] dbus-broker-launch[444]: Invalid user-name in /nix/store/wzmnxp0zgp730c3pgs8fn73jprvp4aib-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1486builder # [ 10.706333] systemd[1]: Started D-Bus System Message Bus.1487builder # [ 10.711410] systemd[1]: Reached target Basic System.1488builder # [ 10.723209] systemd[1]: Starting Import lastlog data into lastlog2 database...1489builder # [ 10.743038] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1490builder # [ 10.756774] systemd[1]: Starting Post-Boot Actions...1491builder # [ 10.767764] dbus-broker-launch[444]: Ready1492builder # [ 10.793454] systemd[1]: Started Reset console on configuration changes.1493server # [ 9.149549] systemd[1]: Finished Update is Completed.1494builder # [ 10.844321] systemd[1]: Starting resolvconf update...1495builder # [ 10.926766] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1496builder # [ 10.978983] systemd[1]: Finished Post-Boot Actions.1497builder # [ 10.984953] systemd[1]: Started Name Service Cache Daemon (nsncd).1498builder # [ 11.005586] systemd[1]: Reached target Host and Network Name Lookups.1499builder # [ 11.006759] systemd[1]: Reached target User and Group Name Lookups.1500builder # [ 11.013694] nsncd[457]: Oct 27 08:55:51.023 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1501builder # [ 11.035171] systemd[1]: Starting User Login Management...1502builder # [ 11.114358] systemd[1]: Finished Import lastlog data into lastlog2 database.1503builder # [ 11.228967] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1504builder # [ 11.256872] systemd-logind[487]: New seat seat0.1505builder # [ 11.264453] systemd[1]: Started User Login Management.1506builder # [ 11.277914] systemd[1]: Starting linger-users.service...1507builder # [ 11.337571] systemd[1]: Stopped target Host and Network Name Lookups.1508builder # [ 11.344892] systemd[1]: Stopping Host and Network Name Lookups...1509builder # [ 11.345984] systemd[1]: Stopped target User and Group Name Lookups.1510builder # [ 11.346901] systemd[1]: Stopping User and Group Name Lookups...1511builder # [ 11.347774] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1512builder # [ 11.367108] systemd[1]: nscd.service: Deactivated successfully.1513builder # [ 11.372486] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1514builder # [ 11.400333] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1515builder # [ 11.405254] systemd[1]: linger-users.service: Deactivated successfully.1516builder # [ 11.415446] systemd[1]: Finished linger-users.service.1517builder # [ 11.427329] systemd[1]: Started backdoor.service.1518builder # [ 11.461489] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1519server # [ 9.824524] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1520server # [ 9.829182] systemd[1]: Finished Create SUID/SGID Wrappers.1521builder # [ 11.494401] systemd[1]: Finished Firewall.1522builder # [ 11.524826] systemd[1]: Finished resolvconf update.1523builder # [ 11.529827] systemd[1]: Reached target Preparation for Network.1524builder # [ 11.547827] systemd[1]: Starting DHCP Client...1525builder # [ 11.561123] systemd[1]: Starting Extra networking commands....1526builder # connecting to host...1527builder # [ 11.595191] nsncd[561]: Oct 27 08:55:51.608 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1528builder # [ 11.610724] systemd[1]: Started Name Service Cache Daemon (nsncd).1529builder # [ 11.620856] systemd[1]: Reached target Host and Network Name Lookups.1530builder # [ 11.621953] systemd[1]: Reached target User and Group Name Lookups.1531builder # [ 11.682493] (udev-worker)[351]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1532builder # [ 11.705892] (udev-worker)[345]: Network interface NamePolicy= disabled on kernel command line.1533builder # [ 11.713735] (udev-worker)[351]: Network interface NamePolicy= disabled on kernel command line.1534server # [ 10.068524] systemd[1]: Finished Coldplug All udev Devices.1535server # [ 10.096183] systemd[1]: Finished register-nix-paths.service.1536server # [ 10.097252] systemd[1]: Reached target System Initialization.1537server # [ 10.104473] systemd[1]: Started Discard unused filesystem blocks once a week.1538server # [ 10.105696] systemd[1]: Started niks3 garbage collection timer.1539server # [ 10.106575] systemd[1]: Started Daily Cleanup of Temporary Directories.1540server # [ 10.107548] systemd[1]: Reached target Timer Units.1541server # [ 10.114553] systemd[1]: Listening on D-Bus System Message Bus Socket.1542server # [ 10.115557] systemd[1]: Starting niks3 server proxy socket...1543server # [ 10.123298] systemd[1]: Listening on niks3 server socket.1544server # [ 10.136347] systemd[1]: Listening on Nix Daemon Socket.1545server # [ 10.137203] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1546server # [ 10.147251] systemd[1]: Starting D-Bus System Message Bus...1547server # [ 10.154334] systemd[1]: Listening on niks3 server proxy socket.1548server # [ 10.155280] systemd[1]: Reached target Socket Units.1549server # [ 10.159398] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1550server # [ 10.190443] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1551builder # [ 11.865632] dhcpcd[591]: dhcpcd-10.3.2 starting1552builder # [ 11.877375] dhcpcd[626]: dev: loaded udev1553builder # [ 11.888933] systemd[1]: Condition check resulted in Virtio network device being skipped.1554builder # [ 11.897246] systemd[1]: Starting Address configuration of eth1...1555server # [ 10.253025] dbus-broker-launch[449]: Looking up NSS user entry for 'systemd-timesync'...1556server # [ 10.259489] dbus-broker-launch[449]: NSS returned no entry for 'systemd-timesync'1557server # [ 10.263851] dbus-broker-launch[449]: Invalid user-name in /nix/store/zai3q4mzyvrmbval90cv5gr2w30q8fz6-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1558server # [ 10.294115] systemd[1]: Started D-Bus System Message Bus.1559server # [ 10.301362] systemd[1]: Reached target Basic System.1560server # [ 10.308395] systemd[1]: Starting Import lastlog data into lastlog2 database...1561builder # [ 11.980625] 8021q: 802.1Q VLAN Support v1.81562server # [ 10.324612] systemd[1]: Starting Generate test mTLS certs...1563server # [ 10.352385] dbus-broker-launch[449]: Ready1564server # [ 10.360128] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1565server # [ 10.390538] systemd[1]: Starting Post-Boot Actions...1566builder # [ 12.056215] systemd[1]: Finished Extra networking commands..1567builder # [ 12.057271] systemd[1]: Reached target Network.1568server # [ 10.412460] systemd[1]: Started Reset console on configuration changes.1569builder # [ 12.078272] systemd[1]: Starting Permit User Sessions...1570builder # [ 12.131974] 8021q: adding VLAN 0 to HW filter on device eth11571server # [ 10.487512] systemd[1]: Starting resolvconf update...1572builder # [ 12.179195] cfg80211: Loading compiled-in X.509 certificates for regulatory database1573builder # [ 12.183305] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1574builder # [ 12.183763] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1575builder # [ 12.172246] network-addresses-eth1-start[635]: adding address 192.168.1.1/24... done1576builder # [ 12.195469] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21577builder # [ 12.195820] cfg80211: failed to load regulatory.db1578builder # [ 12.192251] systemd[1]: Finished Permit User Sessions.1579builder # [ 12.208138] systemd[1]: Started Getty on tty1.1580builder # [ 12.208991] network-addresses-eth1-start[635]: adding address 2001:db8:1::1/64... done1581builder # [ 12.218007] systemd[1]: Reached target Login Prompts.1582server # [ 10.584149] systemd[1]: Started Name Service Cache Daemon (nsncd).1583server # [ 10.591855] nsncd[462]: Oct 27 08:55:51.897 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1584builder # [ 12.257514] systemd[1]: Finished Address configuration of eth1.1585server # [ 10.611345] niks3-test-certs-start[478]: -----1586server # [ 10.621624] systemd[1]: Reached target Host and Network Name Lookups.1587server # [ 10.632379] systemd[1]: Reached target User and Group Name Lookups.1588server # [ 10.660174] systemd[1]: Starting User Login Management...1589builder # [ 12.313706] dhcpcd[626]: eth0: waiting for carrier1590server # [ 10.668198] systemd[1]: Finished Post-Boot Actions.1591builder # [ 12.329643] 8021q: adding VLAN 0 to HW filter on device eth01592builder # [ 12.319912] dhcpcd[626]: eth0: waiting for carrier1593server # [ 10.674044] niks3-test-certs-start[494]: -----1594builder # [ 12.322740] dhcpcd[626]: eth0: carrier acquired1595builder # [ 12.334297] dhcpcd[626]: DUID 00:01:00:01:32:73:23:98:52:54:00:12:34:561596builder # [ 12.335340] dhcpcd[626]: eth0: IAID 00:12:34:561597builder # [ 12.337753] dhcpcd[626]: eth0: adding address fe80::5054:ff:fe12:34561598server # [ 10.716669] systemd[1]: Finished Import lastlog data into lastlog2 database.1599server # [ 10.744281] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1600builder # [ 12.425379] systemd-logind[487]: Watching system buttons on /dev/input/event0 (gpio-keys)1601server # [ 10.856540] niks3-test-certs-start[500]: Certificate request self-signature ok1602server # [ 10.864429] niks3-test-certs-start[500]: subject=CN=server1603builder # [ 12.547022] mousedev: PS/2 mouse device common for all mice1604server # [ 10.889130] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1605server # [ 10.901597] systemd[1]: Started backdoor.service.1606server # [ 10.953917] niks3-test-certs-start[534]: -----1607server # [ 11.014471] systemd-logind[495]: New seat seat0.1608server # [ 11.019376] systemd[1]: Started User Login Management.1609builder # [ 12.673467] systemd-logind[487]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1610server # [ 11.040338] systemd[1]: Starting linger-users.service...1611server # connecting to host...1612builder # [ 12.780948] dhcpcd[626]: eth0: soliciting a DHCP lease1613server # [ 11.138858] niks3-test-certs-start[544]: Certificate request self-signature ok1614builder # [ 12.788624] dhcpcd[626]: eth0: offered 10.0.2.15 from 10.0.2.21615server # [ 11.147063] systemd[1]: Stopped target Host and Network Name Lookups.1616builder # [ 12.796299] dhcpcd[626]: eth0: probing address 10.0.2.15/241617server # [ 11.152925] niks3-test-certs-start[544]: subject=CN=niks3 test client1618server # [ 11.154020] systemd[1]: Stopping Host and Network Name Lookups...1619server # [ 11.154899] systemd[1]: Stopped target User and Group Name Lookups.1620server # [ 11.155773] systemd[1]: Stopping User and Group Name Lookups...1621server # [ 11.175361] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1622server # [ 11.183253] systemd[1]: nscd.service: Deactivated successfully.1623server # [ 11.188819] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1624server # [ 11.189947] systemd[1]: linger-users.service: Deactivated successfully.1625server: Guest shell says: b'Spawning backdoor root shell...\n'1626server # [ 11.202084] systemd[1]: Finished linger-users.service.1627server: connected to guest root shell1628server: (connecting took 11.54 seconds)1629server: (finished: waiting for the VM to finish booting, in 11.54 seconds)1630server # [ 11.229278] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1631server # [ 11.242724] systemd[1]: Finished Generate test mTLS certs.1632server # [ 11.287333] systemd[1]: Finished Firewall.1633server # [ 11.325231] (udev-worker)[355]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1634server # [ 11.339175] (udev-worker)[352]: Network interface NamePolicy= disabled on kernel command line.1635server # [ 11.353927] (udev-worker)[355]: Network interface NamePolicy= disabled on kernel command line.1636server # [ 11.361021] nsncd[576]: Oct 27 08:55:52.667 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1637server # [ 11.431498] systemd[1]: Started Name Service Cache Daemon (nsncd).1638server # [ 11.445787] systemd[1]: Reached target Host and Network Name Lookups.1639server # [ 11.446835] systemd[1]: Reached target User and Group Name Lookups.1640server # [ 11.454505] systemd[1]: Condition check resulted in Virtio network device being skipped.1641server # [ 11.459399] systemd[1]: Finished resolvconf update.1642server # [ 11.469168] systemd[1]: Reached target Preparation for Network.1643server # [ 11.475474] systemd[1]: Starting DHCP Client...1644server # [ 11.489200] systemd[1]: Starting Address configuration of eth1...1645server # [ 11.497221] systemd[1]: Starting Extra networking commands....1646server # [ 11.641688] network-addresses-eth1-start[617]: adding address 192.168.1.2/24... done1647server # [ 11.661121] network-addresses-eth1-start[617]: adding address 2001:db8:1::2/64... done1648builder # [ 13.346423] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31649server # [ 11.707965] systemd[1]: Finished Address configuration of eth1.1650server # [ 11.806953] dhcpcd[638]: dhcpcd-10.3.2 starting1651server # [ 11.818486] dhcpcd[684]: dev: loaded udev1652server # [ 11.884375] 8021q: 802.1Q VLAN Support v1.81653server # [ 11.884743] 8021q: adding VLAN 0 to HW filter on device eth11654server # [ 11.895016] systemd[1]: Finished Extra networking commands..1655server # [ 11.898746] systemd[1]: Reached target Network.1656server # [ 11.909466] systemd[1]: Started Mock OIDC server for testing.1657server # [ 11.919235] systemd[1]: Starting Nginx Web Server...1658server # [ 11.944387] systemd[1]: Starting PostgreSQL Server...1659server # [ 12.009288] systemd[1]: Started RustFS S3-compatible object storage.1660server # [ 12.018859] systemd[1]: Starting Setup RustFS bucket...1661server # [ 12.045072] systemd[1]: Starting Permit User Sessions...1662builder # [ 13.692933] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1663server # [ 12.081423] cfg80211: Loading compiled-in X.509 certificates for regulatory database1664builder # [ 13.712396] systemd[1]: Starting Virtual Console Setup...1665server # [ 12.093015] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1666server # [ 12.093519] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1667server # [ 12.099887] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21668server # [ 12.100260] cfg80211: failed to load regulatory.db1669builder # [ 13.752111] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1670builder # [ 13.753339] systemd[1]: Stopped Virtual Console Setup.1671builder # [ 13.756473] systemd[1]: Starting Virtual Console Setup...1672builder # [ 13.805204] systemd-logind[487]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1673builder # [ 13.898076] systemd-vconsole-setup[686]: Configuration of first virtual console was skipped, ignoring remaining ones.1674builder # [ 13.902451] systemd[1]: Finished Virtual Console Setup.1675server # [ 12.275006] systemd[1]: Finished Permit User Sessions.1676server # [ 12.299444] systemd[1]: Started Getty on tty1.1677server # [ 12.306423] systemd[1]: Reached target Login Prompts.1678server # [ 12.394685] systemd-logind[495]: Watching system buttons on /dev/input/event0 (gpio-keys)1679server # [ 12.452617] 8021q: adding VLAN 0 to HW filter on device eth01680server # [ 12.437108] dhcpcd[684]: eth0: waiting for carrier1681server # [ 12.438039] dhcpcd[684]: eth0: carrier acquired1682server # [ 12.490672] dhcpcd[684]: DUID 00:01:00:01:32:73:23:99:52:54:00:12:34:561683server # [ 12.491766] dhcpcd[684]: eth0: IAID 00:12:34:561684server # [ 12.504191] dhcpcd[684]: eth0: adding address fe80::5054:ff:fe12:34561685builder # [ 14.186697] dhcpcd[626]: eth0: soliciting an IPv6 router1686builder # [ 14.190096] dhcpcd[626]: eth0: Router Advertisement from fe80::21687builder # [ 14.191470] dhcpcd[626]: eth0: adding address fec0::5054:ff:fe12:3456/641688builder # [ 14.193119] dhcpcd[626]: eth0: adding route to fec0::/641689builder # [ 14.194300] dhcpcd[626]: eth0: adding default route via fe80::21690server # [ 12.865723] mock-oidc-server[697]: Mock OIDC Server running1691server # [ 12.874049] mock-oidc-server[697]: OIDC Address: 127.0.0.1:80801692server # [ 12.883181] mock-oidc-server[697]: Issue Address: 127.0.0.1:80811693server # [ 12.885987] mock-oidc-server[697]: Issuer: http://127.0.0.1:8080/oidc1694server # [ 12.887035] mock-oidc-server[697]: JWKS: http://127.0.0.1:8080/oidc/.well-known/jwks.json1695server # [ 12.897449] mock-oidc-server[697]: Discovery: http://127.0.0.1:8080/oidc/.well-known/openid-configuration1696server # [ 12.910069] mock-oidc-server[697]: Issue tokens: http://127.0.0.1:8081/issue?sub=...1697server # [ 12.916429] nginx-pre-start[728]: nginx: the configuration file /nix/store/y3nsm2mq3agsgh29zi9kcydck990mzl7-nginx.conf syntax is ok1698server # [ 12.918191] nginx-pre-start[728]: nginx: configuration file /nix/store/y3nsm2mq3agsgh29zi9kcydck990mzl7-nginx.conf test is successful1699server # [ 12.937758] systemd[1]: Started Nginx Web Server.1700server # [ 12.952615] postgresql-pre-start[729]: The files belonging to this database system will be owned by user "postgres".1701server # [ 12.954147] postgresql-pre-start[729]: This user must also own the server process.1702server # [ 12.978023] postgresql-pre-start[729]: The database cluster will be initialized with locale "en_US.UTF-8".1703server # [ 12.979442] postgresql-pre-start[729]: The default database encoding has accordingly been set to "UTF8".1704server # [ 12.990760] postgresql-pre-start[729]: The default text search configuration will be set to "english".1705server # [ 12.995891] postgresql-pre-start[729]: Data page checksums are enabled.1706server # [ 13.002874] postgresql-pre-start[729]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok1707server # [ 13.011508] postgresql-pre-start[729]: creating subdirectories ... ok1708server # [ 13.016127] postgresql-pre-start[729]: selecting dynamic shared memory implementation ... posix1709server # [ 13.042136] mousedev: PS/2 mouse device common for all mice1710server # [ 13.120772] systemd-logind[495]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1711server # [ 13.272967] dhcpcd[684]: eth0: soliciting a DHCP lease1712server # [ 13.282180] dhcpcd[684]: eth0: offered 10.0.2.15 from 10.0.2.21713server # [ 13.288370] dhcpcd[684]: eth0: probing address 10.0.2.15/241714server # [ 13.404545] postgresql-pre-start[729]: selecting default "max_connections" ... 1001715server # [ 13.637829] postgresql-pre-start[729]: selecting default "shared_buffers" ... 128MB1716server # [ 14.119737] dhcpcd[684]: eth0: soliciting an IPv6 router1717server # [ 14.121422] dhcpcd[684]: eth0: Router Advertisement from fe80::21718server # [ 14.122303] dhcpcd[684]: eth0: adding address fec0::5054:ff:fe12:3456/641719server # [ 14.123225] dhcpcd[684]: eth0: adding route to fec0::/641720server # [ 14.126460] dhcpcd[684]: eth0: adding default route via fe80::21721server # [ 15.056049] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31722server # [ 15.437785] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1723server # [ 15.453847] systemd[1]: Starting Virtual Console Setup...1724server # [ 15.497404] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1725server # [ 15.508152] systemd[1]: Stopped Virtual Console Setup.1726server # [ 15.515296] systemd[1]: Starting Virtual Console Setup...1727server # [ 15.566735] systemd-logind[495]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1728server # [ 15.810798] systemd-vconsole-setup[790]: Configuration of first virtual console was skipped, ignoring remaining ones.1729server # [ 15.817289] systemd[1]: Finished Virtual Console Setup.1730server # [ 15.926777] postgresql-pre-start[729]: selecting default time zone ... UTC1731server # [ 15.929597] postgresql-pre-start[729]: creating configuration files ... ok1732server # [ 16.223307] postgresql-pre-start[729]: running bootstrap script ... ok1733builder # [ 17.949952] dhcpcd[626]: eth0: leased 10.0.2.15 for 86400 seconds1734builder # [ 17.950180] dhcpcd[626]: eth0: adding route to 10.0.2.0/241735builder # [ 17.950268] dhcpcd[626]: eth0: adding default route via 10.0.2.21736builder # [ 18.068562] systemd[1]: Started DHCP Client.1737builder # [ 18.071808] systemd[1]: Reached target Multi-User System.1738builder # [ 18.074134] systemd[1]: Startup finished in 1.577s (kernel) + 4.753s (initrd) + 11.742s (userspace) = 18.073s.1739server # [ 16.895243] postgresql-pre-start[729]: performing post-bootstrap initialization ... ok1740server # [ 17.020464] postgresql-pre-start[729]: syncing data to disk ... ok1741server # [ 17.022750] postgresql-pre-start[729]: initdb: warning: enabling "trust" authentication for local connections1742server # [ 17.024312] postgresql-pre-start[729]: 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.1743server # [ 17.026399] postgresql-pre-start[729]: Success. You can now start the database server using:1744server # [ 17.027554] postgresql-pre-start[729]: pg_ctl -D /var/lib/postgresql/18 -l logfile start1745server # [ 17.148595] postgres[809]: [809] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit1746server # [ 17.151581] postgres[809]: [809] LOG: listening on IPv6 address "::1", port 54321747server # [ 17.153020] postgres[809]: [809] LOG: listening on IPv4 address "127.0.0.1", port 54321748server # [ 17.154787] postgres[809]: [809] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"1749server # [ 17.167686] postgres[822]: [822] LOG: database system was shut down at 2026-10-27 08:55:58 GMT1750server # [ 17.172446] postgres[809]: [809] LOG: database system is ready to accept connections1751server # [ 17.177617] systemd[1]: Started PostgreSQL Server.1752server # [ 17.187149] systemd[1]: Starting PostgreSQL Setup Scripts...1753server # [ 17.416155] postgresql-setup-start[833]: CREATE DATABASE1754server # [ 17.462140] postgresql-setup-start[838]: CREATE ROLE1755server # [ 17.487071] postgresql-setup-start[840]: ALTER DATABASE1756server # [ 17.496469] systemd[1]: Finished PostgreSQL Setup Scripts.1757server # [ 17.498970] systemd[1]: Reached target PostgreSQL.1758server # [ 18.125948] dhcpcd[684]: eth0: leased 10.0.2.15 for 86400 seconds1759server # [ 18.127852] dhcpcd[684]: eth0: adding route to 10.0.2.0/241760server # [ 18.132804] dhcpcd[684]: eth0: adding default route via 10.0.2.21761server: (finished: waiting for unit postgresql.service, in 18.53 seconds)1762server: waiting for unit rustfs.service1763server: (finished: waiting for unit rustfs.service, in 0.06 seconds)1764server: waiting for unit rustfs-setup.service1765server # [ 18.329980] systemd[1]: Started DHCP Client.1766server # [ 29.351264] rustfs-setup-start[960]: mb s3://niks3-test1767server # [ 29.365459] systemd[1]: Finished Setup RustFS bucket.1768server # [ 29.379858] systemd[1]: Starting niks3 server...1769server # [ 29.574421] niks3-server[969]: 2026/10/27 08:56:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:8080/oidc1770server # [ 29.583145] niks3-server[969]: 2026/10/27 08:56:10 INFO OIDC authentication enabled config=/nix/store/v5zq66pblncksk07rwfp2mjsbq7fg0rm-niks3-oidc.json1771server # [ 29.588836] niks3-server[969]: 2026/10/27 08:56:10 INFO Loaded signing key name=niks3-test-1 path=/nix/store/b76isl6b3dijdpvyd9njxcpbxwhf9pyw-niks3-signing-key1772server # [ 29.624088] niks3-server[969]: 2026/10/27 08:56:10 INFO Using socket-activated listener address=0.0.0.0:57511773server # [ 29.625716] niks3-server[969]: 2026/10/27 08:56:10 INFO Using socket-activated listener address=/run/niks3/proxy.sock1774server # [ 29.632153] systemd[1]: Started niks3 server.1775server # [ 29.633098] niks3-server[969]: 2026/10/27 08:56:10 INFO systemd watchdog enabled interval=15s1776server # [ 29.634490] niks3-server[969]: 2026/10/27 08:56:10 INFO Starting HTTP server address=0.0.0.0:57511777server # [ 29.635910] niks3-server[969]: 2026/10/27 08:56:10 INFO Starting HTTP server address=/run/niks3/proxy.sock1778server # [ 29.637668] systemd[1]: Reached target Multi-User System.1779server # [ 29.638545] systemd[1]: Startup finished in 1.263s (kernel) + 4.831s (initrd) + 23.537s (userspace) = 29.631s.1780server: (finished: waiting for unit rustfs-setup.service, in 11.75 seconds)1781server: waiting for unit mock-oidc.service1782server: (finished: waiting for unit mock-oidc.service, in 0.04 seconds)1783server: waiting for unit niks3.service1784server: (finished: waiting for unit niks3.service, in 0.03 seconds)1785server: waiting for TCP port 5751 on localhost1786server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!1787server: (finished: waiting for TCP port 5751 on localhost, in 0.03 seconds)1788server: waiting for TCP port 8080 on localhost1789server # Connection to localhost (127.0.0.1) 8080 port [tcp/http-alt] succeeded!1790server: (finished: waiting for TCP port 8080 on localhost, in 0.02 seconds)1791server: waiting for TCP port 9000 on localhost1792server # Connection to localhost (127.0.0.1) 9000 port [tcp/cslistener] succeeded!1793server: (finished: waiting for TCP port 9000 on localhost, in 0.02 seconds)1794server: must succeed: mkdir -p /tmp/test-config1795server: (finished: must succeed: mkdir -p /tmp/test-config, in 0.02 seconds)1796server: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token1797server: (finished: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token, in 0.01 seconds)1798server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31799server # [ 30.419915] niks3-server[969]: 2026/10/27 08:56:11 INFO Received push request method=POST path=/api/pushes1800server # time=2026-10-27T08:56:11.750Z level=INFO msg="Uploading 5 paths to server (0 already cached)"1801server # time=2026-10-27T08:56:11.751Z level=INFO msg="Uploading dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3 (287.5KB)"1802server # time=2026-10-27T08:56:11.753Z level=INFO msg="Uploading vr8lx1cjz6zw4xhmb4k405v6cqrkslnk-libunistring-1.4.2 (2.0MB)"1803server # time=2026-10-27T08:56:11.757Z level=INFO msg="Uploading nhphqkv18x8fpf3flz0bsm1h554pawn7-glibc-2.44-57 (44.8MB)"1804server # time=2026-10-27T08:56:11.760Z level=INFO msg="Uploading wsn07qxxn13gcdcjw5avz47j8lb2zpdv-libidn2-2.3.8 (366.1KB)"1805server # time=2026-10-27T08:56:11.761Z level=INFO msg="Uploading 09mqjwlgdr2jchjchwpgff2vryn4zc4q-xgcc-16.2.0-libgcc (150.2KB)"1806server # [ 30.668857] niks3-server[969]: 2026/10/27 08:56:11 INFO Registered completed upload object_key=nar/0ik4x86wi4hx5a19m0hrqb82v8pwywwk872j6xqs6cbsmirmckm4.nar.zst1807server # [ 30.731018] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=vr8lx1cjz6zw4xhmb4k405v6cqrkslnk.ls1808server # [ 30.793952] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=dnz35byzl8yw7s81gzqhdq33dds220mx.ls1809server # [ 30.805168] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=09mqjwlgdr2jchjchwpgff2vryn4zc4q.ls1810server # [ 30.835088] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=wsn07qxxn13gcdcjw5avz47j8lb2zpdv.ls1811server # [ 30.840229] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=nar/1ikjnm41hig7040f8bndzqjg1ldxmf536y6s780r51lcml7xcn56.nar.zst1812server # [ 30.846783] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=nar/1m0mgk6b6a19qzcllk6w4njwbwv1dg68rsrw96l54c51ggjk8fqh.nar.zst1813server # [ 30.857640] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=nar/1kzqcp635py2svzfvvnc2bj96pmzfgzc4iplkq1d35zwdg4mn9c7.nar.zst1814server # [ 31.502664] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=nhphqkv18x8fpf3flz0bsm1h554pawn7.ls1815server # [ 31.523291] niks3-server[969]: 2026/10/27 08:56:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1816server # [ 31.539854] niks3-server[969]: 2026/10/27 08:56:12 INFO Completed multipart upload object_key=nar/15klwx7m7d19x32c2v5p6sdaj1xy3a0mrs9bhkwi7ihg4i465hsv.nar.zst upload_id=MTFkMWY2N2YtMTkwOS00NjUwLWJkOTItY2YxNjk2YmEwNmZmLjJkN2E0MGU5LTVjYWEtNDlmNS1hNzI0LTdiOWE5ODI1ZmNhZngxNzkzMDkxMzcxNzQxMDMwNjYw parts=11817server # time=2026-10-27T08:56:12.855Z level=INFO msg="Uploading 5 narinfos"1818server # [ 31.550352] niks3-server[969]: 2026/10/27 08:56:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1819server # [ 31.551891] niks3-server[969]: 2026/10/27 08:56:12 INFO Signed narinfos id=1 count=51820server # [ 31.582846] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=wsn07qxxn13gcdcjw5avz47j8lb2zpdv.narinfo1821server # [ 31.589037] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=vr8lx1cjz6zw4xhmb4k405v6cqrkslnk.narinfo1822server # [ 31.590966] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=dnz35byzl8yw7s81gzqhdq33dds220mx.narinfo1823server # [ 31.593161] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=nhphqkv18x8fpf3flz0bsm1h554pawn7.narinfo1824server # [ 31.599812] niks3-server[969]: 2026/10/27 08:56:12 INFO Received complete push request method=POST path=/api/pushes/1/complete1825server # [ 31.605164] niks3-server[969]: 2026/10/27 08:56:12 INFO Registered completed upload object_key=09mqjwlgdr2jchjchwpgff2vryn4zc4q.narinfo1826server # time=2026-10-27T08:56:12.918Z level=INFO msg="Upload complete. (1.256s)"1827server # [ 31.616271] niks3-server[969]: 2026/10/27 08:56:12 INFO Completed push id=1 objects=15 duration=10.8186ms1828server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 1.40 seconds)1829server: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token1830server: (finished: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token, in 0.01 seconds)1831server: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31832server # [ 31.714630] niks3-server[969]: 2026/10/27 08:56:13 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]1833server # [ 31.769013] niks3-server[969]: 2026/10/27 08:56:13 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]1834server # time=2026-10-27T08:56:13.081Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1835server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 0.14 seconds)1836server: waiting for unit nginx.service1837server: (finished: waiting for unit nginx.service, in 0.03 seconds)1838server: waiting for TCP port 443 on localhost1839server # Connection to localhost (::1) 443 port [tcp/https] succeeded!1840server: (finished: waiting for TCP port 443 on localhost, in 0.02 seconds)1841server: must succeed: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/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/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31842server # time=2026-10-27T08:56:13.202Z 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.pem1843server # time=2026-10-27T08:56:13.216Z level=INFO msg="All 1 paths already cached"1844server: (finished: must succeed: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/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/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 0.08 seconds)1845server: must fail: curl -sf -X POST -H 'X-SSL-Client-Verify: SUCCESS' -H 'X-SSL-Client-Dn: CN=niks3 test client' -d '{}' http://127.0.0.1:5751/api/pending_closures1846server: (finished: must fail: curl -sf -X POST -H 'X-SSL-Client-Verify: SUCCESS' -H 'X-SSL-Client-Dn: CN=niks3 test client' -d '{}' http://127.0.0.1:5751/api/pending_closures, in 0.03 seconds)1847server: must fail: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31848server # time=2026-10-27T08:56:13.263Z 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)"1849server: (finished: must fail: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 0.02 seconds)1850server: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31851server # time=2026-10-27T08:56:13.373Z level=INFO msg="Configuring client TLS" cert="" key="" ca=/etc/niks3-test-certs/ca.pem1852server # time=2026-10-27T08:56:13.387Z level=INFO msg="All 1 paths already cached"1853server: (finished: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 0.12 seconds)1854server: must succeed: cd /etc/niks3-test-certs && /nix/store/1r53ih2yfqw9h9mcbz56b59yxipg0a9c-openssl-3.5.9-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client'1855server # -----1856server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/1r53ih2yfqw9h9mcbz56b59yxipg0a9c-openssl-3.5.9-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client', in 0.02 seconds)1857server: must succeed: cd /etc/niks3-test-certs && /nix/store/1r53ih2yfqw9h9mcbz56b59yxipg0a9c-openssl-3.5.9-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem1858server # Certificate request self-signature ok1859server # subject=CN=other client1860server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/1r53ih2yfqw9h9mcbz56b59yxipg0a9c-openssl-3.5.9-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem, in 0.04 seconds)1861server: must fail: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/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/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31862server # time=2026-10-27T08:56:13.534Z 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.pem1863server # [ 32.234079] niks3-server[969]: 2026/10/27 08:56:13 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1864server # [ 32.288836] niks3-server[969]: 2026/10/27 08:56:13 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1865server # time=2026-10-27T08:56:13.599Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1866server: (finished: must fail: /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/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/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3, in 0.14 seconds)1867server: must succeed: mkdir -p /tmp/test-store1868server: (finished: must succeed: mkdir -p /tmp/test-store, in 0.02 seconds)1869server: must succeed: 1870 export AWS_ACCESS_KEY_ID=rustfsadmin1871export AWS_SECRET_ACCESS_KEY=rustfsadmin1872 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.318731874server # copying 5 paths...1875server # copying path '/nix/store/09mqjwlgdr2jchjchwpgff2vryn4zc4q-xgcc-16.2.0-libgcc' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1876server # copying path '/nix/store/vr8lx1cjz6zw4xhmb4k405v6cqrkslnk-libunistring-1.4.2' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1877server # copying path '/nix/store/wsn07qxxn13gcdcjw5avz47j8lb2zpdv-libidn2-2.3.8' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1878server # copying path '/nix/store/nhphqkv18x8fpf3flz0bsm1h554pawn7-glibc-2.44-57' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1879server # copying path '/nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1880server: (finished: must succeed: 1881 export AWS_ACCESS_KEY_ID=rustfsadmin1882export AWS_SECRET_ACCESS_KEY=rustfsadmin1883 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.31884, in 0.59 seconds)1885server: must succeed: 1886cat > /tmp/test-drv.nix << 'EOF'1887derivation {1888 name = "test-build-log";1889 system = builtins.currentSystem;1890 builder = "/bin/sh";1891 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1892}1893EOF18941895server: (finished: must succeed: 1896cat > /tmp/test-drv.nix << 'EOF'1897derivation {1898 name = "test-build-log";1899 system = builtins.currentSystem;1900 builder = "/bin/sh";1901 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1902}1903EOF1904, in 0.02 seconds)1905server: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix1906server # this derivation will be built:1907server # /nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1908server # building '/nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv'...1909server # test-build-log> test build log output1910server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix, in 0.17 seconds)1911server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1912server # [ 33.214272] niks3-server[969]: 2026/10/27 08:56:14 INFO Received push request method=POST path=/api/pushes1913server # time=2026-10-27T08:56:14.529Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1914server # time=2026-10-27T08:56:14.530Z level=INFO msg="Uploading z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log (128B)"1915server # [ 33.254484] niks3-server[969]: 2026/10/27 08:56:14 INFO Registered completed upload object_key=log/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1916server # time=2026-10-27T08:56:14.568Z level=INFO msg="Uploading 1 narinfos"1917server # [ 33.262289] niks3-server[969]: 2026/10/27 08:56:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1918server # [ 33.263837] niks3-server[969]: 2026/10/27 08:56:14 INFO Signed narinfos id=2 count=11919server # [ 33.269485] niks3-server[969]: 2026/10/27 08:56:14 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.ls1920server # [ 33.273738] niks3-server[969]: 2026/10/27 08:56:14 INFO Registered completed upload object_key=nar/00zns3gj9hwz2a4b0i07y7nmxybq59lh24bl3xsxblcl6333mjil.nar.zst1921server # [ 33.284607] niks3-server[969]: 2026/10/27 08:56:14 INFO Received complete push request method=POST path=/api/pushes/2/complete1922server # [ 33.288357] niks3-server[969]: 2026/10/27 08:56:14 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo1923server # time=2026-10-27T08:56:14.600Z level=INFO msg="Upload complete. (133ms)"1924server # [ 33.292648] niks3-server[969]: 2026/10/27 08:56:14 INFO Completed push id=2 objects=4 duration=9.71224ms1925server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log, in 0.21 seconds)1926server: must succeed: 1927 export AWS_ACCESS_KEY_ID=rustfsadmin1928export AWS_SECRET_ACCESS_KEY=rustfsadmin1929 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log19301931server # got build log for '/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'1932server: (finished: must succeed: 1933 export AWS_ACCESS_KEY_ID=rustfsadmin1934export AWS_SECRET_ACCESS_KEY=rustfsadmin1935 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1936, in 0.14 seconds)1937subtest: push --stdin streams paths and reports each one1938server: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }'1939server # this derivation will be built:1940server # /nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1941server # building '/nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv'...1942server: (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.17 seconds)1943server: 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/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --stdin1944server # [ 33.730714] niks3-server[969]: 2026/10/27 08:56:15 INFO Received push request method=POST path=/api/pushes1945server # time=2026-10-27T08:56:15.045Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1946server # time=2026-10-27T08:56:15.046Z level=INFO msg="Uploading 7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test (120B)"1947server # [ 33.760169] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.ls1948server # [ 33.769505] niks3-server[969]: 2026/10/27 08:56:15 INFO Received sign narinfos request method=POST path=/api/pushes/3/sign1949server # time=2026-10-27T08:56:15.082Z level=INFO msg="Uploading 1 narinfos"1950server # [ 33.777058] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=nar/1hj1r0g515rfxjx685mfn3dgr6akqbn4gf64snlv6bxaxph69lna.nar.zst1951server # [ 33.781299] niks3-server[969]: 2026/10/27 08:56:15 INFO Signed narinfos id=3 count=11952server # [ 33.782437] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=log/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1953server # [ 33.791654] niks3-server[969]: 2026/10/27 08:56:15 INFO Received complete push request method=POST path=/api/pushes/3/complete1954server # time=2026-10-27T08:56:15.104Z level=INFO msg="Upload complete. (121ms)"1955server # [ 33.796379] niks3-server[969]: 2026/10/27 08:56:15 INFO Completed push id=3 objects=4 duration=6.487ms1956server # [ 33.800430] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.narinfo1957server: (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/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --stdin, in 0.20 seconds)1958server: must succeed: 1959 export AWS_ACCESS_KEY_ID=rustfsadmin1960export AWS_SECRET_ACCESS_KEY=rustfsadmin1961 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1962 1963server # copying 1 paths...1964server # copying path '/nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1965server: (finished: must succeed: 1966 export AWS_ACCESS_KEY_ID=rustfsadmin1967export AWS_SECRET_ACCESS_KEY=rustfsadmin1968 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1969 , in 0.15 seconds)1970(finished: subtest: push --stdin streams paths and reports each one, in 0.52 seconds)1971server: must succeed: 1972cat > /tmp/ca-test.nix << 'EOF'1973derivation {1974 name = "ca-test";1975 system = builtins.currentSystem;1976 builder = "/bin/sh";1977 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1978 __contentAddressed = true;1979 outputHashMode = "recursive";1980 outputHashAlgo = "sha256";1981}1982EOF19831984server: (finished: must succeed: 1985cat > /tmp/ca-test.nix << 'EOF'1986derivation {1987 name = "ca-test";1988 system = builtins.currentSystem;1989 builder = "/bin/sh";1990 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1991 __contentAddressed = true;1992 outputHashMode = "recursive";1993 outputHashAlgo = "sha256";1994}1995EOF1996, in 0.02 seconds)1997server: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link1998server # this derivation will be built:1999server # /nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv2000server # building '/nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv'...2001server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link, in 0.18 seconds)2002server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2003server # [ 34.324869] niks3-server[969]: 2026/10/27 08:56:15 INFO Received push request method=POST path=/api/pushes2004server # time=2026-10-27T08:56:15.638Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2005server # time=2026-10-27T08:56:15.639Z level=INFO msg="Uploading 5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test (144B)"2006server # [ 34.353845] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.ls2007server # [ 34.360212] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=log/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv2008server # time=2026-10-27T08:56:15.673Z level=INFO msg="Uploading 1 narinfos"2009server # [ 34.366552] niks3-server[969]: 2026/10/27 08:56:15 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign2010server # [ 34.370802] niks3-server[969]: 2026/10/27 08:56:15 INFO Signed narinfos id=4 count=12011server # [ 34.374683] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2012server # [ 34.384532] niks3-server[969]: 2026/10/27 08:56:15 INFO Received complete push request method=POST path=/api/pushes/4/complete2013server # time=2026-10-27T08:56:15.697Z level=INFO msg="Upload complete. (167ms)"2014server # [ 34.389406] niks3-server[969]: 2026/10/27 08:56:15 INFO Completed push id=4 objects=4 duration=5.47064ms2015server # [ 34.393372] niks3-server[969]: 2026/10/27 08:56:15 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.narinfo2016server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.24 seconds)2017server: must succeed: mkdir -p /tmp/chroot-store2018server: (finished: must succeed: mkdir -p /tmp/chroot-store, in 0.02 seconds)2019server: must succeed: 2020 export AWS_ACCESS_KEY_ID=rustfsadmin2021export AWS_SECRET_ACCESS_KEY=rustfsadmin2022 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test20232024server # copying 1 paths...2025server # copying path '/nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2026server: (finished: must succeed: 2027 export AWS_ACCESS_KEY_ID=rustfsadmin2028export AWS_SECRET_ACCESS_KEY=rustfsadmin2029 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2030, in 0.15 seconds)2031server: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2032server: (finished: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2033server: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2034server # warning: 'realisation' is a deprecated alias for 'store build-trace'2035server: (finished: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2036server: must succeed: readlink /etc/niks3-test/symlink-wrapper2037server: (finished: must succeed: readlink /etc/niks3-test/symlink-wrapper, in 0.02 seconds)2038server: must succeed: readlink /etc/static/niks3-test/symlink-wrapper2039server: (finished: must succeed: readlink /etc/static/niks3-test/symlink-wrapper, in 0.02 seconds)2040server: must succeed: test -L /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper2041server: (finished: must succeed: test -L /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper, in 0.01 seconds)2042server: must succeed: readlink /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper2043server: (finished: must succeed: readlink /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper, in 0.01 seconds)2044server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper2045server # [ 34.864984] niks3-server[969]: 2026/10/27 08:56:16 INFO Received push request method=POST path=/api/pushes2046server # time=2026-10-27T08:56:16.179Z level=INFO msg="Uploading 2 paths to server (0 already cached)"2047server # time=2026-10-27T08:56:16.180Z level=INFO msg="Uploading anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper (192B)"2048server # time=2026-10-27T08:56:16.182Z level=INFO msg="Uploading hyx1mdbgysy7zx01bp948icd8f7lqb5l-base-package (536B)"2049server # [ 34.901134] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=hyx1mdbgysy7zx01bp948icd8f7lqb5l.ls2050server # [ 34.908443] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=nar/0ciy4fw6pqf4wm9m6s9r6sj7rrrv9f7aihcfh4ssw0wyj0jddxic.nar.zst2051server # [ 34.916835] niks3-server[969]: 2026/10/27 08:56:16 INFO Received sign narinfos request method=POST path=/api/pushes/5/sign2052server # time=2026-10-27T08:56:16.228Z level=INFO msg="Uploading 2 narinfos"2053server # [ 34.921934] niks3-server[969]: 2026/10/27 08:56:16 INFO Signed narinfos id=5 count=22054server # [ 34.923115] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=anw3j805qypc3rdml7kzrdr374gihkkh.ls2055server # [ 34.928164] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=nar/0820av37plmfgrxw6pcbym6phk1sv14dilyrablrnkzb7z1fd5js.nar.zst2056server # [ 34.940592] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=hyx1mdbgysy7zx01bp948icd8f7lqb5l.narinfo2057server # [ 34.946871] niks3-server[969]: 2026/10/27 08:56:16 INFO Received complete push request method=POST path=/api/pushes/5/complete2058server # time=2026-10-27T08:56:16.258Z level=INFO msg="Upload complete. (137ms)"2059server # [ 34.950438] niks3-server[969]: 2026/10/27 08:56:16 INFO Completed push id=5 objects=6 duration=5.3515ms2060server # [ 34.954636] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=anw3j805qypc3rdml7kzrdr374gihkkh.narinfo2061server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper, in 0.21 seconds)2062server: must succeed: 2063 export AWS_ACCESS_KEY_ID=rustfsadmin2064export AWS_SECRET_ACCESS_KEY=rustfsadmin2065 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper20662067server # copying 2 paths...2068server # copying path '/nix/store/hyx1mdbgysy7zx01bp948icd8f7lqb5l-base-package' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2069server # copying path '/nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2070server: (finished: must succeed: 2071 export AWS_ACCESS_KEY_ID=rustfsadmin2072export AWS_SECRET_ACCESS_KEY=rustfsadmin2073 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper2074, in 0.15 seconds)2075server: must succeed: 2076cat > /tmp/oidc-test.nix << 'EOF'2077derivation {2078 name = "oidc-test";2079 system = builtins.currentSystem;2080 builder = "/bin/sh";2081 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2082}2083EOF20842085server: (finished: must succeed: 2086cat > /tmp/oidc-test.nix << 'EOF'2087derivation {2088 name = "oidc-test";2089 system = builtins.currentSystem;2090 builder = "/bin/sh";2091 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2092}2093EOF2094, in 0.02 seconds)2095server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link2096server # this derivation will be built:2097server # /nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2098server # building '/nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv'...2099server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link, in 0.18 seconds)2100server: 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'2101server: (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)2102server: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTMwOTQ5NzYsImlhdCI6MTc5MzA5MTM3NiwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ouyIygufCUbORqwenbdkYOvcNaM9y1r8Gg-zHi9kqNR-BdTNpry2GghDTvQeF5e-wQuET_PJZ-43f4ykz48hUZ2TU3a_EdoN2fl-UZ2vX8X0tOrMZ2eH1-m7DONmaQpyR6B9hpEmi8MoZKS1md5_fO217yyfOSKy45NwQH8eiPziDlpkK4p6n7QJuC5-A500mK6Fo6lvGmO6ayW6QgK-b-L3_GCE8bwj2qikFdd4yRYWvsuxhkFES6cQgvyN93tg431udvFFHxDU6RYBwlKSsLw6EGw40nD4luZvoQ1t62LhIxCIkmLFZ1Bin80bOdB7LFH4tRa0N5WvQ4BZJX_EOg' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2103server # time=2026-10-27T08:56:16.695Z 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"2104server # [ 35.501451] niks3-server[969]: 2026/10/27 08:56:16 INFO Received push request method=POST path=/api/pushes2105server # time=2026-10-27T08:56:16.814Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2106server # time=2026-10-27T08:56:16.816Z level=INFO msg="Uploading x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test (136B)"2107server # [ 35.540252] niks3-server[969]: 2026/10/27 08:56:16 INFO Received sign narinfos request method=POST path=/api/pushes/6/sign2108server # time=2026-10-27T08:56:16.854Z level=INFO msg="Uploading 1 narinfos"2109server # [ 35.546843] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.ls2110server # [ 35.550681] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=nar/17h0qgwf5334wia961ibqy9hmpsyvfhrvj5ji9m031klp6sx4v0q.nar.zst2111server # [ 35.554056] niks3-server[969]: 2026/10/27 08:56:16 INFO Signed narinfos id=6 count=12112server # [ 35.555188] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=log/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2113server # [ 35.564342] niks3-server[969]: 2026/10/27 08:56:16 INFO Received complete push request method=POST path=/api/pushes/6/complete2114server # time=2026-10-27T08:56:16.876Z level=INFO msg="Upload complete. (127ms)"2115server # [ 35.568381] niks3-server[969]: 2026/10/27 08:56:16 INFO Completed push id=6 objects=4 duration=4.42792ms2116server # [ 35.570280] niks3-server[969]: 2026/10/27 08:56:16 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.narinfo2117server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTMwOTQ5NzYsImlhdCI6MTc5MzA5MTM3NiwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.ouyIygufCUbORqwenbdkYOvcNaM9y1r8Gg-zHi9kqNR-BdTNpry2GghDTvQeF5e-wQuET_PJZ-43f4ykz48hUZ2TU3a_EdoN2fl-UZ2vX8X0tOrMZ2eH1-m7DONmaQpyR6B9hpEmi8MoZKS1md5_fO217yyfOSKy45NwQH8eiPziDlpkK4p6n7QJuC5-A500mK6Fo6lvGmO6ayW6QgK-b-L3_GCE8bwj2qikFdd4yRYWvsuxhkFES6cQgvyN93tg431udvFFHxDU6RYBwlKSsLw6EGw40nD4luZvoQ1t62LhIxCIkmLFZ1Bin80bOdB7LFH4tRa0N5WvQ4BZJX_EOg' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test, in 0.21 seconds)2118server: must succeed: 2119cat > /tmp/oidc-test2.nix << 'EOF'2120derivation {2121 name = "oidc-test2";2122 system = builtins.currentSystem;2123 builder = "/bin/sh";2124 args = [ "-c" "echo 'OIDC test 2' > $out" ];2125}2126EOF21272128server: (finished: must succeed: 2129cat > /tmp/oidc-test2.nix << 'EOF'2130derivation {2131 name = "oidc-test2";2132 system = builtins.currentSystem;2133 builder = "/bin/sh";2134 args = [ "-c" "echo 'OIDC test 2' > $out" ];2135}2136EOF2137, in 0.02 seconds)2138server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link2139server # this derivation will be built:2140server # /nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv2141server # building '/nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv'...2142server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link, in 0.16 seconds)2143server: 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'2144server: (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.03 seconds)2145server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTMwOTQ5NzcsImlhdCI6MTc5MzA5MTM3NywiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.h3qjoITF-3JRaq7qeWiaKzzR4b-amLrX5ckhh5FJfkYrxL4aIlD3lc1MMzPbpaLvtUrukanHDSivHvOXr-aiXzozO1Vh_t9HMNY0Rz04ZieOpSguK1p56X8yAZTouszJEUMFLp1gcKa6Eg8RiXPsGaqo0a68RFAUPfIHqRZZjYVjJZFrx8p0LVGNu9oRXBTkFs3OodMnRjIUwRSVtLew511eX6RENEca_1abI5ud_6Y_XjFrqowMzuGXVCQLfz4woqWU2aPgcXOUXcqou54HcCegJzZTTVvfRGoj6LtDEykFva3akCWu6hDFrX7DuzegI45jnPvS9urfHmVHCJRdpg' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22146server # time=2026-10-27T08:56:17.119Z 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"2147server # [ 35.872415] niks3-server[969]: 2026/10/27 08:56:17 WARN Authentication failed token_preview=eyJhbGciOi...HmVHCJRdpg token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2148server # [ 35.932904] niks3-server[969]: 2026/10/27 08:56:17 WARN Authentication failed token_preview=eyJhbGciOi...HmVHCJRdpg token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2149server # time=2026-10-27T08:56:17.245Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2150server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTMwOTQ5NzcsImlhdCI6MTc5MzA5MTM3NywiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.h3qjoITF-3JRaq7qeWiaKzzR4b-amLrX5ckhh5FJfkYrxL4aIlD3lc1MMzPbpaLvtUrukanHDSivHvOXr-aiXzozO1Vh_t9HMNY0Rz04ZieOpSguK1p56X8yAZTouszJEUMFLp1gcKa6Eg8RiXPsGaqo0a68RFAUPfIHqRZZjYVjJZFrx8p0LVGNu9oRXBTkFs3OodMnRjIUwRSVtLew511eX6RENEca_1abI5ud_6Y_XjFrqowMzuGXVCQLfz4woqWU2aPgcXOUXcqou54HcCegJzZTTVvfRGoj6LtDEykFva3akCWu6hDFrX7DuzegI45jnPvS9urfHmVHCJRdpg' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.15 seconds)2151server: 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'2152server: (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.03 seconds)2153server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MzA5NDk3NywiaWF0IjoxNzkzMDkxMzc3LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.WvNrlTn4A6Rd1Ehb8GzJOfI956-T4-Gf7RtTEotNj8jIo2JQOjPEv6yxEO620ZogcWl5KvGfX5fNqqzQz-ZDuw5RqW_l9tFi5tE2vteSIBBz2ButoqiwMXe6CedQeoAG9WpRcVSoWYrJujMGZG_y9rSxBnMyJjQp0Zyp2khPeqzoRBchqf1_nm6pKtP0BDKzc23-F0NXfZMEJwj-lP4O1uKiz_AQ2d72y7-4GIFcMgragwZZKjnIlhsj3YlqMoyLLjxOwYgy8P1OY0oPNjoY5JSD2to0fjlu37ek5rw_-Gcc3GV1Y_C3l6ddb_VrijsG50nvsrjluGKWUO623UD06g' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22154server # time=2026-10-27T08:56:17.299Z 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"2155server # [ 36.059078] niks3-server[969]: 2026/10/27 08:56:17 WARN Authentication failed token_preview=eyJhbGciOi...UO623UD06g token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2156server # [ 36.141916] niks3-server[969]: 2026/10/27 08:56:17 WARN Authentication failed token_preview=eyJhbGciOi...UO623UD06g token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2157server # time=2026-10-27T08:56:17.454Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2158server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6Ikp4WVI0MWlRY3Nab09lbHBiS1ppaDNwT25NeHF0WVIybDZGRmFlcHhwZzQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MzA5NDk3NywiaWF0IjoxNzkzMDkxMzc3LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.WvNrlTn4A6Rd1Ehb8GzJOfI956-T4-Gf7RtTEotNj8jIo2JQOjPEv6yxEO620ZogcWl5KvGfX5fNqqzQz-ZDuw5RqW_l9tFi5tE2vteSIBBz2ButoqiwMXe6CedQeoAG9WpRcVSoWYrJujMGZG_y9rSxBnMyJjQp0Zyp2khPeqzoRBchqf1_nm6pKtP0BDKzc23-F0NXfZMEJwj-lP4O1uKiz_AQ2d72y7-4GIFcMgragwZZKjnIlhsj3YlqMoyLLjxOwYgy8P1OY0oPNjoY5JSD2to0fjlu37ek5rw_-Gcc3GV1Y_C3l6ddb_VrijsG50nvsrjluGKWUO623UD06g' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.18 seconds)2159server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22160server # time=2026-10-27T08:56:17.474Z 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"2161server # [ 36.220937] niks3-server[969]: 2026/10/27 08:56:17 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]2162server # [ 36.273458] niks3-server[969]: 2026/10/27 08:56:17 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]2163server # time=2026-10-27T08:56:17.585Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2164server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.13 seconds)2165server: must succeed: 2166 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins create hello-pin /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.321672168server # [ 36.351197] niks3-server[969]: 2026/10/27 08:56:17 INFO Received create pin request method=POST path=/api/pins/hello-pin2169server # time=2026-10-27T08:56:17.675Z level=INFO msg="Created pin" name=hello-pin store_path=/nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.32170server # [ 36.368676] niks3-server[969]: 2026/10/27 08:56:17 INFO Created/updated pin name=hello-pin store_path=/nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.3 narinfo_key=dnz35byzl8yw7s81gzqhdq33dds220mx.narinfo2171server: (finished: must succeed: 2172 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins create hello-pin /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.32173, in 0.09 seconds)2174server: must succeed: 2175 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list21762177server # [ 36.455311] niks3-server[969]: 2026/10/27 08:56:17 INFO Received list pins request method=GET path=/api/pins2178server: (finished: must succeed: 2179 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list2180, in 0.09 seconds)2181server: must succeed: 2182 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only21832184server # [ 36.539466] niks3-server[969]: 2026/10/27 08:56:17 INFO Received list pins request method=GET path=/api/pins2185server: (finished: must succeed: 2186 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only2187, in 0.08 seconds)2188server: must succeed: 2189 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --json21902191server # [ 36.620750] niks3-server[969]: 2026/10/27 08:56:17 INFO Received list pins request method=GET path=/api/pins2192server: (finished: must succeed: 2193 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --json2194, in 0.08 seconds)2195server: must succeed: 2196 export S3_ENDPOINT_URL=http://localhost:90002197 export AWS_ACCESS_KEY_ID=rustfsadmin2198 export AWS_SECRET_ACCESS_KEY=rustfsadmin2199 /nix/store/nrli6p16xgfrgrg8yz9ywkxd34yjvqq1-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin22002201server: (finished: must succeed: 2202 export S3_ENDPOINT_URL=http://localhost:90002203 export AWS_ACCESS_KEY_ID=rustfsadmin2204 export AWS_SECRET_ACCESS_KEY=rustfsadmin2205 /nix/store/nrli6p16xgfrgrg8yz9ywkxd34yjvqq1-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin2206, in 0.04 seconds)2207server: must succeed: 2208 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log22092210server # time=2026-10-27T08:56:18.072Z level=INFO msg="All 1 paths already cached"2211server # [ 36.764500] niks3-server[969]: 2026/10/27 08:56:18 INFO Received create pin request method=POST path=/api/pins/ca-pin2212server # time=2026-10-27T08:56:18.084Z level=INFO msg="Created pin" name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2213server # [ 36.777574] niks3-server[969]: 2026/10/27 08:56:18 INFO Created/updated pin name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log narinfo_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo2214server: (finished: must succeed: 2215 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2216, in 0.12 seconds)2217server: must succeed: 2218 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only22192220server # [ 36.865109] niks3-server[969]: 2026/10/27 08:56:18 INFO Received list pins request method=GET path=/api/pins2221server: (finished: must succeed: 2222 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only2223, in 0.08 seconds)2224server: must succeed: 2225 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins delete hello-pin22262227server # [ 36.948114] niks3-server[969]: 2026/10/27 08:56:18 INFO Received delete pin request method=DELETE path=/api/pins/hello-pin2228server # time=2026-10-27T08:56:18.285Z level=INFO msg="Deleted pin" name=hello-pin2229server # [ 36.977498] niks3-server[969]: 2026/10/27 08:56:18 INFO Deleted pin name=hello-pin2230server: (finished: must succeed: 2231 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins delete hello-pin2232, in 0.11 seconds)2233server: must succeed: 2234 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only22352236server # [ 37.055728] niks3-server[969]: 2026/10/27 08:56:18 INFO Received list pins request method=GET path=/api/pins2237server: (finished: must succeed: 2238 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins list --names-only2239, in 0.08 seconds)2240server: must fail: 2241 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent22422243server # [ 37.148571] niks3-server[969]: 2026/10/27 08:56:18 INFO Received create pin request method=POST path=/api/pins/bad-pin2244server # time=2026-10-27T08:56:18.460Z level=ERROR msg="Fatal error" error="creating pin: server returned 404: closure not found: store path must be pushed before pinning\n"2245server # [ 37.153811] niks3-server[969]: 2026/10/27 08:56:18 ERROR Failed to get closure for pin narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo error="no rows in result set"2246server: (finished: must fail: 2247 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/yvi0f3zrihx5xxm6y60k00k0hx7ddg95-niks3-1.15.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent2248, in 0.10 seconds)2249server: must succeed: systemctl start niks3-gc.service2250server # [ 37.199101] systemd[1]: Starting niks3 garbage collection...2251server # [ 37.251862] niks3[1544]: time=2026-10-27T08:56:18.560Z level=INFO msg="Starting garbage collection" older-than=720h failed-uploads-older-than=6h force=false2252server # [ 37.256920] niks3-server[969]: 2026/10/27 08:56:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures2253server # [ 37.260710] niks3-server[969]: 2026/10/27 08:56:18 INFO Aborted multipart uploads count=0 kept=02254server # [ 37.264199] niks3[1544]: time=2026-10-27T08:56:18.569Z level=INFO msg="Garbage collection started"2255server # [ 37.269815] niks3-server[969]: 2026/10/27 08:56:18 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=02256server # [ 37.275707] niks3-server[969]: 2026/10/27 08:56:18 INFO Vacuumed table table=pending_closures2257server # [ 37.279713] niks3-server[969]: 2026/10/27 08:56:18 INFO Vacuumed table table=pending_objects2258server # [ 37.283518] niks3-server[969]: 2026/10/27 08:56:18 INFO Vacuumed table table=multipart_uploads2259server # [ 37.286698] niks3-server[969]: 2026/10/27 08:56:18 INFO Vacuumed table table=closures2260server # [ 37.290135] niks3-server[969]: 2026/10/27 08:56:18 INFO Vacuumed table table=objects2261server # [ 39.262240] niks3[1544]: time=2026-10-27T08:56:20.570Z level=INFO msg="Garbage collection progress" phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=4 objects_deleted=0 objects_failed=02262server # [ 39.268099] niks3[1544]: time=2026-10-27T08:56:20.570Z 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=02263server # [ 39.276838] systemd[1]: niks3-gc.service: Deactivated successfully.2264server # [ 39.281911] systemd[1]: Finished niks3 garbage collection.2265server # [ 39.283259] systemd[1]: niks3-gc.service: Consumed 42ms CPU time over 2.080s wall clock time, 11.6M memory peak, 1.2K incoming IP traffic, 823B outgoing IP traffic.2266server: (finished: must succeed: systemctl start niks3-gc.service, in 2.14 seconds)2267builder: waiting for unit niks3-auto-upload.socket2268builder: waiting for the VM to finish booting2269builder: Guest shell says: b'Spawning backdoor root shell...\n'2270builder: connected to guest root shell2271builder: (connecting took 0.00 seconds)2272builder: (finished: waiting for the VM to finish booting, in 0.00 seconds)2273builder: (finished: waiting for unit niks3-auto-upload.socket, in 0.05 seconds)2274builder: must succeed: test -S /run/niks3/upload-to-cache.sock2275builder: (finished: must succeed: test -S /run/niks3/upload-to-cache.sock, in 0.02 seconds)2276builder: must succeed: grep post-build-hook /etc/nix/nix.conf2277builder: (finished: must succeed: grep post-build-hook /etc/nix/nix.conf, in 0.02 seconds)2278builder: must succeed: 2279cat > /tmp/test-drv.nix << 'EOF'2280derivation {2281 name = "post-build-hook-test";2282 system = builtins.currentSystem;2283 builder = "/bin/sh";2284 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2285}2286EOF22872288builder: (finished: must succeed: 2289cat > /tmp/test-drv.nix << 'EOF'2290derivation {2291 name = "post-build-hook-test";2292 system = builtins.currentSystem;2293 builder = "/bin/sh";2294 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2295}2296EOF2297, in 0.02 seconds)2298builder: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link2299builder # 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 29 ms (attempt 1/5)2300builder # 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 129 ms (attempt 2/5)2301builder # 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 291 ms (attempt 3/5)2302builder # 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 310 ms (attempt 4/5)2303builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org2304builder # this derivation will be built:2305builder # /nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2306builder # building '/nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv'...2307builder # [ 42.124194] systemd[1]: Started niks3 auto-upload daemon.2308builder # [ 42.272791] niks3-hook[793]: time=2026-10-27T08:56:22.285Z 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=0s2309builder # [ 42.279644] niks3-hook[793]: time=2026-10-27T08:56:22.292Z level=INFO msg="Upload queue status" pending=12310builder # [ 42.283724] niks3-hook[793]: time=2026-10-27T08:56:22.293Z level=INFO msg="Uploading batch" count=12311builder: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link, in 1.25 seconds)2312builder: waiting for unit niks3-auto-upload.service2313builder: (finished: waiting for unit niks3-auto-upload.service, in 0.08 seconds)2314??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2315 File "/nix/store/98jr11lrf50hv3m19d2skc60jqcifc2d-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392316builder: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive2317??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2318 File "/nix/store/98jr11lrf50hv3m19d2skc60jqcifc2d-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392319builder # [ 42.385068] systemd[1]: Started Nix Daemon.2320builder # [ 42.463561] nix-daemon[812]: accepted connection from pid 805, user root (trusted)2321builder # [ 42.478905] nix-daemon[812]: reaped child process 819, status = succeeded2322server # [ 40.838297] niks3-server[969]: 2026/10/27 08:56:22 INFO Received push request method=POST path=/api/pushes2323builder # [ 42.493722] niks3-hook[793]: time=2026-10-27T08:56:22.507Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2324builder # [ 42.496228] niks3-hook[793]: time=2026-10-27T08:56:22.508Z level=INFO msg="Uploading 1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test (144B)"2325server # [ 40.892423] niks3-server[969]: 2026/10/27 08:56:22 INFO Registered completed upload object_key=nar/1a0vfw93shmvlz6lac7d1lv82jxzfdswigh5s32hpvncf74i1i0y.nar.zst2326builder # [ 42.546473] niks3-hook[793]: time=2026-10-27T08:56:22.558Z level=INFO msg="Uploading 1 narinfos"2327server # [ 40.903875] niks3-server[969]: 2026/10/27 08:56:22 INFO Received sign narinfos request method=POST path=/api/pushes/7/sign2328server # [ 40.912146] niks3-server[969]: 2026/10/27 08:56:22 INFO Signed narinfos id=7 count=12329server # [ 40.914007] niks3-server[969]: 2026/10/27 08:56:22 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.ls2330server # [ 40.918615] niks3-server[969]: 2026/10/27 08:56:22 INFO Registered completed upload object_key=log/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2331server # [ 40.929614] niks3-server[969]: 2026/10/27 08:56:22 INFO Received complete push request method=POST path=/api/pushes/7/complete2332server # [ 40.934242] niks3-server[969]: 2026/10/27 08:56:22 INFO Completed push id=7 objects=4 duration=7.10794ms2333builder # [ 42.581481] niks3-hook[793]: time=2026-10-27T08:56:22.594Z level=INFO msg="Upload complete. (301ms)"2334server # [ 40.936780] niks3-server[969]: 2026/10/27 08:56:22 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.narinfo2335builder # [ 47.280811] niks3-hook[793]: time=2026-10-27T08:56:27.293Z level=INFO msg="Idle timeout reached and queue is empty, shutting down"2336builder # [ 47.284302] niks3-hook[793]: time=2026-10-27T08:56:27.294Z level=INFO msg="niks3-hook serve stopped"2337builder # [ 47.295524] systemd[1]: niks3-auto-upload.service: Deactivated successfully.2338builder # [ 47.302980] systemd[1]: niks3-auto-upload.service: Consumed 183ms CPU time over 5.175s wall clock time, 31.6M memory peak, 68K written to disk, 5.9K incoming IP traffic, 8.9K outgoing IP traffic.2339builder: (finished: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive, in 5.22 seconds)2340server: must succeed: 2341 export AWS_ACCESS_KEY_ID=rustfsadmin2342export AWS_SECRET_ACCESS_KEY=rustfsadmin2343 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/hook-test-store /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test23442345server # copying 1 paths...2346server # copying path '/nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2347server: (finished: must succeed: 2348 export AWS_ACCESS_KEY_ID=rustfsadmin2349export AWS_SECRET_ACCESS_KEY=rustfsadmin2350 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/hook-test-store /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2351, in 0.18 seconds)2352server: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2353server: (finished: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test, in 0.06 seconds)2354(finished: run the VM test script, in 50.86 seconds)2355test script finished in 51.13s2356cleanup2357kill QemuMachine (pid 47)2358builder # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lq2fsnmg0q3y0vlxn91w8s8wvj1m6fld-python3-3.14.8/bin/python3.14)2359builder # [2026-10-27T08:56:27Z INFO virtiofsd] Client disconnected, shutting down2360builder # [2026-10-27T08:56:27Z INFO virtiofsd] Client disconnected, shutting down2361builder # [2026-10-27T08:56:27Z INFO virtiofsd] Client disconnected, shutting down2362kill QemuMachine (pid 48)2363server # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/lq2fsnmg0q3y0vlxn91w8s8wvj1m6fld-python3-3.14.8/bin/python3.14)2364server # [2026-10-27T08:56:28Z INFO virtiofsd] Client disconnected, shutting down2365server # [2026-10-27T08:56:28Z INFO virtiofsd] Client disconnected, shutting down2366server # [2026-10-27T08:56:28Z INFO virtiofsd] Client disconnected, shutting down2367(finished: cleanup, in 0.70 seconds)2368additionally exposed symbols:2369 builder, server,2370 vlan1,2371 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_ssh2372Hello store path: /nix/store/dnz35byzl8yw7s81gzqhdq33dds220mx-hello-2.12.32373Test output path: /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2374CA derivation output path: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2375Realisation info in chroot store: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test23762377Symlink wrapper store path: /nix/store/anw3j805qypc3rdml7kzrdr374gihkkh-symlink-wrapper2378Symlink wrapper points to: /nix/store/hyx1mdbgysy7zx01bp948icd8f7lqb5l-base-package/bin/test-program2379OIDC test store path: /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2380Valid OIDC token obtained (length=677)2381OIDC push with valid token: SUCCESS2382Invalid OIDC token obtained (wrong org)2383OIDC push with wrong org: correctly rejected2384Wrong audience OIDC token obtained2385OIDC push with wrong audience: correctly rejected2386OIDC push with malformed token: correctly rejected2387All OIDC tests passed!2388All pin tests passed!2389Built store path: /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2390Post-build-hook pipeline test passed!