vm-test-run-nixos-test-niks3
checks.aarch64-linux.nixos-test-niks3
· build #413
· raw
1tribuchet: building on eliza2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Test will time out and terminate in 3600.0 seconds6run the VM test script7start all VMs8builder: starting vm9server: starting vm10server # Disk image does not exist, creating the virtualisation disk image...11server: QEMU running (pid 48)12server # Formatting '/build/vm-state-server/tmp.shl5IFpdAe', fmt=raw size=107374182413builder: QEMU running (pid 47)14builder # Disk image does not exist, creating the virtualisation disk image...15server # mke2fs 1.47.4 (6-Mar-2025)16builder # Formatting '/build/vm-state-builder/tmp.5N879VDPi3', fmt=raw size=107374182417server # Discarding device blocks: 0/262144 done18builder # mke2fs 1.47.4 (6-Mar-2025)19server # Creating filesystem with 262144 4k blocks and 65536 inodes20builder # Discarding device blocks: 0/262144 done21server # Filesystem UUID: 3af48fb1-0728-41cf-9ce8-33b9cc4d4ace22builder # Creating filesystem with 262144 4k blocks and 65536 inodes23server # Superblock backups stored on blocks:24builder # Filesystem UUID: ab25607d-f86a-427f-b200-15cacfd88c4525server # 32768, 98304, 163840, 22937626builder # Superblock backups stored on blocks:27server # 28builder # 32768, 98304, 163840, 22937629server # Allocating group tables: 0/8 done30builder # 31server # Writing inode tables: 0/8 done32builder # Allocating group tables: 0/8 done33server # Creating journal (8192 blocks): done34builder # Writing inode tables: 0/8 done35server # Writing superblocks and filesystem accounting information: 0/8 done36builder # Creating journal (8192 blocks): done37server # 38builder # Writing superblocks and filesystem accounting information: 0/8 done39server # Virtualisation disk image created.40builder # 41server # Starting virtiofs daemons...42builder # Virtualisation disk image created.43server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)44builder # Starting virtiofs daemons...45server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether46builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)47server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)48builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether49server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether50builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)51server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)52builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether53server # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether54builder # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...55server # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...56builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)57server # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...58builder # [2026-10-14T16:42:16Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether59server # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...60builder # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...61server # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests62builder # [2026-10-14T16:42:16Z INFO virtiofsd] Waiting for vhost-user socket connection...63server # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests64builder # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests65server # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests66builder # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests67(finished: start all VMs, in 0.33 seconds)68builder # [2026-10-14T16:42:16Z INFO virtiofsd] Client connected, servicing requests69server: waiting for unit postgresql.service70server: waiting for the VM to finish booting71server # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]72builder # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]73server # [ 0.000000] Linux version 6.18.55 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Sat Oct 3 10:39:03 UTC 202674server # [ 0.000000] KASLR enabled75server # [ 0.000000] random: crng init done76builder # [ 0.000000] Linux version 6.18.55 (nixbld@localhost) (gcc (GCC) 16.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Sat Oct 3 10:39:03 UTC 202677server # [ 0.000000] Machine model: linux,dummy-virt78builder # [ 0.000000] KASLR enabled79server # [ 0.000000] efi: UEFI not found.80builder # [ 0.000000] random: crng init done81builder # [ 0.000000] Machine model: linux,dummy-virt82server # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT83builder # [ 0.000000] efi: UEFI not found.84server # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]85builder # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT86server # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]87server # [ 0.000000] Zone ranges:88builder # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]89server # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]90builder # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fded700-0x7fdf0e7f]91server # [ 0.000000] DMA32 empty92builder # [ 0.000000] Zone ranges:93server # [ 0.000000] Normal empty94server # [ 0.000000] Device empty95builder # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]96builder # [ 0.000000] DMA32 empty97server # [ 0.000000] Movable zone start for each node98builder # [ 0.000000] Normal empty99server # [ 0.000000] Early memory node ranges100builder # [ 0.000000] Device empty101server # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]102builder # [ 0.000000] Movable zone start for each node103builder # [ 0.000000] Early memory node ranges104server # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]105builder # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]106server # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc00000107server # [ 0.000000] psci: probing for conduit method from DT.108builder # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]109server # [ 0.000000] psci: PSCIv1.3 detected in firmware.110builder # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc00000111server # [ 0.000000] psci: Using standard PSCI v0.2 function IDs112builder # [ 0.000000] psci: probing for conduit method from DT.113server # [ 0.000000] psci: Trusted OS migration not required114builder # [ 0.000000] psci: PSCIv1.3 detected in firmware.115server # [ 0.000000] psci: SMC Calling Convention v1.1116builder # [ 0.000000] psci: Using standard PSCI v0.2 function IDs117builder # [ 0.000000] psci: Trusted OS migration not required118server # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)119builder # [ 0.000000] psci: SMC Calling Convention v1.1120server # [ 0.000000] percpu: Embedded 76 pages/cpu s186840 r8192 d116264 u311296121server # [ 0.000000] Detected PIPT I-cache on CPU0122builder # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)123builder # [ 0.000000] percpu: Embedded 76 pages/cpu s186840 r8192 d116264 u311296124server # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)125builder # [ 0.000000] Detected PIPT I-cache on CPU0126server # [ 0.000000] CPU features: detected: GICv3 CPU interface127server # [ 0.000000] CPU features: detected: Spectre-v4128builder # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)129server # [ 0.000000] CPU features: detected: Spectre-BHB130builder # [ 0.000000] CPU features: detected: GICv3 CPU interface131server # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38132builder # [ 0.000000] CPU features: detected: Spectre-v4133builder # [ 0.000000] CPU features: detected: Spectre-BHB134server # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23135server # [ 0.000000] alternatives: applying boot alternatives136builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38137builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23138builder # [ 0.000000] alternatives: applying boot alternatives139server # [ 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/q8qiyj31z8l99r31gviy629hz4v9x5lm-nixos-system-server-test/init regInfo=/nix/.ro-store/yf4hqml7wzmn69ijcsn4gi7wfv4az1n8-closure-info/registration console=ttyAMA0,115200n8 console=tty0140server # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/yf4hqml7wzmn69ijcsn4gi7wfv4az1n8-closure-info/registration", will be passed to user space.141builder # [ 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/a511rgwk5wqsa9372xhk13cvvh99synz-nixos-system-builder-test/init regInfo=/nix/.ro-store/lf53ky5q1cpz9vlma8bj68fn06r20yzd-closure-info/registration console=ttyAMA0,115200n8 console=tty0142server # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes143server # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)144builder # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/lf53ky5q1cpz9vlma8bj68fn06r20yzd-closure-info/registration", will be passed to user space.145server # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)146builder # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes147server # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB148builder # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)149server # [ 0.000000] software IO TLB: area num 1.150builder # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)151server # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)152builder # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB153server # [ 0.000000] Fallback order for Node 0: 0154builder # [ 0.000000] software IO TLB: area num 1.155server # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 262144156server # [ 0.000000] Policy zone: DMA157builder # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)158builder # [ 0.000000] Fallback order for Node 0: 0159server # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off160builder # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 262144161server # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1162builder # [ 0.000000] Policy zone: DMA163server # [ 0.000000] allocated 2097152 bytes of page_ext164builder # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off165server # [ 0.000000] ftrace: allocating 75039 entries in 294 pages166builder # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1167server # [ 0.000000] ftrace: allocated 294 pages with 4 groups168builder # [ 0.000000] allocated 2097152 bytes of page_ext169server # [ 0.000000] rcu: Hierarchical RCU implementation.170builder # [ 0.000000] ftrace: allocating 75039 entries in 294 pages171server # [ 0.000000] rcu: RCU event tracing is enabled.172builder # [ 0.000000] ftrace: allocated 294 pages with 4 groups173server # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.174builder # [ 0.000000] rcu: Hierarchical RCU implementation.175server # [ 0.000000] Trampoline variant of Tasks RCU enabled.176builder # [ 0.000000] rcu: RCU event tracing is enabled.177server # [ 0.000000] Rude variant of Tasks RCU enabled.178builder # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.179server # [ 0.000000] Tracing variant of Tasks RCU enabled.180builder # [ 0.000000] Trampoline variant of Tasks RCU enabled.181server # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.182builder # [ 0.000000] Rude variant of Tasks RCU enabled.183server # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1184builder # [ 0.000000] Tracing variant of Tasks RCU enabled.185builder # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.186server # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.187builder # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1188server # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.189builder # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.190server # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.191server # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0192builder # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.193server # [ 0.000000] GICv3: 256 SPIs implemented194server # [ 0.000000] GICv3: 0 Extended SPIs implemented195builder # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.196server # [ 0.000000] Root IRQ handler: gic_handle_irq197builder # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0198server # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI199builder # [ 0.000000] GICv3: 256 SPIs implemented200server # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0201builder # [ 0.000000] GICv3: 0 Extended SPIs implemented202builder # [ 0.000000] Root IRQ handler: gic_handle_irq203server # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000204server # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]205builder # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI206builder # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0207server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44cf0000 (indirect, esz 8, psz 64K, shr 1)208builder # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000209builder # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]210server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44d00000 (flat, esz 8, psz 64K, shr 1)211server # [ 0.000000] GICv3: using LPI property table @0x0000000044d10000212builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44ce0000 (indirect, esz 8, psz 64K, shr 1)213server # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000214builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44cf0000 (flat, esz 8, psz 64K, shr 1)215server # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.216builder # [ 0.000000] GICv3: using LPI property table @0x0000000044d10000217server # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns218builder # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000219server # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).220builder # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.221server # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns222builder # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns223builder # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).224server # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns225server # [ 0.000030] arm-pv: using stolen time PV226builder # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns227server # [ 0.000394] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)228builder # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns229server # [ 0.000573] Console: colour dummy device 80x25230builder # [ 0.000032] arm-pv: using stolen time PV231server # [ 0.000581] printk: legacy console [tty0] enabled232builder # [ 0.000491] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)233server # [ 0.000771] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)234builder # [ 0.000713] Console: colour dummy device 80x25235server # [ 0.000778] pid_max: default: 32768 minimum: 301236builder # [ 0.000721] printk: legacy console [tty0] enabled237server # [ 0.000851] LSM: initializing lsm=capability,landlock,yama,bpf,ima238server # [ 0.000977] landlock: Up and running.239server # [ 0.000980] Yama: becoming mindful.240builder # [ 0.000913] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)241server # [ 0.001486] LSM support for eBPF active242builder # [ 0.000920] pid_max: default: 32768 minimum: 301243builder # [ 0.001001] LSM: initializing lsm=capability,landlock,yama,bpf,ima244server # [ 0.001630] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)245builder # [ 0.001139] landlock: Up and running.246builder # [ 0.001142] Yama: becoming mindful.247server # [ 0.001649] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)248builder # [ 0.001615] LSM support for eBPF active249server # [ 0.003492] rcu: Hierarchical SRCU implementation.250server # [ 0.003498] rcu: Max phase no-delay instances is 1000.251builder # [ 0.001725] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)252server # [ 0.004761] fsl-mc MSI: its@8080000 domain created253builder # [ 0.001745] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)254server # [ 0.004884] EFI services will not be available.255builder # [ 0.003623] rcu: Hierarchical SRCU implementation.256server # [ 0.004976] smp: Bringing up secondary CPUs ...257server # [ 0.004985] smp: Brought up 1 node, 1 CPU258builder # [ 0.003629] rcu: Max phase no-delay instances is 1000.259server # [ 0.004989] SMP: Total of 1 processors activated.260builder # [ 0.004985] fsl-mc MSI: its@8080000 domain created261server # [ 0.004991] CPU: All CPU(s) started at EL1262builder # [ 0.005110] EFI services will not be available.263server # [ 0.005001] CPU features: detected: Branch Target Identification264builder # [ 0.005197] smp: Bringing up secondary CPUs ...265builder # [ 0.005206] smp: Brought up 1 node, 1 CPU266server # [ 0.005009] CPU features: detected: ARMv8.4 Translation Table Level267builder # [ 0.005209] SMP: Total of 1 processors activated.268builder # [ 0.005212] CPU: All CPU(s) started at EL1269server # [ 0.005013] CPU features: detected: Instruction cache invalidation not required for I/D coherence270builder # [ 0.005222] CPU features: detected: Branch Target Identification271server # [ 0.005016] CPU features: detected: Data cache clean to the PoU not required for I/D coherence272builder # [ 0.005230] CPU features: detected: ARMv8.4 Translation Table Level273server # [ 0.005021] CPU features: detected: Common not Private translations274server # [ 0.005024] CPU features: detected: CRC32 instructions275builder # [ 0.005233] CPU features: detected: Instruction cache invalidation not required for I/D coherence276server # [ 0.005027] CPU features: detected: Data cache clean to Point of Deep Persistence277builder # [ 0.005237] CPU features: detected: Data cache clean to the PoU not required for I/D coherence278server # [ 0.005030] CPU features: detected: Data cache clean to Point of Persistence279builder # [ 0.005241] CPU features: detected: Common not Private translations280builder # [ 0.005244] CPU features: detected: CRC32 instructions281server # [ 0.005033] CPU features: detected: Data independent timing control (DIT)282server # [ 0.005036] CPU features: detected: E0PD283builder # [ 0.005247] CPU features: detected: Data cache clean to Point of Deep Persistence284server # [ 0.005038] CPU features: detected: Enhanced Counter Virtualization285builder # [ 0.005251] CPU features: detected: Data cache clean to Point of Persistence286server # [ 0.005042] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)287builder # [ 0.005254] CPU features: detected: Data independent timing control (DIT)288server # [ 0.005046] CPU features: detected: Enhanced Virtualization Traps289builder # [ 0.005257] CPU features: detected: E0PD290server # [ 0.005048] CPU features: detected: Fine Grained Traps291builder # [ 0.005259] CPU features: detected: Enhanced Counter Virtualization292server # [ 0.005052] CPU features: detected: Generic authentication (architected QARMA5 algorithm)293builder # [ 0.005262] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)294server # [ 0.005057] CPU features: detected: RCpc load-acquire (LDAPR)295builder # [ 0.005266] CPU features: detected: Enhanced Virtualization Traps296server # [ 0.005059] CPU features: detected: LSE atomic instructions297builder # [ 0.005269] CPU features: detected: Fine Grained Traps298server # [ 0.005062] CPU features: detected: Privileged Access Never299server # [ 0.005065] CPU features: detected: PMUv3300builder # [ 0.005273] CPU features: detected: Generic authentication (architected QARMA5 algorithm)301server # [ 0.005067] CPU features: detected: RAS Extension Support302builder # [ 0.005277] CPU features: detected: RCpc load-acquire (LDAPR)303server # [ 0.005070] CPU features: detected: RASv1p1 Extension Support304builder # [ 0.005280] CPU features: detected: LSE atomic instructions305server # [ 0.005073] CPU features: detected: Random Number Generator306builder # [ 0.005283] CPU features: detected: Privileged Access Never307builder # [ 0.005286] CPU features: detected: PMUv3308builder # [ 0.005289] CPU features: detected: RAS Extension Support309server # [ 0.005076] CPU features: detected: Speculation barrier (SB)310server # [ 0.005078] CPU features: detected: Stage-2 Force Write-Back311builder # [ 0.005292] CPU features: detected: RASv1p1 Extension Support312server # [ 0.005081] CPU features: detected: TLB range maintenance instructions313builder # [ 0.005295] CPU features: detected: Random Number Generator314server # [ 0.005086] CPU features: detected: Speculative Store Bypassing Safe (SSBS)315builder # [ 0.005297] CPU features: detected: Speculation barrier (SB)316server # [ 0.005124] alternatives: applying system-wide alternatives317builder # [ 0.005300] CPU features: detected: Stage-2 Force Write-Back318server # [ 0.008082] CPU features: detected: BBM Level 2 without TLB conflict abort319builder # [ 0.005303] CPU features: detected: TLB range maintenance instructions320builder # [ 0.005307] CPU features: detected: Speculative Store Bypassing Safe (SSBS)321server # [ 0.008286] Memory: 893052K/1048576K available (24576K kernel code, 7094K rwdata, 26568K rodata, 4736K init, 1106K bss, 114176K reserved, 32768K cma-reserved)322builder # [ 0.005344] alternatives: applying system-wide alternatives323server # [ 0.008666] devtmpfs: initialized324builder # [ 0.008303] CPU features: detected: BBM Level 2 without TLB conflict abort325server # [ 0.010438] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)326server # [ 0.010466] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).327builder # [ 0.008489] Memory: 893060K/1048576K available (24576K kernel code, 7094K rwdata, 26568K rodata, 4736K init, 1106K bss, 114188K reserved, 32768K cma-reserved)328builder # [ 0.008857] devtmpfs: initialized329server # [ 0.010658] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL330server # [ 0.010666] 0 pages in range for non-PLT usage331builder # [ 0.010529] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)332server # [ 0.010668] 508192 pages in range for PLT usage333server # [ 0.010771] pinctrl core: initialized pinctrl subsystem334builder # [ 0.010557] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).335server # [ 0.011544] DMI not present or invalid.336builder # [ 0.010754] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL337server # [ 0.014898] NET: Registered PF_NETLINK/PF_ROUTE protocol family338builder # [ 0.010763] 0 pages in range for non-PLT usage339builder # [ 0.010764] 508192 pages in range for PLT usage340server # [ 0.017260] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations341builder # [ 0.010868] pinctrl core: initialized pinctrl subsystem342server # [ 0.017397] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations343builder # [ 0.011694] DMI not present or invalid.344builder # [ 0.014914] NET: Registered PF_NETLINK/PF_ROUTE protocol family345server # [ 0.017560] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations346server # [ 0.017581] audit: initializing netlink subsys (disabled)347builder # [ 0.017231] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations348server # [ 0.018157] thermal_sys: Registered thermal governor 'fair_share'349builder # [ 0.017377] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations350server # [ 0.018159] thermal_sys: Registered thermal governor 'bang_bang'351builder # [ 0.017531] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations352server # [ 0.018162] thermal_sys: Registered thermal governor 'step_wise'353builder # [ 0.017551] audit: initializing netlink subsys (disabled)354server # [ 0.018165] thermal_sys: Registered thermal governor 'user_space'355builder # [ 0.018121] thermal_sys: Registered thermal governor 'fair_share'356server # [ 0.018168] thermal_sys: Registered thermal governor 'power_allocator'357builder # [ 0.018123] thermal_sys: Registered thermal governor 'bang_bang'358server # [ 0.018204] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1359builder # [ 0.018126] thermal_sys: Registered thermal governor 'step_wise'360server # [ 0.018213] cpuidle: using governor ladder361builder # [ 0.018129] thermal_sys: Registered thermal governor 'user_space'362server # [ 0.018220] cpuidle: using governor menu363builder # [ 0.018132] thermal_sys: Registered thermal governor 'power_allocator'364server # [ 0.018399] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.365server # [ 0.018416] ASID allocator initialised with 65536 entries366builder # [ 0.018167] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1367server # [ 0.019647] Serial: AMBA PL011 UART driver368builder # [ 0.018176] cpuidle: using governor ladder369builder # [ 0.018182] cpuidle: using governor menu370server # [ 0.025253] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1371server # [ 0.025417] printk: console [ttyAMA0] enabled372builder # [ 0.018381] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.373builder # [ 0.018396] ASID allocator initialised with 65536 entries374builder # [ 0.019675] Serial: AMBA PL011 UART driver375builder # [ 0.025554] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1376builder # [ 0.025681] printk: console [ttyAMA0] enabled377server # [ 0.155329] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages378server # [ 0.155337] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page379server # [ 0.155341] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages380builder # [ 0.157415] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages381server # [ 0.155344] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page382builder # [ 0.157423] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page383server # [ 0.155346] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages384builder # [ 0.157427] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages385server # [ 0.155349] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page386builder # [ 0.157430] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page387server # [ 0.155352] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages388builder # [ 0.157432] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages389server # [ 0.155354] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page390server # [ 0.156735] fbcon: Taking over console391builder # [ 0.157435] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page392server # [ 0.156744] ACPI: Interpreter disabled.393builder # [ 0.157438] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages394server # [ 0.157787] iommu: Default domain type: Translated395builder # [ 0.157441] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page396server # [ 0.157791] iommu: DMA domain TLB invalidation policy: strict mode397builder # [ 0.158684] fbcon: Taking over console398server # [ 0.158156] SCSI subsystem initialized399builder # [ 0.158692] ACPI: Interpreter disabled.400builder # [ 0.159687] iommu: Default domain type: Translated401builder # [ 0.159691] iommu: DMA domain TLB invalidation policy: strict mode402builder # [ 0.160027] SCSI subsystem initialized403builder # [ 0.160199] usbcore: registered new interface driver usbfs404server # [ 0.168953] usbcore: registered new interface driver usbfs405builder # [ 0.160229] usbcore: registered new interface driver hub406server # [ 0.168984] usbcore: registered new interface driver hub407builder # [ 0.160245] usbcore: registered new device driver usb408server # [ 0.169001] usbcore: registered new device driver usb409server # [ 0.169303] pps_core: LinuxPPS API ver. 1 registered410builder # [ 0.172263] pps_core: LinuxPPS API ver. 1 registered411server # [ 0.169307] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>412builder # [ 0.172268] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>413server # [ 0.169315] PTP clock support registered414builder # [ 0.172276] PTP clock support registered415server # [ 0.169364] EDAC MC: Ver: 3.0.0416builder # [ 0.172327] EDAC MC: Ver: 3.0.0417server # [ 0.169520] scmi_core: SCMI protocol bus registered418builder # [ 0.172484] scmi_core: SCMI protocol bus registered419server # [ 0.169883] FPGA manager framework420builder # [ 0.176338] FPGA manager framework421server # [ 0.177353] vgaarb: loaded422server # [ 0.177665] clocksource: Switched to clocksource arch_sys_counter423server # [ 0.184945] VFS: Disk quotas dquot_6.6.0424server # [ 0.184970] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)425server # [ 0.187256] netfs: FS-Cache loaded426builder # [ 0.184966] vgaarb: loaded427server # [ 0.187388] pnp: PnP ACPI: disabled428builder # [ 0.185226] clocksource: Switched to clocksource arch_sys_counter429builder # [ 0.185847] VFS: Disk quotas dquot_6.6.0430builder # [ 0.185869] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)431builder # [ 0.186139] netfs: FS-Cache loaded432builder # [ 0.186240] pnp: PnP ACPI: disabled433server # [ 0.192969] NET: Registered PF_INET protocol family434server # [ 0.193116] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)435builder # [ 0.194826] NET: Registered PF_INET protocol family436builder # [ 0.194989] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)437server # [ 0.222245] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)438server # [ 0.222277] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)439server # [ 0.222297] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)440server # [ 0.222337] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)441server # [ 0.222409] TCP: Hash tables configured (established 8192 bind 8192)442server # [ 0.222511] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)443server # [ 0.222578] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)444server # [ 0.222601] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)445server # [ 0.222687] NET: Registered PF_UNIX/PF_LOCAL protocol family446server # [ 0.222709] NET: Registered PF_XDP protocol family447server # [ 0.222725] PCI: CLS 0 bytes, default 64448builder # [ 0.224510] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)449server # [ 0.223082] Trying to unpack rootfs image as initramfs...450builder # [ 0.224547] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)451builder # [ 0.224568] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)452builder # [ 0.224605] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)453server # [ 0.235910] kvm [1]: HYP mode not available454builder # [ 0.224688] TCP: Hash tables configured (established 8192 bind 8192)455builder # [ 0.224801] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)456builder # [ 0.224831] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)457builder # [ 0.224877] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)458builder # [ 0.224961] NET: Registered PF_UNIX/PF_LOCAL protocol family459builder # [ 0.224991] NET: Registered PF_XDP protocol family460builder # [ 0.225007] PCI: CLS 0 bytes, default 64461builder # [ 0.225272] Trying to unpack rootfs image as initramfs...462builder # [ 0.243361] kvm [1]: HYP mode not available463server # [ 0.328164] Initialise system trusted keyrings464server # [ 0.328304] workingset: timestamp_bits=42 max_order=18 bucket_order=0465server # [ 0.328724] squashfs: version 4.0 (2009/01/31) Phillip Lougher466server # [ 0.328774] 9p: Installing v9fs 9p2000 file system support467builder # [ 0.333804] Initialise system trusted keyrings468builder # [ 0.333919] workingset: timestamp_bits=42 max_order=18 bucket_order=0469builder # [ 0.334294] squashfs: version 4.0 (2009/01/31) Phillip Lougher470builder # [ 0.334356] 9p: Installing v9fs 9p2000 file system support471server # [ 0.351763] Key type asymmetric registered472server # [ 0.351777] Asymmetric key parser 'x509' registered473server # [ 0.351839] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)474server # [ 0.361713] io scheduler mq-deadline registered475builder # [ 0.362410] Key type asymmetric registered476server # [ 0.361723] io scheduler kyber registered477builder # [ 0.362425] Asymmetric key parser 'x509' registered478builder # [ 0.362487] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)479builder # [ 0.362597] io scheduler mq-deadline registered480builder # [ 0.362602] io scheduler kyber registered481server # [ 0.373970] pl061_gpio 9030000.pl061: PL061 GPIO chip registered482builder # [ 0.375003] pl061_gpio 9030000.pl061: PL061 GPIO chip registered483server # [ 0.374595] ledtrig-cpu: registered to indicate activity on CPUs484builder # [ 0.375588] ledtrig-cpu: registered to indicate activity on CPUs485server # [ 0.374959] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:486builder # [ 0.375948] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:487server # [ 0.374973] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000488builder # [ 0.375961] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000489server # [ 0.374982] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000490builder # [ 0.375971] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000491server # [ 0.374989] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000492builder # [ 0.375977] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000493server # [ 0.375007] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits494builder # [ 0.375996] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits495server # [ 0.375031] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]496builder # [ 0.376015] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]497server # [ 0.375103] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00498builder # [ 0.376084] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00499server # [ 0.375110] pci_bus 0000:00: root bus resource [bus 00-ff]500builder # [ 0.376091] pci_bus 0000:00: root bus resource [bus 00-ff]501server # [ 0.375114] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]502builder # [ 0.376095] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]503server # [ 0.375118] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]504builder # [ 0.376098] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]505server # [ 0.375121] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]506builder # [ 0.376101] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]507server # [ 0.375177] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint508builder # [ 0.376158] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint509server # [ 0.375628] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint510builder # [ 0.376618] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint511server # [ 0.375818] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]512builder # [ 0.376841] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]513server # [ 0.375830] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]514builder # [ 0.376854] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]515server # [ 0.375857] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]516builder # [ 0.376882] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]517server # [ 0.375869] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]518builder # [ 0.376894] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]519server # [ 0.376338] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint520server # [ 0.376524] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]521server # [ 0.376536] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]522server # [ 0.376562] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]523server # [ 0.377029] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint524server # [ 0.377215] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]525server # [ 0.377227] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]526server # [ 0.377253] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]527server # [ 0.402113] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint528builder # [ 0.401450] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint529server # [ 0.402300] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]530builder # [ 0.401654] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]531server # [ 0.402312] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]532builder # [ 0.401667] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]533server # [ 0.402338] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]534builder # [ 0.401694] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]535server # [ 0.402351] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]536builder # [ 0.402204] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint537server # [ 0.402837] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint538builder # [ 0.402397] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]539server # [ 0.403030] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]540builder # [ 0.402408] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]541server # [ 0.403056] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]542builder # [ 0.402435] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]543server # [ 0.403522] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint544builder # [ 0.402927] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint545server # [ 0.403711] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]546builder # [ 0.403119] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]547server # [ 0.403737] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]548builder # [ 0.403130] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]549server # [ 0.404161] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint550builder # [ 0.403157] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]551server # [ 0.404350] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]552builder # [ 0.403170] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]553server # [ 0.404609] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint554builder # [ 0.403678] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint555server # [ 0.404798] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]556builder # [ 0.403879] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]557server # [ 0.404824] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]558builder # [ 0.403906] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]559server # [ 0.405294] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint560builder # [ 0.404413] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint561server # [ 0.405486] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]562builder # [ 0.404611] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]563server # [ 0.405565] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]564builder # [ 0.404638] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]565builder # [ 0.405128] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint566builder # [ 0.422967] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]567builder # [ 0.423248] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint568builder # [ 0.423445] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]569builder # [ 0.423472] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]570builder # [ 0.423963] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint571builder # [ 0.424159] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]572builder # [ 0.424186] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]573builder # [ 0.424688] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint574builder # [ 0.424884] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]575server # [ 0.430150] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint576builder # [ 0.424911] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]577server # [ 0.430351] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]578server # [ 0.430378] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]579server # [ 0.430858] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint580server # [ 0.431102] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]581server # [ 0.431114] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]582server # [ 0.431141] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]583server # [ 0.431611] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint584server # [ 0.431803] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]585server # [ 0.431815] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]586server # [ 0.431841] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]587server # [ 0.432468] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned588server # [ 0.432475] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned589server # [ 0.432478] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned590server # [ 0.432524] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned591builder # [ 0.441524] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint592builder # [ 0.441796] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]593server # [ 0.432570] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned594builder # [ 0.441809] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]595server # [ 0.432615] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned596builder # [ 0.441836] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]597server # [ 0.432660] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned598builder # [ 0.442348] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint599server # [ 0.432705] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned600builder # [ 0.442540] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]601server # [ 0.432751] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned602builder # [ 0.442552] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]603builder # [ 0.442578] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]604server # [ 0.432795] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned605builder # [ 0.443216] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned606server # [ 0.432840] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned607builder # [ 0.443222] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned608server # [ 0.432884] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned609builder # [ 0.443225] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned610server # [ 0.432951] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned611server # [ 0.432998] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned612builder # [ 0.443271] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned613server # [ 0.433016] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned614builder # [ 0.443315] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned615server # [ 0.433033] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned616builder # [ 0.443361] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned617server # [ 0.433051] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned618builder # [ 0.443406] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned619server # [ 0.433069] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned620server # [ 0.433087] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned621builder # [ 0.443451] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned622server # [ 0.433105] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned623builder # [ 0.443497] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned624server # [ 0.433124] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned625builder # [ 0.443543] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned626server # [ 0.433142] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned627builder # [ 0.443588] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned628server # [ 0.433163] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned629builder # [ 0.443632] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned630server # [ 0.433182] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned631server # [ 0.433200] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned632builder # [ 0.443699] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned633server # [ 0.433218] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned634builder # [ 0.443742] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned635server # [ 0.433236] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned636builder # [ 0.443760] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned637server # [ 0.433253] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned638builder # [ 0.443778] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned639server # [ 0.433270] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned640builder # [ 0.443796] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned641server # [ 0.433288] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned642builder # [ 0.443814] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned643server # [ 0.433305] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned644builder # [ 0.443832] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned645server # [ 0.433328] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]646builder # [ 0.443851] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned647server # [ 0.433333] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]648server # [ 0.433336] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]649builder # [ 0.443870] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned650builder # [ 0.443888] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned651builder # [ 0.443910] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned652builder # [ 0.443929] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned653builder # [ 0.443948] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned654builder # [ 0.443966] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned655server # [ 0.474075] pci 0000:00:07.0: enabling device (0000 -> 0002)656builder # [ 0.443984] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned657builder # [ 0.444002] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned658builder # [ 0.444019] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned659builder # [ 0.444037] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned660builder # [ 0.444055] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned661builder # [ 0.444077] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]662builder # [ 0.444082] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]663builder # [ 0.444085] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]664builder # [ 0.445046] pci 0000:00:07.0: enabling device (0000 -> 0002)665builder # [ 0.484035] pci 0000:00:07.0: quirk_usb_early_handoff+0x0/0xa60 took 38082 usecs666server # [ 0.504507] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)667server # [ 0.507407] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)668builder # [ 0.505359] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)669server # [ 0.509302] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)670builder # [ 0.507383] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)671server # [ 0.519063] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)672builder # [ 0.517489] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)673server # [ 0.521097] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)674builder # [ 0.519570] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)675server # [ 0.524788] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)676builder # [ 0.529406] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)677builder # [ 0.531578] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)678server # [ 0.534974] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)679server # [ 0.536837] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)680server # [ 0.540278] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)681builder # [ 0.541854] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)682builder # [ 0.543779] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)683builder # [ 0.547274] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)684builder # [ 0.549038] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)685server # [ 0.550197] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)686server # [ 0.552576] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)687builder # [ 0.558767] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)688server # [ 0.567020] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled689server # [ 0.568793] msm_serial: driver initialized690server # [ 0.568935] SuperH (H)SCI(F) driver initialized691server # [ 0.568993] STM32 USART driver initialized692builder # [ 0.572163] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled693builder # [ 0.574809] msm_serial: driver initialized694builder # [ 0.574953] SuperH (H)SCI(F) driver initialized695builder # [ 0.575011] STM32 USART driver initialized696server # [ 0.600525] loop: module loaded697server # [ 0.600698] virtio_blk virtio2: 1/0/0 default/read/poll queues698server # [ 0.601411] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)699builder # [ 0.613499] loop: module loaded700builder # [ 0.613677] virtio_blk virtio2: 1/0/0 default/read/poll queues701builder # [ 0.614504] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)702server # [ 0.614267] megasas: 07.734.00.00-rc1703builder # [ 0.620051] megasas: 07.734.00.00-rc1704server # [ 0.614970] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]705builder # [ 0.620919] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]706server # [ 0.616941] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000707server # [ 0.616955] Intel/Sharp Extended Query Table at 0x0031708server # [ 0.618620] Using buffer write method709server # [ 0.618645] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]710builder # [ 0.624417] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000711builder # [ 0.624432] Intel/Sharp Extended Query Table at 0x0031712server # [ 0.620208] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000713server # [ 0.620221] Intel/Sharp Extended Query Table at 0x0031714server # [ 0.621578] Using buffer write method715server # [ 0.621591] Concatenating MTD devices:716builder # [ 0.628117] Using buffer write method717server # [ 0.621593] (0): "0.flash"718server # [ 0.621596] (1): "0.flash"719server # [ 0.621598] into device "0.flash"720builder # [ 0.628146] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]721builder # [ 0.637794] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000722builder # [ 0.637810] Intel/Sharp Extended Query Table at 0x0031723builder # [ 0.639527] Using buffer write method724builder # [ 0.639540] Concatenating MTD devices:725builder # [ 0.639543] (0): "0.flash"726builder # [ 0.639545] (1): "0.flash"727builder # [ 0.639547] into device "0.flash"728server # [ 0.887909] Freeing initrd memory: 26932K729builder # [ 0.892222] Freeing initrd memory: 26944K730server # [ 0.894288] tun: Universal TUN/TAP device driver, 1.6731server # [ 0.897308] thunder_xcv, ver 1.0732server # [ 0.897333] thunder_bgx, ver 1.0733server # [ 0.897352] nicpf, ver 1.0734server # [ 0.899847] e1000: Intel(R) PRO/1000 Network Driver735builder # [ 0.898526] tun: Universal TUN/TAP device driver, 1.6736server # [ 0.899853] e1000: Copyright (c) 1999-2006 Intel Corporation.737server # [ 0.899879] e1000e: Intel(R) PRO/1000 Network Driver738server # [ 0.899885] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.739server # [ 0.899908] igb: Intel(R) Gigabit Ethernet Network Driver740server # [ 0.899912] igb: Copyright (c) 2007-2014 Intel Corporation.741builder # [ 0.902330] thunder_xcv, ver 1.0742server # [ 0.899931] igbvf: Intel(R) Gigabit Virtual Function Network Driver743builder # [ 0.902357] thunder_bgx, ver 1.0744builder # [ 0.902376] nicpf, ver 1.0745server # [ 0.899935] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.746server # [ 0.900073] sky2: driver version 1.30747builder # [ 0.903183] e1000: Intel(R) PRO/1000 Network Driver748builder # [ 0.903187] e1000: Copyright (c) 1999-2006 Intel Corporation.749builder # [ 0.903214] e1000e: Intel(R) PRO/1000 Network Driver750builder # [ 0.903220] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.751server # [ 0.908536] ehci-pci 0000:00:07.0: EHCI Host Controller752builder # [ 0.903245] igb: Intel(R) Gigabit Ethernet Network Driver753server # [ 0.908554] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1754builder # [ 0.903248] igb: Copyright (c) 2007-2014 Intel Corporation.755server # [ 0.908716] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000756builder # [ 0.903268] igbvf: Intel(R) Gigabit Virtual Function Network Driver757server # [ 0.908953] usbcore: registered new interface driver usb-storage758builder # [ 0.903272] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.759server # [ 0.908997] usbcore: registered new interface driver usbserial_generic760builder # [ 0.903407] sky2: driver version 1.30761server # [ 0.909008] usbserial: USB Serial support registered for generic762builder # [ 0.905119] usbcore: registered new interface driver usb-storage763builder # [ 0.913644] usbcore: registered new interface driver usbserial_generic764server # [ 0.914479] hv_vmbus: registering driver hyperv_keyboard765builder # [ 0.913658] usbserial: USB Serial support registered for generic766server # [ 0.915352] rtc-pl031 9010000.pl031: registered as rtc0767builder # [ 0.914322] hv_vmbus: registering driver hyperv_keyboard768server # [ 0.915372] rtc-pl031 9010000.pl031: setting system clock to 2026-10-14T16:42:17 UTC (1791996137)769builder # [ 0.915566] ehci-pci 0000:00:07.0: EHCI Host Controller770server # [ 0.915692] i2c_dev: i2c /dev entries driver771builder # [ 0.915604] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1772server # [ 0.917705] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00773server # [ 0.918008] hub 1-0:1.0: USB hub found774builder # [ 0.915799] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000775server # [ 0.918026] hub 1-0:1.0: 6 ports detected776builder # [ 0.916097] rtc-pl031 9010000.pl031: registered as rtc0777builder # [ 0.916119] rtc-pl031 9010000.pl031: setting system clock to 2026-10-14T16:42:17 UTC (1791996137)778builder # [ 0.916438] i2c_dev: i2c /dev entries driver779server # [ 0.924485] sdhci: Secure Digital Host Controller Interface driver780server # [ 0.924490] sdhci: Copyright(c) Pierre Ossman781server # [ 0.924771] Synopsys Designware Multimedia Card Interface Driver782server # [ 0.925148] sdhci-pltfm: SDHCI platform and OF driver helper783builder # [ 0.926800] sdhci: Secure Digital Host Controller Interface driver784builder # [ 0.926805] sdhci: Copyright(c) Pierre Ossman785builder # [ 0.927092] Synopsys Designware Multimedia Card Interface Driver786builder # [ 0.927478] sdhci-pltfm: SDHCI platform and OF driver helper787builder # [ 0.929066] hid: raw HID events driver (C) Jiri Kosina788server # [ 0.929688] hid: raw HID events driver (C) Jiri Kosina789builder # [ 0.929272] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00790server # [ 0.929924] usbcore: registered new interface driver usbhid791builder # [ 0.929584] hub 1-0:1.0: USB hub found792server # [ 0.929928] usbhid: USB HID core driver793builder # [ 0.929600] hub 1-0:1.0: 6 ports detected794server # [ 0.931069] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available795server # [ 0.932625] drop_monitor: Initializing network drop monitor service796server # [ 0.932742] NET: Registered PF_INET6 protocol family797server # [ 0.933248] Segment Routing with IPv6798builder # [ 0.935267] usbcore: registered new interface driver usbhid799server # [ 0.933260] In-situ OAM (IOAM) with IPv6800builder # [ 0.935272] usbhid: USB HID core driver801server # [ 0.933289] NET: Registered PF_PACKET protocol family802server # [ 0.933342] 9pnet: Installing 9P2000 support803builder # [ 0.936448] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available804server # [ 0.933377] Key type dns_resolver registered805builder # [ 0.940423] drop_monitor: Initializing network drop monitor service806builder # [ 0.940543] NET: Registered PF_INET6 protocol family807builder # [ 0.941133] Segment Routing with IPv6808builder # [ 0.941156] In-situ OAM (IOAM) with IPv6809builder # [ 0.941202] NET: Registered PF_PACKET protocol family810builder # [ 0.944317] 9pnet: Installing 9P2000 support811builder # [ 0.944353] Key type dns_resolver registered812server # [ 0.946860] registered taskstats version 1813server # [ 0.946990] Loading compiled-in X.509 certificates814builder # [ 0.951502] registered taskstats version 1815builder # [ 0.951631] Loading compiled-in X.509 certificates816server # [ 0.955568] Demotion targets for Node 0: null817server # [ 0.955674] Key type .fscrypt registered818server # [ 0.955678] Key type fscrypt-provisioning registered819server # [ 0.955764] ima: No TPM chip found, activating TPM-bypass!820server # [ 0.955780] ima: Allocated hash algorithm: sha1821server # [ 0.955804] ima: No architecture policies found822server # [ 0.956367] input: gpio-keys as /devices/platform/gpio-keys/input/input0823builder # [ 0.960302] Demotion targets for Node 0: null824builder # [ 0.960407] Key type .fscrypt registered825builder # [ 0.960414] Key type fscrypt-provisioning registered826builder # [ 0.960505] ima: No TPM chip found, activating TPM-bypass!827builder # [ 0.960523] ima: Allocated hash algorithm: sha1828builder # [ 0.960543] ima: No architecture policies found829builder # [ 0.961113] input: gpio-keys as /devices/platform/gpio-keys/input/input0830server # [ 0.977310] clk: Disabling unused clocks831server # [ 0.977322] PM: genpd: Disabling unused power domains832server # [ 0.981369] Freeing unused kernel memory: 4736K833server # [ 0.981591] Run /init as init process834builder # [ 0.982260] clk: Disabling unused clocks835builder # [ 0.982273] PM: genpd: Disabling unused power domains836builder # [ 0.985192] Freeing unused kernel memory: 4736K837builder # [ 0.987133] Run /init as init process838server # [ 0.995963] systemd[1]: Successfully made /usr/ read-only.839builder # [ 1.003490] systemd[1]: Successfully made /usr/ read-only.840server # [ 1.169705] usb 1-1: new high-speed USB device number 2 using ehci-pci841builder # [ 1.181270] usb 1-1: new high-speed USB device number 2 using ehci-pci842server # [ 1.319358] 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/input1843builder # [ 1.330899] 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/input1844server # [ 1.329888] systemd[1]: systemd 261.3 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)845server # [ 1.329911] systemd[1]: Detected virtualization qemu.846server # [ 1.329951] systemd[1]: Detected architecture arm64.847server # [ 1.329960] systemd[1]: Running in initrd.848server # [ 1.330474] systemd[1]: Initializing machine ID from random generator.849builder # [ 1.337433] systemd[1]: systemd 261.3 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)850server # [ 1.330619] systemd[1]: Hostname set to <server>.851builder # [ 1.337457] systemd[1]: Detected virtualization qemu.852builder # [ 1.337497] systemd[1]: Detected architecture arm64.853builder # [ 1.337507] systemd[1]: Running in initrd.854builder # [ 1.338012] systemd[1]: Initializing machine ID from random generator.855builder # [ 1.338154] systemd[1]: Hostname set to <builder>.856server # [ 1.405860] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0857builder # [ 1.421432] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0858server # [ 1.454650] systemd[1]: bpf-restrict-fs: LSM BPF program attached859builder # [ 1.462155] systemd[1]: bpf-restrict-fs: LSM BPF program attached860server # [ 1.510328] systemd[1]: Queued start job for default target Initrd Default Target.861server # [ 1.517167] systemd[1]: Created slice Slice /system/modprobe.862server # [ 1.517375] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.863server # [ 1.517405] systemd[1]: Expecting device /dev/disk/by-label/nixos...864server # [ 1.517429] systemd[1]: Reached target Path Units.865server # [ 1.517446] systemd[1]: Reached target Slice Units.866server # [ 1.517463] systemd[1]: Reached target Swaps.867server # [ 1.517479] systemd[1]: Reached target Timer Units.868builder # [ 1.517293] systemd[1]: Queued start job for default target Initrd Default Target.869server # [ 1.522736] systemd[1]: Listening on D-Bus System Message Bus Socket.870builder # [ 1.524282] systemd[1]: Created slice Slice /system/modprobe.871server # [ 1.522906] systemd[1]: Listening on Journal Socket (/dev/log).872builder # [ 1.524449] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.873server # [ 1.523024] systemd[1]: Listening on Journal Sockets.874builder # [ 1.524475] systemd[1]: Expecting device /dev/disk/by-label/nixos...875server # [ 1.523128] systemd[1]: Listening on udev Control Socket.876builder # [ 1.524494] systemd[1]: Reached target Path Units.877server # [ 1.523216] systemd[1]: Listening on udev Kernel Socket.878builder # [ 1.524508] systemd[1]: Reached target Slice Units.879server # [ 1.523230] systemd[1]: Reached target Socket Units.880builder # [ 1.524522] systemd[1]: Reached target Swaps.881server # [ 1.524501] systemd[1]: Starting Create List of Static Device Nodes...882builder # [ 1.524535] systemd[1]: Reached target Timer Units.883builder # [ 1.524727] systemd[1]: Listening on D-Bus System Message Bus Socket.884server # [ 1.524555] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs885builder # [ 1.524873] systemd[1]: Listening on Journal Socket (/dev/log).886server # [ 1.525702] usb 1-2: new high-speed USB device number 3 using ehci-pci887builder # [ 1.524992] systemd[1]: Listening on Journal Sockets.888builder # [ 1.525103] systemd[1]: Listening on udev Control Socket.889builder # [ 1.525201] systemd[1]: Listening on udev Kernel Socket.890builder # [ 1.525215] systemd[1]: Reached target Socket Units.891builder # [ 1.536134] systemd[1]: Starting Create List of Static Device Nodes...892builder # [ 1.536190] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs893server # [ 1.540952] systemd[1]: Mounting Kernel Configuration File System...894builder # [ 1.541276] usb 1-2: new high-speed USB device number 3 using ehci-pci895builder # [ 1.545116] systemd[1]: Mounting Kernel Configuration File System...896server # [ 1.550058] systemd[1]: Starting Journal Service...897server # [ 1.568303] systemd[1]: Starting Load Kernel Modules...898builder # [ 1.565423] systemd[1]: Starting Journal Service...899builder # [ 1.566919] systemd[1]: Starting Load Kernel Modules...900server # [ 1.568408] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os901builder # [ 1.567001] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os902server # [ 1.574101] systemd[1]: Starting Coldplug All udev Devices...903builder # [ 1.577001] systemd[1]: Starting Coldplug All udev Devices...904server # [ 1.585970] systemd[1]: Finished Create List of Static Device Nodes.905builder # [ 1.583666] systemd[1]: Finished Create List of Static Device Nodes.906builder # [ 1.584443] systemd[1]: Mounted Kernel Configuration File System.907builder # [ 1.593635] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...908server # [ 1.607022] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...909server # [ 1.611096] systemd[1]: Mounted Kernel Configuration File System.910server # [ 1.619941] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.911builder # [ 1.644886] systemd-journald[71]: Collecting audit messages is disabled.912server # [ 1.644220] systemd-journald[71]: Collecting audit messages is disabled.913builder # [ 1.650847] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.914server # [ 1.645790] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev915server # [ 1.651864] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0916server # [ 1.652093] [drm] features: -virgl +edid -resource_blob -host_visible917server # [ 1.652095] [drm] features: -context_init918server # [ 1.652831] [drm] number of scanouts: 1919server # [ 1.652842] [drm] number of cap sets: 0920builder # [ 1.661187] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.921server # [ 1.662357] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.922builder # [ 1.663299] systemd[1]: Starting Create Static Device Nodes in /dev...923server # [ 1.670081] systemd[1]: Starting Create Static Device Nodes in /dev...924server # [ 1.678894] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic925builder # [ 1.677519] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev926server # [ 1.678906] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0927builder # [ 1.697600] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0928builder # [ 1.697839] [drm] features: -virgl +edid -resource_blob -host_visible929builder # [ 1.697843] [drm] features: -context_init930builder # [ 1.698560] [drm] number of scanouts: 1931builder # [ 1.698571] [drm] number of cap sets: 0932builder # [ 1.707905] systemd[1]: Finished Create Static Device Nodes in /dev.933server # [ 1.702104] 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/input2934builder # [ 1.708241] systemd[1]: Reached target Preparation for Local File Systems.935builder # [ 1.708267] systemd[1]: Reached target Local File Systems.936server # [ 1.702241] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0937builder # [ 1.712774] systemd[1]: Starting Rule-based Manager for Device Events and Files...938server # [ 1.713364] Console: switching to colour frame buffer device 160x50939builder # [ 1.715532] 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/input2940builder # [ 1.715680] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0941server # [ 1.726226] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device942builder # [ 1.725533] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic943server # [ 1.727909] systemd[1]: Finished Create Static Device Nodes in /dev.944builder # [ 1.725550] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0945server # [ 1.728218] systemd[1]: Reached target Preparation for Local File Systems.946server # [ 1.728518] systemd[1]: Reached target Local File Systems.947server # [ 1.742043] systemd[1]: Starting Rule-based Manager for Device Events and Files...948builder # [ 1.749512] Console: switching to colour frame buffer device 160x50949server # [ 1.753892] systemd[1]: Finished Load Kernel Modules.950server # [ 1.758693] systemd[1]: Starting Apply Kernel Variables...951builder # [ 1.769620] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device952builder # [ 1.785849] systemd[1]: Finished Load Kernel Modules.953builder # [ 1.790299] systemd[1]: Starting Apply Kernel Variables...954server # [ 1.818431] systemd[1]: Finished Apply Kernel Variables.955server # [ 1.810982] systemd-modules-load[72]: Inserted module 'dm_mod'956server # [ 1.823540] systemd[1]: Started Journal Service.957server # [ 1.812772] systemd-modules-load[72]: Module 'virtio_balloon' is built in958server # [ 1.823924] systemd-modules-load[72]: Module 'virtio_console' is built in959server # [ 1.828354] systemd-modules-load[72]: Inserted module 'virtio_gpu'960server # [ 1.829449] systemd-modules-load[72]: Module 'virtio_rng' is built in961server # [ 1.830493] systemd[1]: Starting Create System Files and Directories...962builder # [ 1.843261] systemd[1]: Started Journal Service.963builder # [ 1.833135] systemd-modules-load[72]: Inserted module 'dm_mod'964builder # [ 1.834403] systemd-modules-load[72]: Module 'virtio_balloon' is built in965builder # [ 1.837862] systemd-modules-load[72]: Module 'virtio_console' is built in966builder # [ 1.845183] systemd-modules-load[72]: Inserted module 'virtio_gpu'967server # [ 1.848256] systemd-udevd[79]: Using default interface naming scheme 'v261'.968builder # [ 1.849051] systemd-modules-load[72]: Module 'virtio_rng' is built in969builder # [ 1.850487] systemd-udevd[79]: Using default interface naming scheme 'v261'.970builder # [ 1.856318] systemd[1]: Starting Create System Files and Directories...971builder # [ 1.859073] systemd[1]: Finished Apply Kernel Variables.972server # [ 1.867066] systemd[1]: Finished Create System Files and Directories.973server # [ 1.886159] systemd[1]: Started Rule-based Manager for Device Events and Files.974builder # [ 1.892787] systemd[1]: Finished Create System Files and Directories.975builder # [ 1.894474] systemd[1]: Started Rule-based Manager for Device Events and Files.976server # [ 1.960603] systemd[1]: Starting Virtual Console Setup...977builder # [ 1.972600] systemd[1]: Starting Virtual Console Setup...978server # [ 2.033792] systemd-vconsole-setup[101]: Configuration of first virtual console was skipped, ignoring remaining ones.979server # [ 2.037346] systemd[1]: Finished Virtual Console Setup.980builder # [ 2.048510] systemd-vconsole-setup[101]: Configuration of first virtual console was skipped, ignoring remaining ones.981builder # [ 2.053632] systemd[1]: Finished Virtual Console Setup.982server # [ 2.673553] systemd[1]: Finished Coldplug All udev Devices.983server # [ 2.674512] systemd[1]: Reached target System Initialization.984server # [ 2.675343] systemd[1]: Reached target Basic System.985builder # [ 2.674970] systemd[1]: Finished Coldplug All udev Devices.986builder # [ 2.676777] systemd[1]: Reached target System Initialization.987builder # [ 2.680749] systemd[1]: Reached target Basic System.988server # [ 2.808138] (udev-worker)[90]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.989builder # [ 2.808290] (udev-worker)[95]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.990server # [ 2.844098] (udev-worker)[90]: Network interface NamePolicy= disabled on kernel command line.991server # [ 2.853139] (udev-worker)[95]: Network interface NamePolicy= disabled on kernel command line.992builder # [ 2.852686] (udev-worker)[95]: Network interface NamePolicy= disabled on kernel command line.993builder # [ 2.872839] (udev-worker)[92]: Network interface NamePolicy= disabled on kernel command line.994builder # [ 2.920939] systemd[1]: Found device /dev/disk/by-label/nixos.995server # [ 2.923831] systemd[1]: Found device /dev/disk/by-label/nixos.996builder # [ 2.923949] systemd[1]: Reached target Initrd Root Device.997server # [ 2.929286] systemd[1]: Reached target Initrd Root Device.998builder # [ 2.928658] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...999server # [ 2.933574] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...1000builder # [ 2.980169] systemd-fsck[110]: nixos: clean, 12/65536 files, 13019/262144 blocks1001server # [ 2.983359] systemd-fsck[110]: nixos: clean, 12/65536 files, 13019/262144 blocks1002builder # [ 2.988255] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.1003server # [ 2.991259] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.1004server # [ 2.996718] systemd[1]: Mounting /sysroot...1005builder # [ 2.998715] systemd[1]: Mounting /sysroot...1006server # [ 3.039167] EXT4-fs (vda): mounted filesystem 3af48fb1-0728-41cf-9ce8-33b9cc4d4ace r/w with ordered data mode. Quota mode: none.1007builder # [ 3.040824] EXT4-fs (vda): mounted filesystem ab25607d-f86a-427f-b200-15cacfd88c45 r/w with ordered data mode. Quota mode: none.1008server # [ 3.031084] systemd[1]: Mounted /sysroot.1009server # [ 3.033433] systemd[1]: Reached target Initrd Root File System.1010builder # [ 3.034248] systemd[1]: Mounted /sysroot.1011builder # [ 3.036348] systemd[1]: Reached target Initrd Root File System.1012server # [ 3.040090] systemd[1]: Starting Mountpoints Configured in the Real Root...1013builder # [ 3.040141] systemd[1]: Starting Mountpoints Configured in the Real Root...1014server # [ 3.063038] systemd-sysroot-fstab-check[118]: /sysroot should be mounted in the initrd, will request daemon-reload.1015builder # [ 3.067640] systemd-sysroot-fstab-check[118]: /sysroot should be mounted in the initrd, will request daemon-reload.1016server # [ 3.068377] systemd[1]: Reload requested from client PID 118 ('systemd-sysroot') (unit initrd-parse-etc.service)...1017server # [ 3.073822] systemd[1]: Reloading...1018builder # [ 3.075679] systemd[1]: Reload requested from client PID 118 ('systemd-sysroot') (unit initrd-parse-etc.service)...1019builder # [ 3.079673] systemd[1]: Reloading...1020server # [ 3.294661] systemd[1]: Reloading finished in 223 ms.1021builder # [ 3.295485] systemd[1]: Reloading finished in 220 ms.1022server # [ 3.317177] systemd-sysroot-fstab-check[118]: Requesting initrd-fs.target/start/replace...1023server # [ 3.320279] systemd-sysroot-fstab-check[118]: Requesting swap.target/start/replace...1024server # [ 3.327200] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1025builder # [ 3.327781] systemd-sysroot-fstab-check[118]: Requesting initrd-fs.target/start/replace...1026server # [ 3.330527] systemd[1]: Finished Mountpoints Configured in the Real Root.1027server # [ 3.332130] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1028builder # [ 3.332159] systemd-sysroot-fstab-check[118]: Requesting swap.target/start/replace...1029builder # [ 3.338921] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1030builder # [ 3.342033] systemd[1]: Finished Mountpoints Configured in the Real Root.1031builder # [ 3.343706] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1032server # [ 3.564921] systemd[1]: Mounting /sysroot/nix/.ro-store...1033builder # [ 3.569483] systemd[1]: Mounting /sysroot/nix/.ro-store...1034server # [ 3.584525] systemd[1]: Mounting /sysroot/nix/.rw-store...1035builder # [ 3.587530] systemd[1]: Mounting /sysroot/nix/.rw-store...1036builder # [ 3.593003] systemd[1]: Mounting /sysroot/run...1037builder # [ 3.601706] systemd[1]: Mounting /sysroot/tmp/shared...1038server # [ 3.611415] systemd[1]: Mounting /sysroot/run...1039server # [ 3.615412] systemd[1]: Mounting /sysroot/tmp/shared...1040server # [ 3.629713] systemd[1]: Mounting /sysroot/tmp/xchg...1041builder # [ 3.650855] systemd[1]: Mounting /sysroot/tmp/xchg...1042server # [ 3.664867] systemd[1]: Mounted /sysroot/nix/.rw-store.1043server # [ 3.684614] fuse: init (API version 7.45)1044builder # [ 3.688030] fuse: init (API version 7.45)1045server # [ 3.697147] virtiofs virtio6: discovered new tag: nix-store1046builder # [ 3.696963] virtiofs virtio6: discovered new tag: nix-store1047builder # [ 3.703935] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1048server # [ 3.705276] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1049server # [ 3.702412] systemd[1]: Mounted /sysroot/run.1050server # [ 3.719323] virtiofs virtio7: discovered new tag: shared1051builder # [ 3.720028] virtiofs virtio7: discovered new tag: shared1052server # [ 3.720085] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1053builder # [ 3.720808] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1054server # [ 3.727875] virtiofs virtio8: discovered new tag: xchg1055builder # [ 3.726167] virtiofs virtio8: discovered new tag: xchg1056server # [ 3.728618] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1057builder # [ 3.726922] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1058builder # [ 3.718274] systemd[1]: Mounted /sysroot/nix/.rw-store.1059builder # [ 3.722966] systemd[1]: Mounted /sysroot/run.1060server # [ 3.734377] systemd[1]: Starting rw-sysroot-nix-store.service...1061server # [ 3.743011] systemd[1]: Mounted /sysroot/nix/.ro-store.1062builder # [ 3.746210] systemd[1]: Starting rw-sysroot-nix-store.service...1063server # [ 3.750075] systemd[1]: Mounted /sysroot/tmp/shared.1064builder # [ 3.750500] systemd[1]: Mounted /sysroot/tmp/shared.1065server # [ 3.751288] systemd[1]: Mounted /sysroot/tmp/xchg.1066builder # [ 3.753849] systemd[1]: Mounted /sysroot/nix/.ro-store.1067builder # [ 3.755464] systemd[1]: Mounted /sysroot/tmp/xchg.1068server # [ 3.768321] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1069server # [ 3.769438] systemd[1]: Finished rw-sysroot-nix-store.service.1070builder # [ 3.779723] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1071builder # [ 3.782029] systemd[1]: Finished rw-sysroot-nix-store.service.1072server # [ 4.201537] (udev-worker)[97]: mtd0ro: Failed to find and pin callout binary "/nix/store/8w0qabyr98chcmr4y9hh6h6l26albldx-systemd-261.3/lib/udev/mtd_probe": No such file or directory1073server # [ 4.211657] (udev-worker)[97]: 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 directory1074server # [ 4.243901] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1075server # [ 4.245155] systemd[1]: Stopped Virtual Console Setup.1076server # [ 4.245914] systemd[1]: Stopping Virtual Console Setup...1077server # [ 4.248306] systemd[1]: Starting Virtual Console Setup...1078server # [ 4.281390] systemd-vconsole-setup[151]: Configuration of first virtual console was skipped, ignoring remaining ones.1079server # [ 4.284877] systemd[1]: Finished Virtual Console Setup.1080builder # [ 4.283054] (udev-worker)[100]: mtd0ro: Failed to find and pin callout binary "/nix/store/8w0qabyr98chcmr4y9hh6h6l26albldx-systemd-261.3/lib/udev/mtd_probe": No such file or directory1081builder # [ 4.291852] (udev-worker)[100]: 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 directory1082builder # [ 4.312092] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1083builder # [ 4.316153] systemd[1]: Stopped Virtual Console Setup.1084builder # [ 4.320165] systemd[1]: Stopping Virtual Console Setup...1085builder # [ 4.321057] systemd[1]: Starting Virtual Console Setup...1086builder # [ 4.336713] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1087builder # [ 4.339269] systemd[1]: Stopped Virtual Console Setup.1088builder # [ 4.340618] systemd[1]: Starting Virtual Console Setup...1089builder # [ 4.362699] systemd-vconsole-setup[153]: Configuration of first virtual console was skipped, ignoring remaining ones.1090builder # [ 4.366300] systemd[1]: Finished Virtual Console Setup.1091server # [ 4.565336] systemd[1]: Mounting /sysroot/nix/store...1092builder # [ 4.569508] systemd[1]: Mounting /sysroot/nix/store...1093server # [ 4.608951] systemd[1]: Mounted /sysroot/nix/store.1094builder # [ 4.610304] systemd[1]: Mounted /sysroot/nix/store.1095server # [ 4.612167] systemd[1]: Reached target Initrd File Systems.1096builder # [ 4.612770] systemd[1]: Reached target Initrd File Systems.1097server # [ 4.615108] systemd[1]: Starting Find NixOS closure...1098builder # [ 4.616229] systemd[1]: Starting Find NixOS closure...1099server # [ 4.624310] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1100builder # [ 4.624288] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1101builder # [ 4.663337] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1102server # [ 4.665162] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1103builder # [ 4.666232] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.1104server # [ 4.671457] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.1105builder # [ 4.678237] systemd[1]: Finished Find NixOS closure.1106server # [ 4.679304] systemd[1]: Finished Find NixOS closure.1107builder # [ 4.680234] systemd[1]: Reached target Initrd Default Target.1108server # [ 4.682065] systemd[1]: Reached target Initrd Default Target.1109builder # [ 4.682324] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1110server # [ 4.683663] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1111builder # [ 4.704916] systemd[1]: Stopped target Initrd Default Target.1112builder # [ 4.707000] systemd[1]: Stopped target Basic System.1113builder # [ 4.708453] systemd[1]: Stopped target Initrd Root Device.1114builder # [ 4.709629] systemd[1]: Stopped target Path Units.1115server # [ 4.712848] systemd[1]: Stopped target Initrd Default Target.1116builder # [ 4.712407] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1117builder # [ 4.714033] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1118server # [ 4.716430] systemd[1]: Stopped target Basic System.1119server # [ 4.717424] systemd[1]: Stopped target Initrd Root Device.1120builder # [ 4.717427] systemd[1]: Stopped target Slice Units.1121builder # [ 4.719242] systemd[1]: Stopped target Socket Units.1122server # [ 4.720288] systemd[1]: Stopped target Path Units.1123server # [ 4.721239] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1124builder # [ 4.723153] systemd[1]: Stopped target System Initialization.1125server # [ 4.723957] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1126server # [ 4.728172] systemd[1]: Stopped target Slice Units.1127server # [ 4.729104] systemd[1]: Stopped target Socket Units.1128builder # [ 4.729042] systemd[1]: Stopped target Swaps.1129builder # [ 4.729810] systemd[1]: Stopped target Timer Units.1130server # [ 4.730555] systemd[1]: Stopped target System Initialization.1131builder # [ 4.730610] systemd[1]: dbus.socket: Deactivated successfully.1132builder # [ 4.731551] systemd[1]: Closed D-Bus System Message Bus Socket.1133server # [ 4.732748] systemd[1]: Stopped target Swaps.1134server # [ 4.736406] systemd[1]: Stopped target Timer Units.1135server # [ 4.739674] systemd[1]: dbus.socket: Deactivated successfully.1136builder # [ 4.739878] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1137server # [ 4.741706] systemd[1]: Closed D-Bus System Message Bus Socket.1138builder # [ 4.742321] systemd[1]: Stopped Find NixOS closure.1139server # [ 4.744871] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1140builder # [ 4.745300] systemd[1]: Starting rw-sysroot-nix-store.service...1141builder # [ 4.752188] systemd[1]: systemd-sysctl.service: Deactivated successfully.1142server # [ 4.753061] systemd[1]: Stopped Find NixOS closure.1143builder # [ 4.754161] systemd[1]: Stopped Apply Kernel Variables.1144server # [ 4.754670] systemd[1]: Starting rw-sysroot-nix-store.service...1145builder # [ 4.756305] systemd[1]: systemd-modules-load.service: Deactivated successfully.1146server # [ 4.759903] systemd[1]: systemd-sysctl.service: Deactivated successfully.1147builder # [ 4.762782] systemd[1]: Stopped Load Kernel Modules.1148builder # [ 4.763615] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1149server # [ 4.764584] systemd[1]: Stopped Apply Kernel Variables.1150server # [ 4.765389] systemd[1]: systemd-modules-load.service: Deactivated successfully.1151server # [ 4.766422] systemd[1]: Stopped Load Kernel Modules.1152builder # [ 4.765746] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1153server # [ 4.767160] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1154builder # [ 4.768210] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1155server # [ 4.771132] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1156builder # [ 4.772193] systemd[1]: Stopped Create System Files and Directories.1157builder # [ 4.773172] systemd[1]: Stopped target Local File Systems.1158builder # [ 4.773978] systemd[1]: Stopped target Preparation for Local File Systems.1159server # [ 4.776261] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1160builder # [ 4.776245] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1161server # [ 4.778016] systemd[1]: Stopped Create System Files and Directories.1162builder # [ 4.778801] systemd[1]: Stopped Coldplug All udev Devices.1163builder # [ 4.779802] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1164server # [ 4.780616] systemd[1]: Stopped target Local File Systems.1165builder # [ 4.781031] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1166builder # [ 4.782076] systemd[1]: Stopped Virtual Console Setup.1167builder # [ 4.782827] systemd[1]: systemd-udevd.service: Deactivated successfully.1168server # [ 4.784160] systemd[1]: Stopped target Preparation for Local File Systems.1169builder # [ 4.783857] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1170server # [ 4.785206] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1171server # [ 4.786878] systemd[1]: Stopped Coldplug All udev Devices.1172server # [ 4.787783] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1173server # [ 4.789055] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1174server # [ 4.790104] systemd[1]: Stopped Virtual Console Setup.1175builder # [ 4.789316] systemd[1]: systemd-udevd.service: Consumed 1.505s CPU time over 3.054s wall clock time, 42.8M memory peak.1176server # [ 4.790863] systemd[1]: initrd-cleanup.service: Deactivated successfully.1177server # [ 4.791874] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1178server # [ 4.796320] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1179builder # [ 4.796187] systemd[1]: initrd-cleanup.service: Deactivated successfully.1180builder # [ 4.797377] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1181builder # [ 4.798504] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.1182builder # [ 4.799643] systemd[1]: Closed udev Control Socket.1183server # [ 4.800251] systemd[1]: Finished rw-sysroot-nix-store.service.1184server # [ 4.801407] systemd[1]: systemd-udevd.service: Deactivated successfully.1185builder # [ 4.801560] systemd[1]: Starting Cleanup udev Database...1186server # [ 4.804374] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1187builder # [ 4.804238] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1188builder # [ 4.805374] systemd[1]: Stopped Create Static Device Nodes in /dev.1189server # [ 4.805509] systemd[1]: systemd-udevd.service: Consumed 1.436s CPU time over 3.046s wall clock time, 24.9M memory peak.1190builder # [ 4.808118] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1191server # [ 4.812119] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.1192builder # [ 4.812297] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1193server # [ 4.813180] systemd[1]: Closed udev Control Socket.1194server # [ 4.813909] systemd[1]: Starting Cleanup udev Database...1195builder # [ 4.813348] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1196builder # [ 4.814361] systemd[1]: Stopped Create List of Static Device Nodes.1197server # [ 4.814706] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1198server # [ 4.815881] systemd[1]: Stopped Create Static Device Nodes in /dev.1199builder # [ 4.816321] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1200server # [ 4.820206] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1201builder # [ 4.820328] systemd[1]: Finished rw-sysroot-nix-store.service.1202server # [ 4.821625] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1203server # [ 4.824168] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1204server # [ 4.825446] systemd[1]: Stopped Create List of Static Device Nodes.1205builder # [ 4.839653] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1206builder # [ 4.842601] systemd[1]: Finished Cleanup udev Database.1207builder # [ 4.844463] systemd[1]: Reached target Switch Root.1208server # [ 4.847714] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1209builder # [ 4.848538] systemd[1]: Starting NixOS Activation...1210server # [ 4.850805] systemd[1]: Finished Cleanup udev Database.1211server # [ 4.851887] systemd[1]: Reached target Switch Root.1212server # [ 4.856186] systemd[1]: Starting NixOS Activation...1213builder # [ 4.920226] initrd-nixos-activation-start[177]: booting system configuration /nix/store/a511rgwk5wqsa9372xhk13cvvh99synz-nixos-system-builder-test1214server # [ 4.928313] initrd-nixos-activation-start[174]: booting system configuration /nix/store/q8qiyj31z8l99r31gviy629hz4v9x5lm-nixos-system-server-test1215builder # [ 4.950436] initrd-nixos-activation-start[177]: running activation script...1216server # [ 4.959027] initrd-nixos-activation-start[174]: running activation script...1217builder # [ 5.185517] initrd-nixos-activation-start[200]: setting up /etc...1218server # [ 5.201013] initrd-nixos-activation-start[197]: setting up /etc...1219builder # [ 5.299025] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1220builder # [ 5.302046] systemd[1]: Finished NixOS Activation.1221builder # [ 5.303227] systemd[1]: Starting Switch Root...1222server # [ 5.314361] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1223server # [ 5.317526] systemd[1]: Finished NixOS Activation.1224server # [ 5.318712] systemd[1]: Starting Switch Root...1225builder # [ 5.327488] systemd[1]: Switching root.1226server # [ 5.335895] systemd[1]: Switching root.1227builder # [ 5.514659] systemd-journald[71]: Received SIGTERM from PID 1 (systemd).1228server # [ 5.523061] systemd-journald[71]: Received SIGTERM from PID 1 (systemd).1229builder # [ 5.997512] systemd[1]: systemd 261.3 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)1230builder # [ 5.997569] systemd[1]: Detected virtualization qemu.1231builder # [ 5.997623] systemd[1]: Detected architecture arm64.1232builder # [ 5.997723] systemd[1]: Detected first boot.1233builder # [ 5.999390] systemd[1]: Initializing machine ID from random generator.1234server # [ 6.018141] systemd[1]: systemd 261.3 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)1235server # [ 6.018200] systemd[1]: Detected virtualization qemu.1236server # [ 6.018257] systemd[1]: Detected architecture arm64.1237server # [ 6.018362] systemd[1]: Detected first boot.1238server # [ 6.020116] systemd[1]: Initializing machine ID from random generator.1239builder # [ 6.134618] systemd[1]: bpf-restrict-fs: LSM BPF program attached1240server # [ 6.148895] systemd[1]: bpf-restrict-fs: LSM BPF program attached1241builder # [ 6.269739] systemd[1]: Applying preset policy.1242server # [ 6.281549] systemd[1]: Applying preset policy.1243builder # [ 6.470218] systemd[1]: Populated /etc with preset unit settings.1244server # [ 6.493035] systemd[1]: Populated /etc with preset unit settings.1245builder # [ 6.682507] systemd[1]: initrd-switch-root.service: Deactivated successfully.1246builder # [ 6.682902] systemd[1]: Stopped initrd-switch-root.service.1247builder # [ 6.685071] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1248builder # [ 6.690273] systemd[1]: Created slice Slice /system/getty.1249builder # [ 6.691471] systemd[1]: Created slice User and Session Slice.1250builder # [ 6.691976] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1251builder # [ 6.692596] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1252builder # [ 6.693183] systemd[1]: Expecting device /dev/hvc0...1253builder # [ 6.698541] systemd[1]: Expecting device /dev/ttyAMA0...1254builder # [ 6.698941] systemd[1]: Reached target Local Encrypted Volumes.1255builder # [ 6.699563] systemd[1]: Stopped target initrd-fs.target.1256builder # [ 6.700162] systemd[1]: Stopped target initrd-root-fs.target.1257builder # [ 6.700853] systemd[1]: Stopped target initrd-switch-root.target.1258builder # [ 6.705815] systemd[1]: Reached target Virtual Machines and Containers.1259builder # [ 6.706215] systemd[1]: Reached target Path Units.1260builder # [ 6.706799] systemd[1]: Reached target Remote File Systems.1261builder # [ 6.707389] systemd[1]: Reached target Slice Units.1262builder # [ 6.707983] systemd[1]: Reached target Swaps.1263server # [ 6.715137] systemd[1]: initrd-switch-root.service: Deactivated successfully.1264builder # [ 6.713579] systemd[1]: Listening on Query the User Interactively for a Password.1265server # [ 6.715907] systemd[1]: Stopped initrd-switch-root.service.1266builder # [ 6.715549] systemd[1]: Listening on Process Core Dump Socket.1267builder # [ 6.717089] systemd[1]: Listening on Credential Encryption/Decryption.1268server # [ 6.720561] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1269server # [ 6.723874] systemd[1]: Created slice Slice /system/getty.1270server # [ 6.725078] systemd[1]: Created slice User and Session Slice.1271builder # [ 6.721366] systemd[1]: Listening on Factory Reset Management.1272server # [ 6.725583] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1273builder # [ 6.721849] systemd[1]: Listening on Hostname Service Socket.1274builder # [ 6.725152] systemd[1]: Starting Journal Log Access Socket...1275server # [ 6.728674] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1276server # [ 6.728999] systemd[1]: Expecting device /dev/hvc0...1277server # [ 6.729228] systemd[1]: Expecting device /dev/ttyAMA0...1278server # [ 6.729474] systemd[1]: Reached target Local Encrypted Volumes.1279server # [ 6.732836] systemd[1]: Stopped target initrd-fs.target.1280builder # [ 6.729627] systemd[1]: Listening on Journal Audit Socket.1281server # [ 6.733276] systemd[1]: Stopped target initrd-root-fs.target.1282builder # [ 6.731711] systemd[1]: Listening on Console Output Muting Service Socket.1283builder # [ 6.732406] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1284builder # [ 6.732891] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1285server # [ 6.735584] systemd[1]: Stopped target initrd-switch-root.target.1286server # [ 6.735967] systemd[1]: Reached target Virtual Machines and Containers.1287server # [ 6.736403] systemd[1]: Reached target Path Units.1288server # [ 6.736807] systemd[1]: Reached target Remote File Systems.1289server # [ 6.737213] systemd[1]: Reached target Slice Units.1290server # [ 6.737649] systemd[1]: Reached target Swaps.1291builder # [ 6.738136] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1292server # [ 6.744211] systemd[1]: Listening on Query the User Interactively for a Password.1293builder # [ 6.744215] systemd[1]: Listening on Disk Repartitioning Service Socket.1294builder # [ 6.744747] systemd[1]: Listening on udev Control Socket.1295server # [ 6.747279] systemd[1]: Listening on Process Core Dump Socket.1296builder # [ 6.747543] systemd[1]: Listening on udev Varlink Socket.1297server # [ 6.748678] systemd[1]: Listening on Credential Encryption/Decryption.1298server # [ 6.751904] systemd[1]: Listening on Factory Reset Management.1299builder # [ 6.750844] systemd[1]: Mounting Huge Pages File System...1300server # [ 6.752376] systemd[1]: Listening on Hostname Service Socket.1301server # [ 6.756922] systemd[1]: Starting Journal Log Access Socket...1302builder # [ 6.754294] systemd[1]: Mounting POSIX Message Queue File System...1303server # [ 6.759312] systemd[1]: Listening on Journal Audit Socket.1304server # [ 6.761626] systemd[1]: Listening on Console Output Muting Service Socket.1305server # [ 6.763873] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1306server # [ 6.764321] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1307server # [ 6.764871] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1308builder # [ 6.765962] systemd[1]: Mounting Kernel Debug File System...1309server # [ 6.773779] systemd[1]: Listening on Disk Repartitioning Service Socket.1310server # [ 6.774209] systemd[1]: Listening on udev Control Socket.1311server # [ 6.774548] systemd[1]: Listening on udev Varlink Socket.1312server # [ 6.776896] systemd[1]: Mounting Huge Pages File System...1313builder # [ 6.777547] systemd[1]: Mounting Kernel Trace File System...1314server # [ 6.786627] systemd[1]: Mounting POSIX Message Queue File System...1315server # [ 6.789319] systemd[1]: Mounting Kernel Debug File System...1316builder # [ 6.789491] systemd[1]: Starting Create List of Static Device Nodes...1317builder # [ 6.791275] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1318server # [ 6.803309] systemd[1]: Mounting Kernel Trace File System...1319builder # [ 6.805309] systemd[1]: Mounting Kernel Configuration File System...1320builder # [ 6.807639] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1321builder # [ 6.814104] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1322builder # [ 6.814543] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1323server # [ 6.818453] systemd[1]: Starting Create List of Static Device Nodes...1324server # [ 6.820670] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1325server # [ 6.837144] systemd[1]: Mounting Kernel Configuration File System...1326server # [ 6.839087] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1327builder # [ 6.838662] systemd[1]: Mounting FUSE Control File System...1328builder # [ 6.839054] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671329server # [ 6.846892] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1330server # [ 6.847338] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1331server # [ 6.866826] systemd[1]: Mounting FUSE Control File System...1332server # [ 6.867325] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671333builder # [ 6.873458] systemd[1]: Starting Journal Service...1334builder # [ 6.895504] systemd[1]: Starting Load Kernel Modules...1335server # [ 6.900835] systemd[1]: Starting Journal Service...1336server # [ 6.919910] systemd[1]: Starting Load Kernel Modules...1337builder # [ 6.918110] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1338builder # [ 6.926260] systemd[1]: Starting Remount Root and Kernel File Systems...1339builder # [ 6.926612] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1340builder # [ 6.932733] systemd[1]: Starting Coldplug All udev Devices...1341server # [ 6.942357] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1342builder # [ 6.949543] systemd[1]: Listening on Journal Log Access Socket.1343builder # [ 6.950050] systemd[1]: Mounted Huge Pages File System.1344builder # [ 6.950458] systemd[1]: Mounted POSIX Message Queue File System.1345builder # [ 6.950842] systemd[1]: Mounted Kernel Debug File System.1346builder # [ 6.951215] systemd[1]: Mounted Kernel Trace File System.1347server # [ 6.960624] systemd[1]: Starting Remount Root and Kernel File Systems...1348builder # [ 6.960343] systemd-journald[270]: Collecting audit messages is enabled.1349server # [ 6.960994] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1350builder # [ 6.968917] systemd[1]: Finished Create List of Static Device Nodes.1351builder # [ 6.960817] systemd[1]: Queued start job for default target Multi-User System.1352builder # [ 6.962233] systemd[1]: systemd-journald.service: Deactivated successfully.1353server # [ 6.980123] systemd[1]: Starting Coldplug All udev Devices...1354builder # [ 6.974836] systemd-modules-load[271]: Module 'atkbd' is built in1355builder # [ 6.979294] systemd-modules-load[271]: Module 'loop' is built in[ 6.990122] systemd[1]: Started Journal Service.1356builder # 1357server # [ 6.999438] systemd[1]: Listening on Journal Log Access Socket.1358server # [ 6.999900] systemd[1]: Mounted Huge Pages File System.1359server # [ 7.000284] systemd[1]: Mounted POSIX Message Queue File System.1360server # [ 7.000650] systemd[1]: Mounted Kernel Debug File System.1361server # [ 7.001006] systemd[1]: Mounted Kernel Trace File System.1362builder # [ 7.007683] systemd[1]: Finished Load Kernel Modules.1363server # [ 7.020611] systemd[1]: Finished Create List of Static Device Nodes.1364builder # [ 7.019696] systemd[1]: Mounted Kernel Configuration File System.1365server # [ 7.048048] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1366builder # [ 7.043798] systemd[1]: Starting Firewall...1367server # [ 7.054818] systemd-journald[267]: Collecting audit messages is enabled.1368builder # [ 7.055956] systemd[1]: Starting Apply Kernel Variables...1369server # [ 7.065912] systemd[1]: Finished Load Kernel Modules.1370server # [ 7.072628] systemd[1]: Starting Firewall...1371server # [ 7.062029] systemd[1]: Queued start job for default target Multi-User System.1372server # [ 7.065532] systemd[1]: systemd-journald.service: Deactivated successfully.1373server # [ 7.066775] systemd-modules-load[268]: Module 'atkbd' is built in1374server # [ 7.067763] systemd-modules-load[268]: Module 'loop' is built in1375builder # [ 7.069361] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1376builder # [ 7.085286] EXT4-fs (vda): re-mounted ab25607d-f86a-427f-b200-15cacfd88c45.1377server # [ 7.080857] systemd-modules-load[268]: Inserted module 'tls'1378server # [ 7.096908] systemd[1]: Starting Apply Kernel Variables...1379server # [ 7.099905] EXT4-fs (vda): re-mounted 3af48fb1-0728-41cf-9ce8-33b9cc4d4ace.1380builder # [ 7.089122] systemd-oomd[273]: No swap; memory pressure usage will be degraded1381server # [ 7.109564] systemd[1]: Started Journal Service.1382builder # [ 7.097262] systemd[1]: Finished Remount Root and Kernel File Systems.1383builder # [ 7.098313] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1384server # [ 7.099846] systemd-oomd[269]: No swap; memory pressure usage will be degraded1385builder # [ 7.101369] systemd[1]: Listening on Disk Image Download Service Socket.1386server # [ 7.108733] systemd[1]: Mounted Kernel Configuration File System.1387server # [ 7.121985] systemd[1]: Finished Remount Root and Kernel File Systems.1388server # [ 7.123036] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1389builder # [ 7.123128] systemd[1]: Starting Flush Journal to Persistent Storage...1390builder # [ 7.128395] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1391builder # [ 7.153611] systemd[1]: Starting Load/Save OS Random Seed...1392builder # [ 7.154554] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1393builder # [ 7.168194] systemd[1]: Mounted FUSE Control File System.1394server # [ 7.170987] systemd[1]: Mounted FUSE Control File System.1395server # [ 7.188482] systemd[1]: Listening on Disk Image Download Service Socket.1396server # [ 7.203834] systemd[1]: Starting Flush Journal to Persistent Storage...1397server # [ 7.208281] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1398server # [ 7.209910] systemd[1]: Starting Load/Save OS Random Seed...1399server # [ 7.210729] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1400builder # [ 7.239811] systemd-journald[270]: Received client request to flush runtime journal.1401server # [ 7.256907] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1402server # [ 7.269983] systemd[1]: Starting Create Static Device Nodes in /dev...1403builder # [ 7.296619] systemd[1]: Finished Load/Save OS Random Seed.1404builder # [ 7.297583] systemd[1]: Reached target First Boot Complete.1405builder # [ 7.298406] systemd[1]: Finished Apply Kernel Variables.1406builder # [ 7.302916] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1407server # [ 7.311932] systemd-journald[267]: Received client request to flush runtime journal.1408builder # [ 7.310139] systemd[1]: Starting Create Static Device Nodes in /dev...1409builder # [ 7.311606] systemd[1]: Finished Flush Journal to Persistent Storage.1410server # [ 7.376324] systemd[1]: Finished Apply Kernel Variables.1411server # [ 7.377336] systemd[1]: Finished Load/Save OS Random Seed.1412server # [ 7.383210] systemd[1]: Reached target First Boot Complete.1413server # [ 7.385730] systemd[1]: Finished Flush Journal to Persistent Storage.1414server # [ 7.432879] systemd[1]: Finished Create Static Device Nodes in /dev.1415builder # [ 7.432903] systemd[1]: Finished Create Static Device Nodes in /dev.1416builder # [ 7.434293] systemd[1]: Reached target Preparation for Local File Systems.1417server # [ 7.435904] systemd[1]: Reached target Preparation for Local File Systems.1418server # [ 7.442105] systemd[1]: Starting Rule-based Manager for Device Events and Files...1419builder # [ 7.442063] systemd[1]: Starting Rule-based Manager for Device Events and Files...1420builder # [ 7.586226] systemd-udevd[310]: Using default interface naming scheme 'v261'.1421server # [ 7.587069] systemd-udevd[306]: Using default interface naming scheme 'v261'.1422builder # [ 7.684266] systemd[1]: Mounting /run/wrappers...1423server # [ 7.708569] systemd[1]: Mounting /run/wrappers...1424builder # [ 7.709093] systemd[1]: Started Rule-based Manager for Device Events and Files.1425server # [ 7.733158] systemd[1]: Started Rule-based Manager for Device Events and Files.1426builder # [ 7.750710] systemd[1]: Mounted /run/wrappers.1427builder # [ 7.751641] systemd[1]: Reached target Local File Systems.1428builder # [ 7.759071] systemd[1]: Listening on Boot Loader Control Service Socket.1429builder # [ 7.762267] systemd[1]: Starting register-nix-paths.service...1430builder # [ 7.770688] systemd[1]: Starting Create SUID/SGID Wrappers...1431builder # [ 7.771615] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1432builder # [ 7.782095] systemd[1]: Starting Save Transient machine-id to Disk...1433server # [ 7.785148] systemd[1]: Mounted /run/wrappers.1434server # [ 7.785953] systemd[1]: Reached target Local File Systems.1435builder # [ 7.789152] systemd[1]: Starting Create System Files and Directories...1436server # [ 7.792209] systemd[1]: Listening on Boot Loader Control Service Socket.1437server # [ 7.795273] systemd[1]: Starting register-nix-paths.service...1438server # [ 7.802559] systemd[1]: Starting Create SUID/SGID Wrappers...1439server # [ 7.803527] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1440server # [ 7.814303] systemd[1]: Starting Save Transient machine-id to Disk...1441server # [ 7.821068] systemd[1]: Starting Create System Files and Directories...1442builder # [ 7.902434] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1443builder # [ 7.912782] systemd[1]: Finished Save Transient machine-id to Disk.1444server # [ 7.964282] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1445server # [ 7.973395] systemd[1]: Finished Save Transient machine-id to Disk.1446builder # [ 8.004610] systemd[1]: Finished Create System Files and Directories.1447builder # [ 8.018269] systemd[1]: Starting Rebuild Journal Catalog...1448builder # [ 8.026259] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1449server # [ 8.056698] systemd[1]: Finished Create System Files and Directories.1450server # [ 8.070254] systemd[1]: Starting Rebuild Journal Catalog...1451server # [ 8.089095] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1452builder # [ 8.143353] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1453server # [ 8.205124] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1454builder # [ 8.209925] systemd[1]: Finished Rebuild Journal Catalog.1455builder # [ 8.213317] systemd[1]: Starting Update is Completed...1456server # [ 8.246057] systemd[1]: Finished Rebuild Journal Catalog.1457server # [ 8.256439] systemd[1]: Starting Update is Completed...1458builder # [ 8.299424] systemd[1]: Finished Update is Completed.1459server # [ 8.382356] systemd[1]: Finished Update is Completed.1460builder # [ 8.921031] systemd[1]: Finished Coldplug All udev Devices.1461builder # [ 8.988140] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1462server # [ 8.988881] systemd[1]: Finished Coldplug All udev Devices.1463builder # [ 8.991251] systemd[1]: Finished Create SUID/SGID Wrappers.1464builder # [ 9.007619] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1465server # [ 9.025330] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1466server # [ 9.027009] systemd[1]: Finished Create SUID/SGID Wrappers.1467builder # [ 9.040683] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1468server # [ 9.071283] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1469builder # [ 9.075256] systemd[1]: Finished register-nix-paths.service.1470builder # [ 9.080343] systemd[1]: Reached target System Initialization.1471builder # [ 9.081243] systemd[1]: Started Discard unused filesystem blocks once a week.1472builder # [ 9.082261] systemd[1]: Started Daily Cleanup of Temporary Directories.1473builder # [ 9.083219] systemd[1]: Reached target Timer Units.1474builder # [ 9.083978] systemd[1]: Listening on D-Bus System Message Bus Socket.1475builder # [ 9.095312] systemd[1]: Starting niks3 auto-upload socket...1476builder # [ 9.097583] systemd[1]: Listening on Nix Daemon Socket.1477builder # [ 9.098385] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1478server # [ 9.099297] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1479builder # [ 9.104535] systemd[1]: Starting D-Bus System Message Bus...1480builder # [ 9.112710] systemd[1]: Listening on niks3 auto-upload socket.1481builder # [ 9.113629] systemd[1]: Reached target Socket Units.1482server # [ 9.113931] systemd[1]: Finished register-nix-paths.service.1483server # [ 9.117136] systemd[1]: Reached target System Initialization.1484server # [ 9.118055] systemd[1]: Started Discard unused filesystem blocks once a week.1485server # [ 9.119046] systemd[1]: Started niks3 garbage collection timer.1486server # [ 9.119973] systemd[1]: Started Daily Cleanup of Temporary Directories.1487server # [ 9.129057] systemd[1]: Reached target Timer Units.1488server # [ 9.129839] systemd[1]: Listening on D-Bus System Message Bus Socket.1489server # [ 9.130771] systemd[1]: Starting niks3 server proxy socket...1490server # [ 9.140216] systemd[1]: Listening on niks3 server socket.1491server # [ 9.141089] systemd[1]: Listening on Nix Daemon Socket.1492server # [ 9.141876] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1493server # [ 9.149332] systemd[1]: Starting D-Bus System Message Bus...1494server # [ 9.150234] systemd[1]: Listening on niks3 server proxy socket.1495server # [ 9.151098] systemd[1]: Reached target Socket Units.1496builder # [ 9.203968] dbus-broker-launch[458]: Looking up NSS user entry for 'systemd-timesync'...1497builder # [ 9.211073] dbus-broker-launch[458]: NSS returned no entry for 'systemd-timesync'1498builder # [ 9.213869] dbus-broker-launch[458]: Invalid user-name in /nix/store/dlaykmcpgzzzwh2lpi97scy4njnabxlw-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1499builder # [ 9.241360] systemd[1]: Started D-Bus System Message Bus.1500builder # [ 9.243220] systemd[1]: Reached target Basic System.1501server # [ 9.244337] dbus-broker-launch[457]: Looking up NSS user entry for 'systemd-timesync'...1502builder # [ 9.249122] systemd[1]: Starting Import lastlog data into lastlog2 database...1503server # [ 9.251020] dbus-broker-launch[457]: NSS returned no entry for 'systemd-timesync'1504server # [ 9.254893] dbus-broker-launch[457]: Invalid user-name in /nix/store/r93yh01amnfcs9gyj3yzxkjrr33b6i0h-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1505builder # [ 9.257431] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1506builder # [ 9.266106] systemd[1]: Starting Post-Boot Actions...1507server # [ 9.275641] systemd[1]: Started D-Bus System Message Bus.1508server # [ 9.279493] systemd[1]: Reached target Basic System.1509builder # [ 9.282930] dbus-broker-launch[458]: Ready1510server # [ 9.284780] systemd[1]: Starting Import lastlog data into lastlog2 database...1511server # [ 9.291242] systemd[1]: Starting Generate test mTLS certs...1512builder # [ 9.298380] systemd[1]: Started Reset console on configuration changes.1513server # [ 9.307349] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1514server # [ 9.329057] dbus-broker-launch[457]: Ready1515builder # [ 9.329968] systemd[1]: Starting resolvconf update...1516server # [ 9.341720] systemd[1]: Starting Post-Boot Actions...1517server # [ 9.365620] systemd[1]: Started Reset console on configuration changes.1518server # [ 9.390236] systemd[1]: Starting resolvconf update...1519builder # [ 9.423447] systemd[1]: Started Name Service Cache Daemon (nsncd).1520builder # [ 9.427072] nsncd[473]: Oct 14 16:42:26.013 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1521builder # [ 9.444610] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1522builder # [ 9.476149] systemd[1]: Finished Post-Boot Actions.1523builder # [ 9.491670] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1524builder # [ 9.497207] systemd[1]: Reached target Host and Network Name Lookups.1525builder # [ 9.504893] systemd[1]: Reached target User and Group Name Lookups.1526server # [ 9.506545] systemd[1]: Finished Post-Boot Actions.1527builder # [ 9.512632] systemd[1]: Started backdoor.service.1528server # [ 9.524986] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1529server # [ 9.531204] nsncd[472]: Oct 14 16:42:26.127 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1530server # [ 9.548894] systemd[1]: Started Name Service Cache Daemon (nsncd).1531builder # [ 9.551521] systemd[1]: Starting User Login Management...1532builder # [ 9.558502] systemd[1]: Finished Import lastlog data into lastlog2 database.1533server # [ 9.559566] systemd[1]: Finished Import lastlog data into lastlog2 database.1534server # [ 9.570067] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1535server # [ 9.574256] systemd[1]: Reached target Host and Network Name Lookups.1536server # [ 9.575271] systemd[1]: Reached target User and Group Name Lookups.1537builder # [ 9.578472] systemd[1]: Finished Firewall.1538server # [ 9.582523] systemd[1]: Started backdoor.service.1539server # [ 9.583541] niks3-test-certs-start[491]: -----1540server # [ 9.607982] systemd[1]: Starting User Login Management...1541server # [ 9.628869] niks3-test-certs-start[508]: -----1542builder # connecting to host...1543builder # [ 9.733096] systemd-logind[506]: New seat seat0.1544builder # [ 9.740794] systemd[1]: Started User Login Management.1545builder # [ 9.748193] systemd[1]: Stopped target Host and Network Name Lookups.1546builder # [ 9.749202] systemd[1]: Stopping Host and Network Name Lookups...1547builder # [ 9.750067] systemd[1]: Stopped target User and Group Name Lookups.1548builder # [ 9.750954] systemd[1]: Stopping User and Group Name Lookups...1549builder # [ 9.760606] systemd[1]: Starting linger-users.service...1550builder # [ 9.761478] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1551server # connecting to host...1552builder # [ 9.767604] systemd[1]: nscd.service: Deactivated successfully.1553builder # [ 9.771645] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1554builder # [ 9.775787] (udev-worker)[336]: Network interface NamePolicy= disabled on kernel command line.1555builder # [ 9.782532] (udev-worker)[334]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1556builder # [ 9.790457] (udev-worker)[334]: Network interface NamePolicy= disabled on kernel command line.1557server # [ 9.791240] niks3-test-certs-start[514]: Certificate request self-signature ok1558server # [ 9.804085] niks3-test-certs-start[514]: subject=CN=server1559builder # [ 9.812548] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1560server: Guest shell says: b'Spawning backdoor root shell...\n'1561server # [ 9.860514] niks3-test-certs-start[554]: -----1562builder # [ 9.871576] systemd[1]: linger-users.service: Deactivated successfully.1563builder # [ 9.877304] systemd[1]: Finished linger-users.service.1564server: connected to guest root shell1565server: (connecting took 10.28 seconds)1566server: (finished: waiting for the VM to finish booting, in 10.28 seconds)1567server # [ 9.888361] systemd[1]: Finished Firewall.1568server # [ 9.897366] systemd-logind[511]: New seat seat0.1569builder # [ 9.899249] systemd[1]: Finished resolvconf update.1570builder # [ 9.901870] systemd[1]: Reached target Preparation for Network.1571server # [ 9.903492] systemd[1]: Started User Login Management.1572builder # [ 9.910276] systemd[1]: Starting DHCP Client...1573server # [ 9.917317] systemd[1]: Starting linger-users.service...1574builder # [ 9.917487] systemd[1]: Starting Extra networking commands....1575builder # [ 9.939299] nsncd[565]: Oct 14 16:42:26.535 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1576builder # [ 9.949177] systemd[1]: Started Name Service Cache Daemon (nsncd).1577builder # [ 9.950143] systemd[1]: Reached target Host and Network Name Lookups.1578builder # [ 9.951020] systemd[1]: Reached target User and Group Name Lookups.1579server # [ 9.976178] systemd[1]: Stopped target Host and Network Name Lookups.1580server # [ 9.977189] systemd[1]: Stopping Host and Network Name Lookups...1581server # [ 9.978071] systemd[1]: Stopped target User and Group Name Lookups.1582server # [ 9.978918] systemd[1]: Stopping User and Group Name Lookups...1583server # [ 9.998706] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1584server # [ 9.999696] systemd[1]: nscd.service: Deactivated successfully.1585server # [ 10.013173] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1586server # [ 10.014440] niks3-test-certs-start[565]: Certificate request self-signature ok1587server # [ 10.015442] niks3-test-certs-start[565]: subject=CN=niks3 test client1588server # [ 10.030962] (udev-worker)[415]: Network interface NamePolicy= disabled on kernel command line.1589server # [ 10.039485] (udev-worker)[332]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1590server # [ 10.051643] (udev-worker)[332]: Network interface NamePolicy= disabled on kernel command line.1591server # [ 10.102353] systemd[1]: Finished Generate test mTLS certs.1592server # [ 10.106948] systemd[1]: Finished resolvconf update.1593server # [ 10.109709] systemd[1]: linger-users.service: Deactivated successfully.1594server # [ 10.116736] systemd[1]: Finished linger-users.service.1595server # [ 10.143580] systemd[1]: Reached target Preparation for Network.1596builder # [ 10.145604] systemd[1]: Condition check resulted in Virtio network device being skipped.1597builder # [ 10.152796] dhcpcd[595]: dhcpcd-10.3.2 starting1598server # [ 10.156151] systemd[1]: Starting DHCP Client...1599builder # [ 10.158476] dhcpcd[624]: dev: loaded udev1600builder # [ 10.159154] systemd[1]: Starting Address configuration of eth1...1601server # [ 10.178095] systemd[1]: Starting Extra networking commands....1602server # [ 10.182664] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1603builder # [ 10.226400] 8021q: 802.1Q VLAN Support v1.81604builder # [ 10.228123] systemd-logind[506]: Watching system buttons on /dev/input/event0 (gpio-keys)1605server # [ 10.271058] systemd[1]: Started Name Service Cache Daemon (nsncd).1606server # [ 10.276925] systemd[1]: Reached target Host and Network Name Lookups.1607server # [ 10.278187] nsncd[604]: Oct 14 16:42:26.872 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1608server # [ 10.289488] systemd[1]: Reached target User and Group Name Lookups.1609builder # [ 10.304122] 8021q: adding VLAN 0 to HW filter on device eth11610builder # [ 10.318997] systemd[1]: Finished Extra networking commands..1611builder # [ 10.332304] systemd[1]: Reached target Network.1612builder # [ 10.336685] systemd[1]: Starting Permit User Sessions...1613builder # [ 10.362064] network-addresses-eth1-start[625]: adding address 192.168.1.1/24... done1614builder # [ 10.380382] cfg80211: Loading compiled-in X.509 certificates for regulatory database1615builder # [ 10.386197] network-addresses-eth1-start[625]: adding address 2001:db8:1::1/64... done1616builder # [ 10.422575] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1617builder # [ 10.423052] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1618builder # [ 10.424912] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21619builder # [ 10.425215] cfg80211: failed to load regulatory.db1620builder # [ 10.418425] systemd[1]: Finished Permit User Sessions.1621server # [ 10.427455] dhcpcd[622]: dhcpcd-10.3.2 starting1622builder # [ 10.430419] systemd[1]: Started Getty on tty1.1623builder # [ 10.435028] systemd[1]: Reached target Login Prompts.1624server # [ 10.440467] dhcpcd[655]: dev: loaded udev1625builder # [ 10.449191] systemd[1]: Finished Address configuration of eth1.1626server # [ 10.475155] systemd[1]: Condition check resulted in Virtio network device being skipped.1627server # [ 10.482699] systemd-logind[511]: Watching system buttons on /dev/input/event0 (gpio-keys)1628server # [ 10.490746] systemd[1]: Starting Address configuration of eth1...1629server # [ 10.510544] 8021q: 802.1Q VLAN Support v1.81630builder # [ 10.513919] mousedev: PS/2 mouse device common for all mice1631server # [ 10.518503] systemd[1]: Finished Extra networking commands..1632server # [ 10.524452] systemd[1]: Reached target Network.1633builder # [ 10.531168] systemd-logind[506]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1634server # [ 10.532336] systemd[1]: Started Mock OIDC server for testing.1635server # [ 10.550039] systemd[1]: Starting Nginx Web Server...1636builder # [ 10.565065] 8021q: adding VLAN 0 to HW filter on device eth01637builder # [ 10.553692] dhcpcd[624]: eth0: waiting for carrier1638builder # [ 10.554864] dhcpcd[624]: eth0: carrier acquired1639builder # [ 10.570001] dhcpcd[624]: DUID 00:01:00:01:32:62:6d:73:52:54:00:12:34:561640builder # [ 10.571273] dhcpcd[624]: eth0: IAID 00:12:34:561641builder # [ 10.571970] dhcpcd[624]: eth0: adding address fe80::5054:ff:fe12:34561642server # [ 10.572917] systemd[1]: Starting PostgreSQL Server...1643server # [ 10.597678] systemd[1]: Started RustFS S3-compatible object storage.1644server # [ 10.604277] systemd[1]: Starting Setup RustFS bucket...1645builder # [ 10.636493] dhcpcd[624]: eth0: soliciting a DHCP lease1646server # [ 10.642279] systemd[1]: Starting Permit User Sessions...1647builder # [ 10.644488] dhcpcd[624]: eth0: offered 10.0.2.15 from 10.0.2.21648builder # [ 10.652255] dhcpcd[624]: eth0: probing address 10.0.2.15/241649server # [ 10.720942] cfg80211: Loading compiled-in X.509 certificates for regulatory database1650server # [ 10.743760] 8021q: adding VLAN 0 to HW filter on device eth11651server # [ 10.813577] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1652server # [ 10.802107] network-addresses-eth1-start[671]: adding address 192.168.1.2/24... done1653server # [ 10.817117] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1654server # [ 10.819956] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21655server # [ 10.820258] cfg80211: failed to load regulatory.db1656server # [ 10.830601] systemd[1]: Finished Permit User Sessions.1657server # [ 10.852163] network-addresses-eth1-start[671]: adding address 2001:db8:1::2/64... done1658server # [ 10.865980] systemd[1]: Started Getty on tty1.1659server # [ 10.866709] systemd[1]: Reached target Login Prompts.1660server # [ 10.928337] systemd[1]: Finished Address configuration of eth1.1661server # [ 11.098215] 8021q: adding VLAN 0 to HW filter on device eth01662server # [ 11.091342] dhcpcd[655]: eth0: waiting for carrier1663server # [ 11.095509] dhcpcd[655]: eth0: waiting for carrier1664server # [ 11.101254] dhcpcd[655]: eth0: carrier acquired1665server # [ 11.139033] dhcpcd[655]: DUID 00:01:00:01:32:62:6d:73:52:54:00:12:34:561666server # [ 11.148540] dhcpcd[655]: eth0: IAID 00:12:34:561667server # [ 11.149261] dhcpcd[655]: eth0: adding address fe80::5054:ff:fe12:34561668server # [ 11.159396] mock-oidc-server[675]: Mock OIDC Server running1669server # [ 11.163457] mock-oidc-server[675]: OIDC Address: 127.0.0.1:80801670server # [ 11.166967] mock-oidc-server[675]: Issue Address: 127.0.0.1:80811671server # [ 11.167921] mock-oidc-server[675]: Issuer: http://127.0.0.1:8080/oidc1672server # [ 11.180955] mock-oidc-server[675]: JWKS: http://127.0.0.1:8080/oidc/.well-known/jwks.json1673server # [ 11.182103] mock-oidc-server[675]: Discovery: http://127.0.0.1:8080/oidc/.well-known/openid-configuration1674server # [ 11.183364] mock-oidc-server[675]: Issue tokens: http://127.0.0.1:8081/issue?sub=...1675server # [ 11.272201] mousedev: PS/2 mouse device common for all mice1676server # [ 11.279833] nginx-pre-start[717]: nginx: the configuration file /nix/store/faa69z7cxcf98yn9lxcirib5jxnw1vy1-nginx.conf syntax is ok1677server # [ 11.287314] nginx-pre-start[717]: nginx: configuration file /nix/store/faa69z7cxcf98yn9lxcirib5jxnw1vy1-nginx.conf test is successful1678builder # [ 11.303004] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31679server # [ 11.307889] systemd[1]: Started Nginx Web Server.1680server # [ 11.341475] postgresql-pre-start[725]: The files belonging to this database system will be owned by user "postgres".1681server # [ 11.342941] postgresql-pre-start[725]: This user must also own the server process.1682server # [ 11.368414] postgresql-pre-start[725]: The database cluster will be initialized with locale "en_US.UTF-8".1683server # [ 11.369774] postgresql-pre-start[725]: The default database encoding has accordingly been set to "UTF8".1684server # [ 11.371039] postgresql-pre-start[725]: The default text search configuration will be set to "english".1685server # [ 11.389209] postgresql-pre-start[725]: Data page checksums are enabled.1686server # [ 11.396367] postgresql-pre-start[725]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok1687server # [ 11.397737] postgresql-pre-start[725]: creating subdirectories ... ok1688server # [ 11.398585] postgresql-pre-start[725]: selecting dynamic shared memory implementation ... posix1689server # [ 11.455844] systemd-logind[511]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1690builder # [ 11.615773] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1691server # [ 11.619228] postgresql-pre-start[725]: selecting default "max_connections" ... 1001692builder # [ 11.628618] systemd[1]: Starting Virtual Console Setup...1693builder # [ 11.650682] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1694builder # [ 11.654173] systemd[1]: Stopped Virtual Console Setup.1695server # [ 11.659015] dhcpcd[655]: eth0: soliciting a DHCP lease1696server # [ 11.664509] dhcpcd[655]: eth0: offered 10.0.2.15 from 10.0.2.21697builder # [ 11.665683] systemd[1]: Starting Virtual Console Setup...1698server # [ 11.672369] dhcpcd[655]: eth0: probing address 10.0.2.15/241699builder # [ 11.706367] systemd-logind[506]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1700builder # [ 11.793542] systemd-vconsole-setup[688]: Configuration of first virtual console was skipped, ignoring remaining ones.1701builder # [ 11.797630] systemd[1]: Finished Virtual Console Setup.1702server # [ 11.873267] postgresql-pre-start[725]: selecting default "shared_buffers" ... 128MB1703builder # [ 12.036456] dhcpcd[624]: eth0: soliciting an IPv6 router1704builder # [ 12.038370] dhcpcd[624]: eth0: Router Advertisement from fe80::21705builder # [ 12.039801] dhcpcd[624]: eth0: adding address fec0::5054:ff:fe12:3456/641706builder # [ 12.041349] dhcpcd[624]: eth0: adding route to fec0::/641707builder # [ 12.042515] dhcpcd[624]: eth0: adding default route via fe80::21708server # [ 12.752331] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31709server # [ 13.092252] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1710server # [ 13.121596] systemd[1]: Starting Virtual Console Setup...1711server # [ 13.139355] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1712server # [ 13.144332] systemd[1]: Stopped Virtual Console Setup.1713server # [ 13.147509] systemd[1]: Starting Virtual Console Setup...1714server # [ 13.202821] systemd-logind[511]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1715server # [ 13.426558] dhcpcd[655]: eth0: soliciting an IPv6 router1716server # [ 13.427959] dhcpcd[655]: eth0: Router Advertisement from fe80::21717server # [ 13.428949] dhcpcd[655]: eth0: adding address fec0::5054:ff:fe12:3456/641718server # [ 13.429869] dhcpcd[655]: eth0: adding route to fec0::/641719server # [ 13.430606] dhcpcd[655]: eth0: adding default route via fe80::21720server # [ 13.453916] systemd-vconsole-setup[775]: Configuration of first virtual console was skipped, ignoring remaining ones.1721server # [ 13.457851] systemd[1]: Finished Virtual Console Setup.1722server # [ 13.741418] postgresql-pre-start[725]: selecting default time zone ... UTC1723server # [ 13.743988] postgresql-pre-start[725]: creating configuration files ... ok1724server # [ 13.983268] postgresql-pre-start[725]: running bootstrap script ... ok1725server # [ 14.511235] postgresql-pre-start[725]: performing post-bootstrap initialization ... ok1726server # [ 14.664055] postgresql-pre-start[725]: syncing data to disk ... ok1727server # [ 14.666079] postgresql-pre-start[725]: initdb: warning: enabling "trust" authentication for local connections1728server # [ 14.667608] postgresql-pre-start[725]: 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.1729server # [ 14.669955] postgresql-pre-start[725]: Success. You can now start the database server using:1730server # [ 14.671063] postgresql-pre-start[725]: pg_ctl -D /var/lib/postgresql/18 -l logfile start1731server # [ 14.759069] postgres[794]: [794] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit1732server # [ 14.762549] postgres[794]: [794] LOG: listening on IPv6 address "::1", port 54321733server # [ 14.763779] postgres[794]: [794] LOG: listening on IPv4 address "127.0.0.1", port 54321734server # [ 14.765650] postgres[794]: [794] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"1735server # [ 14.776400] postgres[803]: [803] LOG: database system was shut down at 2026-10-14 16:42:31 GMT1736server # [ 14.782253] postgres[794]: [794] LOG: database system is ready to accept connections1737server # [ 14.785675] systemd[1]: Started PostgreSQL Server.1738server # [ 14.793061] systemd[1]: Starting PostgreSQL Setup Scripts...1739server # [ 14.967666] postgresql-setup-start[814]: CREATE DATABASE1740server # [ 15.006808] postgresql-setup-start[819]: CREATE ROLE1741server # [ 15.023388] postgresql-setup-start[821]: ALTER DATABASE1742server # [ 15.028966] systemd[1]: Finished PostgreSQL Setup Scripts.1743server # [ 15.030908] systemd[1]: Reached target PostgreSQL.1744builder # [ 15.442097] dhcpcd[624]: eth0: leased 10.0.2.15 for 86400 seconds1745builder # [ 15.442296] dhcpcd[624]: eth0: adding route to 10.0.2.0/241746builder # [ 15.442369] dhcpcd[624]: eth0: adding default route via 10.0.2.21747builder # [ 15.571456] systemd[1]: Started DHCP Client.1748builder # [ 15.573353] systemd[1]: Reached target Multi-User System.1749builder # [ 15.574920] systemd[1]: Startup finished in 977ms (kernel) + 4.600s (initrd) + 9.996s (userspace) = 15.574s.1750server: (finished: waiting for unit postgresql.service, in 16.01 seconds)1751server: waiting for unit rustfs.service1752server: (finished: waiting for unit rustfs.service, in 0.04 seconds)1753server: waiting for unit rustfs-setup.service1754server # [ 16.678838] dhcpcd[655]: eth0: leased 10.0.2.15 for 86400 seconds1755server # [ 16.679018] dhcpcd[655]: eth0: adding route to 10.0.2.0/241756server # [ 16.679089] dhcpcd[655]: eth0: adding default route via 10.0.2.21757server # [ 16.811689] systemd[1]: Started DHCP Client.1758server # [ 25.866166] rustfs-setup-start[941]: mb s3://niks3-test1759server # [ 25.879027] systemd[1]: Finished Setup RustFS bucket.1760server # [ 25.890148] systemd[1]: Starting niks3 server...1761server # [ 26.061838] niks3-server[951]: 2026/10/14 16:42:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:8080/oidc1762server # [ 26.070944] niks3-server[951]: 2026/10/14 16:42:42 INFO OIDC authentication enabled config=/nix/store/f94czh0qddabanbdhbb264fc54xx8cyh-niks3-oidc.json1763server # [ 26.080224] niks3-server[951]: 2026/10/14 16:42:42 INFO Loaded signing key name=niks3-test-1 path=/nix/store/snw7kmczqsc6g53bbgqlmqjiq9xddgss-niks3-signing-key1764server # [ 26.108191] niks3-server[951]: 2026/10/14 16:42:42 INFO Using socket-activated listener address=0.0.0.0:57511765server # [ 26.109569] niks3-server[951]: 2026/10/14 16:42:42 INFO Using socket-activated listener address=/run/niks3/proxy.sock1766server # [ 26.110922] niks3-server[951]: 2026/10/14 16:42:42 INFO systemd watchdog enabled interval=15s1767server # [ 26.117522] niks3-server[951]: 2026/10/14 16:42:42 INFO Starting HTTP server address=0.0.0.0:57511768server # [ 26.120537] niks3-server[951]: 2026/10/14 16:42:42 INFO Starting HTTP server address=/run/niks3/proxy.sock1769server # [ 26.121856] systemd[1]: Started niks3 server.1770server # [ 26.122521] systemd[1]: Reached target Multi-User System.1771server # [ 26.124187] systemd[1]: Startup finished in 972ms (kernel) + 4.614s (initrd) + 20.527s (userspace) = 26.114s.1772server: (finished: waiting for unit rustfs-setup.service, in 10.49 seconds)1773server: waiting for unit mock-oidc.service1774server: (finished: waiting for unit mock-oidc.service, in 0.05 seconds)1775server: waiting for unit niks3.service1776server: (finished: waiting for unit niks3.service, in 0.03 seconds)1777server: waiting for TCP port 5751 on localhost1778server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!1779server: (finished: waiting for TCP port 5751 on localhost, in 0.03 seconds)1780server: waiting for TCP port 8080 on localhost1781server # Connection to localhost (127.0.0.1) 8080 port [tcp/http-alt] succeeded!1782server: (finished: waiting for TCP port 8080 on localhost, in 0.02 seconds)1783server: waiting for TCP port 9000 on localhost1784server # Connection to localhost (127.0.0.1) 9000 port [tcp/cslistener] succeeded!1785server: (finished: waiting for TCP port 9000 on localhost, in 0.02 seconds)1786server: must succeed: mkdir -p /tmp/test-config1787server: (finished: must succeed: mkdir -p /tmp/test-config, in 0.01 seconds)1788server: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token1789server: (finished: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token, in 0.01 seconds)1790server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31791server # [ 26.475437] niks3-server[951]: 2026/10/14 16:42:43 INFO Received push request method=POST path=/api/pushes1792server # time=2026-10-14T16:42:43.088Z level=INFO msg="Uploading 5 paths to server (0 already cached)"1793server # time=2026-10-14T16:42:43.089Z level=INFO msg="Uploading gxljc46qyjqzvhrnf5wk5ypyg73qv84n-libidn2-2.3.8 (366.1KB)"1794server # time=2026-10-14T16:42:43.091Z level=INFO msg="Uploading 0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3 (287.5KB)"1795server # time=2026-10-14T16:42:43.094Z level=INFO msg="Uploading d3xvwgga6f7mchrbvc77g3gap2yw1pd4-libunistring-1.4.2 (2.0MB)"1796server # time=2026-10-14T16:42:43.097Z level=INFO msg="Uploading ficwc08a9q1rigvr4jv9l3xsvmx3yfqn-xgcc-16.2.0-libgcc (150.2KB)"1797server # time=2026-10-14T16:42:43.099Z level=INFO msg="Uploading hx9wvdx2l59iahwf9nmrx7rwkm6cymgs-glibc-2.44-25 (44.8MB)"1798server # [ 26.818210] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=gxljc46qyjqzvhrnf5wk5ypyg73qv84n.ls1799server # [ 26.834175] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=ficwc08a9q1rigvr4jv9l3xsvmx3yfqn.ls1800server # [ 26.872372] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=nar/0ik4x86wi4hx5a19m0hrqb82v8pwywwk872j6xqs6cbsmirmckm4.nar.zst1801server # [ 26.913413] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=d3xvwgga6f7mchrbvc77g3gap2yw1pd4.ls1802server # [ 26.922734] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=nar/07qvg0nz70dkqx83m02p283r0jrv8d1schf7y6wkai65w85yzvv0.nar.zst1803server # [ 26.934463] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=0xy6jlccm8kfpwmhkxabz3638lchyi74.ls1804server # [ 26.937246] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=nar/18yshwpp5jc6x354ipdplqa3ylhpqlbzihvyv9h05j8hpn888058.nar.zst1805server # [ 26.939595] niks3-server[951]: 2026/10/14 16:42:43 INFO Registered completed upload object_key=nar/18599cw0w0wm2wv1ad31rx00n0643i8z2zgra1j66ikfwcs5q8g0.nar.zst1806server # [ 27.570810] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=hx9wvdx2l59iahwf9nmrx7rwkm6cymgs.ls1807server # [ 27.625641] niks3-server[951]: 2026/10/14 16:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1808server # [ 27.641331] niks3-server[951]: 2026/10/14 16:42:44 INFO Completed multipart upload object_key=nar/1jmx0pk58iv937afmb3f0la32bd0avaixkxq0cx99vzamxdxg5y0.nar.zst upload_id=YTdlYTg1NGItZTRiNC00ZjA5LWI4YmItNTMxM2MyZGQ1OWUxLmI1ZGQ5ODMyLWFlOGEtNDgxNC1hZTNlLTg0ODMyODY2ZjQ4Y3gxNzkxOTk2MTYzMDgyMDYxNDYw parts=11809server # time=2026-10-14T16:42:44.246Z level=INFO msg="Uploading 5 narinfos"1810server # [ 27.652160] niks3-server[951]: 2026/10/14 16:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1811server # [ 27.653672] niks3-server[951]: 2026/10/14 16:42:44 INFO Signed narinfos id=1 count=51812server # [ 27.683942] niks3-server[951]: 2026/10/14 16:42:44 INFO Received complete push request method=POST path=/api/pushes/1/complete1813server # [ 27.693496] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=ficwc08a9q1rigvr4jv9l3xsvmx3yfqn.narinfo1814server # [ 27.698466] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=hx9wvdx2l59iahwf9nmrx7rwkm6cymgs.narinfo1815server # time=2026-10-14T16:42:44.300Z level=INFO msg="Upload complete. (1.28s)"1816server # [ 27.705349] niks3-server[951]: 2026/10/14 16:42:44 INFO Completed push id=1 objects=15 duration=20.4802ms1817server # [ 27.706687] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=d3xvwgga6f7mchrbvc77g3gap2yw1pd4.narinfo1818server # [ 27.714019] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=0xy6jlccm8kfpwmhkxabz3638lchyi74.narinfo1819server # [ 27.715667] niks3-server[951]: 2026/10/14 16:42:44 INFO Registered completed upload object_key=gxljc46qyjqzvhrnf5wk5ypyg73qv84n.narinfo1820server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 1.41 seconds)1821server: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token1822server: (finished: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token, in 0.01 seconds)1823server: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31824server # [ 27.815418] niks3-server[951]: 2026/10/14 16:42:44 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]1825server # [ 27.868862] niks3-server[951]: 2026/10/14 16:42:44 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]1826server # time=2026-10-14T16:42:44.470Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1827server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 0.14 seconds)1828server: waiting for unit nginx.service1829server: (finished: waiting for unit nginx.service, in 0.03 seconds)1830server: waiting for TCP port 443 on localhost1831server # Connection to localhost (::1) 443 port [tcp/https] succeeded!1832server: (finished: waiting for TCP port 443 on localhost, in 0.02 seconds)1833server: must succeed: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-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/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31834server # time=2026-10-14T16:42:44.591Z 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.pem1835server # time=2026-10-14T16:42:44.604Z level=INFO msg="All 1 paths already cached"1836server: (finished: must succeed: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-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/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 0.08 seconds)1837server: 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_closures1838server: (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)1839server: must fail: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31840server # time=2026-10-14T16:42:44.653Z 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)"1841server: (finished: must fail: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 0.02 seconds)1842server: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31843server # time=2026-10-14T16:42:44.724Z level=INFO msg="Configuring client TLS" cert="" key="" ca=/etc/niks3-test-certs/ca.pem1844server # time=2026-10-14T16:42:44.733Z level=INFO msg="All 1 paths already cached"1845server: (finished: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 0.08 seconds)1846server: must succeed: cd /etc/niks3-test-certs && /nix/store/m9xpj129716c3dn7mcja91cb84mplpv9-openssl-3.5.8-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client'1847server # -----1848server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/m9xpj129716c3dn7mcja91cb84mplpv9-openssl-3.5.8-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)1849server: must succeed: cd /etc/niks3-test-certs && /nix/store/m9xpj129716c3dn7mcja91cb84mplpv9-openssl-3.5.8-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem1850server # Certificate request self-signature ok1851server # subject=CN=other client1852server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/m9xpj129716c3dn7mcja91cb84mplpv9-openssl-3.5.8-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem, in 0.04 seconds)1853server: must fail: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-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/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31854server # time=2026-10-14T16:42:44.860Z 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.pem1855server # [ 28.270408] niks3-server[951]: 2026/10/14 16:42:44 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1856server # [ 28.321195] niks3-server[951]: 2026/10/14 16:42:44 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1857server # time=2026-10-14T16:42:44.921Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1858server: (finished: must fail: /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-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/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3, in 0.13 seconds)1859server: must succeed: mkdir -p /tmp/test-store1860server: (finished: must succeed: mkdir -p /tmp/test-store, in 0.02 seconds)1861server: must succeed: 1862 export AWS_ACCESS_KEY_ID=rustfsadmin1863export AWS_SECRET_ACCESS_KEY=rustfsadmin1864 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.318651866server # copying 5 paths...1867server # copying path '/nix/store/d3xvwgga6f7mchrbvc77g3gap2yw1pd4-libunistring-1.4.2' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1868server # copying path '/nix/store/ficwc08a9q1rigvr4jv9l3xsvmx3yfqn-xgcc-16.2.0-libgcc' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1869server # copying path '/nix/store/gxljc46qyjqzvhrnf5wk5ypyg73qv84n-libidn2-2.3.8' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1870server # copying path '/nix/store/hx9wvdx2l59iahwf9nmrx7rwkm6cymgs-glibc-2.44-25' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1871server # copying path '/nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1872server: (finished: must succeed: 1873 export AWS_ACCESS_KEY_ID=rustfsadmin1874export AWS_SECRET_ACCESS_KEY=rustfsadmin1875 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.31876, in 0.55 seconds)1877server: must succeed: 1878cat > /tmp/test-drv.nix << 'EOF'1879derivation {1880 name = "test-build-log";1881 system = builtins.currentSystem;1882 builder = "/bin/sh";1883 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1884}1885EOF18861887server: (finished: must succeed: 1888cat > /tmp/test-drv.nix << 'EOF'1889derivation {1890 name = "test-build-log";1891 system = builtins.currentSystem;1892 builder = "/bin/sh";1893 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1894}1895EOF1896, in 0.02 seconds)1897server: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix1898server # this derivation will be built:1899server # /nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1900server # building '/nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv'...1901server # test-build-log> test build log output1902server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix, in 0.17 seconds)1903server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1904server # [ 29.202274] niks3-server[951]: 2026/10/14 16:42:45 INFO Received push request method=POST path=/api/pushes1905server # time=2026-10-14T16:42:45.806Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1906server # time=2026-10-14T16:42:45.807Z level=INFO msg="Uploading z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log (128B)"1907server # [ 29.234361] niks3-server[951]: 2026/10/14 16:42:45 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.ls1908server # [ 29.243396] niks3-server[951]: 2026/10/14 16:42:45 INFO Registered completed upload object_key=log/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1909server # time=2026-10-14T16:42:45.847Z level=INFO msg="Uploading 1 narinfos"1910server # [ 29.251451] niks3-server[951]: 2026/10/14 16:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1911server # [ 29.255943] niks3-server[951]: 2026/10/14 16:42:45 INFO Signed narinfos id=2 count=11912server # [ 29.259156] niks3-server[951]: 2026/10/14 16:42:45 INFO Registered completed upload object_key=nar/00zns3gj9hwz2a4b0i07y7nmxybq59lh24bl3xsxblcl6333mjil.nar.zst1913server # [ 29.268466] niks3-server[951]: 2026/10/14 16:42:45 INFO Received complete push request method=POST path=/api/pushes/2/complete1914server # time=2026-10-14T16:42:45.873Z level=INFO msg="Upload complete. (130ms)"1915server # [ 29.276398] niks3-server[951]: 2026/10/14 16:42:45 INFO Completed push id=2 objects=4 duration=8.63796ms1916server # [ 29.281584] niks3-server[951]: 2026/10/14 16:42:45 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo1917server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log, in 0.21 seconds)1918server: must succeed: 1919 export AWS_ACCESS_KEY_ID=rustfsadmin1920export AWS_SECRET_ACCESS_KEY=rustfsadmin1921 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log19221923server # got build log for '/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'1924server: (finished: must succeed: 1925 export AWS_ACCESS_KEY_ID=rustfsadmin1926export AWS_SECRET_ACCESS_KEY=rustfsadmin1927 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1928, in 0.13 seconds)1929subtest: push --stdin streams paths and reports each one1930server: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }'1931server # this derivation will be built:1932server # /nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1933server # building '/nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv'...1934server: (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.16 seconds)1935server: 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/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --stdin1936server # [ 29.697902] niks3-server[951]: 2026/10/14 16:42:46 INFO Received push request method=POST path=/api/pushes1937server # time=2026-10-14T16:42:46.301Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1938server # time=2026-10-14T16:42:46.302Z level=INFO msg="Uploading 7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test (120B)"1939server # [ 29.727907] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=log/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1940server # [ 29.737594] niks3-server[951]: 2026/10/14 16:42:46 INFO Received sign narinfos request method=POST path=/api/pushes/3/sign1941server # time=2026-10-14T16:42:46.339Z level=INFO msg="Uploading 1 narinfos"1942server # [ 29.743882] niks3-server[951]: 2026/10/14 16:42:46 INFO Signed narinfos id=3 count=11943server # [ 29.746294] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.ls1944server # [ 29.747841] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=nar/1hj1r0g515rfxjx685mfn3dgr6akqbn4gf64snlv6bxaxph69lna.nar.zst1945server # [ 29.759758] niks3-server[951]: 2026/10/14 16:42:46 INFO Received complete push request method=POST path=/api/pushes/3/complete1946server # time=2026-10-14T16:42:46.360Z level=INFO msg="Upload complete. (115ms)"1947server # [ 29.764997] niks3-server[951]: 2026/10/14 16:42:46 INFO Completed push id=3 objects=4 duration=4.10292ms1948server # [ 29.766277] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.narinfo1949server: (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/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --stdin, in 0.19 seconds)1950server: must succeed: 1951 export AWS_ACCESS_KEY_ID=rustfsadmin1952export AWS_SECRET_ACCESS_KEY=rustfsadmin1953 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1954 1955server # copying 1 paths...1956server # copying path '/nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1957server: (finished: must succeed: 1958 export AWS_ACCESS_KEY_ID=rustfsadmin1959export AWS_SECRET_ACCESS_KEY=rustfsadmin1960 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1961 , in 0.15 seconds)1962(finished: subtest: push --stdin streams paths and reports each one, in 0.50 seconds)1963server: must succeed: 1964cat > /tmp/ca-test.nix << 'EOF'1965derivation {1966 name = "ca-test";1967 system = builtins.currentSystem;1968 builder = "/bin/sh";1969 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1970 __contentAddressed = true;1971 outputHashMode = "recursive";1972 outputHashAlgo = "sha256";1973}1974EOF19751976server: (finished: must succeed: 1977cat > /tmp/ca-test.nix << 'EOF'1978derivation {1979 name = "ca-test";1980 system = builtins.currentSystem;1981 builder = "/bin/sh";1982 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1983 __contentAddressed = true;1984 outputHashMode = "recursive";1985 outputHashAlgo = "sha256";1986}1987EOF1988, in 0.02 seconds)1989server: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link1990server # this derivation will be built:1991server # /nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv1992server # building '/nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv'...1993server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link, in 0.16 seconds)1994server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test1995server # [ 30.245546] niks3-server[951]: 2026/10/14 16:42:46 INFO Received push request method=POST path=/api/pushes1996server # time=2026-10-14T16:42:46.848Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1997server # time=2026-10-14T16:42:46.849Z level=INFO msg="Uploading 5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test (144B)"1998server # [ 30.273614] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.ls1999server # [ 30.280885] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=log/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv2000server # time=2026-10-14T16:42:46.883Z level=INFO msg="Uploading 1 narinfos"2001server # [ 30.287641] niks3-server[951]: 2026/10/14 16:42:46 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign2002server # [ 30.293015] niks3-server[951]: 2026/10/14 16:42:46 INFO Signed narinfos id=4 count=12003server # [ 30.297317] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2004server # [ 30.304431] niks3-server[951]: 2026/10/14 16:42:46 INFO Received complete push request method=POST path=/api/pushes/4/complete2005server # time=2026-10-14T16:42:46.905Z level=INFO msg="Upload complete. (153ms)"2006server # [ 30.308217] niks3-server[951]: 2026/10/14 16:42:46 INFO Completed push id=4 objects=4 duration=3.99796ms2007server # [ 30.312409] niks3-server[951]: 2026/10/14 16:42:46 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.narinfo2008server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.22 seconds)2009server: must succeed: mkdir -p /tmp/chroot-store2010server: (finished: must succeed: mkdir -p /tmp/chroot-store, in 0.02 seconds)2011server: must succeed: 2012 export AWS_ACCESS_KEY_ID=rustfsadmin2013export AWS_SECRET_ACCESS_KEY=rustfsadmin2014 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test20152016server # copying 1 paths...2017server # copying path '/nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2018server: (finished: must succeed: 2019 export AWS_ACCESS_KEY_ID=rustfsadmin2020export AWS_SECRET_ACCESS_KEY=rustfsadmin2021 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2022, in 0.14 seconds)2023server: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2024server: (finished: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2025server: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2026server # warning: 'realisation' is a deprecated alias for 'store build-trace'2027server: (finished: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2028server: must succeed: readlink /etc/niks3-test/symlink-wrapper2029server: (finished: must succeed: readlink /etc/niks3-test/symlink-wrapper, in 0.02 seconds)2030server: must succeed: readlink /etc/static/niks3-test/symlink-wrapper2031server: (finished: must succeed: readlink /etc/static/niks3-test/symlink-wrapper, in 0.01 seconds)2032server: must succeed: test -L /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper2033server: (finished: must succeed: test -L /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper, in 0.01 seconds)2034server: must succeed: readlink /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper2035server: (finished: must succeed: readlink /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper, in 0.01 seconds)2036server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper2037server # [ 30.806932] niks3-server[951]: 2026/10/14 16:42:47 INFO Received push request method=POST path=/api/pushes2038server # time=2026-10-14T16:42:47.409Z level=INFO msg="Uploading 2 paths to server (0 already cached)"2039server # time=2026-10-14T16:42:47.410Z level=INFO msg="Uploading l5aiz90gwfr0i2074qb0pk20v27p5v86-base-package (536B)"2040server # time=2026-10-14T16:42:47.412Z level=INFO msg="Uploading qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper (192B)"2041server # [ 30.840587] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=nar/0820av37plmfgrxw6pcbym6phk1sv14dilyrablrnkzb7z1fd5js.nar.zst2042server # [ 30.847937] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=qlhg6w8ghvjarrf438qw23mymapxfpdp.ls2043server # [ 30.854795] niks3-server[951]: 2026/10/14 16:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/5/sign2044server # time=2026-10-14T16:42:47.454Z level=INFO msg="Uploading 2 narinfos"2045server # [ 30.859923] niks3-server[951]: 2026/10/14 16:42:47 INFO Signed narinfos id=5 count=22046server # [ 30.863387] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=nar/0pls6byi1j0qx38i7wfm9a2mhgj2lwdyl5wmfdzfgvd67yhriq4z.nar.zst2047server # [ 30.867855] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=l5aiz90gwfr0i2074qb0pk20v27p5v86.ls2048server # [ 30.883156] niks3-server[951]: 2026/10/14 16:42:47 INFO Received complete push request method=POST path=/api/pushes/5/complete2049server # time=2026-10-14T16:42:47.485Z level=INFO msg="Upload complete. (158ms)"2050server # [ 30.888464] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=qlhg6w8ghvjarrf438qw23mymapxfpdp.narinfo2051server # [ 30.890079] niks3-server[951]: 2026/10/14 16:42:47 INFO Completed push id=5 objects=6 duration=5.43254ms2052server # [ 30.895384] niks3-server[951]: 2026/10/14 16:42:47 INFO Registered completed upload object_key=l5aiz90gwfr0i2074qb0pk20v27p5v86.narinfo2053server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper, in 0.25 seconds)2054server: must succeed: 2055 export AWS_ACCESS_KEY_ID=rustfsadmin2056export AWS_SECRET_ACCESS_KEY=rustfsadmin2057 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper20582059server # copying 2 paths...2060server # copying path '/nix/store/l5aiz90gwfr0i2074qb0pk20v27p5v86-base-package' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2061server # copying path '/nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2062server: (finished: 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/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper2066, in 0.18 seconds)2067server: must succeed: 2068cat > /tmp/oidc-test.nix << 'EOF'2069derivation {2070 name = "oidc-test";2071 system = builtins.currentSystem;2072 builder = "/bin/sh";2073 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2074}2075EOF20762077server: (finished: must succeed: 2078cat > /tmp/oidc-test.nix << 'EOF'2079derivation {2080 name = "oidc-test";2081 system = builtins.currentSystem;2082 builder = "/bin/sh";2083 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2084}2085EOF2086, in 0.02 seconds)2087server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link2088server # this derivation will be built:2089server # /nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2090server # building '/nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv'...2091server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link, in 0.19 seconds)2092server: 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'2093server: (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.03 seconds)2094server: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTE5OTk3NjcsImlhdCI6MTc5MTk5NjE2NywiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.UUAGxZy_JVps30yb4FZf3YtunmP0RkNQ9QWiZ7IfpWhAV7APe_xMjh7KHqiOEKFHm7XWFq76eQkc462sM5Ujule9cdQJIp-rm7aZGf0iMdx7FAw9sfiVPG4WEteA4XV4531NHSId4RD4xxDinamkrhDEqXuaB4zgjkZcMhaO9SqEyapd40Sh74CycOo_bIA3Wz55mRH4Q2dU_4hGnCujr6507Ag6518qUqKOLZu1bArG8IjeL8L087P1j7_nXP3CoLeFuamps83hmEnBXLRmlor-AJtAxZRsnfc5LgngaFHlfnpAq_Dmh_osDl2vRs5Fwl_L_q5xvc7bL-o4uTE9Kw' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2095server # time=2026-10-14T16:42:47.939Z 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"2096server # [ 31.471769] niks3-server[951]: 2026/10/14 16:42:48 INFO Received push request method=POST path=/api/pushes2097server # time=2026-10-14T16:42:48.075Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2098server # time=2026-10-14T16:42:48.076Z level=INFO msg="Uploading x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test (136B)"2099server # [ 31.517059] niks3-server[951]: 2026/10/14 16:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/6/sign2100server # [ 31.518714] niks3-server[951]: 2026/10/14 16:42:48 INFO Signed narinfos id=6 count=12101server # time=2026-10-14T16:42:48.122Z level=INFO msg="Uploading 1 narinfos"2102server # [ 31.528414] niks3-server[951]: 2026/10/14 16:42:48 INFO Registered completed upload object_key=log/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2103server # [ 31.530244] niks3-server[951]: 2026/10/14 16:42:48 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.ls2104server # [ 31.537644] niks3-server[951]: 2026/10/14 16:42:48 INFO Registered completed upload object_key=nar/17h0qgwf5334wia961ibqy9hmpsyvfhrvj5ji9m031klp6sx4v0q.nar.zst2105server # [ 31.550890] niks3-server[951]: 2026/10/14 16:42:48 INFO Received complete push request method=POST path=/api/pushes/6/complete2106server # time=2026-10-14T16:42:48.152Z level=INFO msg="Upload complete. (150ms)"2107server # [ 31.554939] niks3-server[951]: 2026/10/14 16:42:48 INFO Completed push id=6 objects=4 duration=5.25472ms2108server # [ 31.560587] niks3-server[951]: 2026/10/14 16:42:48 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.narinfo2109server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTE5OTk3NjcsImlhdCI6MTc5MTk5NjE2NywiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.UUAGxZy_JVps30yb4FZf3YtunmP0RkNQ9QWiZ7IfpWhAV7APe_xMjh7KHqiOEKFHm7XWFq76eQkc462sM5Ujule9cdQJIp-rm7aZGf0iMdx7FAw9sfiVPG4WEteA4XV4531NHSId4RD4xxDinamkrhDEqXuaB4zgjkZcMhaO9SqEyapd40Sh74CycOo_bIA3Wz55mRH4Q2dU_4hGnCujr6507Ag6518qUqKOLZu1bArG8IjeL8L087P1j7_nXP3CoLeFuamps83hmEnBXLRmlor-AJtAxZRsnfc5LgngaFHlfnpAq_Dmh_osDl2vRs5Fwl_L_q5xvc7bL-o4uTE9Kw' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test, in 0.24 seconds)2110server: must succeed: 2111cat > /tmp/oidc-test2.nix << 'EOF'2112derivation {2113 name = "oidc-test2";2114 system = builtins.currentSystem;2115 builder = "/bin/sh";2116 args = [ "-c" "echo 'OIDC test 2' > $out" ];2117}2118EOF21192120server: (finished: must succeed: 2121cat > /tmp/oidc-test2.nix << 'EOF'2122derivation {2123 name = "oidc-test2";2124 system = builtins.currentSystem;2125 builder = "/bin/sh";2126 args = [ "-c" "echo 'OIDC test 2' > $out" ];2127}2128EOF2129, in 0.02 seconds)2130server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link2131server # this derivation will be built:2132server # /nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv2133server # building '/nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv'...2134server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link, in 0.19 seconds)2135server: 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'2136server: (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)2137server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTE5OTk3NjgsImlhdCI6MTc5MTk5NjE2OCwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.pugGfydIFFsJ5RlQq4O303600VoRXJ1W_5Sl2xANbgc9UGTUZ52-AkWDMHUQuNpbhEhkvF2IJ4pIDAYzLY7-P9ZscLbztnHG5Mixf5UQ8L8olokaZF_MeCy1wnp_FXvyRFgcjdHD7EeoknIXPwhoYNCDQI8XhO2hiO3-diAi7RkHob6tBwBUu5N_XTIZHAdkiG41OjU0_4B0GKb2ZJZKBn6H_4I_Z2DWcfo1p1w5NcaVKC0tk5yFc7IKbkCSm6gzWZspyPrLj8HkANbar700pbb2QuZ1DooRUxjRYRrm8zK0AZRHjk3cfhpOhj45JPw-OxEkthi9yn8OxhaUFpHafw' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22138server # time=2026-10-14T16:42:48.430Z 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"2139server # [ 31.901923] niks3-server[951]: 2026/10/14 16:42:48 WARN Authentication failed token_preview=eyJhbGciOi...xhaUFpHafw token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2140server # [ 31.963122] niks3-server[951]: 2026/10/14 16:42:48 WARN Authentication failed token_preview=eyJhbGciOi...xhaUFpHafw token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2141server # time=2026-10-14T16:42:48.565Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2142server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTE5OTk3NjgsImlhdCI6MTc5MTk5NjE2OCwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.pugGfydIFFsJ5RlQq4O303600VoRXJ1W_5Sl2xANbgc9UGTUZ52-AkWDMHUQuNpbhEhkvF2IJ4pIDAYzLY7-P9ZscLbztnHG5Mixf5UQ8L8olokaZF_MeCy1wnp_FXvyRFgcjdHD7EeoknIXPwhoYNCDQI8XhO2hiO3-diAi7RkHob6tBwBUu5N_XTIZHAdkiG41OjU0_4B0GKb2ZJZKBn6H_4I_Z2DWcfo1p1w5NcaVKC0tk5yFc7IKbkCSm6gzWZspyPrLj8HkANbar700pbb2QuZ1DooRUxjRYRrm8zK0AZRHjk3cfhpOhj45JPw-OxEkthi9yn8OxhaUFpHafw' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.16 seconds)2143server: 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'2144server: (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)2145server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MTk5OTc2OCwiaWF0IjoxNzkxOTk2MTY4LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.X4TDUuk5WLz7PMRQLMYSx8NxqDmvUEeIMy4FjAb1-zY-4oxftMRv0W0XeFaHhcfmQbDIeqrLRiJjFz2C1ZSW-rRQyt0UeSVZ1ETQUm63JY83cgz9AFx_FVSHbdgZoc2oyQhsGkoPEcNJ5MP7Tib2OeC843g7f8a2vxgMBN7qADRnit2FDAfLVxA1EKL8W2yMxT-KceOMQCNtkAV6IvNvWDLtX1eLirh8QzIva_6fAlPbjquQDLsx1XckbyN0c5IHjo1MZSCS8HefKsjVTUzi-a3s3MY4zynLXlBm7yTxtmcr8_nH9bhMeOVVxv2HcZ_pRrHKtGLxLl7pEJGZtKxi8A' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22146server # time=2026-10-14T16:42:48.619Z 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 # [ 32.096755] niks3-server[951]: 2026/10/14 16:42:48 WARN Authentication failed token_preview=eyJhbGciOi...EJGZtKxi8A token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2148server # [ 32.169127] niks3-server[951]: 2026/10/14 16:42:48 WARN Authentication failed token_preview=eyJhbGciOi...EJGZtKxi8A token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2149server # time=2026-10-14T16:42:48.770Z 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/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6InpiX181SXkyZFg1eVNlbHpKOHB3YVpxZzc2WkFvRGxLNUVneEVKRnBDRE0iLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MTk5OTc2OCwiaWF0IjoxNzkxOTk2MTY4LCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.X4TDUuk5WLz7PMRQLMYSx8NxqDmvUEeIMy4FjAb1-zY-4oxftMRv0W0XeFaHhcfmQbDIeqrLRiJjFz2C1ZSW-rRQyt0UeSVZ1ETQUm63JY83cgz9AFx_FVSHbdgZoc2oyQhsGkoPEcNJ5MP7Tib2OeC843g7f8a2vxgMBN7qADRnit2FDAfLVxA1EKL8W2yMxT-KceOMQCNtkAV6IvNvWDLtX1eLirh8QzIva_6fAlPbjquQDLsx1XckbyN0c5IHjo1MZSCS8HefKsjVTUzi-a3s3MY4zynLXlBm7yTxtmcr8_nH9bhMeOVVxv2HcZ_pRrHKtGLxLl7pEJGZtKxi8A' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.17 seconds)2151server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22152server # time=2026-10-14T16:42:48.799Z 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"2153server # [ 32.276733] niks3-server[951]: 2026/10/14 16:42:48 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]2154server # [ 32.350731] niks3-server[951]: 2026/10/14 16:42:48 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]2155server # time=2026-10-14T16:42:48.953Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2156server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.19 seconds)2157server: must succeed: 2158 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins create hello-pin /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.321592160server # [ 32.486852] niks3-server[951]: 2026/10/14 16:42:49 INFO Received create pin request method=POST path=/api/pins/hello-pin2161server # time=2026-10-14T16:42:49.101Z level=INFO msg="Created pin" name=hello-pin store_path=/nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.32162server # [ 32.505773] niks3-server[951]: 2026/10/14 16:42:49 INFO Created/updated pin name=hello-pin store_path=/nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.3 narinfo_key=0xy6jlccm8kfpwmhkxabz3638lchyi74.narinfo2163server: (finished: must succeed: 2164 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins create hello-pin /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.32165, in 0.15 seconds)2166server: must succeed: 2167 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list21682169server # [ 32.614658] niks3-server[951]: 2026/10/14 16:42:49 INFO Received list pins request method=GET path=/api/pins2170server: (finished: must succeed: 2171 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list2172, in 0.10 seconds)2173server: must succeed: 2174 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only21752176server # [ 32.710020] niks3-server[951]: 2026/10/14 16:42:49 INFO Received list pins request method=GET path=/api/pins2177server: (finished: must succeed: 2178 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only2179, in 0.10 seconds)2180server: must succeed: 2181 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --json21822183server # [ 32.807659] niks3-server[951]: 2026/10/14 16:42:49 INFO Received list pins request method=GET path=/api/pins2184server: (finished: must succeed: 2185 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --json2186, in 0.10 seconds)2187server: must succeed: 2188 export S3_ENDPOINT_URL=http://localhost:90002189 export AWS_ACCESS_KEY_ID=rustfsadmin2190 export AWS_SECRET_ACCESS_KEY=rustfsadmin2191 /nix/store/ilah8j764imsc5p7912a20hyh1lrgzmq-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin21922193server: (finished: must succeed: 2194 export S3_ENDPOINT_URL=http://localhost:90002195 export AWS_ACCESS_KEY_ID=rustfsadmin2196 export AWS_SECRET_ACCESS_KEY=rustfsadmin2197 /nix/store/ilah8j764imsc5p7912a20hyh1lrgzmq-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin2198, in 0.07 seconds)2199server: must succeed: 2200 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log22012202server # time=2026-10-14T16:42:49.566Z level=INFO msg="All 1 paths already cached"2203server # [ 32.969992] niks3-server[951]: 2026/10/14 16:42:49 INFO Received create pin request method=POST path=/api/pins/ca-pin2204server # time=2026-10-14T16:42:49.580Z level=INFO msg="Created pin" name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2205server # [ 32.983806] niks3-server[951]: 2026/10/14 16:42:49 INFO Created/updated pin name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log narinfo_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo2206server: (finished: must succeed: 2207 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2208, in 0.11 seconds)2209server: must succeed: 2210 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only22112212server # [ 33.083809] niks3-server[951]: 2026/10/14 16:42:49 INFO Received list pins request method=GET path=/api/pins2213server: (finished: must succeed: 2214 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only2215, in 0.10 seconds)2216server: must succeed: 2217 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins delete hello-pin22182219server # [ 33.182189] niks3-server[951]: 2026/10/14 16:42:49 INFO Received delete pin request method=DELETE path=/api/pins/hello-pin2220server # time=2026-10-14T16:42:49.789Z level=INFO msg="Deleted pin" name=hello-pin2221server # [ 33.192503] niks3-server[951]: 2026/10/14 16:42:49 INFO Deleted pin name=hello-pin2222server: (finished: must succeed: 2223 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins delete hello-pin2224, in 0.11 seconds)2225server: must succeed: 2226 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only22272228server # [ 33.307167] niks3-server[951]: 2026/10/14 16:42:49 INFO Received list pins request method=GET path=/api/pins2229server: (finished: must succeed: 2230 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins list --names-only2231, in 0.11 seconds)2232server: must fail: 2233 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent22342235server # [ 33.422044] niks3-server[951]: 2026/10/14 16:42:50 INFO Received create pin request method=POST path=/api/pins/bad-pin2236server # time=2026-10-14T16:42:50.023Z level=ERROR msg="Fatal error" error="creating pin: server returned 404: closure not found: store path must be pushed before pinning\n"2237server # [ 33.427242] niks3-server[951]: 2026/10/14 16:42:50 ERROR Failed to get closure for pin narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo error="no rows in result set"2238server: (finished: must fail: 2239 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/b3kb3xm8vdh1kbsg4y6pshz6ki9wykkq-niks3-1.15.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent2240, in 0.12 seconds)2241server: must succeed: systemctl start niks3-gc.service2242server # [ 33.464632] systemd[1]: Starting niks3 garbage collection...2243server # [ 33.530900] niks3[1535]: time=2026-10-14T16:42:50.128Z level=INFO msg="Starting garbage collection" older-than=720h failed-uploads-older-than=6h force=false2244server # [ 33.537603] niks3[1535]: time=2026-10-14T16:42:50.133Z level=INFO msg="Garbage collection started"2245server # [ 33.539461] niks3-server[951]: 2026/10/14 16:42:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures2246server # [ 33.548201] niks3-server[951]: 2026/10/14 16:42:50 INFO Aborted multipart uploads count=0 kept=02247server # [ 33.552731] niks3-server[951]: 2026/10/14 16:42:50 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=02248server # [ 33.559327] niks3-server[951]: 2026/10/14 16:42:50 INFO Vacuumed table table=pending_closures2249server # [ 33.563654] niks3-server[951]: 2026/10/14 16:42:50 INFO Vacuumed table table=pending_objects2250server # [ 33.567871] niks3-server[951]: 2026/10/14 16:42:50 INFO Vacuumed table table=multipart_uploads2251server # [ 33.571180] niks3-server[951]: 2026/10/14 16:42:50 INFO Vacuumed table table=closures2252server # [ 33.575054] niks3-server[951]: 2026/10/14 16:42:50 INFO Vacuumed table table=objects2253server # [ 35.539088] niks3[1535]: time=2026-10-14T16:42:52.136Z level=INFO msg="Garbage collection progress" phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=4 objects_deleted=0 objects_failed=02254server # [ 35.546363] niks3[1535]: time=2026-10-14T16:42:52.136Z 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=02255server # [ 35.557940] systemd[1]: niks3-gc.service: Deactivated successfully.2256server # [ 35.564544] systemd[1]: Finished niks3 garbage collection.2257server # [ 35.565939] systemd[1]: niks3-gc.service: Consumed 56ms CPU time over 2.092s wall clock time, 11.6M memory peak, 1.2K incoming IP traffic, 823B outgoing IP traffic.2258server: (finished: must succeed: systemctl start niks3-gc.service, in 2.15 seconds)2259builder: waiting for unit niks3-auto-upload.socket2260builder: waiting for the VM to finish booting2261builder: Guest shell says: b'Spawning backdoor root shell...\n'2262builder: connected to guest root shell2263builder: (connecting took 0.00 seconds)2264builder: (finished: waiting for the VM to finish booting, in 0.00 seconds)2265builder: (finished: waiting for unit niks3-auto-upload.socket, in 0.06 seconds)2266builder: must succeed: test -S /run/niks3/upload-to-cache.sock2267builder: (finished: must succeed: test -S /run/niks3/upload-to-cache.sock, in 0.02 seconds)2268builder: must succeed: grep post-build-hook /etc/nix/nix.conf2269builder: (finished: must succeed: grep post-build-hook /etc/nix/nix.conf, in 0.02 seconds)2270builder: must succeed: 2271cat > /tmp/test-drv.nix << 'EOF'2272derivation {2273 name = "post-build-hook-test";2274 system = builtins.currentSystem;2275 builder = "/bin/sh";2276 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2277}2278EOF22792280builder: (finished: must succeed: 2281cat > /tmp/test-drv.nix << 'EOF'2282derivation {2283 name = "post-build-hook-test";2284 system = builtins.currentSystem;2285 builder = "/bin/sh";2286 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2287}2288EOF2289, in 0.02 seconds)2290builder: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link2291builder # 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 1 ms (attempt 1/5)2292builder # 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 143 ms (attempt 2/5)2293builder # 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 223 ms (attempt 3/5)2294builder # 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 159 ms (attempt 4/5)2295builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org2296builder # this derivation will be built:2297builder # /nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2298builder # building '/nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv'...2299builder # [ 36.540699] systemd[1]: Started niks3 auto-upload daemon.2300builder # [ 36.693153] niks3-hook[793]: time=2026-10-14T16:42:53.289Z 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=0s2301builder # [ 36.701987] niks3-hook[793]: time=2026-10-14T16:42:53.298Z level=INFO msg="Upload queue status" pending=12302builder # [ 36.703426] niks3-hook[793]: time=2026-10-14T16:42:53.298Z level=INFO msg="Uploading batch" count=12303builder: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link, in 1.02 seconds)2304builder: waiting for unit niks3-auto-upload.service2305builder: (finished: waiting for unit niks3-auto-upload.service, in 0.09 seconds)2306??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2307 File "/nix/store/bsfvpn8q2430b9gbcb0d939kswyw8fyr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392308builder: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive2309??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2310 File "/nix/store/bsfvpn8q2430b9gbcb0d939kswyw8fyr-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392311builder # [ 36.817434] systemd[1]: Started Nix Daemon.2312builder # [ 36.901363] nix-daemon[812]: accepted connection from pid 808, user root (trusted)2313builder # [ 36.917942] nix-daemon[812]: reaped child process 819, status = succeeded2314server # [ 36.925489] niks3-server[951]: 2026/10/14 16:42:53 INFO Received push request method=POST path=/api/pushes2315builder # [ 36.936086] niks3-hook[793]: time=2026-10-14T16:42:53.531Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2316builder # [ 36.937620] niks3-hook[793]: time=2026-10-14T16:42:53.531Z level=INFO msg="Uploading 1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test (144B)"2317server # [ 36.986590] niks3-server[951]: 2026/10/14 16:42:53 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.ls2318server # [ 36.994624] niks3-server[951]: 2026/10/14 16:42:53 INFO Received sign narinfos request method=POST path=/api/pushes/7/sign2319builder # [ 36.999648] niks3-hook[793]: time=2026-10-14T16:42:53.595Z level=INFO msg="Uploading 1 narinfos"2320server # [ 37.005953] niks3-server[951]: 2026/10/14 16:42:53 INFO Signed narinfos id=7 count=12321server # [ 37.007770] niks3-server[951]: 2026/10/14 16:42:53 INFO Registered completed upload object_key=log/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2322server # [ 37.022503] niks3-server[951]: 2026/10/14 16:42:53 INFO Registered completed upload object_key=nar/1a0vfw93shmvlz6lac7d1lv82jxzfdswigh5s32hpvncf74i1i0y.nar.zst2323server # [ 37.036747] niks3-server[951]: 2026/10/14 16:42:53 INFO Received complete push request method=POST path=/api/pushes/7/complete2324server # [ 37.043881] niks3-server[951]: 2026/10/14 16:42:53 INFO Completed push id=7 objects=4 duration=10.97712ms2325builder # [ 37.044244] niks3-hook[793]: time=2026-10-14T16:42:53.640Z level=INFO msg="Upload complete. (342ms)"2326server # [ 37.047741] niks3-server[951]: 2026/10/14 16:42:53 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.narinfo2327builder # [ 41.701428] niks3-hook[793]: time=2026-10-14T16:42:58.297Z level=INFO msg="Idle timeout reached and queue is empty, shutting down"2328builder # [ 41.705603] niks3-hook[793]: time=2026-10-14T16:42:58.299Z level=INFO msg="niks3-hook serve stopped"2329builder # [ 41.714082] systemd[1]: niks3-auto-upload.service: Deactivated successfully.2330builder # [ 41.722015] systemd[1]: niks3-auto-upload.service: Consumed 201ms CPU time over 5.177s wall clock time, 31.1M memory peak, 68K written to disk, 5.8K incoming IP traffic, 8.6K outgoing IP traffic.2331builder: (finished: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive, in 5.23 seconds)2332server: must succeed: 2333 export AWS_ACCESS_KEY_ID=rustfsadmin2334export AWS_SECRET_ACCESS_KEY=rustfsadmin2335 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-test23362337server # copying 1 paths...2338server # copying path '/nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2339server: (finished: must succeed: 2340 export AWS_ACCESS_KEY_ID=rustfsadmin2341export AWS_SECRET_ACCESS_KEY=rustfsadmin2342 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-test2343, in 0.19 seconds)2344server: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2345server: (finished: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test, in 0.05 seconds)2346(finished: run the VM test script, in 43.03 seconds)2347test script finished in 43.11s2348cleanup2349kill QemuMachine (pid 47)2350builder # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/81ag9nxz1flw3xjkv1vvqg8y2ipx2ins-python3-3.14.7/bin/python3.14)2351builder # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2352builder # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2353builder # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2354kill QemuMachine (pid 48)2355server # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/81ag9nxz1flw3xjkv1vvqg8y2ipx2ins-python3-3.14.7/bin/python3.14)2356server # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2357server # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2358server # [2026-10-14T16:42:59Z INFO virtiofsd] Client disconnected, shutting down2359(finished: cleanup, in 0.45 seconds)2360additionally exposed symbols:2361 builder, server,2362 vlan1,2363 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_ssh2364Hello store path: /nix/store/0xy6jlccm8kfpwmhkxabz3638lchyi74-hello-2.12.32365Test output path: /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2366CA derivation output path: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2367Realisation info in chroot store: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test23682369Symlink wrapper store path: /nix/store/qlhg6w8ghvjarrf438qw23mymapxfpdp-symlink-wrapper2370Symlink wrapper points to: /nix/store/l5aiz90gwfr0i2074qb0pk20v27p5v86-base-package/bin/test-program2371OIDC test store path: /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2372Valid OIDC token obtained (length=677)2373OIDC push with valid token: SUCCESS2374Invalid OIDC token obtained (wrong org)2375OIDC push with wrong org: correctly rejected2376Wrong audience OIDC token obtained2377OIDC push with wrong audience: correctly rejected2378OIDC push with malformed token: correctly rejected2379All OIDC tests passed!2380All pin tests passed!2381Built store path: /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2382Post-build-hook pipeline test passed!