vm-test-run-nixos-test-niks3
checks.aarch64-linux.nixos-test-niks3
· build #284
· 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.tX5Fev0Udn', fmt=raw size=107374182413server # mke2fs 1.47.4 (6-Mar-2025)14server # Discarding device blocks: 0/262144 done15server # Creating filesystem with 262144 4k blocks and 65536 inodes16server # Filesystem UUID: 568cc8de-68e1-4bb2-81d0-3a1ec230051817builder: QEMU running (pid 47)18builder # Disk image does not exist, creating the virtualisation disk image...19builder # Formatting '/build/vm-state-builder/tmp.sd047MU5ui', fmt=raw size=107374182420server # Superblock backups stored on blocks:21builder # mke2fs 1.47.4 (6-Mar-2025)22server # 32768, 98304, 163840, 22937623server # 24server # Allocating group tables: 0/8 done25server # Writing inode tables: 0/8 done26server # Creating journal (8192 blocks): done27server # Writing superblocks and filesystem accounting information: 0/8 done28server # 29server # Virtualisation disk image created.30server # Starting virtiofs daemons...31server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)32(finished: start all VMs, in 0.49 seconds)33server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether34server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)35server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether36builder # Discarding device blocks: 0/262144 done37server # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...38server # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...39server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)40server # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether41builder # Creating filesystem with 262144 4k blocks and 65536 inodes42server: waiting for unit postgresql.service43server # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...44server # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests45server # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests46server # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests47server: waiting for the VM to finish booting48builder # Filesystem UUID: 58ef901e-d9d2-4049-9d80-1734dd28e26749builder # Superblock backups stored on blocks:50builder # 32768, 98304, 163840, 22937651builder # 52builder # Allocating group tables: 0/8 done53builder # Writing inode tables: 0/8 done54builder # Creating journal (8192 blocks): done55builder # Writing superblocks and filesystem accounting information: 0/8 done56builder # 57builder # Virtualisation disk image created.58builder # Starting virtiofs daemons...59builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)60builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether61builder # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...62builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)63builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether64builder # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...65builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] Failed to open file handle for the root node: Operation not permitted (os error 1)66builder # [2026-10-01T07:33:04Z WARN virtiofsd::passthrough] File handles do not appear safe to use, disabling file handles altogether67builder # [2026-10-01T07:33:04Z INFO virtiofsd] Waiting for vhost-user socket connection...68builder # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests69builder # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests70builder # [2026-10-01T07:33:04Z INFO virtiofsd] Client connected, servicing requests71builder # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]72builder # [ 0.000000] Linux version 6.18.54 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Sep 25 14:35:54 UTC 202673builder # [ 0.000000] KASLR enabled74builder # [ 0.000000] random: crng init done75builder # [ 0.000000] Machine model: linux,dummy-virt76builder # [ 0.000000] efi: UEFI not found.77server # [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0xc00fac40]78builder # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT79builder # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]80builder # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fdee700-0x7fdf1e7f]81server # [ 0.000000] Linux version 6.18.54 (nixbld@localhost) (gcc (GCC) 15.3.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT Fri Sep 25 14:35:54 UTC 202682builder # [ 0.000000] Zone ranges:83server # [ 0.000000] KASLR enabled84server # [ 0.000000] random: crng init done85builder # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]86server # [ 0.000000] Machine model: linux,dummy-virt87builder # [ 0.000000] DMA32 empty88builder # [ 0.000000] Normal empty89server # [ 0.000000] efi: UEFI not found.90builder # [ 0.000000] Device empty91server # [ 0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT92builder # [ 0.000000] Movable zone start for each node93builder # [ 0.000000] Early memory node ranges94server # [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000007fffffff]95builder # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]96server # [ 0.000000] NODE_DATA(0) allocated [mem 0x7fdee700-0x7fdf1e7f]97server # [ 0.000000] Zone ranges:98builder # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]99server # [ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]100builder # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc00000101server # [ 0.000000] DMA32 empty102builder # [ 0.000000] psci: probing for conduit method from DT.103server # [ 0.000000] Normal empty104server # [ 0.000000] Device empty105builder # [ 0.000000] psci: PSCIv1.3 detected in firmware.106server # [ 0.000000] Movable zone start for each node107builder # [ 0.000000] psci: Using standard PSCI v0.2 function IDs108server # [ 0.000000] Early memory node ranges109builder # [ 0.000000] psci: Trusted OS migration not required110server # [ 0.000000] node 0: [mem 0x0000000040000000-0x000000007fffffff]111builder # [ 0.000000] psci: SMC Calling Convention v1.1112server # [ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000007fffffff]113builder # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)114server # [ 0.000000] cma: Reserved 32 MiB at 0x000000007cc00000115builder # [ 0.000000] percpu: Embedded 76 pages/cpu s186776 r8192 d116328 u311296116server # [ 0.000000] psci: probing for conduit method from DT.117builder # [ 0.000000] Detected PIPT I-cache on CPU0118server # [ 0.000000] psci: PSCIv1.3 detected in firmware.119builder # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)120server # [ 0.000000] psci: Using standard PSCI v0.2 function IDs121server # [ 0.000000] psci: Trusted OS migration not required122builder # [ 0.000000] CPU features: detected: GICv3 CPU interface123server # [ 0.000000] psci: SMC Calling Convention v1.1124builder # [ 0.000000] CPU features: detected: Spectre-v4125builder # [ 0.000000] CPU features: detected: Spectre-BHB126server # [ 0.000000] smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003)127builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38128server # [ 0.000000] percpu: Embedded 76 pages/cpu s186776 r8192 d116328 u311296129server # [ 0.000000] Detected PIPT I-cache on CPU0130builder # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23131builder # [ 0.000000] alternatives: applying boot alternatives132server # [ 0.000000] CPU features: detected: Address authentication (architected QARMA5 algorithm)133server # [ 0.000000] CPU features: detected: GICv3 CPU interface134server # [ 0.000000] CPU features: detected: Spectre-v4135server # [ 0.000000] CPU features: detected: Spectre-BHB136server # [ 0.000000] CPU features: detected: AmpereOne erratum AC03_CPU_38137server # [ 0.000000] CPU features: detected: AmpereOne erratum AC04_CPU_23138builder # [ 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/7q42v4b45lmq438fsnafvr5v4hfy3p5s-nixos-system-builder-test/init regInfo=/nix/.ro-store/db26qq1pnsrhf6jw882hhbq2agchszq4-closure-info/registration console=ttyAMA0,115200n8 console=tty0139server # [ 0.000000] alternatives: applying boot alternatives140builder # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/db26qq1pnsrhf6jw882hhbq2agchszq4-closure-info/registration", will be passed to user space.141server # [ 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/z5m47165qcwbgsm4grhvir7bv793vcg2-nixos-system-server-test/init regInfo=/nix/.ro-store/h5bb7h77k75gifvn64ygknlm3i1w61kb-closure-info/registration console=ttyAMA0,115200n8 console=tty0142builder # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes143builder # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)144builder # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)145builder # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB146builder # [ 0.000000] software IO TLB: area num 1.147server # [ 0.000000] Unknown kernel command line parameters "regInfo=/nix/.ro-store/h5bb7h77k75gifvn64ygknlm3i1w61kb-closure-info/registration", will be passed to user space.148builder # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)149server # [ 0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes150builder # [ 0.000000] Fallback order for Node 0: 0151server # [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)152builder # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 262144153builder # [ 0.000000] Policy zone: DMA154server # [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)155server # [ 0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 1MB156builder # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off157builder # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1158builder # [ 0.000000] allocated 2097152 bytes of page_ext159builder # [ 0.000000] ftrace: allocating 74966 entries in 294 pages160builder # [ 0.000000] ftrace: allocated 294 pages with 4 groups161builder # [ 0.000000] rcu: Hierarchical RCU implementation.162builder # [ 0.000000] rcu: RCU event tracing is enabled.163server # [ 0.000000] software IO TLB: area num 1.164server # [ 0.000000] software IO TLB: mapped [mem 0x000000007ca80000-0x000000007cb80000] (1MB)165server # [ 0.000000] Fallback order for Node 0: 0166server # [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 262144167server # [ 0.000000] Policy zone: DMA168server # [ 0.000000] mem auto-init: stack:all(zero), heap alloc:on, heap free:off169builder # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.170server # [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1171server # [ 0.000000] allocated 2097152 bytes of page_ext172server # [ 0.000000] ftrace: allocating 74966 entries in 294 pages173builder # [ 0.000000] Trampoline variant of Tasks RCU enabled.174builder # [ 0.000000] Rude variant of Tasks RCU enabled.175server # [ 0.000000] ftrace: allocated 294 pages with 4 groups176builder # [ 0.000000] Tracing variant of Tasks RCU enabled.177builder # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.178builder # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1179server # [ 0.000000] rcu: Hierarchical RCU implementation.180server # [ 0.000000] rcu: RCU event tracing is enabled.181server # [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.182server # [ 0.000000] Trampoline variant of Tasks RCU enabled.183server # [ 0.000000] Rude variant of Tasks RCU enabled.184server # [ 0.000000] Tracing variant of Tasks RCU enabled.185builder # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.186builder # [ 0.000000] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.187server # [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.188server # [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1189server # [ 0.000000] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.190builder # [ 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] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.192builder # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0193builder # [ 0.000000] GICv3: 256 SPIs implemented194builder # [ 0.000000] GICv3: 0 Extended SPIs implemented195builder # [ 0.000000] Root IRQ handler: gic_handle_irq196builder # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI197server # [ 0.000000] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.198server # [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0199server # [ 0.000000] GICv3: 256 SPIs implemented200server # [ 0.000000] GICv3: 0 Extended SPIs implemented201server # [ 0.000000] Root IRQ handler: gic_handle_irq202builder # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0203server # [ 0.000000] GICv3: GICv3 features: 16 PPIs, DirectLPI204server # [ 0.000000] GICv3: GICD_CTLR.DS=1, SCR_EL3.FIQ=0205builder # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000206builder # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]207server # [ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000208server # [ 0.000000] ITS [mem 0x08080000-0x0809ffff]209builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44cf0000 (indirect, esz 8, psz 64K, shr 1)210server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Devices @44ce0000 (indirect, esz 8, psz 64K, shr 1)211server # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44cf0000 (flat, esz 8, psz 64K, shr 1)212server # [ 0.000000] GICv3: using LPI property table @0x0000000044d00000213builder # [ 0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @44d00000 (flat, esz 8, psz 64K, shr 1)214builder # [ 0.000000] GICv3: using LPI property table @0x0000000044d10000215server # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000216builder # [ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000044d20000217server # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.218builder # [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.219builder # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns220server # [ 0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns221builder # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).222builder # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns223server # [ 0.000000] arch_timer: cp15 timer running at 1000.00MHz (virt).224server # [ 0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns225builder # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns226builder # [ 0.000035] arm-pv: using stolen time PV227server # [ 0.000000] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns228server # [ 0.000036] arm-pv: using stolen time PV229builder # [ 0.000472] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)230builder # [ 0.000700] Console: colour dummy device 80x25231server # [ 0.000473] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)232builder # [ 0.000710] printk: legacy console [tty0] enabled233server # [ 0.000688] Console: colour dummy device 80x25234server # [ 0.000697] printk: legacy console [tty0] enabled235builder # [ 0.000934] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)236server # [ 0.000961] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)237server # [ 0.000968] pid_max: default: 32768 minimum: 301238server # [ 0.001067] LSM: initializing lsm=capability,landlock,yama,bpf,ima239server # [ 0.001219] landlock: Up and running.240server # [ 0.001222] Yama: becoming mindful.241server # [ 0.001779] LSM support for eBPF active242builder # [ 0.000941] pid_max: default: 32768 minimum: 301243builder # [ 0.001029] LSM: initializing lsm=capability,landlock,yama,bpf,ima244builder # [ 0.001219] landlock: Up and running.245builder # [ 0.001223] Yama: becoming mindful.246builder # [ 0.001715] LSM support for eBPF active247builder # [ 0.001842] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)248server # [ 0.001945] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)249builder # [ 0.001870] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)250builder # [ 0.003966] rcu: Hierarchical SRCU implementation.251builder # [ 0.003972] rcu: Max phase no-delay instances is 1000.252builder # [ 0.005384] fsl-mc MSI: its@8080000 domain created253server # [ 0.001976] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)254builder # [ 0.005512] EFI services will not be available.255server # [ 0.004055] rcu: Hierarchical SRCU implementation.256server # [ 0.004063] rcu: Max phase no-delay instances is 1000.257server # [ 0.005459] fsl-mc MSI: its@8080000 domain created258builder # [ 0.005619] smp: Bringing up secondary CPUs ...259server # [ 0.005585] EFI services will not be available.260builder # [ 0.005628] smp: Brought up 1 node, 1 CPU261builder # [ 0.005631] SMP: Total of 1 processors activated.262server # [ 0.005730] smp: Bringing up secondary CPUs ...263server # [ 0.005741] smp: Brought up 1 node, 1 CPU264builder # [ 0.005634] CPU: All CPU(s) started at EL1265builder # [ 0.005649] CPU features: detected: Branch Target Identification266builder # [ 0.005654] CPU features: detected: ARMv8.4 Translation Table Level267server # [ 0.005744] SMP: Total of 1 processors activated.268server # [ 0.005746] CPU: All CPU(s) started at EL1269server # [ 0.005763] CPU features: detected: Branch Target Identification270server # [ 0.005768] CPU features: detected: ARMv8.4 Translation Table Level271server # [ 0.005771] CPU features: detected: Instruction cache invalidation not required for I/D coherence272server # [ 0.005774] CPU features: detected: Data cache clean to the PoU not required for I/D coherence273builder # [ 0.005658] CPU features: detected: Instruction cache invalidation not required for I/D coherence274builder # [ 0.005661] CPU features: detected: Data cache clean to the PoU not required for I/D coherence275builder # [ 0.005665] CPU features: detected: Common not Private translations276builder # [ 0.005668] CPU features: detected: CRC32 instructions277server # [ 0.005778] CPU features: detected: Common not Private translations278server # [ 0.005781] CPU features: detected: CRC32 instructions279builder # [ 0.005671] CPU features: detected: Data cache clean to Point of Deep Persistence280server # [ 0.005784] CPU features: detected: Data cache clean to Point of Deep Persistence281builder # [ 0.005675] CPU features: detected: Data cache clean to Point of Persistence282server # [ 0.005788] CPU features: detected: Data cache clean to Point of Persistence283builder # [ 0.005678] CPU features: detected: Data independent timing control (DIT)284builder # [ 0.005681] CPU features: detected: E0PD285server # [ 0.005791] CPU features: detected: Data independent timing control (DIT)286server # [ 0.005794] CPU features: detected: E0PD287builder # [ 0.005683] CPU features: detected: Enhanced Counter Virtualization288server # [ 0.005797] CPU features: detected: Enhanced Counter Virtualization289builder # [ 0.005686] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)290builder # [ 0.005690] CPU features: detected: Enhanced Virtualization Traps291server # [ 0.005800] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)292server # [ 0.005804] CPU features: detected: Enhanced Virtualization Traps293builder # [ 0.005694] CPU features: detected: Fine Grained Traps294server # [ 0.005808] CPU features: detected: Fine Grained Traps295builder # [ 0.005697] CPU features: detected: Generic authentication (architected QARMA5 algorithm)296builder # [ 0.005703] CPU features: detected: RCpc load-acquire (LDAPR)297server # [ 0.005811] CPU features: detected: Generic authentication (architected QARMA5 algorithm)298builder # [ 0.005706] CPU features: detected: LSE atomic instructions299server # [ 0.005816] CPU features: detected: RCpc load-acquire (LDAPR)300server # [ 0.005818] CPU features: detected: LSE atomic instructions301builder # [ 0.005708] CPU features: detected: Privileged Access Never302builder # [ 0.005711] CPU features: detected: PMUv3303builder # [ 0.005714] CPU features: detected: RAS Extension Support304server # [ 0.005821] CPU features: detected: Privileged Access Never305server # [ 0.005823] CPU features: detected: PMUv3306builder # [ 0.005717] CPU features: detected: RASv1p1 Extension Support307builder # [ 0.005720] CPU features: detected: Random Number Generator308server # [ 0.005827] CPU features: detected: RAS Extension Support309server # [ 0.005830] CPU features: detected: RASv1p1 Extension Support310server # [ 0.005833] CPU features: detected: Random Number Generator311builder # [ 0.005722] CPU features: detected: Speculation barrier (SB)312builder # [ 0.005725] CPU features: detected: Stage-2 Force Write-Back313builder # [ 0.005728] CPU features: detected: TLB range maintenance instructions314builder # [ 0.005732] CPU features: detected: Speculative Store Bypassing Safe (SSBS)315builder # [ 0.005775] alternatives: applying system-wide alternatives316server # [ 0.005835] CPU features: detected: Speculation barrier (SB)317server # [ 0.005838] CPU features: detected: Stage-2 Force Write-Back318server # [ 0.005841] CPU features: detected: TLB range maintenance instructions319server # [ 0.005846] CPU features: detected: Speculative Store Bypassing Safe (SSBS)320server # [ 0.005887] alternatives: applying system-wide alternatives321builder # [ 0.009113] CPU features: detected: BBM Level 2 without TLB conflict abort322server # [ 0.009365] CPU features: detected: BBM Level 2 without TLB conflict abort323builder # [ 0.009330] Memory: 892932K/1048576K available (24448K kernel code, 7094K rwdata, 26596K rodata, 4736K init, 1107K bss, 114084K reserved, 32768K cma-reserved)324builder # [ 0.009764] devtmpfs: initialized325server # [ 0.009578] Memory: 893236K/1048576K available (24448K kernel code, 7094K rwdata, 26596K rodata, 4736K init, 1107K bss, 114056K reserved, 32768K cma-reserved)326builder # [ 0.011740] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)327server # [ 0.010056] devtmpfs: initialized328server # [ 0.011914] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)329builder # [ 0.011764] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).330builder # [ 0.011978] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL331builder # [ 0.011992] 0 pages in range for non-PLT usage332server # [ 0.011941] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).333server # [ 0.012143] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL334server # [ 0.012156] 0 pages in range for non-PLT usage335server # [ 0.012158] 508224 pages in range for PLT usage336builder # [ 0.011993] 508224 pages in range for PLT usage337builder # [ 0.012115] pinctrl core: initialized pinctrl subsystem338builder # [ 0.013028] DMI not present or invalid.339builder # [ 0.016495] NET: Registered PF_NETLINK/PF_ROUTE protocol family340server # [ 0.012294] pinctrl core: initialized pinctrl subsystem341server # [ 0.013212] DMI not present or invalid.342server # [ 0.016834] NET: Registered PF_NETLINK/PF_ROUTE protocol family343builder # [ 0.019117] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations344server # [ 0.019280] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations345server # [ 0.019443] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations346builder # [ 0.019303] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations347builder # [ 0.019479] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations348server # [ 0.019612] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations349builder # [ 0.019513] audit: initializing netlink subsys (disabled)350server # [ 0.019643] audit: initializing netlink subsys (disabled)351builder # [ 0.020144] thermal_sys: Registered thermal governor 'fair_share'352server # [ 0.020309] thermal_sys: Registered thermal governor 'fair_share'353server # [ 0.020312] thermal_sys: Registered thermal governor 'bang_bang'354builder # [ 0.020147] thermal_sys: Registered thermal governor 'bang_bang'355builder # [ 0.020150] thermal_sys: Registered thermal governor 'step_wise'356server # [ 0.020315] thermal_sys: Registered thermal governor 'step_wise'357server # [ 0.020318] thermal_sys: Registered thermal governor 'user_space'358server # [ 0.020321] thermal_sys: Registered thermal governor 'power_allocator'359builder # [ 0.020153] thermal_sys: Registered thermal governor 'user_space'360builder # [ 0.020156] thermal_sys: Registered thermal governor 'power_allocator'361builder # [ 0.020187] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1362server # [ 0.020353] audit: type=2000 audit(0.016:1): state=initialized audit_enabled=0 res=1363builder # [ 0.020196] cpuidle: using governor ladder364builder # [ 0.020201] cpuidle: using governor menu365builder # [ 0.020428] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.366server # [ 0.020361] cpuidle: using governor ladder367server # [ 0.020366] cpuidle: using governor menu368server # [ 0.020578] hw-breakpoint: found 16 breakpoint and 4 watchpoint registers.369builder # [ 0.020446] ASID allocator initialised with 65536 entries370server # [ 0.020596] ASID allocator initialised with 65536 entries371builder # [ 0.021775] Serial: AMBA PL011 UART driver372server # [ 0.021929] Serial: AMBA PL011 UART driver373server # [ 0.027923] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1374builder # [ 0.027531] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 13, base_baud = 0) is a PL011 rev1375builder # [ 0.027689] printk: console [ttyAMA0] enabled376server # [ 0.028092] printk: console [ttyAMA0] enabled377server # [ 0.158889] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages378server # [ 0.158904] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page379builder # [ 0.164667] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages380server # [ 0.158908] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages381builder # [ 0.164684] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page382server # [ 0.158911] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page383builder # [ 0.164687] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages384server # [ 0.158914] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages385server # [ 0.158917] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page386server # [ 0.158920] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages387builder # [ 0.164690] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page388builder # [ 0.164693] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages389server # [ 0.158923] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page390server # [ 0.160292] fbcon: Taking over console391server # [ 0.160304] ACPI: Interpreter disabled.392server # [ 0.170433] iommu: Default domain type: Translated393builder # [ 0.164696] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page394builder # [ 0.164699] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages395builder # [ 0.164702] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page396builder # [ 0.166311] fbcon: Taking over console397builder # [ 0.166326] ACPI: Interpreter disabled.398server # [ 0.170443] iommu: DMA domain TLB invalidation policy: strict mode399builder # [ 0.175764] iommu: Default domain type: Translated400builder # [ 0.175772] iommu: DMA domain TLB invalidation policy: strict mode401builder # [ 0.176212] SCSI subsystem initialized402server # [ 0.172677] SCSI subsystem initialized403server # [ 0.175021] usbcore: registered new interface driver usbfs404server # [ 0.175052] usbcore: registered new interface driver hub405server # [ 0.175068] usbcore: registered new device driver usb406server # [ 0.175429] pps_core: LinuxPPS API ver. 1 registered407server # [ 0.175433] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>408server # [ 0.175441] PTP clock support registered409server # [ 0.175486] EDAC MC: Ver: 3.0.0410server # [ 0.181443] scmi_core: SCMI protocol bus registered411server # [ 0.181929] FPGA manager framework412builder # [ 0.184679] usbcore: registered new interface driver usbfs413builder # [ 0.184713] usbcore: registered new interface driver hub414builder # [ 0.184732] usbcore: registered new device driver usb415builder # [ 0.185109] pps_core: LinuxPPS API ver. 1 registered416server # [ 0.184058] vgaarb: loaded417server # [ 0.186953] clocksource: Switched to clocksource arch_sys_counter418builder # [ 0.185113] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>419builder # [ 0.185122] PTP clock support registered420builder # [ 0.185163] EDAC MC: Ver: 3.0.0421builder # [ 0.185375] scmi_core: SCMI protocol bus registered422builder # [ 0.185750] FPGA manager framework423builder # [ 0.186385] vgaarb: loaded424builder # [ 0.186893] clocksource: Switched to clocksource arch_sys_counter425builder # [ 0.196492] VFS: Disk quotas dquot_6.6.0426builder # [ 0.196534] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)427server # [ 0.193620] VFS: Disk quotas dquot_6.6.0428server # [ 0.193659] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)429server # [ 0.196360] netfs: FS-Cache loaded430builder # [ 0.200638] netfs: FS-Cache loaded431builder # [ 0.200796] pnp: PnP ACPI: disabled432server # [ 0.198615] pnp: PnP ACPI: disabled433builder # [ 0.205332] NET: Registered PF_INET protocol family434builder # [ 0.205515] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)435server # [ 0.202638] NET: Registered PF_INET protocol family436server # [ 0.202814] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)437builder # [ 0.238376] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)438builder # [ 0.238425] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)439server # [ 0.236204] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)440builder # [ 0.238452] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)441server # [ 0.236261] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)442server # [ 0.236290] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)443builder # [ 0.238506] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)444builder # [ 0.238579] TCP: Hash tables configured (established 8192 bind 8192)445server # [ 0.236348] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)446builder # [ 0.238677] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)447builder # [ 0.238738] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)448builder # [ 0.238764] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)449builder # [ 0.238845] NET: Registered PF_UNIX/PF_LOCAL protocol family450builder # [ 0.238888] NET: Registered PF_XDP protocol family451server # [ 0.240784] TCP: Hash tables configured (established 8192 bind 8192)452server # [ 0.240928] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)453server # [ 0.240986] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)454server # [ 0.241043] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)455server # [ 0.241157] NET: Registered PF_UNIX/PF_LOCAL protocol family456server # [ 0.241235] NET: Registered PF_XDP protocol family457server # [ 0.241257] PCI: CLS 0 bytes, default 64458server # [ 0.241565] Trying to unpack rootfs image as initramfs...459server # [ 0.251662] kvm [1]: HYP mode not available460builder # [ 0.250474] PCI: CLS 0 bytes, default 64461builder # [ 0.250758] Trying to unpack rootfs image as initramfs...462builder # [ 0.260199] kvm [1]: HYP mode not available463server # [ 0.445129] Initialise system trusted keyrings464server # [ 0.445279] workingset: timestamp_bits=42 max_order=18 bucket_order=0465server # [ 0.445719] squashfs: version 4.0 (2009/01/31) Phillip Lougher466builder # [ 0.459491] Initialise system trusted keyrings467server # [ 0.448479] 9p: Installing v9fs 9p2000 file system support468builder # [ 0.459650] workingset: timestamp_bits=42 max_order=18 bucket_order=0469builder # [ 0.460045] squashfs: version 4.0 (2009/01/31) Phillip Lougher470builder # [ 0.460105] 9p: Installing v9fs 9p2000 file system support471server # [ 0.476618] Key type asymmetric registered472server # [ 0.476635] Asymmetric key parser 'x509' registered473server # [ 0.476757] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)474server # [ 0.476921] io scheduler mq-deadline registered475server # [ 0.476925] io scheduler kyber registered476builder # [ 0.488279] Key type asymmetric registered477builder # [ 0.488298] Asymmetric key parser 'x509' registered478builder # [ 0.488377] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)479builder # [ 0.488513] io scheduler mq-deadline registered480builder # [ 0.488517] io scheduler kyber registered481server # [ 0.489358] pl061_gpio 9030000.pl061: PL061 GPIO chip registered482server # [ 0.489959] ledtrig-cpu: registered to indicate activity on CPUs483server # [ 0.490373] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:484server # [ 0.490387] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000485server # [ 0.490398] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000486server # [ 0.490403] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000487builder # [ 0.501267] pl061_gpio 9030000.pl061: PL061 GPIO chip registered488server # [ 0.490429] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits489builder # [ 0.501862] ledtrig-cpu: registered to indicate activity on CPUs490server # [ 0.490450] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]491builder # [ 0.502553] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:492server # [ 0.490523] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00493builder # [ 0.502568] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000494server # [ 0.490529] pci_bus 0000:00: root bus resource [bus 00-ff]495server # [ 0.490533] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]496builder # [ 0.502580] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000497server # [ 0.490537] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]498builder # [ 0.502585] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000499server # [ 0.490540] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]500builder # [ 0.502620] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits501server # [ 0.490600] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint502builder # [ 0.502649] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]503server # [ 0.491051] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint504builder # [ 0.502736] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00505server # [ 0.491239] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]506builder # [ 0.502743] pci_bus 0000:00: root bus resource [bus 00-ff]507server # [ 0.491251] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]508builder # [ 0.502747] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]509server # [ 0.491277] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]510builder # [ 0.502750] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]511server # [ 0.491289] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]512builder # [ 0.502753] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]513server # [ 0.491772] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint514server # [ 0.491959] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]515builder # [ 0.502829] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint516server # [ 0.491971] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]517server # [ 0.491997] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]518builder # [ 0.523415] pci 0000:00:01.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint519builder # [ 0.523618] pci 0000:00:01.0: BAR 0 [io 0x0000-0x001f]520builder # [ 0.523631] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]521server # [ 0.520587] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint522server # [ 0.520820] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]523server # [ 0.520833] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]524builder # [ 0.523658] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]525builder # [ 0.523670] pci 0000:00:01.0: ROM [mem 0x00000000-0x0003ffff pref]526server # [ 0.520860] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]527builder # [ 0.524154] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint528builder # [ 0.524342] pci 0000:00:02.0: BAR 0 [io 0x0000-0x001f]529server # [ 0.521432] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint530server # [ 0.521622] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]531builder # [ 0.524354] pci 0000:00:02.0: BAR 1 [mem 0x00000000-0x00000fff]532server # [ 0.521634] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]533builder # [ 0.524380] pci 0000:00:02.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]534server # [ 0.521660] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]535builder # [ 0.524863] pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint536server # [ 0.521671] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]537builder # [ 0.525077] pci 0000:00:03.0: BAR 0 [io 0x0000-0x007f]538builder # [ 0.525089] pci 0000:00:03.0: BAR 1 [mem 0x00000000-0x00000fff]539server # [ 0.522166] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint540server # [ 0.522361] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]541builder # [ 0.525115] pci 0000:00:03.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]542server # [ 0.522387] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]543builder # [ 0.525595] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint544builder # [ 0.525783] pci 0000:00:04.0: BAR 0 [io 0x0000-0x001f]545server # [ 0.522868] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint546builder # [ 0.525794] pci 0000:00:04.0: BAR 1 [mem 0x00000000-0x00000fff]547server # [ 0.523061] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]548builder # [ 0.525820] pci 0000:00:04.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]549server # [ 0.523087] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]550builder # [ 0.525832] pci 0000:00:04.0: ROM [mem 0x00000000-0x0003ffff pref]551server # [ 0.523504] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint552builder # [ 0.526312] pci 0000:00:05.0: [1af4:1050] type 00 class 0x038000 conventional PCI endpoint553server # [ 0.523692] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]554builder # [ 0.526508] pci 0000:00:05.0: BAR 1 [mem 0x00000000-0x00000fff]555server # [ 0.523947] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint556builder # [ 0.526535] pci 0000:00:05.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]557server # [ 0.524139] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]558server # [ 0.524165] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]559builder # [ 0.545361] pci 0000:00:06.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint560builder # [ 0.545560] pci 0000:00:06.0: BAR 1 [mem 0x00000000-0x00000fff]561server # [ 0.542708] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint562builder # [ 0.545586] pci 0000:00:06.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]563server # [ 0.542903] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]564builder # [ 0.546030] pci 0000:00:07.0: [8086:24cd] type 00 class 0x0c0320 conventional PCI endpoint565server # [ 0.542931] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]566builder # [ 0.546215] pci 0000:00:07.0: BAR 0 [mem 0x00000000-0x00000fff]567server # [ 0.543418] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint568builder # [ 0.546489] pci 0000:00:08.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint569server # [ 0.543610] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]570builder # [ 0.546682] pci 0000:00:08.0: BAR 1 [mem 0x00000000-0x00000fff]571server # [ 0.543636] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]572builder # [ 0.546708] pci 0000:00:08.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]573server # [ 0.544133] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint574server # [ 0.544406] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]575builder # [ 0.554584] pci 0000:00:09.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint576builder # [ 0.554777] pci 0000:00:09.0: BAR 1 [mem 0x00000000-0x00000fff]577builder # [ 0.554803] pci 0000:00:09.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]578server # [ 0.556493] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]579server # [ 0.556530] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]580server # [ 0.557121] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint581builder # [ 0.563467] pci 0000:00:0a.0: [1af4:105a] type 00 class 0x018000 conventional PCI endpoint582server # [ 0.557321] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]583builder # [ 0.563679] pci 0000:00:0a.0: BAR 1 [mem 0x00000000-0x00000fff]584server # [ 0.557333] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]585builder # [ 0.563707] pci 0000:00:0a.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]586server # [ 0.557360] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]587server # [ 0.558032] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned588builder # [ 0.564208] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint589builder # [ 0.564502] pci 0000:00:0b.0: BAR 0 [io 0x0000-0x003f]590server # [ 0.558039] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned591builder # [ 0.564515] pci 0000:00:0b.0: BAR 1 [mem 0x00000000-0x00000fff]592server # [ 0.558042] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned593builder # [ 0.564541] pci 0000:00:0b.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]594server # [ 0.558090] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned595builder # [ 0.565055] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint596builder # [ 0.565242] pci 0000:00:0c.0: BAR 0 [io 0x0000-0x001f]597server # [ 0.558135] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned598builder # [ 0.565254] pci 0000:00:0c.0: BAR 1 [mem 0x00000000-0x00000fff]599server # [ 0.558181] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned600server # [ 0.558227] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned601server # [ 0.558280] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned602server # [ 0.558326] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned603builder # [ 0.565280] pci 0000:00:0c.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]604server # [ 0.558372] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned605builder # [ 0.565929] pci 0000:00:01.0: ROM [mem 0x10000000-0x1003ffff pref]: assigned606server # [ 0.558417] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned607builder # [ 0.565936] pci 0000:00:04.0: ROM [mem 0x10040000-0x1007ffff pref]: assigned608server # [ 0.558462] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned609builder # [ 0.565939] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned610server # [ 0.558593] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned611builder # [ 0.565987] pci 0000:00:02.0: BAR 4 [mem 0x8000004000-0x8000007fff 64bit pref]: assigned612server # [ 0.558636] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned613builder # [ 0.566033] pci 0000:00:03.0: BAR 4 [mem 0x8000008000-0x800000bfff 64bit pref]: assigned614server # [ 0.558654] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned615builder # [ 0.566079] pci 0000:00:04.0: BAR 4 [mem 0x800000c000-0x800000ffff 64bit pref]: assigned616server # [ 0.558672] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned617builder # [ 0.566126] pci 0000:00:05.0: BAR 4 [mem 0x8000010000-0x8000013fff 64bit pref]: assigned618server # [ 0.558689] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned619server # [ 0.558707] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned620builder # [ 0.566172] pci 0000:00:06.0: BAR 4 [mem 0x8000014000-0x8000017fff 64bit pref]: assigned621server # [ 0.558724] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned622builder # [ 0.566218] pci 0000:00:08.0: BAR 4 [mem 0x8000018000-0x800001bfff 64bit pref]: assigned623server # [ 0.558742] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned624builder # [ 0.566263] pci 0000:00:09.0: BAR 4 [mem 0x800001c000-0x800001ffff 64bit pref]: assigned625server # [ 0.558762] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned626builder # [ 0.566308] pci 0000:00:0a.0: BAR 4 [mem 0x8000020000-0x8000023fff 64bit pref]: assigned627server # [ 0.558784] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned628builder # [ 0.566352] pci 0000:00:0b.0: BAR 4 [mem 0x8000024000-0x8000027fff 64bit pref]: assigned629server # [ 0.558802] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned630builder # [ 0.566432] pci 0000:00:0c.0: BAR 4 [mem 0x8000028000-0x800002bfff 64bit pref]: assigned631server # [ 0.558821] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned632builder # [ 0.566523] pci 0000:00:01.0: BAR 1 [mem 0x10080000-0x10080fff]: assigned633server # [ 0.558840] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned634builder # [ 0.566542] pci 0000:00:02.0: BAR 1 [mem 0x10081000-0x10081fff]: assigned635server # [ 0.558857] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned636server # [ 0.558879] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned637builder # [ 0.566560] pci 0000:00:03.0: BAR 1 [mem 0x10082000-0x10082fff]: assigned638server # [ 0.558897] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned639builder # [ 0.566578] pci 0000:00:04.0: BAR 1 [mem 0x10083000-0x10083fff]: assigned640server # [ 0.558914] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned641builder # [ 0.566595] pci 0000:00:05.0: BAR 1 [mem 0x10084000-0x10084fff]: assigned642server # [ 0.558932] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned643builder # [ 0.566613] pci 0000:00:06.0: BAR 1 [mem 0x10085000-0x10085fff]: assigned644server # [ 0.558949] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned645builder # [ 0.566631] pci 0000:00:07.0: BAR 0 [mem 0x10086000-0x10086fff]: assigned646server # [ 0.558972] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]647builder # [ 0.566651] pci 0000:00:08.0: BAR 1 [mem 0x10087000-0x10087fff]: assigned648server # [ 0.558977] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]649builder # [ 0.566674] pci 0000:00:09.0: BAR 1 [mem 0x10088000-0x10088fff]: assigned650server # [ 0.558980] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]651builder # [ 0.566692] pci 0000:00:0a.0: BAR 1 [mem 0x10089000-0x10089fff]: assigned652server # [ 0.559858] pci 0000:00:07.0: enabling device (0000 -> 0002)653builder # [ 0.566711] pci 0000:00:0b.0: BAR 1 [mem 0x1008a000-0x1008afff]: assigned654builder # [ 0.566730] pci 0000:00:0c.0: BAR 1 [mem 0x1008b000-0x1008bfff]: assigned655builder # [ 0.566748] pci 0000:00:03.0: BAR 0 [io 0x1000-0x107f]: assigned656builder # [ 0.566766] pci 0000:00:0b.0: BAR 0 [io 0x1080-0x10bf]: assigned657builder # [ 0.566783] pci 0000:00:01.0: BAR 0 [io 0x10c0-0x10df]: assigned658builder # [ 0.566801] pci 0000:00:02.0: BAR 0 [io 0x10e0-0x10ff]: assigned659builder # [ 0.566819] pci 0000:00:04.0: BAR 0 [io 0x1100-0x111f]: assigned660builder # [ 0.566837] pci 0000:00:0c.0: BAR 0 [io 0x1120-0x113f]: assigned661builder # [ 0.566861] pci_bus 0000:00: resource 4 [io 0x0000-0xffff]662builder # [ 0.566866] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]663builder # [ 0.566869] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]664builder # [ 0.576519] pci 0000:00:07.0: enabling device (0000 -> 0002)665server # [ 0.625231] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)666server # [ 0.627541] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)667builder # [ 0.637906] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)668builder # [ 0.641156] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)669server # [ 0.638052] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)670server # [ 0.640080] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)671builder # [ 0.651600] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)672builder # [ 0.653747] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)673server # [ 0.649945] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)674server # [ 0.652002] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)675builder # [ 0.657657] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)676server # [ 0.662002] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)677server # [ 0.663994] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)678builder # [ 0.668124] virtio-pci 0000:00:06.0: enabling device (0000 -> 0002)679builder # [ 0.670460] virtio-pci 0000:00:08.0: enabling device (0000 -> 0002)680builder # [ 0.674332] virtio-pci 0000:00:09.0: enabling device (0000 -> 0002)681server # [ 0.674039] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)682server # [ 0.676042] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)683builder # [ 0.684748] virtio-pci 0000:00:0a.0: enabling device (0000 -> 0002)684server # [ 0.680618] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)685builder # [ 0.687796] virtio-pci 0000:00:0b.0: enabling device (0000 -> 0003)686builder # [ 0.690445] virtio-pci 0000:00:0c.0: enabling device (0000 -> 0003)687server # [ 0.694972] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled688server # [ 0.698930] msm_serial: driver initialized689server # [ 0.699090] SuperH (H)SCI(F) driver initialized690server # [ 0.699147] STM32 USART driver initialized691builder # [ 0.707814] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled692builder # [ 0.709795] msm_serial: driver initialized693builder # [ 0.709949] SuperH (H)SCI(F) driver initialized694builder # [ 0.710007] STM32 USART driver initialized695server # [ 0.746504] loop: module loaded696server # [ 0.746709] virtio_blk virtio2: 1/0/0 default/read/poll queues697server # [ 0.747562] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)698builder # [ 0.753920] loop: module loaded699builder # [ 0.754131] virtio_blk virtio2: 1/0/0 default/read/poll queues700builder # [ 0.755041] virtio_blk virtio2: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)701server # [ 0.761305] megasas: 07.734.00.00-rc1702server # [ 0.762082] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]703builder # [ 0.759652] megasas: 07.734.00.00-rc1704server # [ 0.764178] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000705builder # [ 0.760429] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]706server # [ 0.764203] Intel/Sharp Extended Query Table at 0x0031707builder # [ 0.773723] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000708builder # [ 0.773748] Intel/Sharp Extended Query Table at 0x0031709server # [ 0.769722] Using buffer write method710server # [ 0.769777] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]711server # [ 0.771564] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000712server # [ 0.771619] Intel/Sharp Extended Query Table at 0x0031713builder # [ 0.783723] Using buffer write method714builder # [ 0.783782] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]715builder # [ 0.785632] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000716builder # [ 0.785652] Intel/Sharp Extended Query Table at 0x0031717server # [ 0.787431] Using buffer write method718server # [ 0.787462] Concatenating MTD devices:719server # [ 0.787465] (0): "0.flash"720server # [ 0.787468] (1): "0.flash"721server # [ 0.787469] into device "0.flash"722builder # [ 0.790917] Using buffer write method723builder # [ 0.790935] Concatenating MTD devices:724builder # [ 0.790937] (0): "0.flash"725builder # [ 0.790940] (1): "0.flash"726builder # [ 0.790941] into device "0.flash"727builder # [ 1.093290] Freeing initrd memory: 26972K728server # [ 1.088503] Freeing initrd memory: 26944K729server # [ 1.095138] tun: Universal TUN/TAP device driver, 1.6730builder # [ 1.100002] tun: Universal TUN/TAP device driver, 1.6731server # [ 1.099871] thunder_xcv, ver 1.0732server # [ 1.099914] thunder_bgx, ver 1.0733server # [ 1.099941] nicpf, ver 1.0734builder # [ 1.103973] thunder_xcv, ver 1.0735builder # [ 1.104003] thunder_bgx, ver 1.0736builder # [ 1.104022] nicpf, ver 1.0737builder # [ 1.104639] e1000: Intel(R) PRO/1000 Network Driver738builder # [ 1.104643] e1000: Copyright (c) 1999-2006 Intel Corporation.739builder # [ 1.104670] e1000e: Intel(R) PRO/1000 Network Driver740server # [ 1.102181] e1000: Intel(R) PRO/1000 Network Driver741builder # [ 1.104675] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.742server # [ 1.102189] e1000: Copyright (c) 1999-2006 Intel Corporation.743builder # [ 1.104699] igb: Intel(R) Gigabit Ethernet Network Driver744server # [ 1.102213] e1000e: Intel(R) PRO/1000 Network Driver745builder # [ 1.104703] igb: Copyright (c) 2007-2014 Intel Corporation.746server # [ 1.102225] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.747builder # [ 1.104724] igbvf: Intel(R) Gigabit Virtual Function Network Driver748server # [ 1.102255] igb: Intel(R) Gigabit Ethernet Network Driver749builder # [ 1.104727] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.750server # [ 1.102258] igb: Copyright (c) 2007-2014 Intel Corporation.751builder # [ 1.104997] sky2: driver version 1.30752server # [ 1.102279] igbvf: Intel(R) Gigabit Virtual Function Network Driver753builder # [ 1.106683] usbcore: registered new interface driver usb-storage754server # [ 1.102284] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.755server # [ 1.102421] sky2: driver version 1.30756builder # [ 1.106732] usbcore: registered new interface driver usbserial_generic757server # [ 1.104168] usbcore: registered new interface driver usb-storage758builder # [ 1.106742] usbserial: USB Serial support registered for generic759server # [ 1.104309] usbcore: registered new interface driver usbserial_generic760server # [ 1.104319] usbserial: USB Serial support registered for generic761server # [ 1.105272] ehci-pci 0000:00:07.0: EHCI Host Controller762builder # [ 1.117735] ehci-pci 0000:00:07.0: EHCI Host Controller763server # [ 1.105304] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1764builder # [ 1.117757] ehci-pci 0000:00:07.0: new USB bus registered, assigned bus number 1765server # [ 1.105501] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000766builder # [ 1.117939] ehci-pci 0000:00:07.0: irq 16, io mem 0x10086000767builder # [ 1.118613] hv_vmbus: registering driver hyperv_keyboard768builder # [ 1.122681] rtc-pl031 9010000.pl031: registered as rtc0769builder # [ 1.122707] rtc-pl031 9010000.pl031: setting system clock to 2026-10-01T07:33:06 UTC (1790839986)770server # [ 1.116685] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00771server # [ 1.117117] hub 1-0:1.0: USB hub found772server # [ 1.117135] hub 1-0:1.0: 6 ports detected773server # [ 1.118314] hv_vmbus: registering driver hyperv_keyboard774server # [ 1.119395] rtc-pl031 9010000.pl031: registered as rtc0775builder # [ 1.125068] i2c_dev: i2c /dev entries driver776builder # [ 1.126956] ehci-pci 0000:00:07.0: USB 2.0 started, EHCI 1.00777server # [ 1.119425] rtc-pl031 9010000.pl031: setting system clock to 2026-10-01T07:33:06 UTC (1790839986)778builder # [ 1.127285] hub 1-0:1.0: USB hub found779server # [ 1.119778] i2c_dev: i2c /dev entries driver780builder # [ 1.127301] hub 1-0:1.0: 6 ports detected781builder # [ 1.131761] sdhci: Secure Digital Host Controller Interface driver782builder # [ 1.131767] sdhci: Copyright(c) Pierre Ossman783server # [ 1.128597] sdhci: Secure Digital Host Controller Interface driver784builder # [ 1.132061] Synopsys Designware Multimedia Card Interface Driver785builder # [ 1.132458] sdhci-pltfm: SDHCI platform and OF driver helper786server # [ 1.128608] sdhci: Copyright(c) Pierre Ossman787builder # [ 1.134286] hid: raw HID events driver (C) Jiri Kosina788server # [ 1.129021] Synopsys Designware Multimedia Card Interface Driver789builder # [ 1.134539] usbcore: registered new interface driver usbhid790server # [ 1.129420] sdhci-pltfm: SDHCI platform and OF driver helper791builder # [ 1.134549] usbhid: USB HID core driver792server # [ 1.131139] hid: raw HID events driver (C) Jiri Kosina793server # [ 1.131388] usbcore: registered new interface driver usbhid794server # [ 1.131399] usbhid: USB HID core driver795builder # [ 1.140752] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available796server # [ 1.137642] hw perfevents: enabled with armv8_pmuv3 PMU driver, 11 (0,800003ff) counters available797server # [ 1.139352] drop_monitor: Initializing network drop monitor service798server # [ 1.139521] NET: Registered PF_INET6 protocol family799builder # [ 1.142491] drop_monitor: Initializing network drop monitor service800builder # [ 1.142666] NET: Registered PF_INET6 protocol family801builder # [ 1.146683] Segment Routing with IPv6802builder # [ 1.146711] In-situ OAM (IOAM) with IPv6803server # [ 1.140200] Segment Routing with IPv6804server # [ 1.140215] In-situ OAM (IOAM) with IPv6805builder # [ 1.146768] NET: Registered PF_PACKET protocol family806builder # [ 1.146829] 9pnet: Installing 9P2000 support807server # [ 1.140246] NET: Registered PF_PACKET protocol family808builder # [ 1.146877] Key type dns_resolver registered809server # [ 1.140310] 9pnet: Installing 9P2000 support810server # [ 1.140353] Key type dns_resolver registered811builder # [ 1.155860] registered taskstats version 1812builder # [ 1.156004] Loading compiled-in X.509 certificates813server # [ 1.152523] registered taskstats version 1814server # [ 1.152688] Loading compiled-in X.509 certificates815builder # [ 1.165665] Demotion targets for Node 0: null816builder # [ 1.165811] Key type .fscrypt registered817builder # [ 1.165823] Key type fscrypt-provisioning registered818builder # [ 1.165937] ima: No TPM chip found, activating TPM-bypass!819server # [ 1.161774] Demotion targets for Node 0: null820builder # [ 1.165956] ima: Allocated hash algorithm: sha1821server # [ 1.161914] Key type .fscrypt registered822builder # [ 1.165978] ima: No architecture policies found823server # [ 1.161924] Key type fscrypt-provisioning registered824builder # [ 1.166819] input: gpio-keys as /devices/platform/gpio-keys/input/input0825server # [ 1.162035] ima: No TPM chip found, activating TPM-bypass!826server # [ 1.162053] ima: Allocated hash algorithm: sha1827server # [ 1.162081] ima: No architecture policies found828server # [ 1.162943] input: gpio-keys as /devices/platform/gpio-keys/input/input0829builder # [ 1.193045] clk: Disabling unused clocks830builder # [ 1.193068] PM: genpd: Disabling unused power domains831server # [ 1.189988] clk: Disabling unused clocks832server # [ 1.190010] PM: genpd: Disabling unused power domains833builder # [ 1.197540] Freeing unused kernel memory: 4736K834builder # [ 1.197769] Run /init as init process835server # [ 1.194452] Freeing unused kernel memory: 4736K836server # [ 1.194677] Run /init as init process837builder # [ 1.209814] systemd[1]: Successfully made /usr/ read-only.838server # [ 1.211254] systemd[1]: Successfully made /usr/ read-only.839server # [ 1.364577] usb 1-1: new high-speed USB device number 2 using ehci-pci840builder # [ 1.379715] usb 1-1: new high-speed USB device number 2 using ehci-pci841server # [ 1.512194] 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/input1842builder # [ 1.529144] 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.543953] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)844builder # [ 1.543978] systemd[1]: Detected virtualization qemu.845builder # [ 1.544028] systemd[1]: Detected architecture arm64.846builder # [ 1.544034] systemd[1]: Running in initrd.847server # [ 1.545462] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)848server # [ 1.545489] systemd[1]: Detected virtualization qemu.849server # [ 1.545542] systemd[1]: Detected architecture arm64.850server # [ 1.545549] systemd[1]: Running in initrd.851server # [ 1.546004] systemd[1]: Initializing machine ID from random generator.852builder # [ 1.544478] systemd[1]: Initializing machine ID from random generator.853builder # [ 1.544620] systemd[1]: Hostname set to <builder>.854server # [ 1.546153] systemd[1]: Hostname set to <server>.855server # [ 1.604728] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0856builder # [ 1.615203] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:07.0-1/input0857server # [ 1.724628] usb 1-2: new high-speed USB device number 3 using ehci-pci858builder # [ 1.735041] usb 1-2: new high-speed USB device number 3 using ehci-pci859builder # [ 1.814041] systemd[1]: bpf-restrict-fs: LSM BPF program attached860server # [ 1.810946] systemd[1]: bpf-restrict-fs: LSM BPF program attached861server # [ 1.875568] systemd[1]: Queued start job for default target Initrd Default Target.862builder # [ 1.879263] systemd[1]: Queued start job for default target Initrd Default Target.863server # [ 1.882533] 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/input2864server # [ 1.884016] systemd[1]: Created slice Slice /system/modprobe.865server # [ 1.884213] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.866builder # [ 1.889432] systemd[1]: Created slice Slice /system/modprobe.867builder # [ 1.889643] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.868server # [ 1.884242] systemd[1]: Expecting device /dev/disk/by-label/nixos...869server # [ 1.884270] systemd[1]: Reached target Path Units.870builder # [ 1.889674] systemd[1]: Expecting device /dev/disk/by-label/nixos...871builder # [ 1.889702] systemd[1]: Reached target Path Units.872server # [ 1.884549] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0873builder # [ 1.889715] systemd[1]: Reached target Slice Units.874server # [ 1.891533] systemd[1]: Reached target Slice Units.875builder # [ 1.889729] systemd[1]: Reached target Swaps.876server # [ 1.891756] systemd[1]: Reached target Swaps.877server # [ 1.891781] systemd[1]: Reached target Timer Units.878builder # [ 1.889743] systemd[1]: Reached target Timer Units.879server # [ 1.892051] systemd[1]: Listening on D-Bus System Message Bus Socket.880server # [ 1.892187] systemd[1]: Listening on Journal Socket (/dev/log).881builder # [ 1.889886] systemd[1]: Listening on D-Bus System Message Bus Socket.882server # [ 1.892309] systemd[1]: Listening on Journal Sockets.883builder # [ 1.890037] systemd[1]: Listening on Journal Socket (/dev/log).884builder # [ 1.890152] systemd[1]: Listening on Journal Sockets.885builder # [ 1.890260] systemd[1]: Listening on udev Control Socket.886builder # [ 1.890356] systemd[1]: Listening on udev Kernel Socket.887server # [ 1.896987] systemd[1]: Listening on udev Control Socket.888builder # [ 1.890373] systemd[1]: Reached target Socket Units.889server # [ 1.897171] systemd[1]: Listening on udev Kernel Socket.890server # [ 1.897190] systemd[1]: Reached target Socket Units.891server # [ 1.898786] systemd[1]: Starting Create List of Static Device Nodes...892builder # [ 1.906586] systemd[1]: Starting Create List of Static Device Nodes...893server # [ 1.898848] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs894builder # [ 1.907061] 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/input2895builder # [ 1.909822] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:07.0-2/input0896builder # [ 1.909978] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs897server # [ 1.912223] systemd[1]: Mounting Kernel Configuration File System...898builder # [ 1.920057] systemd[1]: Mounting Kernel Configuration File System...899builder # [ 1.931237] systemd[1]: Starting Journal Service...900server # [ 1.940653] systemd[1]: Starting Journal Service...901builder # [ 1.951882] systemd[1]: Starting Load Kernel Modules...902builder # [ 1.952008] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os903server # [ 1.952683] systemd[1]: Starting Load Kernel Modules...904server # [ 1.952899] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os905server # [ 1.960828] systemd[1]: Starting Coldplug All udev Devices...906builder # [ 1.979850] systemd[1]: Starting Coldplug All udev Devices...907builder # [ 1.981733] systemd[1]: Finished Create List of Static Device Nodes.908server # [ 1.977084] systemd[1]: Finished Create List of Static Device Nodes.909server # [ 1.978165] systemd[1]: Mounted Kernel Configuration File System.910builder # [ 1.990242] systemd-journald[71]: Collecting audit messages is disabled.911server # [ 1.989620] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...912builder # [ 2.011799] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...913server # [ 2.028040] systemd-journald[71]: Collecting audit messages is disabled.914builder # [ 2.035649] systemd[1]: Mounted Kernel Configuration File System.915server # [ 2.054078] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.916builder # [ 2.058203] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.917server # [ 2.069402] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.918builder # [ 2.075740] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.919server # [ 2.073583] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev920builder # [ 2.080393] systemd[1]: Starting Create Static Device Nodes in /dev...921server # [ 2.078281] systemd[1]: Starting Create Static Device Nodes in /dev...922builder # [ 2.084043] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev923server # [ 2.095177] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0924server # [ 2.095426] [drm] features: -virgl +edid -resource_blob -host_visible925server # [ 2.095430] [drm] features: -context_init926server # [ 2.096229] [drm] number of scanouts: 1927builder # [ 2.101841] [drm] pci: virtio-gpu-pci detected at 0000:00:05.0928server # [ 2.096240] [drm] number of cap sets: 0929builder # [ 2.102094] [drm] features: -virgl +edid -resource_blob -host_visible930builder # [ 2.102097] [drm] features: -context_init931builder # [ 2.102888] [drm] number of scanouts: 1932server # [ 2.117077] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic933server # [ 2.117096] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0934builder # [ 2.123007] [drm] number of cap sets: 0935builder # [ 2.124017] virtio-pci 0000:00:05.0: [drm] Registered 1 planes with drm panic936builder # [ 2.124029] [drm] Initialized virtio_gpu 0.1.0 for 0000:00:05.0 on minor 0937server # [ 2.144936] Console: switching to colour frame buffer device 160x50938builder # [ 2.151326] Console: switching to colour frame buffer device 160x50939server # [ 2.157453] systemd[1]: Finished Create Static Device Nodes in /dev.940server # [ 2.157695] systemd[1]: Reached target Preparation for Local File Systems.941server # [ 2.157717] systemd[1]: Reached target Local File Systems.942server # [ 2.163187] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device943builder # [ 2.167769] systemd[1]: Finished Create Static Device Nodes in /dev.944builder # [ 2.168052] systemd[1]: Reached target Preparation for Local File Systems.945builder # [ 2.168072] systemd[1]: Reached target Local File Systems.946builder # [ 2.170436] virtio-pci 0000:00:05.0: [drm] fb0: virtio_gpudrmfb frame buffer device947builder # [ 2.180533] systemd[1]: Starting Rule-based Manager for Device Events and Files...948server # [ 2.176965] systemd[1]: Starting Rule-based Manager for Device Events and Files...949server # [ 2.177825] systemd[1]: Finished Load Kernel Modules.950builder # [ 2.166880] systemd-modules-load[72]: Inserted module 'dm_mod'951builder # [ 2.191072] systemd[1]: Finished Load Kernel Modules.952builder # [ 2.191437] systemd[1]: Started Journal Service.953builder # [ 2.177760] systemd-modules-load[72]: Module 'virtio_balloon' is built in954builder # [ 2.180486] systemd-modules-load[72]: Module 'virtio_console' is built in955builder # [ 2.188479] systemd-modules-load[72]: Inserted module 'virtio_gpu'956builder # [ 2.189757] systemd-modules-load[72]: Module 'virtio_rng' is built in957builder # [ 2.192334] systemd[1]: Starting Apply Kernel Variables...958server # [ 2.198345] systemd-modules-load[72]: Inserted module 'dm_mod'959builder # [ 2.201414] systemd[1]: Starting Create System Files and Directories...960server # [ 2.199596] systemd-modules-load[72]: Module 'virtio_balloon' is built in[ 2.212648] systemd[1]: Starting Apply Kernel Variables...961server # [ 2.213047] systemd[1]: Started Journal Service.962server # 963server # [ 2.222988] systemd-modules-load[72]: Module 'virtio_console' is built in964server # [ 2.224670] systemd-modules-load[72]: Inserted module 'virtio_gpu'965server # [ 2.225816] systemd-modules-load[72]: Module 'virtio_rng' is built in966server # [ 2.226881] systemd[1]: Starting Create System Files and Directories...967builder # [ 2.269605] systemd[1]: Finished Apply Kernel Variables.968server # [ 2.269008] systemd[1]: Finished Apply Kernel Variables.969server # [ 2.277927] systemd[1]: Finished Create System Files and Directories.970builder # [ 2.284157] systemd[1]: Finished Create System Files and Directories.971server # [ 2.293539] systemd-udevd[77]: Using default interface naming scheme 'v261'.972builder # [ 2.301536] systemd-udevd[77]: Using default interface naming scheme 'v261'.973server # [ 2.322548] systemd[1]: Started Rule-based Manager for Device Events and Files.974builder # [ 2.330628] systemd[1]: Started Rule-based Manager for Device Events and Files.975server # [ 2.392147] systemd[1]: Starting Virtual Console Setup...976builder # [ 2.424175] systemd[1]: Starting Virtual Console Setup...977server # [ 2.452634] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.978server # [ 2.456144] systemd[1]: Finished Virtual Console Setup.979builder # [ 2.497819] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.980builder # [ 2.501701] systemd[1]: Finished Virtual Console Setup.981server # [ 3.049539] systemd[1]: Finished Coldplug All udev Devices.982server # [ 3.052180] systemd[1]: Reached target System Initialization.983server # [ 3.056173] systemd[1]: Reached target Basic System.984builder # [ 3.107482] systemd[1]: Finished Coldplug All udev Devices.985builder # [ 3.112282] systemd[1]: Reached target System Initialization.986builder # [ 3.113202] systemd[1]: Reached target Basic System.987server # [ 3.219452] (udev-worker)[91]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.988server # [ 3.234225] (udev-worker)[91]: Network interface NamePolicy= disabled on kernel command line.989server # [ 3.241299] (udev-worker)[90]: Network interface NamePolicy= disabled on kernel command line.990builder # [ 3.287425] (udev-worker)[94]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.991builder # [ 3.300461] (udev-worker)[88]: Network interface NamePolicy= disabled on kernel command line.992builder # [ 3.311195] (udev-worker)[94]: Network interface NamePolicy= disabled on kernel command line.993server # [ 3.312954] systemd[1]: Found device /dev/disk/by-label/nixos.994server # [ 3.316495] systemd[1]: Reached target Initrd Root Device.995server # [ 3.319765] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...996server # [ 3.381324] systemd-fsck[107]: nixos: clean, 12/65536 files, 13019/262144 blocks997server # [ 3.388542] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.998server # [ 3.394449] systemd[1]: Mounting /sysroot...999builder # [ 3.397603] systemd[1]: Found device /dev/disk/by-label/nixos.1000builder # [ 3.409609] systemd[1]: Reached target Initrd Root Device.1001builder # [ 3.415766] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...1002server # [ 3.454982] EXT4-fs (vda): mounted filesystem 568cc8de-68e1-4bb2-81d0-3a1ec2300518 r/w with ordered data mode. Quota mode: none.1003server # [ 3.445358] systemd[1]: Mounted /sysroot.1004server # [ 3.449628] systemd[1]: Reached target Initrd Root File System.1005server # [ 3.454997] systemd[1]: Starting Mountpoints Configured in the Real Root...1006builder # [ 3.475209] systemd-fsck[108]: nixos: clean, 12/65536 files, 13019/262144 blocks1007builder # [ 3.483298] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.1008builder # [ 3.486707] systemd[1]: Mounting /sysroot...1009server # [ 3.489109] systemd-sysroot-fstab-check[115]: /sysroot should be mounted in the initrd, will request daemon-reload.1010server # [ 3.494944] systemd[1]: Reload requested from client PID 115 ('systemd-sysroot') (unit initrd-parse-etc.service)...1011server # [ 3.500916] systemd[1]: Reloading...1012builder # [ 3.545999] EXT4-fs (vda): mounted filesystem 58ef901e-d9d2-4049-9d80-1734dd28e267 r/w with ordered data mode. Quota mode: none.1013builder # [ 3.535341] systemd[1]: Mounted /sysroot.1014builder # [ 3.536632] systemd[1]: Reached target Initrd Root File System.1015builder # [ 3.544145] systemd[1]: Starting Mountpoints Configured in the Real Root...1016builder # [ 3.582963] systemd-sysroot-fstab-check[116]: /sysroot should be mounted in the initrd, will request daemon-reload.1017builder # [ 3.587480] systemd[1]: Reload requested from client PID 116 ('systemd-sysroot') (unit initrd-parse-etc.service)...1018builder # [ 3.591641] systemd[1]: Reloading...1019server # [ 3.737010] systemd[1]: Reloading finished in 239 ms.1020server # [ 3.764109] systemd-sysroot-fstab-check[115]: Requesting initrd-fs.target/start/replace...1021server # [ 3.769923] systemd-sysroot-fstab-check[115]: Requesting swap.target/start/replace...1022server # [ 3.777770] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1023server # [ 3.780833] systemd[1]: Finished Mountpoints Configured in the Real Root.1024server # [ 3.783144] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1025builder # [ 3.828144] systemd[1]: Reloading finished in 241 ms.1026builder # [ 3.862997] systemd-sysroot-fstab-check[116]: Requesting initrd-fs.target/start/replace...1027builder # [ 3.868355] systemd-sysroot-fstab-check[116]: Requesting swap.target/start/replace...1028builder # [ 3.873930] systemd[1]: initrd-parse-etc.service: Deactivated successfully.1029builder # [ 3.878769] systemd[1]: Finished Mountpoints Configured in the Real Root.1030builder # [ 3.881383] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.1031server # [ 3.950133] systemd[1]: Mounting /sysroot/nix/.ro-store...1032server # [ 3.963339] systemd[1]: Mounting /sysroot/nix/.rw-store...1033builder # [ 3.969376] systemd[1]: Mounting /sysroot/nix/.ro-store...1034server # [ 3.971051] systemd[1]: Mounting /sysroot/run...1035server # [ 3.984986] systemd[1]: Mounting /sysroot/tmp/shared...1036builder # [ 3.987229] systemd[1]: Mounting /sysroot/nix/.rw-store...1037builder # [ 3.998454] systemd[1]: Mounting /sysroot/run...1038server # [ 4.003102] systemd[1]: Mounting /sysroot/tmp/xchg...1039builder # [ 4.017951] systemd[1]: Mounting /sysroot/tmp/shared...1040builder # [ 4.050702] systemd[1]: Mounting /sysroot/tmp/xchg...1041server # [ 4.093311] fuse: init (API version 7.45)1042server # [ 4.103667] virtiofs virtio6: discovered new tag: nix-store1043builder # [ 4.110326] fuse: init (API version 7.45)1044builder # [ 4.103647] systemd[1]: Mounted /sysroot/nix/.rw-store.1045server # [ 4.116753] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1046builder # [ 4.127582] virtiofs virtio6: discovered new tag: nix-store1047builder # [ 4.128420] virtiofs virtio6: virtio_fs_setup_dax: No cache capability1048server # [ 4.134384] virtiofs virtio7: discovered new tag: shared1049server # [ 4.135273] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1050builder # [ 4.144828] virtiofs virtio7: discovered new tag: shared1051builder # [ 4.145796] virtiofs virtio7: virtio_fs_setup_dax: No cache capability1052server # [ 4.146192] virtiofs virtio8: discovered new tag: xchg1053server # [ 4.147069] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1054builder # [ 4.153455] virtiofs virtio8: discovered new tag: xchg1055builder # [ 4.154326] virtiofs virtio8: virtio_fs_setup_dax: No cache capability1056server # [ 4.137797] systemd[1]: Mounted /sysroot/nix/.rw-store.1057builder # [ 4.142055] systemd[1]: Mounted /sysroot/run.1058server # [ 4.143223] systemd[1]: Mounted /sysroot/run.1059server # [ 4.155029] systemd[1]: Starting rw-sysroot-nix-store.service...1060server # [ 4.159653] systemd[1]: Mounted /sysroot/nix/.ro-store.1061server # [ 4.162058] systemd[1]: Mounted /sysroot/tmp/shared.1062server # [ 4.168641] systemd[1]: Mounted /sysroot/tmp/xchg.1063builder # [ 4.174861] systemd[1]: Starting rw-sysroot-nix-store.service...1064builder # [ 4.179416] systemd[1]: Mounted /sysroot/nix/.ro-store.1065builder # [ 4.187897] systemd[1]: Mounted /sysroot/tmp/shared.1066builder # [ 4.205723] systemd[1]: Mounted /sysroot/tmp/xchg.1067server # [ 4.206215] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1068server # [ 4.209688] systemd[1]: Finished rw-sysroot-nix-store.service.1069server # [ 4.213448] systemd[1]: Mounting /sysroot/nix/store...1070builder # [ 4.221268] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1071builder # [ 4.223087] systemd[1]: Finished rw-sysroot-nix-store.service.1072server # [ 4.268638] systemd[1]: Mounted /sysroot/nix/store.1073server # [ 4.271005] systemd[1]: Reached target Initrd File Systems.1074server # [ 4.273702] systemd[1]: Starting Find NixOS closure...1075server # [ 4.283959] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1076server # [ 4.329253] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1077server # [ 4.353479] systemd[1]: Finished Find NixOS closure.1078server # [ 4.356184] systemd[1]: Reached target Initrd Default Target.1079server # [ 4.361459] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1080server # [ 4.403080] systemd[1]: Stopped target Initrd Default Target.1081server # [ 4.407369] systemd[1]: Stopped target Basic System.1082server # [ 4.412612] systemd[1]: Stopped target Initrd Root Device.1083server # [ 4.413486] systemd[1]: Stopped target Path Units.1084server # [ 4.414248] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1085server # [ 4.415285] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1086server # [ 4.421927] systemd[1]: Stopped target Slice Units.1087server # [ 4.425195] systemd[1]: Stopped target Socket Units.1088server # [ 4.429888] systemd[1]: Stopped target System Initialization.1089server # [ 4.432232] systemd[1]: Stopped target Swaps.1090server # [ 4.435809] systemd[1]: Stopped target Timer Units.1091server # [ 4.441621] systemd[1]: dbus.socket: Deactivated successfully.1092server # [ 4.442525] systemd[1]: Closed D-Bus System Message Bus Socket.1093server # [ 4.443333] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1094server # [ 4.452709] systemd[1]: Stopped Find NixOS closure.1095server # [ 4.453585] systemd[1]: Starting rw-sysroot-nix-store.service...1096server # [ 4.454436] systemd[1]: systemd-sysctl.service: Deactivated successfully.1097server # [ 4.455381] systemd[1]: Stopped Apply Kernel Variables.1098server # [ 4.461516] systemd[1]: systemd-modules-load.service: Deactivated successfully.1099server # [ 4.464234] systemd[1]: Stopped Load Kernel Modules.1100server # [ 4.465070] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1101server # [ 4.475149] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1102server # [ 4.481319] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1103server # [ 4.485174] systemd[1]: Stopped Create System Files and Directories.1104server # [ 4.489514] systemd[1]: Stopped target Local File Systems.1105server # [ 4.493134] systemd[1]: Stopped target Preparation for Local File Systems.1106server # [ 4.494812] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1107server # [ 4.496232] systemd[1]: Stopped Coldplug All udev Devices.1108server # [ 4.497139] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1109server # [ 4.498208] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1110server # [ 4.499263] systemd[1]: Stopped Virtual Console Setup.1111server # [ 4.504543] systemd[1]: initrd-cleanup.service: Deactivated successfully.1112server # [ 4.507303] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1113server # [ 4.510069] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1114server # [ 4.516468] systemd[1]: Finished rw-sysroot-nix-store.service.1115server # [ 4.517446] systemd[1]: systemd-udevd.service: Deactivated successfully.1116server # [ 4.518359] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1117server # [ 4.519351] systemd[1]: systemd-udevd.service: Consumed 1.043s CPU time over 2.342s wall clock time, 15.9M memory peak.1118server # [ 4.521922] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.1119server # [ 4.523015] systemd[1]: Closed udev Control Socket.1120server # [ 4.523769] systemd[1]: Starting Cleanup udev Database...1121server # [ 4.524696] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1122server # [ 4.525802] systemd[1]: Stopped Create Static Device Nodes in /dev.1123server # [ 4.526703] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1124server # [ 4.527865] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1125server # [ 4.532433] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1126server # [ 4.535590] systemd[1]: Stopped Create List of Static Device Nodes.1127server # [ 4.562791] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1128server # [ 4.567336] systemd[1]: Finished Cleanup udev Database.1129server # [ 4.568849] systemd[1]: Reached target Switch Root.1130server # [ 4.572249] systemd[1]: Starting NixOS Activation...1131server # [ 4.674687] initrd-nixos-activation-start[167]: booting system configuration /nix/store/z5m47165qcwbgsm4grhvir7bv793vcg2-nixos-system-server-test1132server # [ 4.721283] initrd-nixos-activation-start[167]: running activation script...1133builder # [ 4.901437] (udev-worker)[95]: mtd0ro: Failed to find and pin callout binary "/nix/store/gnadg5slifq2r638xvz4pv6vrsdl9xkj-systemd-261.2/lib/udev/mtd_probe": No such file or directory1134builder # [ 4.904787] (udev-worker)[95]: 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 directory1135builder # [ 4.954994] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1136builder # [ 4.958491] systemd[1]: Stopped Virtual Console Setup.1137builder # [ 4.963299] systemd[1]: Stopping Virtual Console Setup...1138builder # [ 4.964856] systemd[1]: Starting Virtual Console Setup...1139builder # [ 4.987674] systemd[1]: Mounting /sysroot/nix/store...1140builder # [ 5.035615] systemd-vconsole-setup[150]: Configuration of first virtual console was skipped, ignoring remaining ones.1141builder # [ 5.039214] systemd[1]: Finished Virtual Console Setup.1142builder # [ 5.040170] systemd[1]: sysroot-run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Deactivated successfully.1143server # [ 5.041599] initrd-nixos-activation-start[191]: setting up /etc...1144builder # [ 5.044607] systemd[1]: Mounted /sysroot/nix/store.1145builder # [ 5.046598] systemd[1]: Reached target Initrd File Systems.1146builder # [ 5.049640] systemd[1]: Starting Find NixOS closure...1147builder # [ 5.060404] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...1148builder # [ 5.091844] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.1149builder # [ 5.104601] systemd[1]: Finished Find NixOS closure.1150builder # [ 5.108309] systemd[1]: Reached target Initrd Default Target.1151builder # [ 5.110143] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...1152builder # [ 5.144393] systemd[1]: Stopped target Initrd Default Target.1153builder # [ 5.145471] systemd[1]: Stopped target Basic System.1154builder # [ 5.146311] systemd[1]: Stopped target Initrd Root Device.1155builder # [ 5.147209] systemd[1]: Stopped target Path Units.1156builder # [ 5.147941] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.1157builder # [ 5.152221] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.1158builder # [ 5.157133] systemd[1]: Stopped target Slice Units.1159builder # [ 5.160659] systemd[1]: Stopped target Socket Units.1160builder # [ 5.165447] systemd[1]: Stopped target System Initialization.1161builder # [ 5.168910] systemd[1]: Stopped target Swaps.1162builder # [ 5.175275] systemd[1]: Stopped target Timer Units.1163builder # [ 5.177373] systemd[1]: dbus.socket: Deactivated successfully.1164builder # [ 5.178432] systemd[1]: Closed D-Bus System Message Bus Socket.1165builder # [ 5.179295] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.1166builder # [ 5.186000] systemd[1]: Stopped Find NixOS closure.1167builder # [ 5.188260] systemd[1]: Starting rw-sysroot-nix-store.service...1168builder # [ 5.190754] systemd[1]: systemd-sysctl.service: Deactivated successfully.1169builder # [ 5.192260] systemd[1]: Stopped Apply Kernel Variables.1170builder # [ 5.197344] systemd[1]: systemd-modules-load.service: Deactivated successfully.1171builder # [ 5.204497] systemd[1]: Stopped Load Kernel Modules.1172builder # [ 5.207439] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.1173builder # [ 5.209085] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.1174builder # [ 5.216174] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.1175builder # [ 5.217541] systemd[1]: Stopped Create System Files and Directories.1176builder # [ 5.218567] systemd[1]: Stopped target Local File Systems.1177builder # [ 5.219342] systemd[1]: Stopped target Preparation for Local File Systems.1178builder # [ 5.225605] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.1179builder # [ 5.227627] systemd[1]: Stopped Coldplug All udev Devices.1180builder # [ 5.230662] systemd[1]: Stopping Rule-based Manager for Device Events and Files...1181builder # [ 5.232345] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1182builder # [ 5.233412] systemd[1]: Stopped Virtual Console Setup.1183builder # [ 5.234204] systemd[1]: initrd-cleanup.service: Deactivated successfully.1184builder # [ 5.235131] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.1185server # [ 5.235012] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1186server # [ 5.238373] systemd[1]: Finished NixOS Activation.1187builder # [ 5.240360] systemd[1]: systemd-udevd.service: Deactivated successfully.1188server # [ 5.239766] systemd[1]: Starting Switch Root...1189builder # [ 5.243939] systemd[1]: Stopped Rule-based Manager for Device Events and Files.1190builder # [ 5.248641] systemd[1]: systemd-udevd.service: Consumed 1.657s CPU time over 3.028s wall clock time, 21.9M memory peak.1191builder # [ 5.252332] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.1192builder # [ 5.256234] systemd[1]: Closed udev Control Socket.1193builder # [ 5.257125] systemd[1]: Starting Cleanup udev Database...1194builder # [ 5.257937] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.1195builder # [ 5.264326] systemd[1]: Stopped Create Static Device Nodes in /dev.1196builder # [ 5.265378] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.1197builder # [ 5.266594] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.1198builder # [ 5.267632] systemd[1]: kmod-static-nodes.service: Deactivated successfully.1199server # [ 5.266868] systemd[1]: Switching root.1200builder # [ 5.272621] systemd[1]: Stopped Create List of Static Device Nodes.1201builder # [ 5.273590] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.1202builder # [ 5.274684] systemd[1]: Finished rw-sysroot-nix-store.service.1203builder # [ 5.297580] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.1204builder # [ 5.300763] systemd[1]: Finished Cleanup udev Database.1205builder # [ 5.302882] systemd[1]: Reached target Switch Root.1206builder # [ 5.304744] systemd[1]: Starting NixOS Activation...1207builder # [ 5.408148] initrd-nixos-activation-start[173]: booting system configuration /nix/store/7q42v4b45lmq438fsnafvr5v4hfy3p5s-nixos-system-builder-test1208server # [ 5.445939] systemd-journald[71]: Received SIGTERM from PID 1 (systemd).1209builder # [ 5.447993] initrd-nixos-activation-start[173]: running activation script...1210builder # [ 5.706482] initrd-nixos-activation-start[196]: setting up /etc...1211builder # [ 5.831101] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.1212builder # [ 5.834414] systemd[1]: Finished NixOS Activation.1213builder # [ 5.835715] systemd[1]: Starting Switch Root...1214builder # [ 5.861436] systemd[1]: Switching root.1215builder # [ 6.044317] systemd-journald[71]: Received SIGTERM from PID 1 (systemd).1216server # [ 6.560307] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)1217server # [ 6.560359] systemd[1]: Detected virtualization qemu.1218server # [ 6.567330] systemd[1]: Detected architecture arm64.1219server # [ 6.568369] systemd[1]: Detected first boot.1220server # [ 6.572627] systemd[1]: Initializing machine ID from random generator.1221builder # [ 6.595335] systemd[1]: systemd 261.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)1222builder # [ 6.595379] systemd[1]: Detected virtualization qemu.1223builder # [ 6.595437] systemd[1]: Detected architecture arm64.1224builder # [ 6.595539] systemd[1]: Detected first boot.1225builder # [ 6.597413] systemd[1]: Initializing machine ID from random generator.1226server # [ 6.837272] systemd[1]: bpf-restrict-fs: LSM BPF program attached1227builder # [ 6.891882] systemd[1]: bpf-restrict-fs: LSM BPF program attached1228server # [ 6.977039] systemd[1]: Applying preset policy.1229builder # [ 7.044174] systemd[1]: Applying preset policy.1230server # [ 7.246571] systemd[1]: Populated /etc with preset unit settings.1231builder # [ 7.309431] systemd[1]: Populated /etc with preset unit settings.1232server # [ 7.463143] systemd[1]: initrd-switch-root.service: Deactivated successfully.1233server # [ 7.463938] systemd[1]: Stopped initrd-switch-root.service.1234server # [ 7.469455] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1235server # [ 7.471363] systemd[1]: Created slice Slice /system/getty.1236server # [ 7.474871] systemd[1]: Created slice User and Session Slice.1237server # [ 7.475346] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1238server # [ 7.475694] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1239server # [ 7.475975] systemd[1]: Expecting device /dev/hvc0...1240server # [ 7.476222] systemd[1]: Expecting device /dev/ttyAMA0...1241server # [ 7.480879] systemd[1]: Reached target Local Encrypted Volumes.1242server # [ 7.481596] systemd[1]: Stopped target initrd-fs.target.1243server # [ 7.482218] systemd[1]: Stopped target initrd-root-fs.target.1244server # [ 7.482789] systemd[1]: Stopped target initrd-switch-root.target.1245server # [ 7.483348] systemd[1]: Reached target Virtual Machines and Containers.1246server # [ 7.483895] systemd[1]: Reached target Path Units.1247server # [ 7.488916] systemd[1]: Reached target Remote File Systems.1248server # [ 7.491252] systemd[1]: Reached target Slice Units.1249server # [ 7.491641] systemd[1]: Reached target Swaps.1250server # [ 7.495233] systemd[1]: Listening on Query the User Interactively for a Password.1251server # [ 7.498348] systemd[1]: Listening on Process Core Dump Socket.1252server # [ 7.499721] systemd[1]: Listening on Credential Encryption/Decryption.1253server # [ 7.503159] systemd[1]: Listening on Factory Reset Management.1254server # [ 7.503659] systemd[1]: Listening on Hostname Service Socket.1255server # [ 7.509436] systemd[1]: Starting Journal Log Access Socket...1256server # [ 7.510480] systemd[1]: Listening on Journal Audit Socket.1257server # [ 7.514214] systemd[1]: Listening on Console Output Muting Service Socket.1258server # [ 7.514816] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1259server # [ 7.515125] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1260server # [ 7.515385] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1261builder # [ 7.525050] systemd[1]: initrd-switch-root.service: Deactivated successfully.1262builder # [ 7.525849] systemd[1]: Stopped initrd-switch-root.service.1263builder # [ 7.530503] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.1264server # [ 7.524860] systemd[1]: Listening on Disk Repartitioning Service Socket.1265server # [ 7.525475] systemd[1]: Listening on udev Control Socket.1266server # [ 7.526234] systemd[1]: Listening on udev Varlink Socket.1267server # [ 7.531349] systemd[1]: Mounting Huge Pages File System...1268builder # [ 7.535237] systemd[1]: Created slice Slice /system/getty.1269builder # [ 7.536368] systemd[1]: Created slice User and Session Slice.1270server # [ 7.534987] systemd[1]: Mounting POSIX Message Queue File System...1271builder # [ 7.536776] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.1272builder # [ 7.537158] systemd[1]: Started Forward Password Requests to Wall Directory Watch.1273builder # [ 7.537441] systemd[1]: Expecting device /dev/hvc0...1274builder # [ 7.537688] systemd[1]: Expecting device /dev/ttyAMA0...1275builder # [ 7.537938] systemd[1]: Reached target Local Encrypted Volumes.1276builder # [ 7.538196] systemd[1]: Stopped target initrd-fs.target.1277builder # [ 7.538433] systemd[1]: Stopped target initrd-root-fs.target.1278builder # [ 7.538660] systemd[1]: Stopped target initrd-switch-root.target.1279builder # [ 7.547747] systemd[1]: Reached target Virtual Machines and Containers.1280builder # [ 7.548223] systemd[1]: Reached target Path Units.1281builder # [ 7.549175] systemd[1]: Reached target Remote File Systems.1282builder # [ 7.549836] systemd[1]: Reached target Slice Units.1283builder # [ 7.550482] systemd[1]: Reached target Swaps.1284builder # [ 7.557477] systemd[1]: Listening on Query the User Interactively for a Password.1285server # [ 7.552600] systemd[1]: Mounting Kernel Debug File System...1286builder # [ 7.560773] systemd[1]: Listening on Process Core Dump Socket.1287builder # [ 7.562257] systemd[1]: Listening on Credential Encryption/Decryption.1288server # [ 7.558403] systemd[1]: Mounting Kernel Trace File System...1289builder # [ 7.565831] systemd[1]: Listening on Factory Reset Management.1290builder # [ 7.566350] systemd[1]: Listening on Hostname Service Socket.1291builder # [ 7.571824] systemd[1]: Starting Journal Log Access Socket...1292builder # [ 7.573272] systemd[1]: Listening on Journal Audit Socket.1293builder # [ 7.576999] systemd[1]: Listening on Console Output Muting Service Socket.1294builder # [ 7.577729] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.1295builder # [ 7.578263] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os1296server # [ 7.576162] systemd[1]: Starting Create List of Static Device Nodes...1297builder # [ 7.582774] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki1298server # [ 7.578681] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1299builder # [ 7.589004] systemd[1]: Listening on Disk Repartitioning Service Socket.1300builder # [ 7.589614] systemd[1]: Listening on udev Control Socket.1301builder # [ 7.590391] systemd[1]: Listening on udev Varlink Socket.1302builder # [ 7.596187] systemd[1]: Mounting Huge Pages File System...1303server # [ 7.593128] systemd[1]: Mounting Kernel Configuration File System...1304server # [ 7.597623] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1305builder # [ 7.606686] systemd[1]: Mounting POSIX Message Queue File System...1306server # [ 7.604919] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1307server # [ 7.606353] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1308builder # [ 7.615150] systemd[1]: Mounting Kernel Debug File System...1309server # [ 7.626417] systemd[1]: Mounting FUSE Control File System...1310server # [ 7.631555] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671311builder # [ 7.635174] systemd[1]: Mounting Kernel Trace File System...1312builder # [ 7.648968] systemd[1]: Starting Create List of Static Device Nodes...1313builder # [ 7.653177] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1314builder # [ 7.670549] systemd[1]: Mounting Kernel Configuration File System...1315server # [ 7.673367] systemd[1]: Starting Journal Service...1316builder # [ 7.679334] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm1317builder # [ 7.680007] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore1318builder # [ 7.686125] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1319server # [ 7.686147] systemd[1]: Starting Load Kernel Modules...1320server # [ 7.700882] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1321builder # [ 7.714563] systemd[1]: Mounting FUSE Control File System...1322builder # [ 7.721437] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc671323server # [ 7.735888] systemd[1]: Starting Remount Root and Kernel File Systems...1324server # [ 7.736310] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1325builder # [ 7.755417] systemd[1]: Starting Journal Service...1326server # [ 7.758922] systemd[1]: Starting Coldplug All udev Devices...1327builder # [ 7.771368] systemd[1]: Starting Load Kernel Modules...1328server # [ 7.764927] systemd-journald[262]: Collecting audit messages is enabled.1329server # [ 7.778511] systemd[1]: Listening on Journal Log Access Socket.1330server # [ 7.779005] systemd[1]: Mounted Huge Pages File System.1331server # [ 7.779443] systemd[1]: Mounted POSIX Message Queue File System.1332server # [ 7.779843] systemd[1]: Mounted Kernel Debug File System.1333server # [ 7.780307] systemd[1]: Mounted Kernel Trace File System.1334server # [ 7.769798] systemd[1]: Queued start job for default target Multi-User System.1335server # [ 7.773955] systemd[1]: systemd-journald.service: Deactivated successfully.1336builder # [ 7.793584] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...1337server # [ 7.782683] systemd[1]: Finished Create List of Static Device Nodes.[ 7.797226] systemd[1]: Started Journal Service.1338server # 1339server # [ 7.789817] systemd-modules-load[263]: Module 'atkbd' is built in1340server # [ 7.797138] systemd-modules-load[263]: Module 'loop' is built in1341builder # [ 7.821158] systemd[1]: Starting Remount Root and Kernel File Systems...1342builder # [ 7.821625] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1343server # [ 7.821178] systemd-modules-load[263]: Inserted module 'tls'1344builder # [ 7.847217] systemd-journald[266]: Collecting audit messages is enabled.1345server # [ 7.832196] systemd[1]: Finished Load Kernel Modules.1346builder # [ 7.856045] systemd[1]: Starting Coldplug All udev Devices...1347server # [ 7.845849] systemd[1]: Starting Firewall...1348builder # [ 7.849125] systemd[1]: Queued start job for default target Multi-User System.1349builder # [ 7.853252] systemd[1]: systemd-journald.service: Deactivated successfully.1350builder # [ 7.876203] systemd[1]: Started Journal Service.1351server # [ 7.859754] systemd-oomd[264]: No swap; memory pressure usage will be degraded1352builder # [ 7.866934] systemd[1]: Listening on Journal Log Access Socket.1353builder # [ 7.868612] systemd[1]: Mounted Huge Pages File System.1354builder # [ 7.869469] systemd[1]: Mounted POSIX Message Queue File System.1355server # [ 7.867956] systemd[1]: Starting Apply Kernel Variables...1356builder # [ 7.870473] systemd[1]: Mounted Kernel Debug File System.1357builder # [ 7.871294] systemd[1]: Mounted Kernel Trace File System.1358server # [ 7.888590] EXT4-fs (vda): re-mounted 568cc8de-68e1-4bb2-81d0-3a1ec2300518.1359server # [ 7.882992] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1360builder # [ 7.885767] systemd[1]: Finished Create List of Static Device Nodes.1361server # [ 7.884769] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1362builder # [ 7.887285] systemd-modules-load[267]: Module 'atkbd' is built in1363builder # [ 7.896323] systemd-modules-load[267]: Module 'loop' is built in1364builder # [ 7.906588] systemd[1]: Finished Load Kernel Modules.1365server # [ 7.916192] systemd[1]: Mounted Kernel Configuration File System.1366server # [ 7.933947] systemd[1]: Finished Remount Root and Kernel File Systems.1367builder # [ 7.934176] systemd-oomd[269]: No swap; memory pressure usage will be degraded1368builder # [ 7.944857] systemd[1]: Starting Firewall...1369server # [ 7.948400] systemd[1]: Mounted FUSE Control File System.1370builder # [ 7.955422] systemd[1]: Starting Apply Kernel Variables...[ 7.973061] EXT4-fs (vda): re-mounted 58ef901e-d9d2-4049-9d80-1734dd28e267.1371builder # 1372server # [ 7.962370] systemd[1]: Listening on Disk Image Download Service Socket.1373server # [ 7.971554] systemd[1]: Starting Flush Journal to Persistent Storage...1374builder # [ 7.976186] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...1375server # [ 7.974817] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1376builder # [ 7.982301] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.1377builder # [ 7.983398] systemd[1]: Mounted Kernel Configuration File System.1378server # [ 7.988543] systemd[1]: Starting Load/Save OS Random Seed...1379server # [ 7.989432] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1380builder # [ 7.998233] systemd[1]: Finished Remount Root and Kernel File Systems.1381builder # [ 8.030585] systemd[1]: Mounted FUSE Control File System.1382builder # [ 8.043808] systemd[1]: Listening on Disk Image Download Service Socket.1383builder # [ 8.055097] systemd[1]: Starting Flush Journal to Persistent Storage...1384builder # [ 8.057326] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore1385server # [ 8.082001] systemd-journald[262]: Received client request to flush runtime journal.1386builder # [ 8.073520] systemd[1]: Starting Load/Save OS Random Seed...1387builder # [ 8.074528] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os1388builder # [ 8.133285] systemd[1]: Finished Apply Kernel Variables.1389builder # [ 8.163480] systemd-journald[266]: Received client request to flush runtime journal.1390server # [ 8.239399] systemd[1]: Finished Apply Kernel Variables.1391server # [ 8.244489] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1392server # [ 8.252169] systemd[1]: Starting Create Static Device Nodes in /dev...1393server # [ 8.253265] systemd[1]: Finished Load/Save OS Random Seed.1394server # [ 8.254070] systemd[1]: Reached target First Boot Complete.1395server # [ 8.254918] systemd[1]: Finished Flush Journal to Persistent Storage.1396builder # [ 8.256612] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.1397builder # [ 8.257813] systemd[1]: Starting Create Static Device Nodes in /dev...1398builder # [ 8.258862] systemd[1]: Finished Load/Save OS Random Seed.1399builder # [ 8.259659] systemd[1]: Reached target First Boot Complete.1400builder # [ 8.268795] systemd[1]: Finished Flush Journal to Persistent Storage.1401server # [ 8.318859] systemd[1]: Finished Create Static Device Nodes in /dev.1402server # [ 8.319965] systemd[1]: Reached target Preparation for Local File Systems.1403server # [ 8.326452] systemd[1]: Starting Rule-based Manager for Device Events and Files...1404builder # [ 8.410161] systemd[1]: Finished Create Static Device Nodes in /dev.1405builder # [ 8.411292] systemd[1]: Reached target Preparation for Local File Systems.1406builder # [ 8.415333] systemd[1]: Starting Rule-based Manager for Device Events and Files...1407server # [ 8.455214] systemd[1]: Mounting /run/wrappers...1408builder # [ 8.516254] systemd[1]: Mounting /run/wrappers...1409builder # [ 8.565376] systemd-udevd[307]: Using default interface naming scheme 'v261'.1410builder # [ 8.584761] systemd[1]: Mounted /run/wrappers.1411builder # [ 8.585620] systemd[1]: Reached target Local File Systems.1412builder # [ 8.592145] systemd[1]: Listening on Boot Loader Control Service Socket.1413builder # [ 8.599324] systemd[1]: Starting register-nix-paths.service...1414builder # [ 8.608141] systemd[1]: Starting Create SUID/SGID Wrappers...1415builder # [ 8.609138] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1416builder # [ 8.620186] systemd[1]: Starting Save Transient machine-id to Disk...1417server # [ 8.624900] systemd[1]: Mounted /run/wrappers.1418server # [ 8.625773] systemd[1]: Reached target Local File Systems.1419server # [ 8.635848] systemd[1]: Listening on Boot Loader Control Service Socket.1420builder # [ 8.637785] systemd[1]: Starting Create System Files and Directories...1421server # [ 8.640302] systemd[1]: Starting register-nix-paths.service...1422server # [ 8.644187] systemd[1]: Starting Create SUID/SGID Wrappers...1423server # [ 8.645285] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.1424server # [ 8.655011] systemd[1]: Starting Save Transient machine-id to Disk...1425server # [ 8.669387] systemd-udevd[302]: Using default interface naming scheme 'v261'.1426server # [ 8.678495] systemd[1]: Starting Create System Files and Directories...1427builder # [ 8.814885] systemd[1]: Started Rule-based Manager for Device Events and Files.1428server # [ 8.878797] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1429builder # [ 8.883943] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.1430server # [ 8.892631] systemd[1]: Finished Save Transient machine-id to Disk.1431builder # [ 8.896681] systemd[1]: Finished Save Transient machine-id to Disk.1432builder # [ 8.904319] systemd[1]: Finished Create System Files and Directories.1433server # [ 8.910135] systemd[1]: Started Rule-based Manager for Device Events and Files.1434builder # [ 8.920412] systemd[1]: Starting Rebuild Journal Catalog...1435builder # [ 8.929304] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1436server # [ 8.964153] systemd[1]: Finished Create System Files and Directories.1437server # [ 8.982762] systemd[1]: Starting Rebuild Journal Catalog...1438server # [ 9.002419] systemd[1]: Starting Record System Boot/Shutdown in UTMP...1439builder # [ 9.097854] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1440builder # [ 9.122510] systemd[1]: Finished Rebuild Journal Catalog.1441builder # [ 9.130666] systemd[1]: Starting Update is Completed...1442server # [ 9.173248] systemd[1]: Finished Record System Boot/Shutdown in UTMP.1443server # [ 9.216204] systemd[1]: Finished Rebuild Journal Catalog.1444server # [ 9.229646] systemd[1]: Starting Update is Completed...1445builder # [ 9.231884] systemd[1]: Finished Update is Completed.1446server # [ 9.353826] systemd[1]: Finished Update is Completed.1447server # [ 9.752382] systemd[1]: Finished Coldplug All udev Devices.1448builder # [ 9.850692] systemd[1]: Finished Coldplug All udev Devices.1449builder # [ 9.943371] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1450builder # [ 9.971696] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1451builder # [ 9.976516] systemd[1]: Finished Create SUID/SGID Wrappers.1452builder # [ 9.985588] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse1453builder # [ 10.006359] systemd[1]: Finished register-nix-paths.service.1454builder # [ 10.012324] systemd[1]: Reached target System Initialization.1455builder # [ 10.013297] systemd[1]: Started Discard unused filesystem blocks once a week.1456builder # [ 10.014440] systemd[1]: Started Daily Cleanup of Temporary Directories.1457builder # [ 10.015383] systemd[1]: Reached target Timer Units.1458builder # [ 10.033360] systemd[1]: Listening on D-Bus System Message Bus Socket.1459builder # [ 10.034391] systemd[1]: Starting niks3 auto-upload socket...1460builder # [ 10.035248] systemd[1]: Listening on Nix Daemon Socket.1461builder # [ 10.041498] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1462builder # [ 10.046900] systemd[1]: Starting D-Bus System Message Bus...1463builder # [ 10.057146] systemd[1]: Listening on niks3 auto-upload socket.1464builder # [ 10.058191] systemd[1]: Reached target Socket Units.1465server # [ 10.090545] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.1466server # [ 10.098402] systemd[1]: Finished Create SUID/SGID Wrappers.1467builder # [ 10.144226] dbus-broker-launch[445]: Looking up NSS user entry for 'systemd-timesync'...1468builder # [ 10.151171] dbus-broker-launch[445]: NSS returned no entry for 'systemd-timesync'1469server # [ 10.154537] systemd[1]: Finished register-nix-paths.service.1470builder # [ 10.155491] dbus-broker-launch[445]: Invalid user-name in /nix/store/ybvyf0zqij3wcdq5yx45bzdpnl3272hn-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1471server # [ 10.157869] systemd[1]: Reached target System Initialization.1472server # [ 10.158898] systemd[1]: Started Discard unused filesystem blocks once a week.1473server # [ 10.159937] systemd[1]: Started niks3 garbage collection timer.1474server # [ 10.168765] systemd[1]: Started Daily Cleanup of Temporary Directories.1475server # [ 10.169801] systemd[1]: Reached target Timer Units.1476server # [ 10.170548] systemd[1]: Listening on D-Bus System Message Bus Socket.1477server # [ 10.171495] systemd[1]: Starting niks3 server proxy socket...1478builder # [ 10.178192] systemd[1]: Started D-Bus System Message Bus.1479builder # [ 10.184152] systemd[1]: Reached target Basic System.1480server # [ 10.182474] systemd[1]: Listening on niks3 server socket.1481server # [ 10.183361] systemd[1]: Listening on Nix Daemon Socket.1482builder # [ 10.190496] systemd[1]: Starting Import lastlog data into lastlog2 database...1483server # [ 10.188924] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.1484builder # [ 10.196277] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1485server # [ 10.196238] systemd[1]: Starting D-Bus System Message Bus...1486server # [ 10.197213] systemd[1]: Listening on niks3 server proxy socket.1487server # [ 10.204392] systemd[1]: Reached target Socket Units.1488builder # [ 10.227135] dbus-broker-launch[445]: Ready1489builder # [ 10.227952] systemd[1]: Starting Post-Boot Actions...1490builder # [ 10.247345] systemd[1]: Started Reset console on configuration changes.1491builder # [ 10.283295] systemd[1]: Starting resolvconf update...1492server # [ 10.302257] dbus-broker-launch[445]: Looking up NSS user entry for 'systemd-timesync'...1493server # [ 10.307238] dbus-broker-launch[445]: NSS returned no entry for 'systemd-timesync'1494server # [ 10.311405] dbus-broker-launch[445]: Invalid user-name in /nix/store/lnmblbwfzhp14bsp0v94a889k70nkqni-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"1495server # [ 10.334005] systemd[1]: Started D-Bus System Message Bus.1496server # [ 10.338460] systemd[1]: Reached target Basic System.1497server # [ 10.348529] systemd[1]: Starting Import lastlog data into lastlog2 database...1498builder # [ 10.358024] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1499server # [ 10.362657] systemd[1]: Starting Generate test mTLS certs...1500server # [ 10.368123] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1501builder # [ 10.379598] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1502server # [ 10.384516] dbus-broker-launch[445]: Ready1503builder # [ 10.386152] nsncd[458]: Oct 01 07:33:15.777 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1504server # [ 10.388841] systemd[1]: Starting Post-Boot Actions...1505builder # [ 10.403168] systemd[1]: Started backdoor.service.1506builder # [ 10.409885] systemd[1]: Started Name Service Cache Daemon (nsncd).1507builder # [ 10.411019] systemd[1]: Reached target Host and Network Name Lookups.1508builder # [ 10.411991] systemd[1]: Reached target User and Group Name Lookups.1509server # [ 10.441684] systemd[1]: Started Reset console on configuration changes.1510builder # [ 10.445807] systemd[1]: Starting User Login Management...1511builder # [ 10.480905] systemd[1]: Finished Post-Boot Actions.1512server # [ 10.485194] systemd[1]: Starting resolvconf update...1513builder # connecting to host...1514server # [ 10.577644] systemd[1]: Finished Post-Boot Actions.1515server # [ 10.585386] niks3-test-certs-start[475]: -----1516builder # [ 10.600430] systemd[1]: Finished Import lastlog data into lastlog2 database.1517server # [ 10.604861] systemd[1]: Started Name Service Cache Daemon (nsncd).1518server # [ 10.618459] nsncd[461]: Oct 01 07:33:16.003 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1519server # [ 10.636481] systemd[1]: Reached target Host and Network Name Lookups.1520server # [ 10.637792] systemd[1]: Reached target User and Group Name Lookups.1521server # [ 10.652437] systemd[1]: Starting User Login Management...1522server # [ 10.671303] niks3-test-certs-start[490]: -----1523builder # [ 10.689566] systemd-logind[483]: New seat seat0.1524server # [ 10.691476] systemd[1]: Finished Import lastlog data into lastlog2 database.1525builder # [ 10.696256] systemd[1]: Started User Login Management.1526builder # [ 10.708413] systemd[1]: Starting linger-users.service...1527builder # [ 10.738896] (udev-worker)[404]: Network interface NamePolicy= disabled on kernel command line.1528builder # [ 10.748965] systemd[1]: Stopped target Host and Network Name Lookups.1529builder # [ 10.750103] systemd[1]: Stopping Host and Network Name Lookups...1530builder # [ 10.750969] systemd[1]: Stopped target User and Group Name Lookups.1531builder # [ 10.751844] systemd[1]: Stopping User and Group Name Lookups...1532builder # [ 10.768465] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1533builder # [ 10.769811] (udev-worker)[345]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1534builder # [ 10.790901] (udev-worker)[345]: Network interface NamePolicy= disabled on kernel command line.1535builder # [ 10.797359] systemd[1]: nscd.service: Deactivated successfully.1536builder # [ 10.798410] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1537server # [ 10.809367] niks3-test-certs-start[498]: Certificate request self-signature ok1538server # [ 10.810525] niks3-test-certs-start[498]: subject=CN=server1539builder # [ 10.812640] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1540builder # [ 10.830022] systemd[1]: Finished Firewall.1541builder # [ 10.834268] systemd[1]: linger-users.service: Deactivated successfully.1542builder # [ 10.839665] systemd[1]: Finished linger-users.service.1543server # [ 10.876297] niks3-test-certs-start[522]: -----1544builder # [ 10.883150] systemd[1]: Started Name Service Cache Daemon (nsncd).1545builder # [ 10.887304] systemd[1]: Reached target Host and Network Name Lookups.1546builder # [ 10.891579] nsncd[558]: Oct 01 07:33:16.281 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1547builder # [ 10.900489] systemd[1]: Reached target User and Group Name Lookups.1548server # [ 10.903489] systemd-logind[491]: New seat seat0.1549builder # [ 10.907385] systemd[1]: Finished resolvconf update.1550server # [ 10.906303] systemd[1]: Started User Login Management.1551builder # [ 10.915249] systemd[1]: Reached target Preparation for Network.1552builder # [ 10.918133] systemd[1]: Starting DHCP Client...1553builder # [ 10.923504] systemd[1]: Starting Extra networking commands....1554server # [ 10.923414] systemd[1]: Starting linger-users.service...1555server # [ 11.004729] niks3-test-certs-start[534]: Certificate request self-signature ok1556server # [ 11.015745] niks3-test-certs-start[534]: subject=CN=niks3 test client1557server # [ 11.021670] systemd[1]: Stopped target Host and Network Name Lookups.1558server # [ 11.022658] systemd[1]: Stopping Host and Network Name Lookups...1559server # [ 11.023553] systemd[1]: Stopped target User and Group Name Lookups.1560server # [ 11.037421] systemd[1]: Stopping User and Group Name Lookups...1561server # [ 11.038370] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...1562server # [ 11.039306] systemd[1]: nscd.service: Deactivated successfully.1563server # [ 11.054613] systemd[1]: Stopped Name Service Cache Daemon (nsncd).1564server # [ 11.055626] systemd[1]: linger-users.service: Deactivated successfully.1565server # [ 11.069058] systemd[1]: Finished linger-users.service.1566server # [ 11.082229] systemd[1]: Starting Name Service Cache Daemon (nsncd)...1567server # [ 11.087664] systemd[1]: Finished Generate test mTLS certs.1568builder # [ 11.156756] systemd[1]: Condition check resulted in Virtio network device being skipped.1569builder # [ 11.163475] systemd[1]: Starting Address configuration of eth1...1570server # [ 11.164386] systemd[1]: Finished Firewall.1571builder # [ 11.179566] dhcpcd[593]: dhcpcd-10.3.2 starting1572server # [ 11.178066] nsncd[560]: Oct 01 07:33:16.571 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"1573server # [ 11.183304] systemd[1]: Started Name Service Cache Daemon (nsncd).1574server # [ 11.186319] systemd[1]: Reached target Host and Network Name Lookups.1575server # [ 11.187298] systemd[1]: Reached target User and Group Name Lookups.1576builder # [ 11.191564] dhcpcd[631]: dev: loaded udev1577server # [ 11.203959] systemd[1]: Finished resolvconf update.1578server # [ 11.208409] systemd[1]: Reached target Preparation for Network.1579server # [ 11.216411] systemd[1]: Starting DHCP Client...1580server # [ 11.221821] systemd[1]: Starting Extra networking commands....1581builder # [ 11.260112] 8021q: 802.1Q VLAN Support v1.81582builder # [ 11.246887] systemd-logind[483]: Watching system buttons on /dev/input/event0 (gpio-keys)1583server # [ 11.262315] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31584builder # [ 11.257115] systemd[1]: Finished Extra networking commands..1585builder # [ 11.263530] systemd[1]: Reached target Network.1586builder # [ 11.270583] systemd[1]: Starting Permit User Sessions...1587builder # [ 11.309201] 8021q: adding VLAN 0 to HW filter on device eth11588builder # [ 11.364557] network-addresses-eth1-start[624]: adding address 192.168.1.1/24... done1589builder # [ 11.386822] systemd[1]: Finished Permit User Sessions.1590builder # [ 11.391522] systemd[1]: Started Getty on tty1.1591builder # [ 11.402946] systemd[1]: Reached target Login Prompts.1592builder # [ 11.433940] cfg80211: Loading compiled-in X.509 certificates for regulatory database1593builder # [ 11.419514] network-addresses-eth1-start[624]: adding address 2001:db8:1::1/64... done1594builder # [ 11.440531] systemd[1]: Finished Address configuration of eth1.1595server # [ 11.445826] dhcpcd[601]: dhcpcd-10.3.2 starting1596server # [ 11.461458] dhcpcd[634]: dev: loaded udev1597builder # [ 11.479167] mousedev: PS/2 mouse device common for all mice1598server # [ 11.466272] dhcpcd[634]: no valid interfaces found1599server # [ 11.468730] dhcpcd[634]: no valid interfaces found1600builder # [ 11.488973] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1601builder # [ 11.489450] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1602builder # [ 11.490414] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21603builder # [ 11.490724] cfg80211: failed to load regulatory.db1604builder # [ 11.553659] dhcpcd[631]: eth0: waiting for carrier1605builder # [ 11.571129] 8021q: adding VLAN 0 to HW filter on device eth01606builder # [ 11.557645] dhcpcd[631]: libudev: received NULL device1607builder # [ 11.558615] dhcpcd[631]: libudev: received NULL device1608builder # [ 11.559536] dhcpcd[631]: eth0: carrier acquired1609builder # [ 11.572097] systemd-logind[483]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1610builder # [ 11.577758] dhcpcd[631]: DUID 00:01:00:01:32:50:c9:3c:52:54:00:12:34:561611builder # [ 11.578874] dhcpcd[631]: eth0: IAID 00:12:34:561612builder # [ 11.579534] dhcpcd[631]: eth0: adding address fe80::5054:ff:fe12:34561613server # [ 11.596748] systemd[1]: Finished Extra networking commands..1614server # [ 11.600134] systemd[1]: Reached target Network.1615server # [ 11.605597] systemd[1]: Started Mock OIDC server for testing.1616server # [ 11.615022] systemd[1]: Starting Nginx Web Server...1617server # [ 11.636545] systemd[1]: Starting PostgreSQL Server...1618server # [ 11.656339] systemd[1]: Started RustFS S3-compatible object storage.1619server # [ 11.683743] systemd[1]: Starting Setup RustFS bucket...1620server # [ 11.704465] systemd[1]: Starting Permit User Sessions...1621builder # [ 11.730204] dhcpcd[631]: eth0: soliciting a DHCP lease1622builder # [ 11.736600] dhcpcd[631]: eth0: offered 10.0.2.15 from 10.0.2.21623builder # [ 11.744283] dhcpcd[631]: eth0: probing address 10.0.2.15/241624server # [ 11.816141] systemd[1]: Finished Permit User Sessions.1625server # [ 11.837573] systemd[1]: Started Getty on tty1.1626server # [ 11.844466] systemd[1]: Reached target Login Prompts.1627server # [ 12.247887] mock-oidc-server[651]: Mock OIDC Server running1628server # [ 12.254013] mock-oidc-server[651]: OIDC Address: 127.0.0.1:80801629server # [ 12.254973] mock-oidc-server[651]: Issue Address: 127.0.0.1:80811630server # [ 12.258926] mock-oidc-server[651]: Issuer: http://127.0.0.1:8080/oidc1631server # [ 12.259908] mock-oidc-server[651]: JWKS: http://127.0.0.1:8080/oidc/.well-known/jwks.json1632server # [ 12.264853] mock-oidc-server[651]: Discovery: http://127.0.0.1:8080/oidc/.well-known/openid-configuration1633server # [ 12.266235] mock-oidc-server[651]: Issue tokens: http://127.0.0.1:8081/issue?sub=...1634server # [ 12.267648] nginx-pre-start[681]: nginx: the configuration file /nix/store/yp5jb2wj0rv7jdsw17jpq148jhgkfqdb-nginx.conf syntax is ok1635server # [ 12.279167] nginx-pre-start[681]: nginx: configuration file /nix/store/yp5jb2wj0rv7jdsw17jpq148jhgkfqdb-nginx.conf test is successful1636server # [ 12.286432] systemd[1]: Started Nginx Web Server.1637builder # [ 12.333396] input: QEMU Virtio Keyboard as /devices/platform/4010000000.pcie/pci0000:00/0000:00:06.0/virtio5/input/input31638server # [ 12.388120] systemd[1]: Starting Virtual Console Setup...1639server # [ 12.435931] postgresql-pre-start[689]: The files belonging to this database system will be owned by user "postgres".1640server # [ 12.444578] postgresql-pre-start[689]: This user must also own the server process.1641server # [ 12.450243] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1642server # [ 12.451481] systemd[1]: Stopped Virtual Console Setup.1643server # [ 12.467718] postgresql-pre-start[689]: The database cluster will be initialized with locale "en_US.UTF-8".1644server # [ 12.475310] postgresql-pre-start[689]: The default database encoding has accordingly been set to "UTF8".1645server # [ 12.481983] postgresql-pre-start[689]: The default text search configuration will be set to "english".1646server # [ 12.483287] postgresql-pre-start[689]: Data page checksums are enabled.1647server # [ 12.500559] postgresql-pre-start[689]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok1648server # [ 12.501950] postgresql-pre-start[689]: creating subdirectories ... ok1649server # [ 12.502845] postgresql-pre-start[689]: selecting dynamic shared memory implementation ... posix1650server # [ 12.521310] systemd[1]: Load Kernel Module configfs skipped, unmet condition check ConditionKernelModuleLoaded=!configfs1651server # [ 12.522961] systemd[1]: Starting Virtual Console Setup...1652builder # [ 12.636580] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1653builder # [ 12.645795] systemd[1]: Starting Virtual Console Setup...1654builder # [ 12.665605] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1655builder # [ 12.671270] systemd[1]: Stopped Virtual Console Setup.1656builder # [ 12.676852] systemd[1]: Starting Virtual Console Setup...1657server # [ 12.703258] postgresql-pre-start[689]: selecting default "max_connections" ... 1001658builder # [ 12.719599] systemd-logind[483]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1659builder # [ 12.801999] systemd-vconsole-setup[686]: Configuration of first virtual console was skipped, ignoring remaining ones.1660builder # [ 12.806554] systemd[1]: Finished Virtual Console Setup.1661server # [ 12.882756] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.1662server # [ 12.913726] postgresql-pre-start[689]: selecting default "shared_buffers" ... 128MB1663server # [ 12.955218] systemd[1]: Condition check resulted in /dev/ttyAMA0 being skipped.1664server # [ 12.966947] systemd[1]: Started backdoor.service.1665server # connecting to host...1666server: Guest shell says: b'Spawning backdoor root shell...\n'1667server: connected to guest root shell1668server # [ 13.171503] 8021q: 802.1Q VLAN Support v1.81669server: (connecting took 13.65 seconds)1670server: (finished: waiting for the VM to finish booting, in 13.65 seconds)1671server # [ 13.260537] (udev-worker)[688]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.1672server # [ 13.262772] (udev-worker)[688]: Network interface NamePolicy= disabled on kernel command line.1673server # [ 13.273199] (udev-worker)[682]: Network interface NamePolicy= disabled on kernel command line.1674server # [ 13.384964] cfg80211: Loading compiled-in X.509 certificates for regulatory database1675server # [ 13.413313] systemd-vconsole-setup[709]: Configuration of first virtual console was skipped, ignoring remaining ones.1676server # [ 13.443959] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'1677server # [ 13.445460] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'1678server # [ 13.453415] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -21679server # [ 13.453750] cfg80211: failed to load regulatory.db1680server # [ 13.448317] systemd[1]: Finished Virtual Console Setup.1681builder # [ 13.618859] dhcpcd[631]: eth0: soliciting an IPv6 router1682builder # [ 13.620919] dhcpcd[631]: eth0: Router Advertisement from fe80::21683builder # [ 13.622844] dhcpcd[631]: eth0: adding address fec0::5054:ff:fe12:3456/641684builder # [ 13.624461] dhcpcd[631]: eth0: adding route to fec0::/641685builder # [ 13.625719] dhcpcd[631]: eth0: adding default route via fe80::21686server # [ 13.652407] systemd[1]: Condition check resulted in Virtio network device being skipped.1687server # [ 13.661152] systemd[1]: Starting Address configuration of eth1...1688server # [ 13.746781] systemd-logind[491]: Watching system buttons on /dev/input/event0 (gpio-keys)1689server # [ 13.787709] 8021q: adding VLAN 0 to HW filter on device eth11690server # [ 13.808241] 8021q: adding VLAN 0 to HW filter on device eth01691server # [ 13.797175] dhcpcd[634]: eth0: waiting for carrier1692server # [ 13.802254] dhcpcd[634]: eth0: carrier acquired1693server # [ 13.809549] network-addresses-eth1-start[746]: adding address 192.168.1.2/24... done1694server # [ 13.820589] dhcpcd[634]: DUID 00:01:00:01:32:50:c9:3f:52:54:00:12:34:561695server # [ 13.821699] dhcpcd[634]: eth0: IAID 00:12:34:561696server # [ 13.822388] dhcpcd[634]: eth0: adding address fe80::5054:ff:fe12:34561697server # [ 13.835744] network-addresses-eth1-start[746]: adding address 2001:db8:1::2/64... done1698server # [ 13.863006] systemd[1]: Finished Address configuration of eth1.1699server # [ 13.965792] mousedev: PS/2 mouse device common for all mice1700server # [ 13.977323] dhcpcd[634]: eth0: soliciting a DHCP lease1701server # [ 13.984703] dhcpcd[634]: eth0: offered 10.0.2.15 from 10.0.2.21702server # [ 13.988228] dhcpcd[634]: eth0: probing address 10.0.2.15/241703server # [ 13.995379] systemd-logind[491]: Watching system buttons on /dev/input/event1 (QEMU QEMU USB Keyboard)1704server # [ 15.374458] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1705server # [ 15.378245] systemd[1]: Stopped Virtual Console Setup.1706server # [ 15.379105] systemd[1]: Stopping Virtual Console Setup...1707server # [ 15.389523] systemd[1]: Starting Virtual Console Setup...1708server # [ 15.428082] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.1709server # [ 15.445688] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.1710server # [ 15.451150] systemd[1]: Stopped Virtual Console Setup.1711server # [ 15.458598] systemd[1]: Starting Virtual Console Setup...1712server # [ 15.513587] systemd-logind[491]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)1713server # [ 15.598006] dhcpcd[634]: eth0: soliciting an IPv6 router1714server # [ 15.598878] dhcpcd[634]: eth0: Router Advertisement from fe80::21715server # [ 15.599723] dhcpcd[634]: eth0: adding address fec0::5054:ff:fe12:3456/641716server # [ 15.604125] dhcpcd[634]: eth0: adding route to fec0::/641717server # [ 15.604900] dhcpcd[634]: eth0: adding default route via fe80::21718server # [ 15.788000] postgresql-pre-start[689]: selecting default time zone ... UTC1719server # [ 15.791318] postgresql-pre-start[689]: creating configuration files ... ok1720server # [ 15.920365] systemd-vconsole-setup[784]: Configuration of first virtual console was skipped, ignoring remaining ones.1721server # [ 15.927916] systemd[1]: Finished Virtual Console Setup.1722server # [ 16.050613] postgresql-pre-start[689]: running bootstrap script ... ok1723server # [ 16.580855] postgresql-pre-start[689]: performing post-bootstrap initialization ... ok1724builder # [ 16.596984] dhcpcd[631]: eth0: leased 10.0.2.15 for 86400 seconds1725builder # [ 16.597195] dhcpcd[631]: eth0: adding route to 10.0.2.0/241726builder # [ 16.597266] dhcpcd[631]: eth0: adding default route via 10.0.2.21727builder # [ 16.709992] systemd[1]: Started DHCP Client.1728builder # [ 16.712433] systemd[1]: Reached target Multi-User System.1729builder # [ 16.713717] systemd[1]: Startup finished in 1.184s (kernel) + 4.983s (initrd) + 10.545s (userspace) = 16.713s.1730server # [ 16.748596] postgresql-pre-start[689]: syncing data to disk ... ok1731server # [ 16.750892] postgresql-pre-start[689]: initdb: warning: enabling "trust" authentication for local connections1732server # [ 16.752602] postgresql-pre-start[689]: 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.1733server # [ 16.754680] postgresql-pre-start[689]: Success. You can now start the database server using:1734server # [ 16.755785] postgresql-pre-start[689]: pg_ctl -D /var/lib/postgresql/18 -l logfile start1735server # [ 16.851542] postgres[802]: [802] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit1736server # [ 16.854704] postgres[802]: [802] LOG: listening on IPv6 address "::1", port 54321737server # [ 16.855966] postgres[802]: [802] LOG: listening on IPv4 address "127.0.0.1", port 54321738server # [ 16.858968] postgres[802]: [802] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"1739server # [ 16.871856] postgres[811]: [811] LOG: database system was shut down at 2026-10-01 07:33:21 GMT1740server # [ 16.881396] postgres[802]: [802] LOG: database system is ready to accept connections1741server # [ 16.886326] systemd[1]: Started PostgreSQL Server.1742server # [ 16.897092] systemd[1]: Starting PostgreSQL Setup Scripts...1743server # [ 17.122466] postgresql-setup-start[827]: CREATE DATABASE1744server # [ 17.167166] postgresql-setup-start[832]: CREATE ROLE1745server # [ 17.187069] postgresql-setup-start[834]: ALTER DATABASE1746server # [ 17.194015] systemd[1]: Finished PostgreSQL Setup Scripts.1747server # [ 17.196366] systemd[1]: Reached target PostgreSQL.1748server: (finished: waiting for unit postgresql.service, in 18.17 seconds)1749server: waiting for unit rustfs.service1750server: (finished: waiting for unit rustfs.service, in 0.03 seconds)1751server: waiting for unit rustfs-setup.service1752server # [ 18.827533] dhcpcd[634]: eth0: leased 10.0.2.15 for 86400 seconds1753server # [ 18.829883] dhcpcd[634]: eth0: adding route to 10.0.2.0/241754server # [ 18.831148] dhcpcd[634]: eth0: adding default route via 10.0.2.21755server # [ 18.937154] systemd[1]: Started DHCP Client.1756server # [ 30.337136] rustfs-setup-start[956]: mb s3://niks3-test1757server # [ 30.347679] systemd[1]: Finished Setup RustFS bucket.1758server # [ 30.357592] systemd[1]: Starting niks3 server...1759server # [ 30.473817] postgres[971]: [971] ERROR: relation "goose_db_version" does not exist at character 361760server # [ 30.475148] postgres[971]: [971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1761server # [ 30.503211] niks3-server[966]: 2026/10/01 07:33:35 OK 20241026095416_initial_model.sql (16.2ms)1762server # [ 30.515381] niks3-server[966]: 2026/10/01 07:33:35 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)1763server # [ 30.517263] niks3-server[966]: 2026/10/01 07:33:35 OK 20251218171726_add_pins.sql (5.15ms)1764server # [ 30.518941] niks3-server[966]: 2026/10/01 07:33:35 OK 20260628120000_add_object_size_and_stats.sql (6.47ms)1765server # [ 30.524168] niks3-server[966]: 2026/10/01 07:33:35 OK 20260905000000_add_claims.sql (5.41ms)1766server # [ 30.528145] niks3-server[966]: 2026/10/01 07:33:35 OK 20260920000000_drop_claims.sql (3.73ms)1767server # [ 30.530901] niks3-server[966]: 2026/10/01 07:33:35 OK 20260923120000_add_pushes.sql (2.83ms)1768server # [ 30.533471] niks3-server[966]: 2026/10/01 07:33:35 goose: successfully migrated database to version: 202609231200001769server # [ 30.536683] niks3-server[966]: 2026/10/01 07:33:35 OK 1_commit_pending_closure.sql (5.74ms)1770server # [ 30.539271] niks3-server[966]: 2026/10/01 07:33:35 OK 2_object_stats_trigger.sql (2.56ms)1771server # [ 30.542265] niks3-server[966]: 2026/10/01 07:33:35 OK 3_commit_push.sql (2.51ms)1772server # [ 30.543894] niks3-server[966]: 2026/10/01 07:33:35 goose: up to current file version: 31773server # [ 30.548729] niks3-server[966]: 2026/10/01 07:33:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:8080/oidc1774server # [ 30.550442] niks3-server[966]: 2026/10/01 07:33:35 INFO OIDC authentication enabled config=/nix/store/z019gvf710g6d8396v9cvsyidwg4d4yk-niks3-oidc.json1775server # [ 30.553400] niks3-server[966]: 2026/10/01 07:33:35 INFO Loaded signing key name=niks3-test-1 path=/nix/store/6jgpl7z0sjpvlynzpcik37wwz06qi4np-niks3-signing-key1776server # [ 30.578737] niks3-server[966]: 2026/10/01 07:33:35 INFO Using socket-activated listener address=0.0.0.0:57511777server # [ 30.584905] niks3-server[966]: 2026/10/01 07:33:35 INFO Using socket-activated listener address=/run/niks3/proxy.sock1778server # [ 30.586366] niks3-server[966]: 2026/10/01 07:33:35 INFO systemd watchdog enabled interval=15s1779server # [ 30.587495] niks3-server[966]: 2026/10/01 07:33:35 INFO Starting HTTP server address=0.0.0.0:57511780server # [ 30.589553] niks3-server[966]: 2026/10/01 07:33:35 INFO Starting HTTP server address=/run/niks3/proxy.sock1781server # [ 30.591265] systemd[1]: Started niks3 server.1782server # [ 30.592397] systemd[1]: Reached target Multi-User System.1783server # [ 30.593220] systemd[1]: Startup finished in 1.183s (kernel) + 4.946s (initrd) + 24.453s (userspace) = 30.584s.1784server: (finished: waiting for unit rustfs-setup.service, in 13.52 seconds)1785server: waiting for unit mock-oidc.service1786server: (finished: waiting for unit mock-oidc.service, in 0.04 seconds)1787server: waiting for unit niks3.service1788server: (finished: waiting for unit niks3.service, in 0.03 seconds)1789server: waiting for TCP port 5751 on localhost1790server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!1791server: (finished: waiting for TCP port 5751 on localhost, in 0.03 seconds)1792server: waiting for TCP port 8080 on localhost1793server # Connection to localhost (127.0.0.1) 8080 port [tcp/http-alt] succeeded!1794server: (finished: waiting for TCP port 8080 on localhost, in 0.02 seconds)1795server: waiting for TCP port 9000 on localhost1796server # Connection to localhost (127.0.0.1) 9000 port [tcp/cslistener] succeeded!1797server: (finished: waiting for TCP port 9000 on localhost, in 0.02 seconds)1798server: must succeed: mkdir -p /tmp/test-config1799server: (finished: must succeed: mkdir -p /tmp/test-config, in 0.02 seconds)1800server: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token1801server: (finished: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/test-config/auth-token, in 0.01 seconds)1802server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31803server # [ 31.582159] niks3-server[966]: 2026/10/01 07:33:36 INFO Received push request method=POST path=/api/pushes1804server # time=2026-10-01T07:33:36.995Z level=INFO msg="Uploading 5 paths to server (0 already cached)"1805server # time=2026-10-01T07:33:36.997Z level=INFO msg="Uploading kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3 (287.5KB)"1806server # time=2026-10-01T07:33:36.999Z level=INFO msg="Uploading 0s40b0an0cz4vypbji92cb7qbr65icl4-libidn2-2.3.8 (366.1KB)"1807server # time=2026-10-01T07:33:37.001Z level=INFO msg="Uploading m54cs0m994hc3n9lax7sg98sgy729qsa-glibc-2.42-84 (44.4MB)"1808server # time=2026-10-01T07:33:37.004Z level=INFO msg="Uploading waax852balprvsvdziyaf1h7r3ldvakg-xgcc-15.3.0-libgcc (150.1KB)"1809server # time=2026-10-01T07:33:37.017Z level=INFO msg="Uploading h0hd048jzxs7fx9a6g75jwrrhbg50bp8-libunistring-1.4.2 (2.0MB)"1810server # [ 31.826942] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=0s40b0an0cz4vypbji92cb7qbr65icl4.ls1811server # [ 31.917332] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=waax852balprvsvdziyaf1h7r3ldvakg.ls1812server # [ 31.980287] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=h0hd048jzxs7fx9a6g75jwrrhbg50bp8.ls1813server # [ 31.993167] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=nar/0x48iv4crw96wayixvwmbhz9znvm9djawdf9j0wszdqdxpn92kw1.nar.zst1814server # [ 31.995203] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=kwhxkl8yn5y8wqiq11jsybagw3fbc4iv.ls1815server # [ 32.009340] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=nar/0rbj231dr19n59qcahf76cdwmqlqv239j85j94g8c89kf9kf5p04.nar.zst1816server # [ 32.011247] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=nar/07lydviym1nzmxy9y72apc8lgzy9v6x110r4vxac3kk2xslg0gcg.nar.zst1817server # [ 32.027829] niks3-server[966]: 2026/10/01 07:33:37 INFO Registered completed upload object_key=nar/16z5dldwcmmhv0ij0pz8h0z98mv285jvqw0ly64fsg0s9lbffamb.nar.zst1818server # [ 32.670717] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=m54cs0m994hc3n9lax7sg98sgy729qsa.ls1819server # [ 32.691057] niks3-server[966]: 2026/10/01 07:33:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1820server # [ 32.708868] niks3-server[966]: 2026/10/01 07:33:38 INFO Completed multipart upload object_key=nar/1vzbqdhwmbhwll0g4bniam5qjj71a1ci2n6lc100n2yfpbpygw8c.nar.zst upload_id=NGZjNjJmOWItYTc5Yy00ODI1LWIxZTMtNzVkYzFiY2RlN2MyLjExMWUwY2RlLTk0ZDItNGMxYS04YTRkLWQyNzk4MTk1YTkxN3gxNzkwODQwMDE2OTg4NDI2MjQw parts=11821server # time=2026-10-01T07:33:38.112Z level=INFO msg="Uploading 5 narinfos"1822server # [ 32.718940] niks3-server[966]: 2026/10/01 07:33:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1823server # [ 32.723456] niks3-server[966]: 2026/10/01 07:33:38 INFO Signed narinfos id=1 count=51824server # [ 32.746193] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=h0hd048jzxs7fx9a6g75jwrrhbg50bp8.narinfo1825server # [ 32.756545] niks3-server[966]: 2026/10/01 07:33:38 INFO Received complete push request method=POST path=/api/pushes/1/complete1826server # [ 32.761083] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=m54cs0m994hc3n9lax7sg98sgy729qsa.narinfo1827server # [ 32.765528] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=kwhxkl8yn5y8wqiq11jsybagw3fbc4iv.narinfo1828server # [ 32.767239] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=waax852balprvsvdziyaf1h7r3ldvakg.narinfo1829server # [ 32.771144] niks3-server[966]: 2026/10/01 07:33:38 INFO Registered completed upload object_key=0s40b0an0cz4vypbji92cb7qbr65icl4.narinfo1830server # time=2026-10-01T07:33:38.170Z level=INFO msg="Upload complete. (1.251s)"1831server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 1.37 seconds)1832server: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token1833server: (finished: must succeed: echo -n 'invalid-token' > /tmp/test-config/invalid-token, in 0.01 seconds)1834server: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31835server # [ 32.879614] niks3-server[966]: 2026/10/01 07:33:38 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]1836server # [ 32.930688] niks3-server[966]: 2026/10/01 07:33:38 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]1837server # time=2026-10-01T07:33:38.330Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1838server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/invalid-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 0.14 seconds)1839server: waiting for unit nginx.service1840server: (finished: waiting for unit nginx.service, in 0.03 seconds)1841server: waiting for TCP port 443 on localhost1842server # Connection to localhost (::1) 443 port [tcp/https] succeeded!1843server: (finished: waiting for TCP port 443 on localhost, in 0.02 seconds)1844server: must succeed: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.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/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31845server # time=2026-10-01T07:33:38.447Z 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.pem1846server # time=2026-10-01T07:33:38.460Z level=INFO msg="All 1 paths already cached"1847server: (finished: must succeed: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.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/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 0.08 seconds)1848server: 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_closures1849server: (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)1850server: must fail: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31851server # time=2026-10-01T07:33:38.508Z 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)"1852server: (finished: must fail: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 0.02 seconds)1853server: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31854server # time=2026-10-01T07:33:38.578Z level=INFO msg="Configuring client TLS" cert="" key="" ca=/etc/niks3-test-certs/ca.pem1855server # time=2026-10-01T07:33:38.587Z level=INFO msg="All 1 paths already cached"1856server: (finished: must succeed: NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --server-url https://server --ca-cert /etc/niks3-test-certs/ca.pem /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 0.08 seconds)1857server: must succeed: cd /etc/niks3-test-certs && /nix/store/ai0jh6nymysikgd4liv2k8iv9kmipcva-openssl-3.6.4-bin/bin/openssl req -newkey ec -pkeyopt ec_paramgen_curve:prime256v1 -nodes -keyout other.key -out other.csr -subj '/CN=other client'1858server # -----1859server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/ai0jh6nymysikgd4liv2k8iv9kmipcva-openssl-3.6.4-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)1860server: must succeed: cd /etc/niks3-test-certs && /nix/store/ai0jh6nymysikgd4liv2k8iv9kmipcva-openssl-3.6.4-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem1861server # Certificate request self-signature ok1862server # subject=CN=other client1863server: (finished: must succeed: cd /etc/niks3-test-certs && /nix/store/ai0jh6nymysikgd4liv2k8iv9kmipcva-openssl-3.6.4-bin/bin/openssl x509 -req -in other.csr -CA ca.pem -CAkey ca.key -CAcreateserial -days 1 -out other.pem, in 0.05 seconds)1864server: must fail: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.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/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31865server # time=2026-10-01T07:33:38.767Z 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.pem1866server # [ 33.378942] niks3-server[966]: 2026/10/01 07:33:38 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1867server # [ 33.431966] niks3-server[966]: 2026/10/01 07:33:38 WARN mTLS auth: subject not in bound subjects subject="CN=other client"1868server # time=2026-10-01T07:33:38.831Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"1869server: (finished: must fail: /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.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/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3, in 0.17 seconds)1870server: must succeed: mkdir -p /tmp/test-store1871server: (finished: must succeed: mkdir -p /tmp/test-store, in 0.02 seconds)1872server: 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/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.318761877server # copying 5 paths...1878server # copying path '/nix/store/h0hd048jzxs7fx9a6g75jwrrhbg50bp8-libunistring-1.4.2' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1879server # copying path '/nix/store/waax852balprvsvdziyaf1h7r3ldvakg-xgcc-15.3.0-libgcc' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1880server # copying path '/nix/store/0s40b0an0cz4vypbji92cb7qbr65icl4-libidn2-2.3.8' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1881server # copying path '/nix/store/m54cs0m994hc3n9lax7sg98sgy729qsa-glibc-2.42-84' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1882server # copying path '/nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1883server: (finished: must succeed: 1884 export AWS_ACCESS_KEY_ID=rustfsadmin1885export AWS_SECRET_ACCESS_KEY=rustfsadmin1886 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.31887, in 0.54 seconds)1888server: must succeed: 1889cat > /tmp/test-drv.nix << 'EOF'1890derivation {1891 name = "test-build-log";1892 system = builtins.currentSystem;1893 builder = "/bin/sh";1894 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1895}1896EOF18971898server: (finished: must succeed: 1899cat > /tmp/test-drv.nix << 'EOF'1900derivation {1901 name = "test-build-log";1902 system = builtins.currentSystem;1903 builder = "/bin/sh";1904 args = [ "-c" "echo 'test build log output'; echo 'hello world' > $out" ];1905}1906EOF1907, in 0.03 seconds)1908server: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix1909server # this derivation will be built:1910server # /nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1911server # building '/nix/store/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv'...1912server # test-build-log> test build log output1913server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix, in 0.22 seconds)1914server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1915server # [ 34.363633] niks3-server[966]: 2026/10/01 07:33:39 INFO Received push request method=POST path=/api/pushes1916server # time=2026-10-01T07:33:39.765Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1917server # time=2026-10-01T07:33:39.767Z level=INFO msg="Uploading z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log (128B)"1918server # [ 34.398862] niks3-server[966]: 2026/10/01 07:33:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1919server # time=2026-10-01T07:33:39.798Z level=INFO msg="Uploading 1 narinfos"1920server # [ 34.405575] niks3-server[966]: 2026/10/01 07:33:39 INFO Signed narinfos id=2 count=11921server # [ 34.406740] niks3-server[966]: 2026/10/01 07:33:39 INFO Registered completed upload object_key=nar/00zns3gj9hwz2a4b0i07y7nmxybq59lh24bl3xsxblcl6333mjil.nar.zst1922server # [ 34.413993] niks3-server[966]: 2026/10/01 07:33:39 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.ls1923server # [ 34.415669] niks3-server[966]: 2026/10/01 07:33:39 INFO Registered completed upload object_key=log/04bylz4wv9mr41hs78kv5ygm2d5xg9k9-test-build-log.drv1924server # [ 34.424531] niks3-server[966]: 2026/10/01 07:33:39 INFO Received complete push request method=POST path=/api/pushes/2/complete1925server # [ 34.426128] niks3-server[966]: 2026/10/01 07:33:39 INFO Registered completed upload object_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo1926server # time=2026-10-01T07:33:39.825Z level=INFO msg="Upload complete. (120ms)"1927server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log, in 0.20 seconds)1928server: must succeed: 1929 export AWS_ACCESS_KEY_ID=rustfsadmin1930export AWS_SECRET_ACCESS_KEY=rustfsadmin1931 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log19321933server # got build log for '/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'1934server: (finished: must succeed: 1935 export AWS_ACCESS_KEY_ID=rustfsadmin1936export AWS_SECRET_ACCESS_KEY=rustfsadmin1937 nix log --store 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log1938, in 0.13 seconds)1939subtest: push --stdin streams paths and reports each one1940server: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }'1941server # this derivation will be built:1942server # /nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1943server # building '/nix/store/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv'...1944server: (finished: must succeed: nix-build --no-out-link -E 'derivation { name = "stdin-test"; system = builtins.currentSystem; builder = "/bin/sh"; args = [ "-c" "echo stdin > $out" ]; }', in 0.17 seconds)1945server: 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/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --stdin1946server # [ 34.862447] niks3-server[966]: 2026/10/01 07:33:40 INFO Received push request method=POST path=/api/pushes1947server # time=2026-10-01T07:33:40.264Z level=INFO msg="Uploading 1 paths to server (0 already cached)"1948server # time=2026-10-01T07:33:40.265Z level=INFO msg="Uploading 7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test (120B)"1949server # [ 34.897384] niks3-server[966]: 2026/10/01 07:33:40 INFO Received sign narinfos request method=POST path=/api/pushes/3/sign1950server # time=2026-10-01T07:33:40.300Z level=INFO msg="Uploading 1 narinfos"1951server # [ 34.904321] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=nar/1hj1r0g515rfxjx685mfn3dgr6akqbn4gf64snlv6bxaxph69lna.nar.zst1952server # [ 34.909444] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=log/nw68n44n5z31m0d7a0s2mnhrkndz212d-stdin-test.drv1953server # [ 34.911465] niks3-server[966]: 2026/10/01 07:33:40 INFO Signed narinfos id=3 count=11954server # [ 34.921657] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.ls1955server # [ 34.923546] niks3-server[966]: 2026/10/01 07:33:40 INFO Received complete push request method=POST path=/api/pushes/3/complete1956server # [ 34.927765] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=7j8147s8h4si9jmv6bxa86ql7z6j2m37.narinfo1957server # time=2026-10-01T07:33:40.327Z level=INFO msg="Upload complete. (125ms)"1958server: (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/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --stdin, in 0.20 seconds)1959server: must succeed: 1960 export AWS_ACCESS_KEY_ID=rustfsadmin1961export AWS_SECRET_ACCESS_KEY=rustfsadmin1962 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1963 1964server # copying 1 paths...1965server # copying path '/nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...1966server: (finished: must succeed: 1967 export AWS_ACCESS_KEY_ID=rustfsadmin1968export AWS_SECRET_ACCESS_KEY=rustfsadmin1969 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/stdin-store /nix/store/7j8147s8h4si9jmv6bxa86ql7z6j2m37-stdin-test1970 , in 0.16 seconds)1971(finished: subtest: push --stdin streams paths and reports each one, in 0.53 seconds)1972server: must succeed: 1973cat > /tmp/ca-test.nix << 'EOF'1974derivation {1975 name = "ca-test";1976 system = builtins.currentSystem;1977 builder = "/bin/sh";1978 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1979 __contentAddressed = true;1980 outputHashMode = "recursive";1981 outputHashAlgo = "sha256";1982}1983EOF19841985server: (finished: must succeed: 1986cat > /tmp/ca-test.nix << 'EOF'1987derivation {1988 name = "ca-test";1989 system = builtins.currentSystem;1990 builder = "/bin/sh";1991 args = [ "-c" "echo 'Hello from CA derivation' > $out" ];1992 __contentAddressed = true;1993 outputHashMode = "recursive";1994 outputHashAlgo = "sha256";1995}1996EOF1997, in 0.02 seconds)1998server: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link1999server # this derivation will be built:2000server # /nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv2001server # building '/nix/store/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv'...2002server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/ca-test.nix --no-out-link, in 0.18 seconds)2003server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2004server # [ 35.487573] niks3-server[966]: 2026/10/01 07:33:40 INFO Received push request method=POST path=/api/pushes2005server # time=2026-10-01T07:33:40.890Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2006server # time=2026-10-01T07:33:40.891Z level=INFO msg="Uploading 5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test (144B)"2007server # [ 35.523113] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=log/8j226mdc8yhan5fv0s31bbzx0iiny3pa-ca-test.drv2008server # time=2026-10-01T07:33:40.927Z level=INFO msg="Uploading 1 narinfos"2009server # [ 35.532347] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.ls2010server # [ 35.534214] niks3-server[966]: 2026/10/01 07:33:40 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign2011server # [ 35.535900] niks3-server[966]: 2026/10/01 07:33:40 INFO Signed narinfos id=4 count=12012server # [ 35.546986] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2013server # time=2026-10-01T07:33:40.948Z level=INFO msg="Upload complete. (178ms)"2014server # [ 35.554523] niks3-server[966]: 2026/10/01 07:33:40 INFO Received complete push request method=POST path=/api/pushes/4/complete2015server # [ 35.559748] niks3-server[966]: 2026/10/01 07:33:40 INFO Registered completed upload object_key=5v8l1dc99hcg2ss10dgkivlhwbkpppjh.narinfo2016server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.26 seconds)2017server: must succeed: mkdir -p /tmp/chroot-store2018server: (finished: must succeed: mkdir -p /tmp/chroot-store, in 0.02 seconds)2019server: must succeed: 2020 export AWS_ACCESS_KEY_ID=rustfsadmin2021export AWS_SECRET_ACCESS_KEY=rustfsadmin2022 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test20232024server # copying 1 paths...2025server # copying path '/nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2026server: (finished: must succeed: 2027 export AWS_ACCESS_KEY_ID=rustfsadmin2028export AWS_SECRET_ACCESS_KEY=rustfsadmin2029 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/chroot-store /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2030, in 0.15 seconds)2031server: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2032server: (finished: must succeed: nix --store /tmp/chroot-store store cat /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2033server: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2034server # warning: 'realisation' is a deprecated alias for 'store build-trace'2035server: (finished: must succeed: nix --store /tmp/chroot-store realisation info /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test, in 0.06 seconds)2036server: must succeed: readlink /etc/niks3-test/symlink-wrapper2037server: (finished: must succeed: readlink /etc/niks3-test/symlink-wrapper, in 0.02 seconds)2038server: must succeed: readlink /etc/static/niks3-test/symlink-wrapper2039server: (finished: must succeed: readlink /etc/static/niks3-test/symlink-wrapper, in 0.02 seconds)2040server: must succeed: test -L /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper2041server: (finished: must succeed: test -L /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper, in 0.01 seconds)2042server: must succeed: readlink /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper2043server: (finished: must succeed: readlink /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper, in 0.02 seconds)2044server: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper2045server # [ 36.042072] niks3-server[966]: 2026/10/01 07:33:41 INFO Received push request method=POST path=/api/pushes2046server # time=2026-10-01T07:33:41.446Z level=INFO msg="Uploading 2 paths to server (0 already cached)"2047server # time=2026-10-01T07:33:41.447Z level=INFO msg="Uploading 0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper (192B)"2048server # time=2026-10-01T07:33:41.449Z level=INFO msg="Uploading xafv64bljflg1v8hnf22lyk0w4gma3v5-base-package (536B)"2049server # [ 36.088952] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=nar/1ncc9lqll9lyam30m8vdy4yyaym0q7sps47afadhzvyqsw833fy8.nar.zst2050server # time=2026-10-01T07:33:41.494Z level=INFO msg="Uploading 2 narinfos"2051server # [ 36.098463] niks3-server[966]: 2026/10/01 07:33:41 INFO Received sign narinfos request method=POST path=/api/pushes/5/sign2052server # [ 36.104141] niks3-server[966]: 2026/10/01 07:33:41 INFO Signed narinfos id=5 count=22053server # [ 36.112898] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=nar/0820av37plmfgrxw6pcbym6phk1sv14dilyrablrnkzb7z1fd5js.nar.zst2054server # [ 36.119134] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=xafv64bljflg1v8hnf22lyk0w4gma3v5.ls2055server # [ 36.122899] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=0caxmbk1mdnhh6zbyh0sz4faqqy5f08r.ls2056server # [ 36.132843] niks3-server[966]: 2026/10/01 07:33:41 INFO Received complete push request method=POST path=/api/pushes/5/complete2057server # time=2026-10-01T07:33:41.540Z level=INFO msg="Upload complete. (160ms)"2058server # [ 36.144601] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=0caxmbk1mdnhh6zbyh0sz4faqqy5f08r.narinfo2059server # [ 36.151496] niks3-server[966]: 2026/10/01 07:33:41 INFO Registered completed upload object_key=xafv64bljflg1v8hnf22lyk0w4gma3v5.narinfo2060server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper, in 0.24 seconds)2061server: must succeed: 2062 export AWS_ACCESS_KEY_ID=rustfsadmin2063export AWS_SECRET_ACCESS_KEY=rustfsadmin2064 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper20652066server # copying 2 paths...2067server # copying path '/nix/store/xafv64bljflg1v8hnf22lyk0w4gma3v5-base-package' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2068server # copying path '/nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2069server: (finished: must succeed: 2070 export AWS_ACCESS_KEY_ID=rustfsadmin2071export AWS_SECRET_ACCESS_KEY=rustfsadmin2072 nix copy --from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1' --to /tmp/test-store /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper2073, in 0.15 seconds)2074server: must succeed: 2075cat > /tmp/oidc-test.nix << 'EOF'2076derivation {2077 name = "oidc-test";2078 system = builtins.currentSystem;2079 builder = "/bin/sh";2080 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2081}2082EOF20832084server: (finished: must succeed: 2085cat > /tmp/oidc-test.nix << 'EOF'2086derivation {2087 name = "oidc-test";2088 system = builtins.currentSystem;2089 builder = "/bin/sh";2090 args = [ "-c" "echo 'OIDC test derivation' > $out" ];2091}2092EOF2093, in 0.02 seconds)2094server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link2095server # this derivation will be built:2096server # /nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2097server # building '/nix/store/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv'...2098server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test.nix --no-out-link, in 0.17 seconds)2099server: 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'2100server: (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)2101server: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTA4NDM2MjEsImlhdCI6MTc5MDg0MDAyMSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Hk17uBNGgh7vmzepi7NRL6eoKcslTwivm7wnyZ2L3bUO49nUWvSjM8TWT2JJFvehxhw7L6uzCR5DrP6wxGqvRuZrauNluP0eCvcgf-i8F92sqP2z4kJHLMUbLne8pC_aM8nRTuaF71sW8JVYuRu0vVpwEB2_tYnsOmPT3SvMtvBHkMEFoKkUTCsA6Pc6RHnL4T4a-VpBi1KKj7_kw2NFDgg38c5f09fBEt963fajpB65fyUsGDOuxkkQ71PtWhBzmLRewdo9wUyxbTJ9V7j3_x-wV-DZT8I1ceiYlhZQCvSm5Bl2ZDnWXmCpoopCy6zWNVWGyKkQw0548g9q58ovKg' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2102server # time=2026-10-01T07:33:41.932Z 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"2103server # [ 36.693262] niks3-server[966]: 2026/10/01 07:33:42 INFO Received push request method=POST path=/api/pushes2104server # time=2026-10-01T07:33:42.096Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2105server # time=2026-10-01T07:33:42.098Z level=INFO msg="Uploading x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test (136B)"2106server # [ 36.724488] niks3-server[966]: 2026/10/01 07:33:42 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.ls2107server # time=2026-10-01T07:33:42.128Z level=INFO msg="Uploading 1 narinfos"2108server # [ 36.733074] niks3-server[966]: 2026/10/01 07:33:42 INFO Received sign narinfos request method=POST path=/api/pushes/6/sign2109server # [ 36.740301] niks3-server[966]: 2026/10/01 07:33:42 INFO Signed narinfos id=6 count=12110server # [ 36.741424] niks3-server[966]: 2026/10/01 07:33:42 INFO Registered completed upload object_key=log/i8di75gyikk8ykgks7k6q09blyqm3g2x-oidc-test.drv2111server # [ 36.751423] niks3-server[966]: 2026/10/01 07:33:42 INFO Received complete push request method=POST path=/api/pushes/6/complete2112server # time=2026-10-01T07:33:42.154Z level=INFO msg="Upload complete. (145ms)"2113server # [ 36.760233] niks3-server[966]: 2026/10/01 07:33:42 INFO Registered completed upload object_key=nar/17h0qgwf5334wia961ibqy9hmpsyvfhrvj5ji9m031klp6sx4v0q.nar.zst2114server # [ 36.765090] niks3-server[966]: 2026/10/01 07:33:42 INFO Registered completed upload object_key=x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj.narinfo2115server: (finished: must succeed: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTA4NDM2MjEsImlhdCI6MTc5MDg0MDAyMSwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoibXlvcmciLCJzdWIiOiJyZXBvOm15b3JnL215cmVwbzpyZWY6cmVmcy9oZWFkcy9tYWluIn0.Hk17uBNGgh7vmzepi7NRL6eoKcslTwivm7wnyZ2L3bUO49nUWvSjM8TWT2JJFvehxhw7L6uzCR5DrP6wxGqvRuZrauNluP0eCvcgf-i8F92sqP2z4kJHLMUbLne8pC_aM8nRTuaF71sW8JVYuRu0vVpwEB2_tYnsOmPT3SvMtvBHkMEFoKkUTCsA6Pc6RHnL4T4a-VpBi1KKj7_kw2NFDgg38c5f09fBEt963fajpB65fyUsGDOuxkkQ71PtWhBzmLRewdo9wUyxbTJ9V7j3_x-wV-DZT8I1ceiYlhZQCvSm5Bl2ZDnWXmCpoopCy6zWNVWGyKkQw0548g9q58ovKg' /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test, in 0.25 seconds)2116server: must succeed: 2117cat > /tmp/oidc-test2.nix << 'EOF'2118derivation {2119 name = "oidc-test2";2120 system = builtins.currentSystem;2121 builder = "/bin/sh";2122 args = [ "-c" "echo 'OIDC test 2' > $out" ];2123}2124EOF21252126server: (finished: must succeed: 2127cat > /tmp/oidc-test2.nix << 'EOF'2128derivation {2129 name = "oidc-test2";2130 system = builtins.currentSystem;2131 builder = "/bin/sh";2132 args = [ "-c" "echo 'OIDC test 2' > $out" ];2133}2134EOF2135, in 0.02 seconds)2136server: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link2137server # this derivation will be built:2138server # /nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv2139server # building '/nix/store/ldlfjwl576hkm4b5ag3b447nnn59cwiw-oidc-test2.drv'...2140server: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/oidc-test2.nix --no-out-link, in 0.19 seconds)2141server: 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'2142server: (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)2143server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTA4NDM2MjIsImlhdCI6MTc5MDg0MDAyMiwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.UVy0Awpm2pGzwa-YXDDQTBMg-okE73kSBjs6E2NSKVa2rGAhxgkgiri4m7J1-YwAFZISMKlOZ3gyAweqMluGye3KVWOXsofWAtdTSxUkbZsv4jkgA0CJfoyNnkpF9GJHXjAAJrXQwAITMybTY5xqXT5tQDdnkbQs_UmpWSjAjVB-v8vgy7EJfnXaSmff7JDVUx_CntyTkro2RME9vuGGKH1Bi6qXBWcZ7FI9xKroDfMNpb0HLm8bwbGgdrOZ23HL4NBQPGffNw8W9NeLgWcjEAmOz5rJ6FeaTg6DxEEBW8-aSYMfVTD1hZYH4Dne8wWrpTlIUWRzHAUdOUt_ivsotQ' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22144server # time=2026-10-01T07:33:42.425Z 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"2145server # [ 37.101040] niks3-server[966]: 2026/10/01 07:33:42 WARN Authentication failed token_preview=eyJhbGciOi...OUt_ivsotQ token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2146server # [ 37.179309] niks3-server[966]: 2026/10/01 07:33:42 WARN Authentication failed token_preview=eyJhbGciOi...OUt_ivsotQ token_length=682 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2147server # time=2026-10-01T07:33:42.580Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2148server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vc2VydmVyOjU3NTEiLCJleHAiOjE3OTA4NDM2MjIsImlhdCI6MTc5MDg0MDAyMiwiaXNzIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL29pZGMiLCJyZXBvc2l0b3J5X293bmVyIjoib3RoZXJvcmciLCJzdWIiOiJyZXBvOm90aGVyb3JnL3JlcG86cmVmOnJlZnMvaGVhZHMvbWFpbiJ9.UVy0Awpm2pGzwa-YXDDQTBMg-okE73kSBjs6E2NSKVa2rGAhxgkgiri4m7J1-YwAFZISMKlOZ3gyAweqMluGye3KVWOXsofWAtdTSxUkbZsv4jkgA0CJfoyNnkpF9GJHXjAAJrXQwAITMybTY5xqXT5tQDdnkbQs_UmpWSjAjVB-v8vgy7EJfnXaSmff7JDVUx_CntyTkro2RME9vuGGKH1Bi6qXBWcZ7FI9xKroDfMNpb0HLm8bwbGgdrOZ23HL4NBQPGffNw8W9NeLgWcjEAmOz5rJ6FeaTg6DxEEBW8-aSYMfVTD1hZYH4Dne8wWrpTlIUWRzHAUdOUt_ivsotQ' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.18 seconds)2149server: 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'2150server: (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)2151server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MDg0MzYyMiwiaWF0IjoxNzkwODQwMDIyLCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.g7XRhsvCGy7dZShtfl7CNzZEvXP0r-DuDMCCZ3CcAn-L_sHpwhBBkl4-6LmXmPBhEj8eroYx7wFyljDu3Jm-pzBIZbwbsevyRiTEGcGltpF_xxqHV3EkKRyVWhn621Z8AU7qa3im7lMb4BXuYwZ0AODC16GYEMNVuaxilC9Ir89Fqhk0LHvDoHxPamlpPOX8gcyX7AoktgbO1ymfUOOzvKDtBvt-lVEGDh23iUv4SiRBpka97mKHIRNUHNjlnupaREPW8e4xQ-XsLjAYWKAJ_woyNFkFfABuYq29CicaS3_9VaMjAGXPI4i2dCyowKAzxlY_aJY-TbVRRPd30IQxAA' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22152server # time=2026-10-01T07:33:42.630Z 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 # [ 37.290799] niks3-server[966]: 2026/10/01 07:33:42 WARN Authentication failed token_preview=eyJhbGciOi...RPd30IQxAA token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2154server # [ 37.345591] niks3-server[966]: 2026/10/01 07:33:42 WARN Authentication failed token_preview=eyJhbGciOi...RPd30IQxAA token_length=676 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2155server # time=2026-10-01T07:33:42.745Z 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/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImJtZlZQX3RHdWZvQ2Q5elp0eFl6aHFjUnJPbGpnbnVUNUFoenQ4U2tTRFUiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vd3Jvbmc6NTc1MSIsImV4cCI6MTc5MDg0MzYyMiwiaWF0IjoxNzkwODQwMDIyLCJpc3MiOiJodHRwOi8vMTI3LjAuMC4xOjgwODAvb2lkYyIsInJlcG9zaXRvcnlfb3duZXIiOiJteW9yZyIsInN1YiI6InJlcG86bXlvcmcvbXlyZXBvOnJlZjpyZWZzL2hlYWRzL21haW4ifQ.g7XRhsvCGy7dZShtfl7CNzZEvXP0r-DuDMCCZ3CcAn-L_sHpwhBBkl4-6LmXmPBhEj8eroYx7wFyljDu3Jm-pzBIZbwbsevyRiTEGcGltpF_xxqHV3EkKRyVWhn621Z8AU7qa3im7lMb4BXuYwZ0AODC16GYEMNVuaxilC9Ir89Fqhk0LHvDoHxPamlpPOX8gcyX7AoktgbO1ymfUOOzvKDtBvt-lVEGDh23iUv4SiRBpka97mKHIRNUHNjlnupaREPW8e4xQ-XsLjAYWKAJ_woyNFkFfABuYq29CicaS3_9VaMjAGXPI4i2dCyowKAzxlY_aJY-TbVRRPd30IQxAA' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.14 seconds)2157server: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test22158server # time=2026-10-01T07:33:42.765Z 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"2159server # [ 37.424542] niks3-server[966]: 2026/10/01 07:33:42 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]2160server # [ 37.478372] niks3-server[966]: 2026/10/01 07:33:42 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]2161server # time=2026-10-01T07:33:42.878Z level=ERROR msg="Fatal error" error="pushing paths: creating pending closures: creating push: server returned 401: Unauthorized\n"2162server: (finished: must fail: NIKS3_SERVER_URL=http://server:5751 /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --auth-token 'not-a-valid-jwt-token' /nix/store/dby496qg7y54y76acj9wnf06zq5ad9fy-oidc-test2, in 0.13 seconds)2163server: must succeed: 2164 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins create hello-pin /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.321652166server # [ 37.556954] niks3-server[966]: 2026/10/01 07:33:42 INFO Received create pin request method=POST path=/api/pins/hello-pin2167server # time=2026-10-01T07:33:42.963Z level=INFO msg="Created pin" name=hello-pin store_path=/nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.32168server # [ 37.568884] niks3-server[966]: 2026/10/01 07:33:42 INFO Created/updated pin name=hello-pin store_path=/nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.3 narinfo_key=kwhxkl8yn5y8wqiq11jsybagw3fbc4iv.narinfo2169server: (finished: must succeed: 2170 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins create hello-pin /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.32171, in 0.09 seconds)2172server: must succeed: 2173 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list21742175server # [ 37.658167] niks3-server[966]: 2026/10/01 07:33:43 INFO Received list pins request method=GET path=/api/pins2176server: (finished: must succeed: 2177 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list2178, in 0.09 seconds)2179server: must succeed: 2180 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only21812182server # [ 37.741353] niks3-server[966]: 2026/10/01 07:33:43 INFO Received list pins request method=GET path=/api/pins2183server: (finished: must succeed: 2184 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only2185, in 0.08 seconds)2186server: must succeed: 2187 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --json21882189server # [ 37.822937] niks3-server[966]: 2026/10/01 07:33:43 INFO Received list pins request method=GET path=/api/pins2190server: (finished: must succeed: 2191 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --json2192, in 0.08 seconds)2193server: must succeed: 2194 export S3_ENDPOINT_URL=http://localhost:90002195 export AWS_ACCESS_KEY_ID=rustfsadmin2196 export AWS_SECRET_ACCESS_KEY=rustfsadmin2197 /nix/store/1mxif175wb0rn50pgaisvczshqv3mw1i-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin21982199server: (finished: must succeed: 2200 export S3_ENDPOINT_URL=http://localhost:90002201 export AWS_ACCESS_KEY_ID=rustfsadmin2202 export AWS_SECRET_ACCESS_KEY=rustfsadmin2203 /nix/store/1mxif175wb0rn50pgaisvczshqv3mw1i-s5cmd-2.3.0/bin/s5cmd cat s3://niks3-test/pins/hello-pin2204, in 0.04 seconds)2205server: must succeed: 2206 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log22072208server # time=2026-10-01T07:33:43.347Z level=INFO msg="All 1 paths already cached"2209server # [ 37.953801] niks3-server[966]: 2026/10/01 07:33:43 INFO Received create pin request method=POST path=/api/pins/ca-pin2210server # time=2026-10-01T07:33:43.359Z level=INFO msg="Created pin" name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2211server # [ 37.964915] niks3-server[966]: 2026/10/01 07:33:43 INFO Created/updated pin name=ca-pin store_path=/nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log narinfo_key=z57vvdhnnry9vypazxb33pyi7hsaz71i.narinfo2212server: (finished: must succeed: 2213 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 push --pin ca-pin /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2214, in 0.11 seconds)2215server: must succeed: 2216 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only22172218server # [ 38.058961] niks3-server[966]: 2026/10/01 07:33:43 INFO Received list pins request method=GET path=/api/pins2219server: (finished: must succeed: 2220 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only2221, in 0.09 seconds)2222server: must succeed: 2223 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins delete hello-pin22242225server # [ 38.138329] niks3-server[966]: 2026/10/01 07:33:43 INFO Received delete pin request method=DELETE path=/api/pins/hello-pin2226server # time=2026-10-01T07:33:43.543Z level=INFO msg="Deleted pin" name=hello-pin2227server # [ 38.147256] niks3-server[966]: 2026/10/01 07:33:43 INFO Deleted pin name=hello-pin2228server: (finished: must succeed: 2229 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins delete hello-pin2230, in 0.09 seconds)2231server: must succeed: 2232 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only22332234server # [ 38.228771] niks3-server[966]: 2026/10/01 07:33:43 INFO Received list pins request method=GET path=/api/pins2235server: (finished: must succeed: 2236 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins list --names-only2237, in 0.08 seconds)2238server: must fail: 2239 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent22402241server # [ 38.321336] niks3-server[966]: 2026/10/01 07:33:43 INFO Received create pin request method=POST path=/api/pins/bad-pin2242server # time=2026-10-01T07:33:43.720Z level=ERROR msg="Fatal error" error="creating pin: server returned 404: closure not found: store path must be pushed before pinning\n"2243server # [ 38.325886] niks3-server[966]: 2026/10/01 07:33:43 ERROR Failed to get closure for pin narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo error="no rows in result set"2244server: (finished: must fail: 2245 NIKS3_SERVER_URL=http://server:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/test-config/auth-token /nix/store/g7phak0a4pn3ngv3id2qqx5cp4iq7r7s-niks3-1.13.0/bin/niks3 pins create bad-pin /nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-nonexistent2246, in 0.10 seconds)2247server: must succeed: systemctl start niks3-gc.service2248server # [ 38.369544] systemd[1]: Starting niks3 garbage collection...2249server # [ 38.413448] niks3[1543]: time=2026-10-01T07:33:43.809Z level=INFO msg="Starting garbage collection" older-than=720h failed-uploads-older-than=6h force=false2250server # [ 38.418269] niks3-server[966]: 2026/10/01 07:33:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures2251server # [ 38.419885] niks3[1543]: time=2026-10-01T07:33:43.814Z level=INFO msg="Garbage collection started"2252server # [ 38.423748] niks3-server[966]: 2026/10/01 07:33:43 INFO Aborted multipart uploads count=02253server # [ 38.430096] niks3-server[966]: 2026/10/01 07:33:43 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=02254server # [ 38.436182] niks3-server[966]: 2026/10/01 07:33:43 INFO Vacuumed table table=pending_closures2255server # [ 38.440335] niks3-server[966]: 2026/10/01 07:33:43 INFO Vacuumed table table=pending_objects2256server # [ 38.444298] niks3-server[966]: 2026/10/01 07:33:43 INFO Vacuumed table table=multipart_uploads2257server # [ 38.448316] niks3-server[966]: 2026/10/01 07:33:43 INFO Vacuumed table table=closures2258server # [ 38.451706] niks3-server[966]: 2026/10/01 07:33:43 INFO Vacuumed table table=objects2259server # [ 40.419622] niks3[1543]: time=2026-10-01T07:33:45.815Z level=INFO msg="Garbage collection progress" phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=4 objects_deleted=0 objects_failed=02260server # [ 40.425430] niks3[1543]: time=2026-10-01T07:33:45.815Z 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=02261server # [ 40.435066] systemd[1]: niks3-gc.service: Deactivated successfully.2262server # [ 40.440576] systemd[1]: Finished niks3 garbage collection.2263server # [ 40.442158] systemd[1]: niks3-gc.service: Consumed 39ms CPU time over 2.065s wall clock time, 2.4M memory peak, 1.2K incoming IP traffic, 823B outgoing IP traffic.2264server: (finished: must succeed: systemctl start niks3-gc.service, in 2.12 seconds)2265builder: waiting for unit niks3-auto-upload.socket2266builder: waiting for the VM to finish booting2267builder: Guest shell says: b'Spawning backdoor root shell...\n'2268builder: connected to guest root shell2269builder: (connecting took 0.00 seconds)2270builder: (finished: waiting for the VM to finish booting, in 0.00 seconds)2271builder: (finished: waiting for unit niks3-auto-upload.socket, in 0.05 seconds)2272builder: must succeed: test -S /run/niks3/upload-to-cache.sock2273builder: (finished: must succeed: test -S /run/niks3/upload-to-cache.sock, in 0.02 seconds)2274builder: must succeed: grep post-build-hook /etc/nix/nix.conf2275builder: (finished: must succeed: grep post-build-hook /etc/nix/nix.conf, in 0.02 seconds)2276builder: must succeed: 2277cat > /tmp/test-drv.nix << 'EOF'2278derivation {2279 name = "post-build-hook-test";2280 system = builtins.currentSystem;2281 builder = "/bin/sh";2282 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2283}2284EOF22852286builder: (finished: must succeed: 2287cat > /tmp/test-drv.nix << 'EOF'2288derivation {2289 name = "post-build-hook-test";2290 system = builtins.currentSystem;2291 builder = "/bin/sh";2292 args = [ "-c" "echo 'hello from post-build-hook test' > $out" ];2293}2294EOF2295, in 0.02 seconds)2296builder: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link2297builder # 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 87 ms (attempt 1/5)2298builder # 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 148 ms (attempt 2/5)2299builder # 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 315 ms (attempt 3/5)2300builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 439 ms (attempt 4/5)2301builder # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org2302builder # this derivation will be built:2303builder # /nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2304builder # building '/nix/store/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv'...2305builder # [ 41.832329] systemd[1]: Started niks3 auto-upload daemon.2306builder # [ 41.956498] niks3-hook[793]: time=2026-10-01T07:33:47.352Z 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=0s2307builder # [ 41.962980] niks3-hook[793]: time=2026-10-01T07:33:47.358Z level=INFO msg="Upload queue status" pending=12308builder # [ 41.965978] niks3-hook[793]: time=2026-10-01T07:33:47.359Z level=INFO msg="Uploading batch" count=12309builder: (finished: must succeed: nix-build --log-format bar-with-logs /tmp/test-drv.nix --no-out-link, in 1.42 seconds)2310builder: waiting for unit niks3-auto-upload.service2311builder # [ 42.044702] systemd[1]: Started Nix Daemon.2312builder: (finished: waiting for unit niks3-auto-upload.service, in 0.10 seconds)2313??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2314 File "/nix/store/iiab4a2pmymr5lc22a6yc0d0fyf3g00n-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392315builder: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive2316??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.2317 File "/nix/store/iiab4a2pmymr5lc22a6yc0d0fyf3g00n-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 392318builder # [ 42.132591] nix-daemon[812]: accepted connection from pid 805, user root (trusted)2319builder # [ 42.158632] nix-daemon[812]: reaped child process 819, status = succeeded2320server # [ 42.164893] niks3-server[966]: 2026/10/01 07:33:47 INFO Received push request method=POST path=/api/pushes2321builder # [ 42.176089] niks3-hook[793]: time=2026-10-01T07:33:47.570Z level=INFO msg="Uploading 1 paths to server (0 already cached)"2322builder # [ 42.177782] niks3-hook[793]: time=2026-10-01T07:33:47.570Z level=INFO msg="Uploading 1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test (144B)"2323server # [ 42.202974] niks3-server[966]: 2026/10/01 07:33:47 INFO Registered completed upload object_key=log/agd1mlaczhjppin104qn9mshm9plkg2x-post-build-hook-test.drv2324builder # [ 42.215676] niks3-hook[793]: time=2026-10-01T07:33:47.610Z level=INFO msg="Uploading 1 narinfos"2325server # [ 42.213373] niks3-server[966]: 2026/10/01 07:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/7/sign2326server # [ 42.215964] niks3-server[966]: 2026/10/01 07:33:47 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.ls2327server # [ 42.229225] niks3-server[966]: 2026/10/01 07:33:47 INFO Signed narinfos id=7 count=12328server # [ 42.231127] niks3-server[966]: 2026/10/01 07:33:47 INFO Received complete push request method=POST path=/api/pushes/7/complete2329builder # [ 42.243039] niks3-hook[793]: time=2026-10-01T07:33:47.638Z level=INFO msg="Upload complete. (280ms)"2330server # [ 42.241223] niks3-server[966]: 2026/10/01 07:33:47 INFO Registered completed upload object_key=nar/1a0vfw93shmvlz6lac7d1lv82jxzfdswigh5s32hpvncf74i1i0y.nar.zst2331server # [ 42.244613] niks3-server[966]: 2026/10/01 07:33:47 INFO Registered completed upload object_key=1qlca7drab1x7rccc3h1pw1fl9c0j7yx.narinfo2332builder # [ 46.963026] niks3-hook[793]: time=2026-10-01T07:33:52.358Z level=INFO msg="Idle timeout reached and queue is empty, shutting down"2333builder # [ 46.966529] niks3-hook[793]: time=2026-10-01T07:33:52.359Z level=INFO msg="niks3-hook serve stopped"2334builder # [ 46.977989] systemd[1]: niks3-auto-upload.service: Deactivated successfully.2335builder # [ 46.982303] systemd[1]: niks3-auto-upload.service: Consumed 164ms CPU time over 5.148s wall clock time, 19.6M memory peak, 68K written to disk, 5.7K incoming IP traffic, 8.5K outgoing IP traffic.2336builder: (finished: waiting for success: test $(systemctl is-active niks3-auto-upload.service) = inactive, in 5.25 seconds)2337server: must succeed: 2338 export AWS_ACCESS_KEY_ID=rustfsadmin2339export AWS_SECRET_ACCESS_KEY=rustfsadmin2340 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-test23412342server # copying 1 paths...2343server # copying path '/nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test' from 's3://niks3-test?endpoint=http://server:9000®ion=us-east-1'...2344server: (finished: must succeed: 2345 export AWS_ACCESS_KEY_ID=rustfsadmin2346export AWS_SECRET_ACCESS_KEY=rustfsadmin2347 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-test2348, in 0.20 seconds)2349server: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2350server: (finished: must succeed: nix --store /tmp/hook-test-store store cat /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test, in 0.08 seconds)2351(finished: run the VM test script, in 48.59 seconds)2352test script finished in 48.68s2353cleanup2354kill QemuMachine (pid 47)2355builder # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/3fl7bdkdxk2k4nssy1d1161isbzn6bsr-python3-3.14.7/bin/python3.14)2356builder # [2026-10-01T07:33:52Z INFO virtiofsd] Client disconnected, shutting down2357builder # [2026-10-01T07:33:52Z INFO virtiofsd] Client disconnected, shutting down2358builder # [2026-10-01T07:33:52Z INFO virtiofsd] Client disconnected, shutting down2359kill QemuMachine (pid 48)2360server # qemu-system-aarch64: terminating on signal 15 from pid 39 (/nix/store/3fl7bdkdxk2k4nssy1d1161isbzn6bsr-python3-3.14.7/bin/python3.14)2361server # [2026-10-01T07:33:53Z INFO virtiofsd] Client disconnected, shutting down2362server # [2026-10-01T07:33:53Z INFO virtiofsd] Client disconnected, shutting down2363server # [2026-10-01T07:33:53Z INFO virtiofsd] Client disconnected, shutting down2364(finished: cleanup, in 0.56 seconds)2365additionally exposed symbols:2366 builder, server,2367 vlan1,2368 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_ssh2369Hello store path: /nix/store/kwhxkl8yn5y8wqiq11jsybagw3fbc4iv-hello-2.12.32370Test output path: /nix/store/z57vvdhnnry9vypazxb33pyi7hsaz71i-test-build-log2371CA derivation output path: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test2372Realisation info in chroot store: /nix/store/5v8l1dc99hcg2ss10dgkivlhwbkpppjh-ca-test23732374Symlink wrapper store path: /nix/store/0caxmbk1mdnhh6zbyh0sz4faqqy5f08r-symlink-wrapper2375Symlink wrapper points to: /nix/store/xafv64bljflg1v8hnf22lyk0w4gma3v5-base-package/bin/test-program2376OIDC test store path: /nix/store/x6bp2ql9fqpj8iqqnnpyn3v0qs5b88gj-oidc-test2377Valid OIDC token obtained (length=677)2378OIDC push with valid token: SUCCESS2379Invalid OIDC token obtained (wrong org)2380OIDC push with wrong org: correctly rejected2381Wrong audience OIDC token obtained2382OIDC push with wrong audience: correctly rejected2383OIDC push with malformed token: correctly rejected2384All OIDC tests passed!2385All pin tests passed!2386Built store path: /nix/store/1qlca7drab1x7rccc3h1pw1fl9c0j7yx-post-build-hook-test2387Post-build-hook pipeline test passed!